Attachment 7528 Details for Bug 8901 – Log file

Log file

volker.log (text/x-log), 160.00 KB, created by Gilles Dufour on 2012-05-07 08:22:01 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Gilles Dufour

Created: 2012-05-07 08:22:01 UTC

Size: 160.00 KB

patch

obsolete

>
>[2012/05/07 10:12:36.352795, 10, pid=13888, effective(500, 500), real(0, 0)] lib/events.c:131(run_events)
>  Running timed event "smbd_idle_event_handler" 0x2ba8c0998cc0
>[2012/05/07 10:12:36.352853, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:683(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(deadtime) (nil) called
>[2012/05/07 10:12:36.352876, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:694(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled
>[2012/05/07 10:12:36.352903, 10, pid=13888, effective(500, 500), real(0, 0)] lib/events.c:131(run_events)
>  Running timed event "smbd_idle_event_handler" 0x2ba8c0998480
>[2012/05/07 10:12:36.352923, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:683(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(housekeeping) (nil) called
>[2012/05/07 10:12:36.352943,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/sec_ctx.c:310(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2012/05/07 10:12:36.352959,  5, pid=13888, effective(500, 500), real(0, 0)] auth/token_util.c:525(debug_nt_user_token)
>  NT user token: (NULL)
>[2012/05/07 10:12:36.352978,  5, pid=13888, effective(500, 500), real(0, 0)] auth/token_util.c:551(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2012/05/07 10:12:36.353007,  5, pid=13888, effective(0, 0), real(0, 0)] smbd/uid.c:369(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2012/05/07 10:12:36.353049, 10, pid=13888, effective(0, 0), real(0, 0)] smbd/process.c:694(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled
>[2012/05/07 10:12:54.928400, 10, pid=13888, effective(0, 0), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 102
>[2012/05/07 10:12:54.928447,  6, pid=13888, effective(0, 0), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x66
>[2012/05/07 10:12:54.928470,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 651 of length 106 (0 toread)
>[2012/05/07 10:12:54.928487,  5, pid=13888, effective(0, 0), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.928501,  5, pid=13888, effective(0, 0), real(0, 0)] lib/util.c:627(show_msg)
>  size=102
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=17922
>  smt_wct=15
>  smb_vwv[ 0]=   34 (0x22)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   34 (0x22)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=37
>[2012/05/07 10:12:54.928652, 10, pid=13888, effective(0, 0), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 EC 03 00 00 00   00 5C 00 54 00 65 00 73   ........ .\.T.e.s
>  [0010] 00 74 00 4E 00 6F 00 74   00 69 00 66 00 47 00 44   .t.N.o.t .i.f.G.D
>  [0020] 00 46 00 00 00                                    .F... 
>[2012/05/07 10:12:54.928728,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:12:54.928751,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/sec_ctx.c:310(set_sec_ctx)
>  setting sec ctx (500, 500) - sec_ctx_stack_ndx = 0
>[2012/05/07 10:12:54.928770,  5, pid=13888, effective(0, 0), real(0, 0)] auth/token_util.c:531(debug_nt_user_token)
>  NT user token of user S-1-5-21-1877780346-3202980130-1748215726-1000
>  contains 8 SIDs
>  SID[  0]: S-1-5-21-1877780346-3202980130-1748215726-1000
>  SID[  1]: S-1-22-2-500
>  SID[  2]: S-1-1-0
>  SID[  3]: S-1-5-2
>  SID[  4]: S-1-5-11
>  SID[  5]: S-1-22-2-1000
>  SID[  6]: S-1-22-2-1001
>  SID[  7]: S-1-22-1-500
>  SE_PRIV  0x0 0x0 0x0 0x0
>[2012/05/07 10:12:54.928839,  5, pid=13888, effective(0, 0), real(0, 0)] auth/token_util.c:551(debug_unix_user_token)
>  UNIX token of user 500
>  Primary group is 500 and contains 3 supplementary groups
>  Group[  0]: 500
>  Group[  1]: 1000
>  Group[  2]: 1001
>[2012/05/07 10:12:54.928917,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:354(change_to_user)
>  change_to_user uid=(0,500) gid=(0,500)
>[2012/05/07 10:12:54.928937,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5099(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
>[2012/05/07 10:12:54.928960,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF"
>[2012/05/07 10:12:54.928977, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:236(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [TESTNOTIFGDF]
>[2012/05/07 10:12:54.928993,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:328(unix_convert)
>  unix_convert begin: name = TestNotifGDF, dirpath = , start = TestNotifGDF
>[2012/05/07 10:12:54.929019,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:138(stat_cache_add)
>  stat_cache_add: Added entry (2ba8c09bb180:size c) TESTNOTIFGDF -> TestNotifGDF
>[2012/05/07 10:12:54.929037,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:351(unix_convert)
>  conversion of base_name finished TestNotifGDF -> TestNotifGDF
>[2012/05/07 10:12:54.929060,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.929086,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.929107,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF] [/mnt/hires]
>[2012/05/07 10:12:54.929129, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF] -> [/mnt/hires/TestNotifGDF]
>[2012/05/07 10:12:54.929151,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF reduced to /mnt/hires/TestNotifGDF
>[2012/05/07 10:12:54.929180, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:926(fetch_share_mode_unlocked)
>  fetch_share_mode_unlocked: no share_mode record around (file not open)
>[2012/05/07 10:12:54.929195,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF (fnum = -1) level=1004 call=5 total_data=0
>[2012/05/07 10:12:54.929216,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF (fnum = -1) level=1004 max_data=40
>[2012/05/07 10:12:54.929232,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF
>[2012/05/07 10:12:54.929253,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:12:54.929272,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.929296,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.929312,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:12:54.929341, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4431(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2012/05/07 10:12:54.929358,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4441(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Mon Apr 23 11:29:50 2012
>   access: Mon Apr 23 11:29:50 2012
>   write: Thu May  3 14:46:16 2012
>   change: Thu May  3 14:46:16 2012
>   mode: 10
>[2012/05/07 10:12:54.929410,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 131010
>[2012/05/07 10:12:54.929437,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2012/05/07 10:12:54.929459,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.929480,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=17922
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2012/05/07 10:12:54.929562, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 3B 7D   A1 33 21 CD 01 00 3B 7D   ......;} .3!...;}
>  [0010] A1 33 21 CD 01 00 9C 9F   BA 2A 29 CD 01 00 9C 9F   .3!..... .*).....
>  [0020] BA 2A 29 CD 01 10 00 00   00 00 00 00 00           .*)..... .....
>[2012/05/07 10:12:54.930920, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 102
>[2012/05/07 10:12:54.930959,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x66
>[2012/05/07 10:12:54.930981,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 652 of length 106 (0 toread)
>[2012/05/07 10:12:54.930994,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.931004,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=102
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=17986
>  smt_wct=15
>  smb_vwv[ 0]=   34 (0x22)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   56 (0x38)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   34 (0x22)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=37
>[2012/05/07 10:12:54.931101, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 0A 04 00 00 00   00 5C 00 54 00 65 00 73   ........ .\.T.e.s
>  [0010] 00 74 00 4E 00 6F 00 74   00 69 00 66 00 47 00 44   .t.N.o.t .i.f.G.D
>  [0020] 00 46 00 00 00                                    .F... 
>[2012/05/07 10:12:54.931152,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:12:54.931167,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:12:54.931194,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5099(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1034
>[2012/05/07 10:12:54.931209,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF"
>[2012/05/07 10:12:54.931231, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF] -> [TestNotifGDF]
>[2012/05/07 10:12:54.931253,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.931270,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.931284,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF] [/mnt/hires]
>[2012/05/07 10:12:54.931325, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF] -> [/mnt/hires/TestNotifGDF]
>[2012/05/07 10:12:54.931339,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF reduced to /mnt/hires/TestNotifGDF
>[2012/05/07 10:12:54.931367, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:926(fetch_share_mode_unlocked)
>  fetch_share_mode_unlocked: no share_mode record around (file not open)
>[2012/05/07 10:12:54.931389,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF (fnum = -1) level=1034 call=5 total_data=0
>[2012/05/07 10:12:54.931404,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF (fnum = -1) level=1034 max_data=56
>[2012/05/07 10:12:54.931418,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF
>[2012/05/07 10:12:54.931431,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:12:54.931444,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.931457,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.931475,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:12:54.931502, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4694(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_NETWORK_OPEN_INFORMATION
>[2012/05/07 10:12:54.931519,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 56, useable_space = 131010
>[2012/05/07 10:12:54.931533,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 56, paramsize = 2, datasize = 56
>[2012/05/07 10:12:54.931546,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.931556,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=116
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=17986
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   56 (0x38)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   56 (0x38)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=61
>[2012/05/07 10:12:54.931637, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 3B 7D   A1 33 21 CD 01 00 3B 7D   ......;} .3!...;}
>  [0010] A1 33 21 CD 01 00 9C 9F   BA 2A 29 CD 01 00 9C 9F   .3!..... .*).....
>  [0020] BA 2A 29 CD 01 00 00 00   00 00 00 00 00 00 00 00   .*)..... ........
>  [0030] 00 00 00 00 00 10 00 00   00 00 00 00 00           ........ .....
>[2012/05/07 10:12:54.933065, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 102
>[2012/05/07 10:12:54.933090,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x66
>[2012/05/07 10:12:54.933104,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 653 of length 106 (0 toread)
>[2012/05/07 10:12:54.933117,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.933126,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=102
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18050
>  smt_wct=15
>  smb_vwv[ 0]=   34 (0x22)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   34 (0x22)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=37
>[2012/05/07 10:12:54.933259, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 EC 03 00 00 00   00 5C 00 54 00 65 00 73   ........ .\.T.e.s
>  [0010] 00 74 00 4E 00 6F 00 74   00 69 00 66 00 47 00 44   .t.N.o.t .i.f.G.D
>  [0020] 00 46 00 00 00                                    .F... 
>[2012/05/07 10:12:54.933310,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:12:54.933324,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:12:54.933338,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5099(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
>[2012/05/07 10:12:54.933352,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF"
>[2012/05/07 10:12:54.933366, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF] -> [TestNotifGDF]
>[2012/05/07 10:12:54.933383,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.933400,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.933413,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF] [/mnt/hires]
>[2012/05/07 10:12:54.933442, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF] -> [/mnt/hires/TestNotifGDF]
>[2012/05/07 10:12:54.933456,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF reduced to /mnt/hires/TestNotifGDF
>[2012/05/07 10:12:54.933479, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:926(fetch_share_mode_unlocked)
>  fetch_share_mode_unlocked: no share_mode record around (file not open)
>[2012/05/07 10:12:54.933493,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF (fnum = -1) level=1004 call=5 total_data=0
>[2012/05/07 10:12:54.933507,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF (fnum = -1) level=1004 max_data=40
>[2012/05/07 10:12:54.933521,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF
>[2012/05/07 10:12:54.933534,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:12:54.933548,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.933560,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.933573,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:12:54.933595, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4431(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2012/05/07 10:12:54.933608,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4441(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Mon Apr 23 11:29:50 2012
>   access: Mon Apr 23 11:29:50 2012
>   write: Thu May  3 14:46:16 2012
>   change: Thu May  3 14:46:16 2012
>   mode: 10
>[2012/05/07 10:12:54.933669,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 131010
>[2012/05/07 10:12:54.933690,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2012/05/07 10:12:54.933704,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.933713,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18050
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2012/05/07 10:12:54.933796, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 3B 7D   A1 33 21 CD 01 00 3B 7D   ......;} .3!...;}
>  [0010] A1 33 21 CD 01 00 9C 9F   BA 2A 29 CD 01 00 9C 9F   .3!..... .*).....
>  [0020] BA 2A 29 CD 01 10 00 00   00 00 00 00 00           .*)..... .....
>[2012/05/07 10:12:54.935061, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 102
>[2012/05/07 10:12:54.935088,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x66
>[2012/05/07 10:12:54.935111,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 654 of length 106 (0 toread)
>[2012/05/07 10:12:54.935124,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.935134,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=102
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18114
>  smt_wct=15
>  smb_vwv[ 0]=   34 (0x22)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   56 (0x38)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   34 (0x22)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=37
>[2012/05/07 10:12:54.935234, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 0A 04 00 00 00   00 5C 00 54 00 65 00 73   ........ .\.T.e.s
>  [0010] 00 74 00 4E 00 6F 00 74   00 69 00 66 00 47 00 44   .t.N.o.t .i.f.G.D
>  [0020] 00 46 00 00 00                                    .F... 
>[2012/05/07 10:12:54.935289,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:12:54.935303,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:12:54.935317,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5099(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1034
>[2012/05/07 10:12:54.935332,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF"
>[2012/05/07 10:12:54.935346, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF] -> [TestNotifGDF]
>[2012/05/07 10:12:54.935363,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.935398,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.935422,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF] [/mnt/hires]
>[2012/05/07 10:12:54.935450, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF] -> [/mnt/hires/TestNotifGDF]
>[2012/05/07 10:12:54.935475,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF reduced to /mnt/hires/TestNotifGDF
>[2012/05/07 10:12:54.935493, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:926(fetch_share_mode_unlocked)
>  fetch_share_mode_unlocked: no share_mode record around (file not open)
>[2012/05/07 10:12:54.935506,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF (fnum = -1) level=1034 call=5 total_data=0
>[2012/05/07 10:12:54.935521,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF (fnum = -1) level=1034 max_data=56
>[2012/05/07 10:12:54.935535,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF
>[2012/05/07 10:12:54.935548,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:12:54.935561,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.935574,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.935587,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:12:54.935602, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4694(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_NETWORK_OPEN_INFORMATION
>[2012/05/07 10:12:54.935624,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 56, useable_space = 131010
>[2012/05/07 10:12:54.935638,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 56, paramsize = 2, datasize = 56
>[2012/05/07 10:12:54.935652,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.935661,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=116
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18114
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   56 (0x38)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   56 (0x38)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=61
>[2012/05/07 10:12:54.935743, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 3B 7D   A1 33 21 CD 01 00 3B 7D   ......;} .3!...;}
>  [0010] A1 33 21 CD 01 00 9C 9F   BA 2A 29 CD 01 00 9C 9F   .3!..... .*).....
>  [0020] BA 2A 29 CD 01 00 00 00   00 00 00 00 00 00 00 00   .*)..... ........
>  [0030] 00 00 00 00 00 10 00 00   00 00 00 00 00           ........ .....
>[2012/05/07 10:12:54.937150, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 112
>[2012/05/07 10:12:54.937177,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x70
>[2012/05/07 10:12:54.937191,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 655 of length 116 (0 toread)
>[2012/05/07 10:12:54.937222,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.937232,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=112
>  smb_com=0xa2
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18178
>  smt_wct=24
>  smb_vwv[ 0]=  255 (0xFF)
>  smb_vwv[ 1]=57054 (0xDEDE)
>  smb_vwv[ 2]= 6656 (0x1A00)
>  smb_vwv[ 3]= 5632 (0x1600)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=33024 (0x8100)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_vwv[10]=    0 (0x0)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    0 (0x0)
>  smb_vwv[14]=    0 (0x0)
>  smb_vwv[15]= 1792 (0x700)
>  smb_vwv[16]=    0 (0x0)
>  smb_vwv[17]=  256 (0x100)
>  smb_vwv[18]=    0 (0x0)
>  smb_vwv[19]=    0 (0x0)
>  smb_vwv[20]=    0 (0x0)
>  smb_vwv[21]=  512 (0x200)
>  smb_vwv[22]=    0 (0x0)
>  smb_vwv[23]=  768 (0x300)
>  smb_bcc=29
>[2012/05/07 10:12:54.937374, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 5C 00 54 00 65 00 73   00 74 00 4E 00 6F 00 74   .\.T.e.s .t.N.o.t
>  [0010] 00 69 00 66 00 47 00 44   00 46 00 00 00           .i.f.G.D .F...
>[2012/05/07 10:12:54.937414,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBntcreateX (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:12:54.937438,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:12:54.937462, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/nttrans.c:498(reply_ntcreate_and_X)
>  reply_ntcreate_and_X: flags = 0x16, access_mask = 0x81 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 root_dir_fid = 0x0, fname = TestNotifGDF
>[2012/05/07 10:12:54.937485,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF"
>[2012/05/07 10:12:54.937499, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF] -> [TestNotifGDF]
>[2012/05/07 10:12:54.937516,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.937534,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.937547,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF] [/mnt/hires]
>[2012/05/07 10:12:54.937575, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF] -> [/mnt/hires/TestNotifGDF]
>[2012/05/07 10:12:54.937590,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF reduced to /mnt/hires/TestNotifGDF
>[2012/05/07 10:12:54.937613, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:3407(create_file_default)
>  create_file: access_mask = 0x81 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x3 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = TestNotifGDF
>[2012/05/07 10:12:54.937632,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.937660,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.937673,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF] [/mnt/hires]
>[2012/05/07 10:12:54.937700, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF] -> [/mnt/hires/TestNotifGDF]
>[2012/05/07 10:12:54.937735,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF reduced to /mnt/hires/TestNotifGDF
>[2012/05/07 10:12:54.937758, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:2925(create_file_unixpath)
>  create_file_unixpath: access_mask = 0x81 file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x3 ea_list = 0x(nil), sd = 0x(nil), fname = TestNotifGDF
>[2012/05/07 10:12:54.937793,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/files.c:119(file_new)
>  allocated file structure 13822, fnum = 17918 (1 used)
>[2012/05/07 10:12:54.937816,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:166(unix_mode)
>  unix_mode(TestNotifGDF) returning 0664
>[2012/05/07 10:12:54.937833, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1523(open_file_ntcreate)
>  open_file_ntcreate: fname=TestNotifGDF, dos_attrs=0x0 access_mask=0x81 share_access=0x7 create_disposition = 0x1 create_options=0x0 unix mode=0664 oplock_request=3
>[2012/05/07 10:12:54.937852,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.937870,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.937883,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF] [/mnt/hires]
>[2012/05/07 10:12:54.937911, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF] -> [/mnt/hires/TestNotifGDF]
>[2012/05/07 10:12:54.937925,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF reduced to /mnt/hires/TestNotifGDF
>[2012/05/07 10:12:54.937939,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF
>[2012/05/07 10:12:54.937952,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:12:54.937966,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.937987,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.938000,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:12:54.938023, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1705(open_file_ntcreate)
>  open_file_ntcreate: fname=TestNotifGDF, after mapping access_mask=0x81
>[2012/05/07 10:12:54.938046, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
>  Locking key 01FC00000000000075F0
>[2012/05/07 10:12:54.938068, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
>  Allocated locked data 0x0x2ba8c09ad570
>[2012/05/07 10:12:54.938091, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1031(delay_for_oplocks)
>  delay_for_oplocks: oplock type 0x3 on file TestNotifGDF
>[2012/05/07 10:12:54.938115, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1031(delay_for_oplocks)
>  delay_for_oplocks: oplock type 0x3 on file TestNotifGDF
>[2012/05/07 10:12:54.938130,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1967(open_file_ntcreate)
>  calling open_file with flags=0x0 flags2=0x0 mode=0664, access_mask = 0x81, open_access_mask = 0x81
>[2012/05/07 10:12:54.938161, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:167(fd_open)
>  fd_open: name TestNotifGDF, flags = 00 mode = 0664, fd = 29. 
>[2012/05/07 10:12:54.938180, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/posix.c:512(get_windows_lock_ref_count)
>  get_windows_lock_count for file TestNotifGDF = 0
>[2012/05/07 10:12:54.938200, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/posix.c:538(delete_windows_lock_ref_count)
>  delete_windows_lock_ref_count for file TestNotifGDF
>[2012/05/07 10:12:54.938233, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
>  Unlocking key 01FC00000000000075F0
>[2012/05/07 10:12:54.938268,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/files.c:497(file_free)
>  freed files structure 17918 (0 used)
>[2012/05/07 10:12:54.938293,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:2447(open_directory)
>  open_directory: opening directory TestNotifGDF, access_mask = 0x81, share_access = 0x7 create_options = 0x0, create_disposition = 0x1, file_attributes = 0x0
>[2012/05/07 10:12:54.938322, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:3479(posix_get_nt_acl)
>  posix_get_nt_acl: called for file TestNotifGDF
>[2012/05/07 10:12:54.938374, 10, pid=13888, effective(500, 500), real(0, 0), class=tdb] lib/gencache.c:334(gencache_get_data_blob)
>  Cache entry with key = IDMAP/UID2SID/500 couldn't be found 
>[2012/05/07 10:12:54.938412,  5, pid=13888, effective(500, 500), real(0, 0)] passdb/lookup_sid.c:1334(uid_to_sid)
>  uid_to_sid: winbind failed to find a sid for uid 500
>[2012/05/07 10:12:54.938430,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/sec_ctx.c:210(push_sec_ctx)
>  push_sec_ctx(500, 500) : sec_ctx_stack_ndx = 1
>[2012/05/07 10:12:54.938452,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:429(push_conn_ctx)
>  push_conn_ctx(100) : conn_ctx_stack_ndx = 0
>[2012/05/07 10:12:54.938473,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/sec_ctx.c:310(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2012/05/07 10:12:54.938493,  5, pid=13888, effective(500, 500), real(0, 0)] auth/token_util.c:525(debug_nt_user_token)
>  NT user token: (NULL)
>[2012/05/07 10:12:54.938505,  5, pid=13888, effective(500, 500), real(0, 0)] auth/token_util.c:551(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2012/05/07 10:12:54.938634,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/sec_ctx.c:210(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
>[2012/05/07 10:12:54.938659,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/uid.c:429(push_conn_ctx)
>  push_conn_ctx(100) : conn_ctx_stack_ndx = 1
>[2012/05/07 10:12:54.938673,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/sec_ctx.c:310(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2012/05/07 10:12:54.938686,  5, pid=13888, effective(0, 0), real(0, 0)] auth/token_util.c:525(debug_nt_user_token)
>  NT user token: (NULL)
>[2012/05/07 10:12:54.938709,  5, pid=13888, effective(0, 0), real(0, 0)] auth/token_util.c:551(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2012/05/07 10:12:54.938769, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:608(pdb_set_username)
>  pdb_set_username: setting username dvb, was 
>[2012/05/07 10:12:54.938786, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:631(pdb_set_domain)
>  pdb_set_domain: setting domain MEDIASRV04, was 
>[2012/05/07 10:12:54.938804, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:654(pdb_set_nt_username)
>  pdb_set_nt_username: setting nt username , was 
>[2012/05/07 10:12:54.938827, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:677(pdb_set_fullname)
>  pdb_set_full_name: setting full name , was 
>[2012/05/07 10:12:54.938846,  4, pid=13888, effective(0, 0), real(0, 0)] lib/substitute.c:504(automount_server)
>  Home server: mediasrv04
>[2012/05/07 10:12:54.938870, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:770(pdb_set_homedir)
>  pdb_set_homedir: setting home dir \\mediasrv04\dvb, was 
>[2012/05/07 10:12:54.938889, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:746(pdb_set_dir_drive)
>  pdb_set_dir_drive: setting dir drive , was NULL
>[2012/05/07 10:12:54.938915, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:700(pdb_set_logon_script)
>  pdb_set_logon_script: setting logon script , was 
>[2012/05/07 10:12:54.938933,  4, pid=13888, effective(0, 0), real(0, 0)] lib/substitute.c:504(automount_server)
>  Home server: mediasrv04
>[2012/05/07 10:12:54.938962, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:723(pdb_set_profile_path)
>  pdb_set_profile_path: setting profile path \\mediasrv04\dvb\profile, was 
>[2012/05/07 10:12:54.938985, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:813(pdb_set_workstations)
>  pdb_set_workstations: setting workstations , was 
>[2012/05/07 10:12:54.939004,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/sec_ctx.c:210(push_sec_ctx)
>  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3
>[2012/05/07 10:12:54.939023,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/uid.c:429(push_conn_ctx)
>  push_conn_ctx(100) : conn_ctx_stack_ndx = 2
>[2012/05/07 10:12:54.939040,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/sec_ctx.c:310(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3
>[2012/05/07 10:12:54.939064,  5, pid=13888, effective(0, 0), real(0, 0)] auth/token_util.c:525(debug_nt_user_token)
>  NT user token: (NULL)
>[2012/05/07 10:12:54.939089,  5, pid=13888, effective(0, 0), real(0, 0)] auth/token_util.c:551(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2012/05/07 10:12:54.939139, 10, pid=13888, effective(0, 0), real(0, 0)] lib/account_pol.c:333(account_policy_get)
>  account_policy_get: name: password history, val: 0
>[2012/05/07 10:12:54.939160,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/sec_ctx.c:418(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2
>[2012/05/07 10:12:54.939190, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_get_set.c:537(pdb_set_user_sid)
>  pdb_set_user_sid: setting user sid S-1-5-21-1877780346-3202980130-1748215726-1000
>[2012/05/07 10:12:54.939210, 10, pid=13888, effective(0, 0), real(0, 0), class=passdb] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid)
>  pdb_set_user_sid_from_rid:
>  	setting user sid S-1-5-21-1877780346-3202980130-1748215726-1000 from rid 1000
>[2012/05/07 10:12:54.939241,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/sec_ctx.c:418(pop_sec_ctx)
>  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
>[2012/05/07 10:12:54.939271,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/sec_ctx.c:418(pop_sec_ctx)
>  pop_sec_ctx (500, 500) - sec_ctx_stack_ndx = 0
>[2012/05/07 10:12:54.939289, 10, pid=13888, effective(500, 500), real(0, 0)] passdb/lookup_sid.c:1151(legacy_uid_to_sid)
>  LEGACY: uid 500 -> sid S-1-5-21-1877780346-3202980130-1748215726-1000
>[2012/05/07 10:12:54.939324, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:2605(canonicalise_acl)
>  canonicalise_acl: Access ace entries before arrange :
>[2012/05/07 10:12:54.939345, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:2618(canonicalise_acl)
>  canon_ace index 0. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x
>[2012/05/07 10:12:54.939374, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:2618(canonicalise_acl)
>  canon_ace index 1. Type = allow SID = S-1-22-2-1001 gid 1001 (hires_rw) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>[2012/05/07 10:12:54.939459, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:2618(canonicalise_acl)
>  canon_ace index 2. Type = allow SID = S-1-5-21-1877780346-3202980130-1748215726-1000 uid 500 (dvb) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>[2012/05/07 10:12:54.939555, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:841(print_canon_ace_list)
>  print_canon_ace_list: canonicalise_acl: ace entries after arrange
>  canon_ace index 0. Type = allow SID = S-1-5-21-1877780346-3202980130-1748215726-1000 uid 500 (dvb) SMB_ACL_USER_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 1. Type = allow SID = S-1-22-2-1001 gid 1001 (hires_rw) SMB_ACL_GROUP_OBJ ace_flags = 0x0 perms rwx
>  canon_ace index 2. Type = allow SID = S-1-1-0 other SMB_ACL_OTHER ace_flags = 0x0 perms r-x
>[2012/05/07 10:12:54.939713, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:1117(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
>[2012/05/07 10:12:54.939733, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:1117(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 1c0 to (NT) 1f01ff
>[2012/05/07 10:12:54.939747, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/posix_acls.c:1117(map_canon_ace_perms)
>  map_canon_ace_perms: Mapped (UNIX) 140 to (NT) 1200a9
>[2012/05/07 10:12:54.939775, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:110(smbd_check_open_rights)
>  smbd_check_open_rights: file TestNotifGDF requesting 0x81 returning 0x1 (NT_STATUS_OK)
>[2012/05/07 10:12:54.939800,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/files.c:119(file_new)
>  allocated file structure 13823, fnum = 17919 (1 used)
>[2012/05/07 10:12:54.939831, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
>  Locking key 01FC00000000000075F0
>[2012/05/07 10:12:54.939859, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
>  Allocated locked data 0x0x2ba8c09b0f90
>[2012/05/07 10:12:54.939894, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:726(unparse_share_modes)
>  unparse_share_modes: del: 0, owrt: Thu 03 May 2012 02:46:17 PM CEST CEST cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num: 1
>[2012/05/07 10:12:54.939962, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:518(print_share_mode_table)
>  print_share_mode_table: share_mode_entry[0]:  pid = 13888, share_access = 0x7, private_options = 0x0, access_mask = 0x81, mid = 0x0, type= 0x0, gen_id = 8, uid = 500, flags = 0, file_id fc01:11f075:0
>[2012/05/07 10:12:54.940024, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
>  Unlocking key 01FC00000000000075F0
>[2012/05/07 10:12:54.940054, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:3232(create_file_unixpath)
>  create_file_unixpath: info=1
>[2012/05/07 10:12:54.940074, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:3478(create_file_default)
>  create_file: info=1
>[2012/05/07 10:12:54.940088,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF
>[2012/05/07 10:12:54.940111,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:12:54.940126,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.940139,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.940152,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:12:54.940182, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Thu 03 May 2012 02:46:17 PM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:12:54.940254, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x7, private_options = 0x0, access_mask = 0x81, mid = 0x0, type= 0x0, gen_id = 8, uid = 500, flags = 0, file_id fc01:11f075:0
>[2012/05/07 10:12:54.940298,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/nttrans.c:722(reply_ntcreate_and_X)
>  reply_ntcreate_and_X: fnum = 17919, open name = TestNotifGDF
>[2012/05/07 10:12:54.941642, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 72
>[2012/05/07 10:12:54.941686,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x48
>[2012/05/07 10:12:54.941701,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 656 of length 76 (0 toread)
>[2012/05/07 10:12:54.941714,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.941723,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=72
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18242
>  smt_wct=15
>  smb_vwv[ 0]=    4 (0x4)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=    8 (0x8)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    4 (0x4)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    7 (0x7)
>  smb_bcc=7
>[2012/05/07 10:12:54.941824, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 FF 45 EE 03                              ....E.. 
>[2012/05/07 10:12:54.941857,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:12:54.941871,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:12:54.941896,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5012(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1006
>[2012/05/07 10:12:54.941923, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Thu 03 May 2012 02:46:17 PM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:12:54.941970, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x7, private_options = 0x0, access_mask = 0x81, mid = 0x0, type= 0x0, gen_id = 8, uid = 500, flags = 0, file_id fc01:11f075:0
>[2012/05/07 10:12:54.941995,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF (fnum = 17919) level=1006 call=7 total_data=0
>[2012/05/07 10:12:54.942010,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF (fnum = 17919) level=1006 max_data=8
>[2012/05/07 10:12:54.942024,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF
>[2012/05/07 10:12:54.942037,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:12:54.942059,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.942072,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.942085,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:12:54.942111, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4594(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_INTERNAL_INFORMATION
>[2012/05/07 10:12:54.942133,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 8, useable_space = 131010
>[2012/05/07 10:12:54.942147,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 8, paramsize = 2, datasize = 8
>[2012/05/07 10:12:54.942161,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.942188,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=68
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18242
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=    8 (0x8)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    8 (0x8)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=13
>[2012/05/07 10:12:54.942283, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 75 F0 11   00 00 00 00 00           .....u.. .....
>[2012/05/07 10:12:54.943447, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 72
>[2012/05/07 10:12:54.943470,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x48
>[2012/05/07 10:12:54.943484,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 657 of length 76 (0 toread)
>[2012/05/07 10:12:54.943497,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.943506,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=72
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18306
>  smt_wct=15
>  smb_vwv[ 0]=    4 (0x4)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   24 (0x18)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    4 (0x4)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    7 (0x7)
>  smb_bcc=7
>[2012/05/07 10:12:54.943606, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 FF 45 ED 03                              ....E.. 
>[2012/05/07 10:12:54.943628,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:12:54.943641,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:12:54.943655,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5012(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005
>[2012/05/07 10:12:54.943679, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Thu 03 May 2012 02:46:17 PM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:12:54.943725, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x7, private_options = 0x0, access_mask = 0x81, mid = 0x0, type= 0x0, gen_id = 8, uid = 500, flags = 0, file_id fc01:11f075:0
>[2012/05/07 10:12:54.943740,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF (fnum = 17919) level=1005 call=7 total_data=0
>[2012/05/07 10:12:54.943755,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF (fnum = 17919) level=1005 max_data=24
>[2012/05/07 10:12:54.943769,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF
>[2012/05/07 10:12:54.943782,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:12:54.943796,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF
>[2012/05/07 10:12:54.943828,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:12:54.943841,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:12:54.943857, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4452(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_STANDARD_INFORMATION
>[2012/05/07 10:12:54.943880,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 24, useable_space = 131010
>[2012/05/07 10:12:54.943894,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 24, paramsize = 2, datasize = 24
>[2012/05/07 10:12:54.943908,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.943917,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=84
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18306
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   24 (0x18)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   24 (0x18)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=29
>[2012/05/07 10:12:54.944000, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 00 00   00 00 00 00 00 00 00 00   ........ ........
>  [0010] 00 00 00 00 00 01 00 00   00 00 01 00 00           ........ .....
>[2012/05/07 10:12:54.945286, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 84
>[2012/05/07 10:12:54.945313,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x54
>[2012/05/07 10:12:54.945326,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 658 of length 88 (0 toread)
>[2012/05/07 10:12:54.945340,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:12:54.945349,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=84
>  smb_com=0xa0
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=2488
>  smb_uid=100
>  smb_mid=18370
>  smt_wct=23
>  smb_vwv[ 0]=    0 (0x0)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    0 (0x0)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   32 (0x20)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_vwv[10]=    0 (0x0)
>  smb_vwv[11]=21504 (0x5400)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    0 (0x0)
>  smb_vwv[14]=    0 (0x0)
>  smb_vwv[15]=    0 (0x0)
>  smb_vwv[16]=    0 (0x0)
>  smb_vwv[17]= 1024 (0x400)
>  smb_vwv[18]=    4 (0x4)
>  smb_vwv[19]=   19 (0x13)
>  smb_vwv[20]=    0 (0x0)
>  smb_vwv[21]=17919 (0x45FF)
>  smb_vwv[22]=    1 (0x1)
>  smb_bcc=3
>[2012/05/07 10:12:54.945487, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00                                          ... 
>[2012/05/07 10:12:54.945517,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBnttrans (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:12:54.945531,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:12:54.945555, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/nttrans.c:2832(reply_nttrans)
>  num_setup=8, param_total=0, this_param=0, max_param=8192, data_total=0, this_data=0, max_data=0, param_offset=84, data_offset=0
>[2012/05/07 10:12:54.945575, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/nttrans.c:2904(reply_nttrans)
>  reply_nttrans: state->setup_count = 8
>[2012/05/07 10:12:54.945598, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 13 00 00 00 FF 45 01 00                            .....E.. 
>[2012/05/07 10:12:54.945626,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/nttrans.c:1606(call_nt_transact_notify_change)
>  call_nt_transact_notify_change
>[2012/05/07 10:12:54.945647,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/nttrans.c:1623(call_nt_transact_notify_change)
>  call_nt_transact_notify_change: notify change called on TestNotifGDF, filter = FILE_NAME|DIR_NAME|LAST_WRITE, recursive = 1
>[2012/05/07 10:12:54.945676, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
>  Locking key 6E6F7469667920617272
>[2012/05/07 10:12:54.945705, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
>  Allocated locked data 0x0x2ba8c09ace20
>[2012/05/07 10:12:54.945732, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/notify_internal.c:189(notify_load)
>  notify_load:
>[2012/05/07 10:12:54.945752,  1, pid=13888, effective(500, 500), real(0, 0)] ../librpc/ndr/ndr.c:214(ndr_print_debug)
>       notify->array: struct notify_array
>          num_depths               : 0x00000000 (0)
>          depth: ARRAY(0)
>[2012/05/07 10:12:54.945797, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/notify_inotify.c:426(inotify_watch)
>  inotify_add_watch for /mnt/hires/TestNotifGDF mask 210003c4 returned wd 2
>[2012/05/07 10:12:54.945827, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/notify_internal.c:243(notify_save)
>  notify_save:
>[2012/05/07 10:12:54.945845,  1, pid=13888, effective(500, 500), real(0, 0)] ../librpc/ndr/ndr.c:214(ndr_print_debug)
>       notify->array: struct notify_array
>          num_depths               : 0x00000004 (4)
>          depth: ARRAY(4)
>              depth: struct notify_depth
>                  max_mask                 : 0x00000000 (0)
>                  max_mask_subdir          : 0x00000000 (0)
>                  num_entries              : 0x00000000 (0)
>                  entries: ARRAY(0)
>              depth: struct notify_depth
>                  max_mask                 : 0x00000000 (0)
>                  max_mask_subdir          : 0x00000000 (0)
>                  num_entries              : 0x00000000 (0)
>                  entries: ARRAY(0)
>              depth: struct notify_depth
>                  max_mask                 : 0x00000000 (0)
>                  max_mask_subdir          : 0x00000000 (0)
>                  num_entries              : 0x00000000 (0)
>                  entries: ARRAY(0)
>              depth: struct notify_depth
>                  max_mask                 : 0x00000000 (0)
>                  max_mask_subdir          : 0x00000013 (19)
>                  num_entries              : 0x00000001 (1)
>                  entries: ARRAY(1)
>                      entries: struct notify_entry
>                          server: struct server_id
>                              id                       : 0x00003640 (13888)
>                              vnn                      : 0xffffffff (4294967295)
>                          filter                   : 0x00000000 (0)
>                          subdir_filter            : 0x00000013 (19)
>                          dir_fd                   : 0xffffffff (4294967295)
>                          dir_id: struct file_id
>                              devid                    : 0x000000000000fc01 (64513)
>                              inode                    : 0x000000000011f075 (1175669)
>                              extid                    : 0x0000000000000000 (0)
>                          path                     : '/mnt/hires/TestNotifGDF'
>                          path_len                 : 0x00000017 (23)
>                          private_data             : 0x2ba8c09b6620
>[2012/05/07 10:12:54.946166, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
>  Unlocking key 6E6F7469667920617272
>[2012/05/07 10:12:54.946196, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/notify.c:250(change_notify_add_request)
>  change_notify_add_request: Adding request for TestNotifGDF: max_param = 8192
>[2012/05/07 10:13:06.752560, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 166
>[2012/05/07 10:13:06.752605,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0xa6
>[2012/05/07 10:13:06.752625,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 659 of length 170 (0 toread)
>[2012/05/07 10:13:06.752649,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.752664,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=166
>  smb_com=0xa2
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18433
>  smt_wct=24
>  smb_vwv[ 0]=  255 (0xFF)
>  smb_vwv[ 1]=57054 (0xDEDE)
>  smb_vwv[ 2]=20480 (0x5000)
>  smb_vwv[ 3]= 5632 (0x1600)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=40704 (0x9F00)
>  smb_vwv[ 8]=  513 (0x201)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_vwv[10]=    0 (0x0)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=32768 (0x8000)
>  smb_vwv[14]=    0 (0x0)
>  smb_vwv[15]=  256 (0x100)
>  smb_vwv[16]=    0 (0x0)
>  smb_vwv[17]=  768 (0x300)
>  smb_vwv[18]=    0 (0x0)
>  smb_vwv[19]=16384 (0x4000)
>  smb_vwv[20]=    0 (0x0)
>  smb_vwv[21]=  512 (0x200)
>  smb_vwv[22]=    0 (0x0)
>  smb_vwv[23]=  768 (0x300)
>  smb_bcc=83
>[2012/05/07 10:13:06.752858, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 5C 00 54 00 65 00 73   00 74 00 4E 00 6F 00 74   .\.T.e.s .t.N.o.t
>  [0010] 00 69 00 66 00 47 00 44   00 46 00 5C 00 44 00 69   .i.f.G.D .F.\.D.i
>  [0020] 00 72 00 65 00 63 00 74   00 6F 00 72 00 79 00 31   .r.e.c.t .o.r.y.1
>  [0030] 00 5C 00 67 00 64 00 66   00 5C 00 76 00 6F 00 6C   .\.g.d.f .\.v.o.l
>  [0040] 00 6B 00 65 00 72 00 31   00 2E 00 74 00 78 00 74   .k.e.r.1 ...t.x.t
>  [0050] 00 00 00                                          ... 
>[2012/05/07 10:13:06.752993,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBntcreateX (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.753014,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.753039, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/nttrans.c:498(reply_ntcreate_and_X)
>  reply_ntcreate_and_X: flags = 0x16, access_mask = 0x2019f file_attributes = 0x80, share_access = 0x1, create_disposition = 0x3 create_options = 0x40 root_dir_fid = 0x0, fname = TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753065,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF/Directory1/gdf/volker1.txt"
>[2012/05/07 10:13:06.753084, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:236(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [TESTNOTIFGDF/DIRECTORY1/GDF/VOLKER1.TXT]
>[2012/05/07 10:13:06.753104, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:236(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [TESTNOTIFGDF/DIRECTORY1/GDF]
>[2012/05/07 10:13:06.753121, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:236(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [TESTNOTIFGDF/DIRECTORY1]
>[2012/05/07 10:13:06.753139, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF] -> [TestNotifGDF]
>[2012/05/07 10:13:06.753167,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:328(unix_convert)
>  unix_convert begin: name = TestNotifGDF/Directory1/gdf/volker1.txt, dirpath = TestNotifGDF, start = Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753198,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:138(stat_cache_add)
>  stat_cache_add: Added entry (2ba8c09bcc10:size 27) TESTNOTIFGDF/DIRECTORY1/GDF/VOLKER1.TXT -> TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753233,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:351(unix_convert)
>  conversion of base_name finished TestNotifGDF/Directory1/gdf/volker1.txt -> TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753251,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753277,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.753297,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF/Directory1/gdf/volker1.txt] [/mnt/hires]
>[2012/05/07 10:13:06.753331, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF/Directory1/gdf/volker1.txt] -> [/mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.753357,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF/Directory1/gdf/volker1.txt reduced to /mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753382, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:3407(create_file_default)
>  create_file: access_mask = 0x2019f file_attributes = 0x80, share_access = 0x1, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x3 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), fname = TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753404,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753428,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.753445,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF/Directory1/gdf/volker1.txt] [/mnt/hires]
>[2012/05/07 10:13:06.753493, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF/Directory1/gdf/volker1.txt] -> [/mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.753510,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF/Directory1/gdf/volker1.txt reduced to /mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753527, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:2925(create_file_unixpath)
>  create_file_unixpath: access_mask = 0x2019f file_attributes = 0x80, share_access = 0x1, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x3 ea_list = 0x(nil), sd = 0x(nil), fname = TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753563,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/files.c:119(file_new)
>  allocated file structure 13824, fnum = 17920 (2 used)
>[2012/05/07 10:13:06.753584,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:166(unix_mode)
>  unix_mode(TestNotifGDF/Directory1/gdf/volker1.txt) returning 0664
>[2012/05/07 10:13:06.753602, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1523(open_file_ntcreate)
>  open_file_ntcreate: fname=TestNotifGDF/Directory1/gdf/volker1.txt, dos_attrs=0x80 access_mask=0x2019f share_access=0x1 create_disposition = 0x3 create_options=0x40 unix mode=0664 oplock_request=3
>[2012/05/07 10:13:06.753625,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753643,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.753667,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF/Directory1/gdf/volker1.txt] [/mnt/hires]
>[2012/05/07 10:13:06.753704, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF/Directory1/gdf/volker1.txt] -> [/mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.753719,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF/Directory1/gdf/volker1.txt reduced to /mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753744,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753769,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.753799,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753818,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.753831,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.753862, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1705(open_file_ntcreate)
>  open_file_ntcreate: fname=TestNotifGDF/Directory1/gdf/volker1.txt, after mapping access_mask=0x2019f
>[2012/05/07 10:13:06.753888, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
>  Locking key 01FC000000000000BCF0
>[2012/05/07 10:13:06.753915, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
>  Allocated locked data 0x0x2ba8c09acfc0
>[2012/05/07 10:13:06.753941, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1031(delay_for_oplocks)
>  delay_for_oplocks: oplock type 0x3 on file TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753959, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1031(delay_for_oplocks)
>  delay_for_oplocks: oplock type 0x3 on file TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.753984,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:1967(open_file_ntcreate)
>  calling open_file with flags=0x2 flags2=0x40 mode=0664, access_mask = 0x2019f, open_access_mask = 0x2019f
>[2012/05/07 10:13:06.754194, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:167(fd_open)
>  fd_open: name TestNotifGDF/Directory1/gdf/volker1.txt, flags = 0102 mode = 0664, fd = 29. 
>[2012/05/07 10:13:06.754217,  2, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:631(open_file)
>  dvb opened file TestNotifGDF/Directory1/gdf/volker1.txt read=Yes write=Yes (numopen=2)
>[2012/05/07 10:13:06.754260,  3, pid=13888, effective(500, 500), real(0, 0), class=locking] smbd/oplock_linux.c:127(linux_set_kernel_oplock)
>  linux_set_kernel_oplock: got kernel oplock on file TestNotifGDF/Directory1/gdf/volker1.txt, file_id = fc01:11f0bc:0 gen_id = 9
>[2012/05/07 10:13:06.754282,  5, pid=13888, effective(500, 500), real(0, 0), class=locking] smbd/oplock.c:86(set_file_oplock)
>  set_file_oplock: granted oplock on file TestNotifGDF/Directory1/gdf/volker1.txt, fc01:11f0bc:0/9, tv_sec = 4fa78412, tv_usec = b7f97
>[2012/05/07 10:13:06.754310, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:726(unparse_share_modes)
>  unparse_share_modes: del: 0, owrt: Mon 07 May 2012 10:10:11 AM CEST CEST cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num: 1
>[2012/05/07 10:13:06.754383, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:518(print_share_mode_table)
>  print_share_mode_table: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.754437, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
>  Unlocking key 01FC000000000000BCF0
>[2012/05/07 10:13:06.754471, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:3232(create_file_unixpath)
>  create_file_unixpath: info=1
>[2012/05/07 10:13:06.754487, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/open.c:3478(create_file_default)
>  create_file: info=1
>[2012/05/07 10:13:06.754519,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.754547,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.754561,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.754574,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.754587,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.754616, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:10:11 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.754688, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.754721, 10, pid=13888, effective(500, 500), real(0, 0), class=acls] smbd/file_access.c:185(can_access_file_data)
>  can_access_file_data: requesting 0x2 on file TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.754741,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/nttrans.c:722(reply_ntcreate_and_X)
>  reply_ntcreate_and_X: fnum = 17920, open name = TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.755907, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 72
>[2012/05/07 10:13:06.755937,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x48
>[2012/05/07 10:13:06.755951,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 660 of length 76 (0 toread)
>[2012/05/07 10:13:06.755964,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.755974,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=72
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18497
>  smt_wct=15
>  smb_vwv[ 0]=    4 (0x4)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=    8 (0x8)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    4 (0x4)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    7 (0x7)
>  smb_bcc=7
>[2012/05/07 10:13:06.756073, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 46 EE 03                              ....F.. 
>[2012/05/07 10:13:06.756113,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.756137,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.756161,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5012(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1006
>[2012/05/07 10:13:06.756198, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:10:11 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.756257, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.756273,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF/Directory1/gdf/volker1.txt (fnum = 17920) level=1006 call=7 total_data=0
>[2012/05/07 10:13:06.756302,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF/Directory1/gdf/volker1.txt (fnum = 17920) level=1006 max_data=8
>[2012/05/07 10:13:06.756325,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.756343,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.756357,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.756370,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.756382,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.756408, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4594(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_INTERNAL_INFORMATION
>[2012/05/07 10:13:06.756423,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 8, useable_space = 131010
>[2012/05/07 10:13:06.756440,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 8, paramsize = 2, datasize = 8
>[2012/05/07 10:13:06.756462,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.756479,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=68
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18497
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=    8 (0x8)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    8 (0x8)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=13
>[2012/05/07 10:13:06.756562, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 BC F0 11   00 00 00 00 00           ........ .....
>[2012/05/07 10:13:06.757698, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 72
>[2012/05/07 10:13:06.757727,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x48
>[2012/05/07 10:13:06.757747,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 661 of length 76 (0 toread)
>[2012/05/07 10:13:06.757760,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.757769,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=72
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18561
>  smt_wct=15
>  smb_vwv[ 0]=    4 (0x4)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    4 (0x4)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    7 (0x7)
>  smb_bcc=7
>[2012/05/07 10:13:06.757885, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 46 EC 03                              ....F.. 
>[2012/05/07 10:13:06.757907,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.757920,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.757935,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5012(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
>[2012/05/07 10:13:06.757957, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:10:11 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.758013, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.758029,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF/Directory1/gdf/volker1.txt (fnum = 17920) level=1004 call=7 total_data=0
>[2012/05/07 10:13:06.758044,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF/Directory1/gdf/volker1.txt (fnum = 17920) level=1004 max_data=40
>[2012/05/07 10:13:06.758059,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.758072,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.758095,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.758108,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.758120,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.758146, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4431(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2012/05/07 10:13:06.758173,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4441(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Thu May  3 15:50:30 2012
>   access: Thu May  3 15:50:30 2012
>   write: Mon May  7 10:10:10 2012
>   change: Mon May  7 10:10:10 2012
>   mode: 80
>[2012/05/07 10:13:06.758234,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 131010
>[2012/05/07 10:13:06.758248,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2012/05/07 10:13:06.758262,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.758271,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18561
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2012/05/07 10:13:06.758374, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 57 C9   B3 33 29 CD 01 00 57 C9   ......W. .3)...W.
>  [0010] B3 33 29 CD 01 00 9D 2B   D2 28 2C CD 01 00 9D 2B   .3)....+ .(,....+
>  [0020] D2 28 2C CD 01 80 00 00   00 00 00 00 00           .(,..... .....
>[2012/05/07 10:13:06.759895, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 59
>[2012/05/07 10:13:06.759914,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x3b
>[2012/05/07 10:13:06.759928,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 662 of length 63 (0 toread)
>[2012/05/07 10:13:06.759941,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.759950,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=59
>  smb_com=0x2e
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=59399
>  smb_tid=1
>  smb_pid=65279
>  smb_uid=100
>  smb_mid=18625
>  smt_wct=12
>  smb_vwv[ 0]=  255 (0xFF)
>  smb_vwv[ 1]=57054 (0xDEDE)
>  smb_vwv[ 2]=17920 (0x4600)
>  smb_vwv[ 3]=    0 (0x0)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    5 (0x5)
>  smb_vwv[ 6]=    5 (0x5)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    5 (0x5)
>  smb_vwv[10]=    0 (0x0)
>  smb_vwv[11]=    0 (0x0)
>  smb_bcc=0
>[2012/05/07 10:13:06.760058,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBreadX (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.760072,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.760117, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/fileio.c:106(read_file)
>  read_file (TestNotifGDF/Directory1/gdf/volker1.txt): pos = 0, size = 5, returned 5
>[2012/05/07 10:13:06.760147,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/reply.c:3572(send_file_readX)
>  send_file_readX fnum=17920 max=5 nread=5
>[2012/05/07 10:13:06.763689, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 84
>[2012/05/07 10:13:06.763707,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x54
>[2012/05/07 10:13:06.763721,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 663 of length 88 (0 toread)
>[2012/05/07 10:13:06.763734,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.763743,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=84
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18689
>  smt_wct=15
>  smb_vwv[ 0]=    6 (0x6)
>  smb_vwv[ 1]=    8 (0x8)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=    0 (0x0)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    6 (0x6)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    8 (0x8)
>  smb_vwv[12]=   76 (0x4C)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    8 (0x8)
>  smb_bcc=19
>[2012/05/07 10:13:06.763840, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 46 FB 03 00   00 00 00 2A 00 00 00 00   ....F... ...*....
>  [0010] 00 00 00                                          ... 
>[2012/05/07 10:13:06.763885,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.763918,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.763946,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:7724(call_trans2setfilepathinfo)
>  call_trans2setfilepathinfo(8) TestNotifGDF/Directory1/gdf/volker1.txt (fnum 17920) info_level=1019 totdata=8
>[2012/05/07 10:13:06.763966,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:7322(smbd_do_setfilepathinfo)
>  smbd_do_setfilepathinfo: TestNotifGDF/Directory1/gdf/volker1.txt (fnum 17920) info_level=1019 totdata=8
>[2012/05/07 10:13:06.763984, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:6381(smb_set_file_allocation_info)
>  smb_set_file_allocation_info: Set file allocation info for file TestNotifGDF/Directory1/gdf/volker1.txt to 42
>[2012/05/07 10:13:06.764007, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:6389(smb_set_file_allocation_info)
>  smb_set_file_allocation_info: file TestNotifGDF/Directory1/gdf/volker1.txt : setting new allocation size to 1048576
>[2012/05/07 10:13:06.764032, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:466(vfs_allocate_file_space)
>  vfs_allocate_file_space: file TestNotifGDF/Directory1/gdf/volker1.txt, len 1048576
>[2012/05/07 10:13:06.764057,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/fileio.c:263(trigger_write_time_update_immediate)
>  Update write time immediate on TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.764075,  5, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:1498(set_write_time)
>  set_write_time: Mon 07 May 2012 10:13:07 AM CEST CEST id=fc01:11f0bc:0
>[2012/05/07 10:13:06.764109, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
>  Locking key 01FC000000000000BCF0
>[2012/05/07 10:13:06.764148, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
>  Allocated locked data 0x0x2ba8c09ad990
>[2012/05/07 10:13:06.764162, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:10:11 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.764208, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.764224, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:726(unparse_share_modes)
>  unparse_share_modes: del: 0, owrt: Mon 07 May 2012 10:13:07 AM CEST CEST cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num: 1
>[2012/05/07 10:13:06.764270, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:518(print_share_mode_table)
>  print_share_mode_table: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.764302, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
>  Unlocking key 01FC000000000000BCF0
>[2012/05/07 10:13:06.764336,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5438(smb_set_file_time)
>  smb_set_filetime: actime: Thu Jan  1 01:00:00 1970
>  
>   smb_set_filetime: modtime: Mon May  7 10:13:07 2012
>  
>   smb_set_filetime: ctime: Thu Jan  1 01:00:00 1970
>  
>   smb_set_file_time: createtime: Thu Jan  1 01:00:00 1970
>  
>   smb_set_file_time: setting utimes to modified values.
>[2012/05/07 10:13:06.764399,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:861(file_ntimes)
>  file_ntime: actime: Thu Jan  1 01:00:00 1970
>[2012/05/07 10:13:06.764418,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:863(file_ntimes)
>  file_ntime: modtime: Mon May  7 10:13:07 2012
>[2012/05/07 10:13:06.764444,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:865(file_ntimes)
>  file_ntime: ctime: Thu Jan  1 01:00:00 1970
>[2012/05/07 10:13:06.764459,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:867(file_ntimes)
>  file_ntime: createtime: Thu Jan  1 01:00:00 1970
>[2012/05/07 10:13:06.764716, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/notify_internal.c:890(notify_trigger)
>  notify_trigger called action=0x3, filter=0x0, path=/mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.764761, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/notify_internal.c:189(notify_load)
>  notify_load:
>[2012/05/07 10:13:06.764781,  1, pid=13888, effective(500, 500), real(0, 0)] ../librpc/ndr/ndr.c:214(ndr_print_debug)
>       notify->array: struct notify_array
>          num_depths               : 0x00000004 (4)
>          depth: ARRAY(4)
>              depth: struct notify_depth
>                  max_mask                 : 0x00000000 (0)
>                  max_mask_subdir          : 0x00000000 (0)
>                  num_entries              : 0x00000000 (0)
>                  entries: ARRAY(0)
>              depth: struct notify_depth
>                  max_mask                 : 0x00000000 (0)
>                  max_mask_subdir          : 0x00000000 (0)
>                  num_entries              : 0x00000000 (0)
>                  entries: ARRAY(0)
>              depth: struct notify_depth
>                  max_mask                 : 0x00000000 (0)
>                  max_mask_subdir          : 0x00000000 (0)
>                  num_entries              : 0x00000000 (0)
>                  entries: ARRAY(0)
>              depth: struct notify_depth
>                  max_mask                 : 0x00000000 (0)
>                  max_mask_subdir          : 0x00000013 (19)
>                  num_entries              : 0x00000001 (1)
>                  entries: ARRAY(1)
>                      entries: struct notify_entry
>                          server: struct server_id
>                              id                       : 0x00003640 (13888)
>                              vnn                      : 0xffffffff (4294967295)
>                          filter                   : 0x00000000 (0)
>                          subdir_filter            : 0x00000013 (19)
>                          dir_fd                   : 0xffffffff (4294967295)
>                          dir_id: struct file_id
>                              devid                    : 0x000000000000fc01 (64513)
>                              inode                    : 0x000000000011f075 (1175669)
>                              extid                    : 0x0000000000000000 (0)
>                          path                     : '/mnt/hires/TestNotifGDF'
>                          path_len                 : 0x00000017 (23)
>                          private_data             : 0x2ba8c09b6620
>[2012/05/07 10:13:06.765058,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 131012
>[2012/05/07 10:13:06.765077,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0
>[2012/05/07 10:13:06.765091,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.765101,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=58
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18689
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=3
>[2012/05/07 10:13:06.765182, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00                                          ... 
>[2012/05/07 10:13:06.766693, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 156
>[2012/05/07 10:13:06.766731,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x9c
>[2012/05/07 10:13:06.766745,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 664 of length 160 (0 toread)
>[2012/05/07 10:13:06.766759,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.766768,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=156
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18753
>  smt_wct=15
>  smb_vwv[ 0]=   88 (0x58)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   88 (0x58)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=91
>[2012/05/07 10:13:06.766877, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 EC 03 00 00 00   00 5C 00 54 00 65 00 73   ........ .\.T.e.s
>  [0010] 00 74 00 4E 00 6F 00 74   00 69 00 66 00 47 00 44   .t.N.o.t .i.f.G.D
>  [0020] 00 46 00 5C 00 44 00 69   00 72 00 65 00 63 00 74   .F.\.D.i .r.e.c.t
>  [0030] 00 6F 00 72 00 79 00 31   00 5C 00 67 00 64 00 66   .o.r.y.1 .\.g.d.f
>  [0040] 00 5C 00 76 00 6F 00 6C   00 6B 00 65 00 72 00 31   .\.v.o.l .k.e.r.1
>  [0050] 00 2E 00 74 00 78 00 74   00 00 00                 ...t.x.t ...
>[2012/05/07 10:13:06.766978,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.767001,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.767016,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5099(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
>[2012/05/07 10:13:06.767046,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF/Directory1/gdf/volker1.txt"
>[2012/05/07 10:13:06.767070, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF/DIRECTORY1/GDF/VOLKER1.TXT] -> [TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.767091,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.767110,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.767123,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF/Directory1/gdf/volker1.txt] [/mnt/hires]
>[2012/05/07 10:13:06.767163, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF/Directory1/gdf/volker1.txt] -> [/mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.767178,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF/Directory1/gdf/volker1.txt reduced to /mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.767211, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:13:07 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.767289, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.767305,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF/Directory1/gdf/volker1.txt (fnum = -1) level=1004 call=5 total_data=0
>[2012/05/07 10:13:06.767330,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF/Directory1/gdf/volker1.txt (fnum = -1) level=1004 max_data=40
>[2012/05/07 10:13:06.767344,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.767358,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.767371,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.767384,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.767405,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.767429, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4431(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2012/05/07 10:13:06.767442,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4441(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Thu May  3 15:50:30 2012
>   access: Thu May  3 15:50:30 2012
>   write: Mon May  7 10:13:06 2012
>   change: Mon May  7 10:13:06 2012
>   mode: 80
>[2012/05/07 10:13:06.767488,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 131010
>[2012/05/07 10:13:06.767502,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2012/05/07 10:13:06.767515,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.767525,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18753
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2012/05/07 10:13:06.767609, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 57 C9   B3 33 29 CD 01 00 57 C9   ......W. .3)...W.
>  [0010] B3 33 29 CD 01 00 15 13   3B 29 2C CD 01 00 15 13   .3)..... ;),.....
>  [0020] 3B 29 2C CD 01 80 00 00   00 00 00 00 00           ;),..... .....
>[2012/05/07 10:13:06.768920, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 156
>[2012/05/07 10:13:06.768939,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x9c
>[2012/05/07 10:13:06.768953,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 665 of length 160 (0 toread)
>[2012/05/07 10:13:06.768966,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.768976,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=156
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18817
>  smt_wct=15
>  smb_vwv[ 0]=   88 (0x58)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   88 (0x58)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=91
>[2012/05/07 10:13:06.769092, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 EC 03 00 00 00   00 5C 00 54 00 65 00 73   ........ .\.T.e.s
>  [0010] 00 74 00 4E 00 6F 00 74   00 69 00 66 00 47 00 44   .t.N.o.t .i.f.G.D
>  [0020] 00 46 00 5C 00 44 00 69   00 72 00 65 00 63 00 74   .F.\.D.i .r.e.c.t
>  [0030] 00 6F 00 72 00 79 00 31   00 5C 00 67 00 64 00 66   .o.r.y.1 .\.g.d.f
>  [0040] 00 5C 00 76 00 6F 00 6C   00 6B 00 65 00 72 00 31   .\.v.o.l .k.e.r.1
>  [0050] 00 2E 00 74 00 78 00 74   00 00 00                 ...t.x.t ...
>[2012/05/07 10:13:06.769186,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.769200,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.769214,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5099(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
>[2012/05/07 10:13:06.769230,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF/Directory1/gdf/volker1.txt"
>[2012/05/07 10:13:06.769245, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF/DIRECTORY1/GDF/VOLKER1.TXT] -> [TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.769265,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.769283,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.769296,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF/Directory1/gdf/volker1.txt] [/mnt/hires]
>[2012/05/07 10:13:06.769334, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF/Directory1/gdf/volker1.txt] -> [/mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.769349,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF/Directory1/gdf/volker1.txt reduced to /mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.769372, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:13:07 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.769440, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.769455,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF/Directory1/gdf/volker1.txt (fnum = -1) level=1004 call=5 total_data=0
>[2012/05/07 10:13:06.769470,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF/Directory1/gdf/volker1.txt (fnum = -1) level=1004 max_data=40
>[2012/05/07 10:13:06.769503,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.769528,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.769544,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.769557,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.769570,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.769586, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4431(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2012/05/07 10:13:06.769599,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4441(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Thu May  3 15:50:30 2012
>   access: Thu May  3 15:50:30 2012
>   write: Mon May  7 10:13:06 2012
>   change: Mon May  7 10:13:06 2012
>   mode: 80
>[2012/05/07 10:13:06.769635,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 131010
>[2012/05/07 10:13:06.769649,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2012/05/07 10:13:06.769662,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.769671,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18817
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2012/05/07 10:13:06.769753, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 57 C9   B3 33 29 CD 01 00 57 C9   ......W. .3)...W.
>  [0010] B3 33 29 CD 01 00 15 13   3B 29 2C CD 01 00 15 13   .3)..... ;),.....
>  [0020] 3B 29 2C CD 01 80 00 00   00 00 00 00 00           ;),..... .....
>[2012/05/07 10:13:06.771976, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 106
>[2012/05/07 10:13:06.771994,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x6a
>[2012/05/07 10:13:06.772008,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 666 of length 110 (0 toread)
>[2012/05/07 10:13:06.772021,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.772030,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=106
>  smb_com=0x2f
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=59399
>  smb_tid=1
>  smb_pid=65279
>  smb_uid=100
>  smb_mid=18881
>  smt_wct=14
>  smb_vwv[ 0]=  255 (0xFF)
>  smb_vwv[ 1]=57054 (0xDEDE)
>  smb_vwv[ 2]=17920 (0x4600)
>  smb_vwv[ 3]=    0 (0x0)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=65535 (0xFFFF)
>  smb_vwv[ 6]=65535 (0xFFFF)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_vwv[10]=   42 (0x2A)
>  smb_vwv[11]=   64 (0x40)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    0 (0x0)
>  smb_bcc=43
>[2012/05/07 10:13:06.772127, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] EE 4D 6F 64 69 66 69 63   61 74 69 6F 6E 20 6F 66   .Modific ation of
>  [0010] 20 61 20 66 69 6C 65 20   69 6E 20 61 20 73 75 62    a file  in a sub
>  [0020] 64 69 72 65 63 74 6F 72   79 0D 0A                 director y..
>[2012/05/07 10:13:06.772198,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBwriteX (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.772213,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.772520, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/fileio.c:139(real_write_file)
>  real_write_file (TestNotifGDF/Directory1/gdf/volker1.txt): pos = 0, size = 42, returned 42
>[2012/05/07 10:13:06.772556,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/reply.c:4418(reply_write_and_X)
>  writeX fnum=17920 num=42 wrote=42
>[2012/05/07 10:13:06.773822, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 132
>[2012/05/07 10:13:06.773851,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x84
>[2012/05/07 10:13:06.773865,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 667 of length 136 (0 toread)
>[2012/05/07 10:13:06.773879,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.773888,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=132
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18944
>  smt_wct=15
>  smb_vwv[ 0]=   64 (0x40)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   64 (0x40)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=67
>[2012/05/07 10:13:06.774009, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 EC 03 00 00 00   00 5C 00 54 00 65 00 73   ........ .\.T.e.s
>  [0010] 00 74 00 4E 00 6F 00 74   00 69 00 66 00 47 00 44   .t.N.o.t .i.f.G.D
>  [0020] 00 46 00 5C 00 44 00 69   00 72 00 65 00 63 00 74   .F.\.D.i .r.e.c.t
>  [0030] 00 6F 00 72 00 79 00 31   00 5C 00 67 00 64 00 66   .o.r.y.1 .\.g.d.f
>  [0040] 00 00 00                                          ... 
>[2012/05/07 10:13:06.774097,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.774122,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.774147,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5099(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
>[2012/05/07 10:13:06.774183,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF/Directory1/gdf"
>[2012/05/07 10:13:06.774199, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:236(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [TESTNOTIFGDF/DIRECTORY1/GDF]
>[2012/05/07 10:13:06.774213, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:236(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [TESTNOTIFGDF/DIRECTORY1]
>[2012/05/07 10:13:06.774227, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF] -> [TestNotifGDF]
>[2012/05/07 10:13:06.774255,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:328(unix_convert)
>  unix_convert begin: name = TestNotifGDF/Directory1/gdf, dirpath = TestNotifGDF, start = Directory1/gdf
>[2012/05/07 10:13:06.774290,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:138(stat_cache_add)
>  stat_cache_add: Added entry (2ba8c09bcba0:size 1b) TESTNOTIFGDF/DIRECTORY1/GDF -> TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.774324,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:351(unix_convert)
>  conversion of base_name finished TestNotifGDF/Directory1/gdf -> TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.774339,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.774366,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.774380,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF/Directory1/gdf] [/mnt/hires]
>[2012/05/07 10:13:06.774422, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF/Directory1/gdf] -> [/mnt/hires/TestNotifGDF/Directory1/gdf]
>[2012/05/07 10:13:06.774437,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF/Directory1/gdf reduced to /mnt/hires/TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.774471, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:926(fetch_share_mode_unlocked)
>  fetch_share_mode_unlocked: no share_mode record around (file not open)
>[2012/05/07 10:13:06.774492,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF/Directory1/gdf (fnum = -1) level=1004 call=5 total_data=0
>[2012/05/07 10:13:06.774506,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF/Directory1/gdf (fnum = -1) level=1004 max_data=40
>[2012/05/07 10:13:06.774521,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.774536,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2012/05/07 10:13:06.774551,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.774564,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.774576,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning d
>[2012/05/07 10:13:06.774598, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4431(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2012/05/07 10:13:06.774611,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4441(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Wed Apr 25 11:22:18 2012
>   access: Wed Apr 25 11:22:18 2012
>   write: Thu May  3 15:50:38 2012
>   change: Thu May  3 15:50:38 2012
>   mode: 10
>[2012/05/07 10:13:06.774677,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 131010
>[2012/05/07 10:13:06.774691,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2012/05/07 10:13:06.774714,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.774724,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=18944
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2012/05/07 10:13:06.774816, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 01 E7   E8 C4 22 CD 01 00 01 E7   ........ ..".....
>  [0010] E8 C4 22 CD 01 00 0B 8E   B8 33 29 CD 01 00 0B 8E   .."..... .3).....
>  [0020] B8 33 29 CD 01 10 00 00   00 00 00 00 00           .3)..... .....
>[2012/05/07 10:13:06.776175, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 162
>[2012/05/07 10:13:06.776203,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0xa2
>[2012/05/07 10:13:06.776217,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 668 of length 166 (0 toread)
>[2012/05/07 10:13:06.776231,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.776240,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=162
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=19008
>  smt_wct=15
>  smb_vwv[ 0]=   94 (0x5E)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=   10 (0xA)
>  smb_vwv[ 3]=16384 (0x4000)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=   94 (0x5E)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    1 (0x1)
>  smb_bcc=97
>[2012/05/07 10:13:06.776339, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 16 00 56 05 07   00 04 01 00 00 00 00 5C   .....V.. .......\
>  [0010] 00 54 00 65 00 73 00 74   00 4E 00 6F 00 74 00 69   .T.e.s.t .N.o.t.i
>  [0020] 00 66 00 47 00 44 00 46   00 5C 00 44 00 69 00 72   .f.G.D.F .\.D.i.r
>  [0030] 00 65 00 63 00 74 00 6F   00 72 00 79 00 31 00 5C   .e.c.t.o .r.y.1.\
>  [0040] 00 67 00 64 00 66 00 5C   00 76 00 6F 00 6C 00 6B   .g.d.f.\ .v.o.l.k
>  [0050] 00 65 00 72 00 31 00 2E   00 74 00 78 00 74 00 00   .e.r.1.. .t.x.t..
>  [0060] 00                                                . 
>[2012/05/07 10:13:06.776457,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.776471,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.776497,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:2252(call_trans2findfirst)
>  call_trans2findfirst: dirtype = 16, maxentries = 1366, close_after_first=1, close_if_end = 1 requires_resume_key = 1 level = 0x104, max_data_bytes = 16384
>[2012/05/07 10:13:06.776519,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/filename.c:169(unix_convert)
>  unix_convert called on file "TestNotifGDF/Directory1/gdf/volker1.txt"
>[2012/05/07 10:13:06.776536, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/statcache.c:275(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [TESTNOTIFGDF/DIRECTORY1/GDF/VOLKER1.TXT] -> [TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.776566,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.776584,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.776598,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF/Directory1/gdf/volker1.txt] [/mnt/hires]
>[2012/05/07 10:13:06.776644, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF/Directory1/gdf/volker1.txt] -> [/mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt]
>[2012/05/07 10:13:06.776659,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF/Directory1/gdf/volker1.txt reduced to /mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.776695,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:2333(call_trans2findfirst)
>  dir=TestNotifGDF/Directory1/gdf, mask = volker1.txt
>[2012/05/07 10:13:06.776719,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/dir.c:423(dptr_create)
>  dptr_create dir=TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.776735,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.776752,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.776764,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:851(check_reduced_name)
>  check_reduced_name [TestNotifGDF/Directory1/gdf] [/mnt/hires]
>[2012/05/07 10:13:06.776798, 10, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:938(check_reduced_name)
>  check_reduced_name realpath [TestNotifGDF/Directory1/gdf] -> [/mnt/hires/TestNotifGDF/Directory1/gdf]
>[2012/05/07 10:13:06.776813,  3, pid=13888, effective(500, 500), real(0, 0), class=vfs] smbd/vfs.c:1008(check_reduced_name)
>  check_reduced_name: TestNotifGDF/Directory1/gdf reduced to /mnt/hires/TestNotifGDF/Directory1/gdf
>[2012/05/07 10:13:06.776852,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/dir.c:544(dptr_create)
>  creating new dirptr 256 for path TestNotifGDF/Directory1/gdf, expect_close = 1
>[2012/05/07 10:13:06.776869,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:2400(call_trans2findfirst)
>  dptr_num is 256, wcard = volker1.txt, attr = 22
>[2012/05/07 10:13:06.776892,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:2409(call_trans2findfirst)
>  dirpath=<TestNotifGDF/Directory1/gdf> dontdescend=<>
>[2012/05/07 10:13:06.776914,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: volker1.txt
>[2012/05/07 10:13:06.776938,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.776968,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dir.c:921(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry: dirptr 0x2ba8bcf4c760 now at offset -1
>[2012/05/07 10:13:06.776989,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.777007,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.777025,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.777038,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.777051,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.777083, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:13:07 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.777144, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.777170,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/dir.c:993(smbd_dirptr_get_entry)
>  smbd_dirptr_get_entry mask=[volker1.txt] found TestNotifGDF/Directory1/gdf/volker1.txt fname=volker1.txt (volker1.txt)
>[2012/05/07 10:13:06.777204, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:1691(smbd_marshall_dir_entry)
>  smbd_marshall_dir_entry: SMB_FIND_FILE_BOTH_DIRECTORY_INFO
>[2012/05/07 10:13:06.777224,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:2466(call_trans2findfirst)
>  call_trans2findfirst - (2) closing dptr_num 256
>[2012/05/07 10:13:06.777257,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/dir.c:250(dptr_close_internal)
>  closing dptr key 256
>[2012/05/07 10:13:06.777280,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 10, data_sent_thistime = 116, useable_space = 131010
>[2012/05/07 10:13:06.777294,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 10, data_to_send = 116, paramsize = 10, datasize = 116
>[2012/05/07 10:13:06.777307,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.777316,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=184
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=19008
>  smt_wct=10
>  smb_vwv[ 0]=   10 (0xA)
>  smb_vwv[ 1]=  116 (0x74)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=   10 (0xA)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=  116 (0x74)
>  smb_vwv[ 7]=   68 (0x44)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=129
>[2012/05/07 10:13:06.777408, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 FD FF 01 00 01 00 00   00 00 00 00 00 74 00 00   ........ .....t..
>  [0010] 00 00 00 00 00 00 57 C9   B3 33 29 CD 01 00 57 C9   ......W. .3)...W.
>  [0020] B3 33 29 CD 01 00 15 13   3B 29 2C CD 01 00 15 13   .3)..... ;),.....
>  [0030] 3B 29 2C CD 01 2A 00 00   00 00 00 00 00 00 00 10   ;),..*.. ........
>  [0040] 00 00 00 00 00 80 00 00   00 16 00 00 00 00 00 00   ........ ........
>  [0050] 00 00 00 00 00 00 00 00   00 00 00 00 00 00 00 00   ........ ........
>  [0060] 00 00 00 00 00 00 00 00   00 00 00 76 00 6F 00 6C   ........ ...v.o.l
>  [0070] 00 6B 00 65 00 72 00 31   00 2E 00 74 00 78 00 74   .k.e.r.1 ...t.x.t
>  [0080] 00                                                . 
>[2012/05/07 10:13:06.777609,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:2510(call_trans2findfirst)
>  SMBtrans2 mask=volker1.txt directory=TestNotifGDF/Directory1/gdf dirtype=22 numentries=1
>[2012/05/07 10:13:06.780625, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 72
>[2012/05/07 10:13:06.780659,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x48
>[2012/05/07 10:13:06.780674,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 669 of length 76 (0 toread)
>[2012/05/07 10:13:06.780687,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.780697,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=72
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=19072
>  smt_wct=15
>  smb_vwv[ 0]=    4 (0x4)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    4 (0x4)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    7 (0x7)
>  smb_bcc=7
>[2012/05/07 10:13:06.780798, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 46 EC 03                              ....F.. 
>[2012/05/07 10:13:06.780821,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.780835,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.780858,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5012(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
>[2012/05/07 10:13:06.780913, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:13:07 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.780971, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.780987,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF/Directory1/gdf/volker1.txt (fnum = 17920) level=1004 call=7 total_data=0
>[2012/05/07 10:13:06.781002,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF/Directory1/gdf/volker1.txt (fnum = 17920) level=1004 max_data=40
>[2012/05/07 10:13:06.781017,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.781031,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.781045,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.781058,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.781071,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.781098, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4431(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2012/05/07 10:13:06.781111,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4441(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Thu May  3 15:50:30 2012
>   access: Thu May  3 15:50:30 2012
>   write: Mon May  7 10:13:06 2012
>   change: Mon May  7 10:13:06 2012
>   mode: 80
>[2012/05/07 10:13:06.781159,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 131010
>[2012/05/07 10:13:06.781173,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2012/05/07 10:13:06.781187,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.781196,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=19072
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2012/05/07 10:13:06.781279, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 57 C9   B3 33 29 CD 01 00 57 C9   ......W. .3)...W.
>  [0010] B3 33 29 CD 01 00 15 13   3B 29 2C CD 01 00 15 13   .3)..... ;),.....
>  [0020] 3B 29 2C CD 01 80 00 00   00 00 00 00 00           ;),..... .....
>[2012/05/07 10:13:06.782796, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 72
>[2012/05/07 10:13:06.782837,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x48
>[2012/05/07 10:13:06.782871,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 670 of length 76 (0 toread)
>[2012/05/07 10:13:06.782893,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.782907,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=72
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=19136
>  smt_wct=15
>  smb_vwv[ 0]=    4 (0x4)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    4 (0x4)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    7 (0x7)
>  smb_bcc=7
>[2012/05/07 10:13:06.783030, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 46 EC 03                              ....F.. 
>[2012/05/07 10:13:06.783062,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.783081,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.783101,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5012(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
>[2012/05/07 10:13:06.783137, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:13:07 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:06.783204, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:06.783222,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5225(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo TestNotifGDF/Directory1/gdf/volker1.txt (fnum = 17920) level=1004 call=7 total_data=0
>[2012/05/07 10:13:06.783240,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4197(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: TestNotifGDF/Directory1/gdf/volker1.txt (fnum = 17920) level=1004 max_data=40
>[2012/05/07 10:13:06.783267,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:613(dos_mode)
>  dos_mode: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.783298,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:207(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning 
>[2012/05/07 10:13:06.783320,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1668(is_in_path)
>  is_in_path: TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:06.783336,  8, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:1692(is_in_path)
>  is_in_path: match not found
>[2012/05/07 10:13:06.783370,  8, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:666(dos_mode)
>  dos_mode returning 
>[2012/05/07 10:13:06.783394, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4431(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2012/05/07 10:13:06.783416,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:4441(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Thu May  3 15:50:30 2012
>   access: Thu May  3 15:50:30 2012
>   write: Mon May  7 10:13:06 2012
>   change: Mon May  7 10:13:06 2012
>   mode: 80
>[2012/05/07 10:13:06.783468,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:927(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 131010
>[2012/05/07 10:13:06.783502,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2012/05/07 10:13:06.783516,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.783528,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=19136
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2012/05/07 10:13:06.783631, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 00 00 57 C9   B3 33 29 CD 01 00 57 C9   ......W. .3)...W.
>  [0010] B3 33 29 CD 01 00 15 13   3B 29 2C CD 01 00 15 13   .3)..... ;),.....
>  [0020] 3B 29 2C CD 01 80 00 00   00 00 00 00 00           ;),..... .....
>[2012/05/07 10:13:06.786432, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 84
>[2012/05/07 10:13:06.786481,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x54
>[2012/05/07 10:13:06.786516,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 671 of length 88 (0 toread)
>[2012/05/07 10:13:06.786530,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.786570,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=84
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=19200
>  smt_wct=15
>  smb_vwv[ 0]=    6 (0x6)
>  smb_vwv[ 1]=    8 (0x8)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=    0 (0x0)
>  smb_vwv[ 4]=    0 (0x0)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    6 (0x6)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    8 (0x8)
>  smb_vwv[12]=   76 (0x4C)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    8 (0x8)
>  smb_bcc=19
>[2012/05/07 10:13:06.786684, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00 00 46 FC 03 00   00 00 00 2A 00 00 00 00   ....F... ...*....
>  [0010] 00 00 00                                          ... 
>[2012/05/07 10:13:06.786720,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBtrans2 (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:06.786743,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:06.786771,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:7724(call_trans2setfilepathinfo)
>  call_trans2setfilepathinfo(8) TestNotifGDF/Directory1/gdf/volker1.txt (fnum 17920) info_level=1020 totdata=8
>[2012/05/07 10:13:06.786791,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:7322(smbd_do_setfilepathinfo)
>  smbd_do_setfilepathinfo: TestNotifGDF/Directory1/gdf/volker1.txt (fnum 17920) info_level=1020 totdata=8
>[2012/05/07 10:13:06.786809, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:6481(smb_set_file_end_of_file_info)
>  smb_set_file_end_of_file_info: Set end of file info for file TestNotifGDF/Directory1/gdf/volker1.txt to 42
>[2012/05/07 10:13:06.786835,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5564(smb_set_file_size)
>  smb_set_file_size: size: 42 t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 131012
>[2012/05/07 10:13:06.786860,  9, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:929(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0
>[2012/05/07 10:13:06.786893,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:06.786903,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=58
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=684
>  smb_uid=100
>  smb_mid=19200
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=    0 (0x0)
>  smb_vwv[ 7]=    0 (0x0)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=3
>[2012/05/07 10:13:06.786985, 10, pid=13888, effective(500, 500), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 00 00 00                                          ... 
>[2012/05/07 10:13:17.707494, 10, pid=13888, effective(500, 500), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 41
>[2012/05/07 10:13:17.707535,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x29
>[2012/05/07 10:13:17.707556,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 672 of length 45 (0 toread)
>[2012/05/07 10:13:17.707578,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:17.707588,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=41
>  smb_com=0x4
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=1
>  smb_pid=65279
>  smb_uid=100
>  smb_mid=19264
>  smt_wct=3
>  smb_vwv[ 0]=17920 (0x4600)
>  smb_vwv[ 1]=65535 (0xFFFF)
>  smb_vwv[ 2]=65535 (0xFFFF)
>  smb_bcc=0
>[2012/05/07 10:13:17.707663,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBclose (pid 13888) conn 0x2ba8c09972c0
>[2012/05/07 10:13:17.707682,  4, pid=13888, effective(500, 500), real(0, 0)] smbd/uid.c:257(change_to_user)
>  change_to_user: Skipping user change - already user
>[2012/05/07 10:13:17.707703,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/reply.c:4634(reply_close)
>  close fd=29 fnum=17920 (numopen=2)
>[2012/05/07 10:13:17.707722,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/close.c:501(set_close_write_time)
>  close_write_time: Sun Feb  7 07:28:15 2106
>[2012/05/07 10:13:17.707750, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] smbd/oplock_linux.c:139(linux_release_kernel_oplock)
>  linux_release_kernel_oplock: file TestNotifGDF/Directory1/gdf/volker1.txt, file_id = fc01:11f0bc:0 gen_id = 9 has kernel oplock state of 1.
>[2012/05/07 10:13:17.707786, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
>  Locking key 01FC000000000000BCF0
>[2012/05/07 10:13:17.707813, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
>  Allocated locked data 0x0x2ba8c09bcbe0
>[2012/05/07 10:13:17.707836, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:552(parse_share_modes)
>  parse_share_modes: delete_on_close: 0, owrt: Mon 07 May 2012 10:13:07 AM CEST CEST, cwrt: Thu 01 Jan 1970 01:00:00 AM CET CET, tok: 0, num_share_modes: 1
>[2012/05/07 10:13:17.707897, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:655(parse_share_modes)
>  parse_share_modes: share_mode_entry[0]:  pid = 13888, share_access = 0x1, private_options = 0x40, access_mask = 0x2019f, mid = 0x0, type= 0x3, gen_id = 9, uid = 500, flags = 0, file_id fc01:11f0bc:0
>[2012/05/07 10:13:17.707920, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/close.c:311(close_remove_share_mode)
>  close_remove_share_mode: update to current time for file TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:17.707939,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/close.c:501(set_close_write_time)
>  close_write_time: Mon May  7 10:13:18 2012
>[2012/05/07 10:13:17.707966, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
>  Unlocking key 01FC000000000000BCF0
>[2012/05/07 10:13:17.708017, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/posix.c:512(get_windows_lock_ref_count)
>  get_windows_lock_count for file TestNotifGDF/Directory1/gdf/volker1.txt = 0
>[2012/05/07 10:13:17.708037, 10, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/posix.c:538(delete_windows_lock_ref_count)
>  delete_windows_lock_ref_count for file TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:17.708254,  5, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:1498(set_write_time)
>  set_write_time: Mon 07 May 2012 10:13:18 AM CEST CEST id=fc01:11f0bc:0
>[2012/05/07 10:13:17.708301, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
>  Locking key 01FC000000000000BCF0
>[2012/05/07 10:13:17.708319, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
>  Allocated locked data 0x0x2ba8c09acfc0
>[2012/05/07 10:13:17.708351,  3, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:895(get_share_mode_lock)
>  fill_share_mode_lock failed
>[2012/05/07 10:13:17.708373, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
>  Unlocking key 01FC000000000000BCF0
>[2012/05/07 10:13:17.708412, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked)
>  Locking key 01FC000000000000BCF0
>[2012/05/07 10:13:17.708437, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked)
>  Allocated locked data 0x0x2ba8c09bdca0
>[2012/05/07 10:13:17.708461,  3, pid=13888, effective(500, 500), real(0, 0), class=locking] locking/locking.c:895(get_share_mode_lock)
>  fill_share_mode_lock failed
>[2012/05/07 10:13:17.708481, 10, pid=13888, effective(500, 500), real(0, 0)] lib/dbwrap_tdb.c:42(db_tdb_record_destr)
>  Unlocking key 01FC000000000000BCF0
>[2012/05/07 10:13:17.708516,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/trans2.c:5438(smb_set_file_time)
>  smb_set_filetime: actime: Thu Jan  1 01:00:00 1970
>  
>   smb_set_filetime: modtime: Mon May  7 10:13:18 2012
>  
>   smb_set_filetime: ctime: Thu Jan  1 01:00:00 1970
>  
>   smb_set_file_time: createtime: Thu Jan  1 01:00:00 1970
>  
>   smb_set_file_time: setting utimes to modified values.
>[2012/05/07 10:13:17.708587,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:861(file_ntimes)
>  file_ntime: actime: Thu Jan  1 01:00:00 1970
>[2012/05/07 10:13:17.708610,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:863(file_ntimes)
>  file_ntime: modtime: Mon May  7 10:13:18 2012
>[2012/05/07 10:13:17.708631,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:865(file_ntimes)
>  file_ntime: ctime: Thu Jan  1 01:00:00 1970
>[2012/05/07 10:13:17.708651,  6, pid=13888, effective(500, 500), real(0, 0)] smbd/dosmode.c:867(file_ntimes)
>  file_ntime: createtime: Thu Jan  1 01:00:00 1970
>[2012/05/07 10:13:17.708903, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/notify_internal.c:890(notify_trigger)
>  notify_trigger called action=0x3, filter=0x0, path=/mnt/hires/TestNotifGDF/Directory1/gdf/volker1.txt
>[2012/05/07 10:13:17.708935,  2, pid=13888, effective(500, 500), real(0, 0)] smbd/close.c:656(close_normal_file)
>  dvb closed file TestNotifGDF/Directory1/gdf/volker1.txt (numopen=1) NT_STATUS_OK
>[2012/05/07 10:13:17.708960,  5, pid=13888, effective(500, 500), real(0, 0)] smbd/files.c:497(file_free)
>  freed files structure 17920 (1 used)
>[2012/05/07 10:13:17.708979,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:13:17.708992,  5, pid=13888, effective(500, 500), real(0, 0)] lib/util.c:627(show_msg)
>  size=35
>  smb_com=0x4
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=1
>  smb_pid=65279
>  smb_uid=100
>  smb_mid=19264
>  smt_wct=0
>  smb_bcc=0
>[2012/05/07 10:13:36.353282, 10, pid=13888, effective(500, 500), real(0, 0)] lib/events.c:131(run_events)
>  Running timed event "smbd_idle_event_handler" 0x2ba8c09b2b70
>[2012/05/07 10:13:36.353359, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:683(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(deadtime) (nil) called
>[2012/05/07 10:13:36.353386, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:694(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled
>[2012/05/07 10:13:36.353413, 10, pid=13888, effective(500, 500), real(0, 0)] lib/events.c:131(run_events)
>  Running timed event "smbd_idle_event_handler" 0x2ba8c0998480
>[2012/05/07 10:13:36.353432, 10, pid=13888, effective(500, 500), real(0, 0)] smbd/process.c:683(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(housekeeping) (nil) called
>[2012/05/07 10:13:36.353451,  3, pid=13888, effective(500, 500), real(0, 0)] smbd/sec_ctx.c:310(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2012/05/07 10:13:36.353472,  5, pid=13888, effective(500, 500), real(0, 0)] auth/token_util.c:525(debug_nt_user_token)
>  NT user token: (NULL)
>[2012/05/07 10:13:36.353490,  5, pid=13888, effective(500, 500), real(0, 0)] auth/token_util.c:551(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2012/05/07 10:13:36.353525,  5, pid=13888, effective(0, 0), real(0, 0)] smbd/uid.c:369(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2012/05/07 10:13:36.353548, 10, pid=13888, effective(0, 0), real(0, 0)] smbd/process.c:694(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled
>[2012/05/07 10:14:18.754194, 10, pid=13888, effective(0, 0), real(0, 0)] lib/util_sock.c:731(read_smb_length_return_keepalive)
>  got smb length of 49
>[2012/05/07 10:14:18.754240,  6, pid=13888, effective(0, 0), real(0, 0)] smbd/process.c:1482(process_smb)
>  got message type 0x0 of len 0x31
>[2012/05/07 10:14:18.754261,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/process.c:1485(process_smb)
>  Transaction 673 of length 53 (0 toread)
>[2012/05/07 10:14:18.754278,  5, pid=13888, effective(0, 0), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:14:18.754291,  5, pid=13888, effective(0, 0), real(0, 0)] lib/util.c:627(show_msg)
>  size=49
>  smb_com=0x2b
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=49219
>  smb_tid=65535
>  smb_pid=65279
>  smb_uid=0
>  smb_mid=65534
>  smt_wct=1
>  smb_vwv[ 0]=    1 (0x1)
>  smb_bcc=12
>[2012/05/07 10:14:18.754355, 10, pid=13888, effective(0, 0), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 4A 6C 4A 6D 49 68 43 6C   42 73 72 00              JlJmIhCl Bsr.
>[2012/05/07 10:14:18.754390,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/process.c:1294(switch_message)
>  switch message SMBecho (pid 13888) conn 0x0
>[2012/05/07 10:14:18.754410,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/sec_ctx.c:310(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2012/05/07 10:14:18.754429,  5, pid=13888, effective(0, 0), real(0, 0)] auth/token_util.c:525(debug_nt_user_token)
>  NT user token: (NULL)
>[2012/05/07 10:14:18.754442,  5, pid=13888, effective(0, 0), real(0, 0)] auth/token_util.c:551(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2012/05/07 10:14:18.754475,  5, pid=13888, effective(0, 0), real(0, 0)] smbd/uid.c:369(change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2012/05/07 10:14:18.754497,  5, pid=13888, effective(0, 0), real(0, 0)] lib/util.c:617(show_msg)
>[2012/05/07 10:14:18.754509,  5, pid=13888, effective(0, 0), real(0, 0)] lib/util.c:627(show_msg)
>  size=49
>  smb_com=0x2b
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51203
>  smb_tid=65535
>  smb_pid=65279
>  smb_uid=0
>  smb_mid=65534
>  smt_wct=1
>  smb_vwv[ 0]=    1 (0x1)
>  smb_bcc=12
>[2012/05/07 10:14:18.754590, 10, pid=13888, effective(0, 0), real(0, 0)] ../lib/util/util.c:278(_dump_data)
>  [0000] 4A 6C 4A 6D 49 68 43 6C   42 73 72 00              JlJmIhCl Bsr.
>[2012/05/07 10:14:18.754638,  3, pid=13888, effective(0, 0), real(0, 0)] smbd/reply.c:4959(reply_echo)
>  echo 1 times

Actions: View

Attachments on bug 8901: 7505 | 7506 | 7507 | 7514 | 7515 | 7527 | 7528