[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= 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