[2009/06/30 04:35:01.345931, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 02 00 00 00 00 00 00 ........ . [2009/06/30 04:35:01.346040, 3] smbd/process.c:1251(switch_message) switch message SMBtrans2 (pid 5441) conn 0x809eb0d8 [2009/06/30 04:35:01.346107, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/06/30 04:35:01.346188, 3] smbd/trans2.c:3952(call_trans2qfilepathinfo) call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 512 [2009/06/30 04:35:01.346273, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "" [2009/06/30 04:35:01.346349, 5] smbd/filename.c:181(unix_convert) conversion finished "" -> . [2009/06/30 04:35:01.346472, 10] locking/locking.c:891(fetch_share_mode_unlocked) fetch_share_mode_unlocked: no share_mode record around (file not open) [2009/06/30 04:35:01.346537, 3] smbd/trans2.c:4066(call_trans2qfilepathinfo) call_trans2qfilepathinfo . (fnum = -1) level=512 call=5 total_data=0 [2009/06/30 04:35:01.346602, 8] smbd/dosmode.c:474(dos_mode) dos_mode: . [2009/06/30 04:35:01.346744, 8] smbd/dosmode.c:175(dos_mode_from_sbuf) dos_mode_from_sbuf returning d [2009/06/30 04:35:01.346812, 8] smbd/dosmode.c:521(dos_mode) dos_mode returning d [2009/06/30 04:35:01.346897, 10] smbd/trans2.c:3520(store_file_unix_basic) store_file_unix_basic: SMB_QUERY_FILE_UNIX_BASIC [2009/06/30 04:35:01.346953, 4] smbd/trans2.c:3521(store_file_unix_basic) store_file_unix_basic: st_mode=40777 [2009/06/30 04:35:01.347016, 4] smbd/trans2.c:4569(call_trans2qfilepathinfo) call_trans2qfilepathinfo: SMB_QUERY_FILE_UNIX_BASIC 0=0, 1=0, 2=0, 3=0, 4=0, 5=0, 6=0, 7=0, 8=0, 9=0, 10=0, 11=0, 12=0, 13=0, 14=0, 15=0, 16=ffffffbb, 17=ffffffa4, 18=ffffffb1, 19=52, 20=2b, 21=fffffff9, 22=ffffffc9, 23=1, 24=ffffffd7, 25=1, 26=ffffffbc, 27=35, 28=28, 29=fffffff9, 30=ffffffc9, 31=1, 32=ffffffbb, 33=ffffffa4, 34=ffffffb1, 35=52, 36=2b, 37=fffffff9, 38=ffffffc9, 39=1, 40=ffffffe8, 41=3, 42=0, 43=0, 44=0, 45=0, 46=0, 47=0, 48=64, 49=0, 50=0, 51=0, 52=0, 53=0, 54=0, 55=0, 56=1, 57=0, 58=0, 59=0, 60=0, 61=0, 62=0, 63=0, 64=0, 65=0, 66=0, 67=0, 68=0, 69=0, 70=0, 71=0, 72=0, 73=0, 74=0, 75=0, 76=ffffffbc, 77=6a, 78=ffffffc7, 79=e, 80=0, 81=0, 82=0, 83=0, 84=ffffffff, 85=1, 86=0, 87=0, 88=0, 89=0, 90=0, 91=0, 92=9, 93=0, 94=0, 95=0, 96=0, 97=0, 98=0, 99=0, [2009/06/30 04:35:01.347319, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 100, useable_space = 16410 [2009/06/30 04:35:01.347379, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 100, paramsize = 2, datasize = 100 [2009/06/30 04:35:01.347437, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.347478, 5] lib/util.c:642(show_msg) size=160 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=20 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 100 (0x64) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 100 (0x64) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=105 [2009/06/30 04:35:01.347776, 10] ../lib/util/util.c:304(_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 BB A4 B1 52 2B F9 C9 01 D7 01 BC ........ R+...... [0020] 35 28 F9 C9 01 BB A4 B1 52 2B F9 C9 01 E8 03 00 5(...... R+...... [0030] 00 00 00 00 00 64 00 00 00 00 00 00 00 01 00 00 .....d.. ........ [0040] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0050] 00 BC 6A C7 0E 00 00 00 00 FF 01 00 00 00 00 00 ..j..... ........ [0060] 00 09 00 00 00 00 00 00 00 ........ . [2009/06/30 04:35:01.349012, 10] lib/util_sock.c:781(read_smb_length_return_keepalive) got smb length of 90 [2009/06/30 04:35:01.349095, 6] smbd/process.c:1430(process_smb) got message type 0x0 of len 0x5a [2009/06/30 04:35:01.349156, 3] smbd/process.c:1433(process_smb) Transaction 20 of length 94 (0 toread) [2009/06/30 04:35:01.349212, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.349253, 5] lib/util.c:642(show_msg) size=90 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=21 smt_wct=15 smb_vwv[ 0]= 24 (0x18) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) 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]= 24 (0x18) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=25 [2009/06/30 04:35:01.349614, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 02 00 00 00 00 2F 00 74 00 73 00 74 00 2E ......./ .t.s.t.. [0010] 00 74 00 73 00 74 00 00 00 .t.s.t.. . [2009/06/30 04:35:01.349765, 3] smbd/process.c:1251(switch_message) switch message SMBtrans2 (pid 5441) conn 0x809eb0d8 [2009/06/30 04:35:01.349861, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/06/30 04:35:01.349934, 3] smbd/trans2.c:3952(call_trans2qfilepathinfo) call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 512 [2009/06/30 04:35:01.350009, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "tst.tst" [2009/06/30 04:35:01.350080, 5] smbd/filename.c:303(unix_convert) unix_convert begin: name = tst.tst, dirpath = , start = tst.tst [2009/06/30 04:35:01.350150, 3] smbd/trans2.c:4037(call_trans2qfilepathinfo) call_trans2qfilepathinfo: SMB_VFS_LSTAT of tst.tst failed (Datei oder Verzeichnis nicht gefunden) [2009/06/30 04:35:01.350697, 3] smbd/error.c:153(reply_unix_error) unix_error_packet: error string = Datei oder Verzeichnis nicht gefunden [2009/06/30 04:35:01.350773, 3] smbd/error.c:60(error_packet_set) error packet at smbd/trans2.c(4038) cmd=50 (SMBtrans2) NT_STATUS_OBJECT_NAME_NOT_FOUND [2009/06/30 04:35:01.350849, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.350892, 5] lib/util.c:642(show_msg) size=35 smb_com=0x32 smb_rcls=52 smb_reh=0 smb_err=49152 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=21 smt_wct=0 smb_bcc=0 [2009/06/30 04:35:01.363360, 10] lib/util_sock.c:781(read_smb_length_return_keepalive) got smb length of 110 [2009/06/30 04:35:01.363455, 6] smbd/process.c:1430(process_smb) got message type 0x0 of len 0x6e [2009/06/30 04:35:01.363519, 3] smbd/process.c:1433(process_smb) Transaction 21 of length 114 (0 toread) [2009/06/30 04:35:01.363577, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.363620, 5] lib/util.c:642(show_msg) size=110 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=22 smt_wct=15 smb_vwv[ 0]= 24 (0x18) smb_vwv[ 1]= 18 (0x12) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) 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]= 24 (0x18) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 18 (0x12) smb_vwv[12]= 92 (0x5C) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=45 [2009/06/30 04:35:01.363983, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 09 02 00 00 00 00 2F 00 74 00 73 00 74 ........ ./.t.s.t [0010] 00 2E 00 74 00 73 00 74 00 00 00 E2 1B FF D4 12 ...t.s.t ........ [0020] 00 00 00 A4 81 00 00 00 00 00 00 00 02 ........ ..... [2009/06/30 04:35:01.364196, 3] smbd/process.c:1251(switch_message) switch message SMBtrans2 (pid 5441) conn 0x809eb0d8 [2009/06/30 04:35:01.364262, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/06/30 04:35:01.364350, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "tst.tst" [2009/06/30 04:35:01.364423, 5] smbd/filename.c:303(unix_convert) unix_convert begin: name = tst.tst, dirpath = , start = tst.tst [2009/06/30 04:35:01.364491, 3] smbd/trans2.c:6858(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) tst.tst (fnum -1) info_level=521 totdata=18 [2009/06/30 04:35:01.364563, 10] smbd/trans2.c:6478(smb_posix_open) smb_posix_open: file tst.tst, smb_posix_flags = 16, mode 0644 [2009/06/30 04:35:01.364625, 10] smbd/open.c:3365(create_file_default) create_file: access_mask = 0x2 file_attributes = 0x10001a4, share_access = 0x7, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x1 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x0, fname = tst.tst [2009/06/30 04:35:01.364716, 10] smbd/open.c:2896(create_file_unixpath) create_file_unixpath: access_mask = 0x2 file_attributes = 0x10001a4, share_access = 0x7, create_disposition = 0x3 create_options = 0x40 oplock_request = 0x1 ea_list = 0x(nil), sd = 0x(nil), fname = tst.tst [2009/06/30 04:35:01.364813, 5] smbd/files.c:103(file_new) allocated file structure 223, fnum = 4319 (1 used) [2009/06/30 04:35:01.364928, 10] smbd/open.c:1475(open_file_ntcreate) open_file_ntcreate: fname=tst.tst, dos_attrs=0x0 access_mask=0x2 share_access=0x7 create_disposition = 0x3 create_options=0x40 unix mode=0644 oplock_request=1 [2009/06/30 04:35:01.365009, 10] smbd/open.c:1653(open_file_ntcreate) open_file_ntcreate: fname=tst.tst, after mapping access_mask=0x2 [2009/06/30 04:35:01.365073, 4] smbd/open.c:1913(open_file_ntcreate) calling open_file with flags=0x1 flags2=0x40 mode=0644, access_mask = 0x2, open_access_mask = 0x2 [2009/06/30 04:35:01.365415, 10] smbd/open.c:160(fd_open) fd_open: name tst.tst, flags = 0400101 mode = 0644, fd = 29. [2009/06/30 04:35:01.365492, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x1, filter=0x1, path=/home/gk/cifstest/tst.tst [2009/06/30 04:35:01.365570, 2] smbd/open.c:580(open_file) gk opened file tst.tst read=No write=Yes (numopen=1) [2009/06/30 04:35:01.365659, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0808000000000000FC19 [2009/06/30 04:35:01.365758, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x80a04f18 [2009/06/30 04:35:01.365826, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x1 on file tst.tst [2009/06/30 04:35:01.365888, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x1 on file tst.tst [2009/06/30 04:35:01.365969, 3] smbd/oplock_linux.c:123(linux_set_kernel_oplock) linux_set_kernel_oplock: got kernel oplock on file tst.tst, file_id = 808:ecb19fc:0 gen_id = 4 [2009/06/30 04:35:01.366044, 5] smbd/oplock.c:86(set_file_oplock) set_file_oplock: granted oplock on file tst.tst, 808:ecb19fc:0/4, tv_sec = 4a4979d5, tv_usec = 590fe [2009/06/30 04:35:01.366131, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 30 Jun 2009 04:35:01 CEST CEST cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/06/30 04:35:01.366339, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 5441, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x1, gen_id = 4, uid = 1000, flags = 1, file_id 808:ecb19fc:0 [2009/06/30 04:35:01.366424, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0808000000000000FC19 [2009/06/30 04:35:01.366519, 10] smbd/open.c:3200(create_file_unixpath) create_file_unixpath: info=2 [2009/06/30 04:35:01.366582, 10] smbd/open.c:3495(create_file_default) create_file: info=2 [2009/06/30 04:35:01.366642, 10] smbd/trans2.c:3520(store_file_unix_basic) store_file_unix_basic: SMB_QUERY_FILE_UNIX_BASIC [2009/06/30 04:35:01.366699, 4] smbd/trans2.c:3521(store_file_unix_basic) store_file_unix_basic: st_mode=100644 [2009/06/30 04:35:01.366778, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 112, useable_space = 16410 [2009/06/30 04:35:01.366840, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 112, paramsize = 2, datasize = 112 [2009/06/30 04:35:01.366899, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.366942, 5] lib/util.c:642(show_msg) size=172 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=22 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 112 (0x70) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 112 (0x70) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=117 [2009/06/30 04:35:01.367318, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 00 01 00 DF 10 02 00 00 00 00 02 00 ........ ........ [0010] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0020] 00 87 FA 04 5E 2B F9 C9 01 87 FA 04 5E 2B F9 C9 ....^+.. ....^+.. [0030] 01 87 FA 04 5E 2B F9 C9 01 E8 03 00 00 00 00 00 ....^+.. ........ [0040] 00 64 00 00 00 00 00 00 00 00 00 00 00 00 00 00 .d...... ........ [0050] 00 00 00 00 00 00 00 00 00 00 00 00 00 FC 19 CB ........ ........ [0060] 0E 00 00 00 00 A4 01 00 00 00 00 00 00 01 00 00 ........ ........ [0070] 00 00 00 00 00 ..... [2009/06/30 04:35:01.369627, 10] lib/util_sock.c:781(read_smb_length_return_keepalive) got smb length of 1088 [2009/06/30 04:35:01.369722, 6] smbd/process.c:1430(process_smb) got message type 0x0 of len 0x440 [2009/06/30 04:35:01.369784, 3] smbd/process.c:1433(process_smb) Transaction 22 of length 1092 (0 toread) [2009/06/30 04:35:01.369842, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.369884, 5] lib/util.c:642(show_msg) size=1088 smb_com=0x2f smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=23 smt_wct=14 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 4319 (0x10DF) 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]= 1024 (0x400) smb_vwv[11]= 64 (0x40) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 0 (0x0) smb_bcc=1025 [2009/06/30 04:35:01.370238, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 .AAAAAAA AAAAAAAA [0010] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0020] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0030] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0040] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0050] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0060] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0070] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0080] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0090] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [00A0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [00B0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [00C0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [00D0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [00E0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [00F0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0100] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0110] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0120] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0130] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0140] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0150] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0160] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0170] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0180] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [0190] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [01A0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [01B0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [01C0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [01D0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [01E0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [01F0] 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 AAAAAAAA AAAAAAAA [2009/06/30 04:35:01.372090, 3] smbd/process.c:1251(switch_message) switch message SMBwriteX (pid 5441) conn 0x809eb0d8 [2009/06/30 04:35:01.372301, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/06/30 04:35:01.372381, 10] locking/locking.c:112(strict_lock_default) is_locked: optimisation - exclusive oplock on file tst.tst [2009/06/30 04:35:01.372475, 10] locking/locking.c:152(strict_lock_default) strict_lock_default: flavour = POSIX_LOCK brl start=0 len=1024 unlocked for fnum 4319 file tst.tst [2009/06/30 04:35:01.372572, 10] smbd/aio.c:231(schedule_aio_write_and_X) schedule_aio_write_and_X: write size (1024) too small for minimum aio_write of 0 [2009/06/30 04:35:01.372667, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "update_write_time_handler": 0x809f51e0 [2009/06/30 04:35:01.372726, 8] smbd/dosmode.c:474(dos_mode) dos_mode: tst.tst [2009/06/30 04:35:01.372817, 8] smbd/dosmode.c:175(dos_mode_from_sbuf) dos_mode_from_sbuf returning [2009/06/30 04:35:01.372879, 8] smbd/dosmode.c:521(dos_mode) dos_mode returning [2009/06/30 04:35:01.372939, 10] smbd/dosmode.c:554(file_set_dosmode) file_set_dosmode: setting dos mode 0x20 on file tst.tst [2009/06/30 04:35:01.373054, 8] smbd/dosmode.c:474(dos_mode) dos_mode: tst.tst [2009/06/30 04:35:01.373123, 8] smbd/dosmode.c:175(dos_mode_from_sbuf) dos_mode_from_sbuf returning [2009/06/30 04:35:01.373181, 8] smbd/dosmode.c:521(dos_mode) dos_mode returning [2009/06/30 04:35:01.373392, 10] smbd/dosmode.c:301(set_ea_dos_attribute) set_ea_dos_attribute: set EA 0x20 on file tst.tst [2009/06/30 04:35:01.373463, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x4, path=/home/gk/cifstest/tst.tst [2009/06/30 04:35:01.373537, 3] smbd/fileio.c:336(write_file) WRITECACHE: initwrites=0 abutted=0 total=0 nonop=0 allocated=0 active=0 direct=0 perfect=0 readhits=0 [2009/06/30 04:35:01.373606, 3] smbd/fileio.c:345(write_file) WRITECACHE: Flushes SEEK=0, READ=0, WRITE=0, READRAW=0, OPLOCK=0, CLOSE=0, SYNC=0 [2009/06/30 04:35:01.373720, 10] smbd/fileio.c:138(real_write_file) real_write_file (tst.tst): pos = 0, size = 1024, returned 1024 [2009/06/30 04:35:01.373795, 3] smbd/reply.c:4237(reply_write_and_X) writeX fnum=4319 num=1024 wrote=1024 [2009/06/30 04:35:01.374672, 10] lib/util_sock.c:781(read_smb_length_return_keepalive) got smb length of 192 [2009/06/30 04:35:01.374761, 6] smbd/process.c:1430(process_smb) got message type 0x0 of len 0xc0 [2009/06/30 04:35:01.374821, 3] smbd/process.c:1433(process_smb) Transaction 23 of length 196 (0 toread) [2009/06/30 04:35:01.374881, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.374924, 5] lib/util.c:642(show_msg) size=192 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=24 smt_wct=15 smb_vwv[ 0]= 24 (0x18) smb_vwv[ 1]= 100 (0x64) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) 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]= 24 (0x18) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 100 (0x64) smb_vwv[12]= 92 (0x5C) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=127 [2009/06/30 04:35:01.375339, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 02 00 00 00 00 2F 00 74 00 73 00 74 ........ ./.t.s.t [0010] 00 2E 00 74 00 73 00 74 00 00 00 FF FF FF FF FF ...t.s.t ........ [0020] FF FF FF FF FF FF FF FF FF FF FF 1C 92 70 82 2B ........ .....p.+ [0030] F9 C9 01 00 FD 62 07 1F F9 C9 01 80 0C EA D8 B5 .....b.. ........ [0040] BE B2 01 FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........ [0050] FF FF FF 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 00 00 00 00 FF ........ ........ [0070] FF FF FF FF FF FF FF 00 00 00 00 00 00 00 00 ........ ....... [2009/06/30 04:35:01.375827, 3] smbd/process.c:1251(switch_message) switch message SMBtrans2 (pid 5441) conn 0x809eb0d8 [2009/06/30 04:35:01.375893, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/06/30 04:35:01.375989, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "tst.tst" [2009/06/30 04:35:01.376104, 5] smbd/filename.c:297(unix_convert) conversion finished tst.tst -> tst.tst [2009/06/30 04:35:01.376175, 3] smbd/trans2.c:6858(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) tst.tst (fnum -1) info_level=512 totdata=100 [2009/06/30 04:35:01.376246, 10] smbd/trans2.c:6090(smb_set_file_unix_basic) smb_set_file_unix_basic: SMB_SET_FILE_UNIX_BASIC: name = tst.tst size = 0, uid = 4294967295, gid = 4294967295, raw perms = 037777777777 [2009/06/30 04:35:01.376328, 6] smbd/trans2.c:5051(smb_set_file_size) smb_set_file_size: size: 1024 smb_set_filetime: actime: Tue Jun 30 03:06:42 2009 smb_set_filetime: modtime: Mon Oct 10 18:53:33 1988 smb_set_file_time: setting pending modtime to Mon Oct 10 18:53:33 1988 [2009/06/30 04:35:01.376500, 5] locking/locking.c:1425(set_sticky_write_time) set_sticky_write_time: Mo 10 Okt 1988 18:53:33 CET CET id=808:ecb19fc:0 [2009/06/30 04:35:01.376653, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0808000000000000FC19 [2009/06/30 04:35:01.376753, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x809f55a8 [2009/06/30 04:35:01.376816, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 30 Jun 2009 04:35:01 CEST CEST, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/06/30 04:35:01.377016, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 5441, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x1, gen_id = 4, uid = 1000, flags = 1, file_id 808:ecb19fc:0 [2009/06/30 04:35:01.377087, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 30 Jun 2009 04:35:01 CEST CEST cwrt: Mo 10 Okt 1988 18:53:33 CET CET, tok: 0, num: 1 [2009/06/30 04:35:01.377281, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 5441, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x1, gen_id = 4, uid = 1000, flags = 1, file_id 808:ecb19fc:0 [2009/06/30 04:35:01.377357, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0808000000000000FC19 [2009/06/30 04:35:01.377447, 10] smbd/trans2.c:4972(smb_set_file_time) smb_set_file_time: setting utimes to modified values. [2009/06/30 04:35:01.377507, 6] smbd/dosmode.c:721(file_ntimes) file_ntime: actime: Tue Jun 30 03:06:42 2009 [2009/06/30 04:35:01.377572, 6] smbd/dosmode.c:723(file_ntimes) file_ntime: modtime: Mon Oct 10 18:53:33 1988 [2009/06/30 04:35:01.377638, 6] smbd/dosmode.c:725(file_ntimes) file_ntime: createtime: Thu Jan 1 01:00:00 1970 [2009/06/30 04:35:01.377732, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x30, path=/home/gk/cifstest/tst.tst [2009/06/30 04:35:01.377805, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 16412 [2009/06/30 04:35:01.377866, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0 [2009/06/30 04:35:01.377925, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.377967, 5] lib/util.c:642(show_msg) size=58 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=24 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 [2009/06/30 04:35:01.378278, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 ... [2009/06/30 04:35:01.379186, 10] lib/util_sock.c:781(read_smb_length_return_keepalive) got smb length of 192 [2009/06/30 04:35:01.379274, 6] smbd/process.c:1430(process_smb) got message type 0x0 of len 0xc0 [2009/06/30 04:35:01.379373, 3] smbd/process.c:1433(process_smb) Transaction 24 of length 196 (0 toread) [2009/06/30 04:35:01.379434, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.379476, 5] lib/util.c:642(show_msg) size=192 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=25 smt_wct=15 smb_vwv[ 0]= 24 (0x18) smb_vwv[ 1]= 100 (0x64) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) 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]= 24 (0x18) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 100 (0x64) smb_vwv[12]= 92 (0x5C) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=127 [2009/06/30 04:35:01.379836, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 02 00 00 00 00 2F 00 74 00 73 00 74 ........ ./.t.s.t [0010] 00 2E 00 74 00 73 00 74 00 00 00 FF FF FF FF FF ...t.s.t ........ [0020] FF FF FF FF FF FF FF FF FF FF FF 65 2E 71 82 2B ........ ...e.q.+ [0030] F9 C9 01 FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........ [0040] FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........ [0050] FF FF FF 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 00 00 00 00 B6 ........ ........ [0070] 81 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ....... [2009/06/30 04:35:01.380320, 3] smbd/process.c:1251(switch_message) switch message SMBtrans2 (pid 5441) conn 0x809eb0d8 [2009/06/30 04:35:01.380387, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/06/30 04:35:01.380470, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "tst.tst" [2009/06/30 04:35:01.380544, 5] smbd/filename.c:297(unix_convert) conversion finished tst.tst -> tst.tst [2009/06/30 04:35:01.380611, 3] smbd/trans2.c:6858(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) tst.tst (fnum -1) info_level=512 totdata=100 [2009/06/30 04:35:01.380675, 10] smbd/trans2.c:6090(smb_set_file_unix_basic) smb_set_file_unix_basic: SMB_SET_FILE_UNIX_BASIC: name = tst.tst size = 0, uid = 4294967295, gid = 4294967295, raw perms = 0100666 [2009/06/30 04:35:01.380757, 10] smbd/trans2.c:6136(smb_set_file_unix_basic) smb_set_file_unix_basic: SMB_SET_FILE_UNIX_BASIC setting mode 0666 for file tst.tst [2009/06/30 04:35:01.380936, 6] smbd/trans2.c:5051(smb_set_file_size) smb_set_file_size: size: 1024 smb_set_filetime: actime: Tue Jun 30 03:06:42 2009 smb_set_filetime: modtime: Mon Oct 10 18:53:33 1988 t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 16412 [2009/06/30 04:35:01.381098, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0 [2009/06/30 04:35:01.381159, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.381200, 5] lib/util.c:642(show_msg) size=58 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=25 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 [2009/06/30 04:35:01.381510, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 ... [2009/06/30 04:35:01.382103, 10] lib/util_sock.c:781(read_smb_length_return_keepalive) got smb length of 41 [2009/06/30 04:35:01.382184, 6] smbd/process.c:1430(process_smb) got message type 0x0 of len 0x29 [2009/06/30 04:35:01.382245, 3] smbd/process.c:1433(process_smb) Transaction 25 of length 45 (0 toread) [2009/06/30 04:35:01.382303, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.382345, 5] lib/util.c:642(show_msg) size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=26 smt_wct=3 smb_vwv[ 0]= 4319 (0x10DF) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2009/06/30 04:35:01.382605, 3] smbd/process.c:1251(switch_message) switch message SMBclose (pid 5441) conn 0x809eb0d8 [2009/06/30 04:35:01.382669, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/06/30 04:35:01.382732, 3] smbd/reply.c:4454(reply_close) close fd=29 fnum=4319 (numopen=1) [2009/06/30 04:35:01.382791, 6] smbd/close.c:454(set_close_write_time) close_write_time: Thu Jan 1 00:59:59 1970 [2009/06/30 04:35:01.382868, 10] smbd/oplock_linux.c:135(linux_release_kernel_oplock) linux_release_kernel_oplock: file tst.tst, file_id = 808:ecb19fc:0 gen_id = 4 has kernel oplock state of 1. [2009/06/30 04:35:01.382995, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0808000000000000FC19 [2009/06/30 04:35:01.383091, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x80a04d98 [2009/06/30 04:35:01.383199, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 30 Jun 2009 04:35:01 CEST CEST, cwrt: Mo 10 Okt 1988 18:53:33 CET CET, tok: 0, num_share_modes: 1 [2009/06/30 04:35:01.383404, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 5441, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x1, gen_id = 4, uid = 1000, flags = 1, file_id 808:ecb19fc:0 [2009/06/30 04:35:01.383491, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0808000000000000FC19 [2009/06/30 04:35:01.383596, 10] locking/posix.c:495(get_windows_lock_ref_count) get_windows_lock_count for file tst.tst = 0 [2009/06/30 04:35:01.383662, 10] locking/posix.c:521(delete_windows_lock_ref_count) delete_windows_lock_ref_count for file tst.tst [2009/06/30 04:35:01.383832, 5] smbd/trans2.c:4922(smb_set_file_time) smb_set_filetime: actime: Tue Jun 30 03:06:42 2009 smb_set_filetime: modtime: Tue Jun 30 04:35:01 2009 smb_set_file_time: setting pending modtime to Tue Jun 30 04:35:01 2009 [2009/06/30 04:35:01.383985, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0x809f51e0 "update_write_time_handler" [2009/06/30 04:35:01.384045, 5] locking/locking.c:1425(set_sticky_write_time) set_sticky_write_time: Di 30 Jun 2009 04:35:01 CEST CEST id=808:ecb19fc:0 [2009/06/30 04:35:01.384183, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0808000000000000FC19 [2009/06/30 04:35:01.384252, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0x809fdd60 [2009/06/30 04:35:01.384312, 3] locking/locking.c:858(get_share_mode_lock) fill_share_mode_lock failed [2009/06/30 04:35:01.384368, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0808000000000000FC19 [2009/06/30 04:35:01.384453, 10] smbd/trans2.c:4972(smb_set_file_time) smb_set_file_time: setting utimes to modified values. [2009/06/30 04:35:01.384512, 6] smbd/dosmode.c:721(file_ntimes) file_ntime: actime: Tue Jun 30 03:06:42 2009 [2009/06/30 04:35:01.384577, 6] smbd/dosmode.c:723(file_ntimes) file_ntime: modtime: Tue Jun 30 04:35:01 2009 [2009/06/30 04:35:01.384643, 6] smbd/dosmode.c:725(file_ntimes) file_ntime: createtime: Thu Jan 1 01:00:00 1970 [2009/06/30 04:35:01.384737, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x10, path=/home/gk/cifstest/tst.tst [2009/06/30 04:35:01.384801, 2] smbd/close.c:612(close_normal_file) gk closed file tst.tst (numopen=0) NT_STATUS_OK [2009/06/30 04:35:01.384867, 5] smbd/files.c:472(file_free) freed files structure 4319 (0 used) [2009/06/30 04:35:01.384931, 5] lib/util.c:632(show_msg) [2009/06/30 04:35:01.384974, 5] lib/util.c:642(show_msg) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=11909 smb_uid=100 smb_mid=26 smt_wct=0 smb_bcc=0