> Could you send me a level 10 debug from smbd of the > file with a 0 mtime getting created ? I've got a > feeling something else is going on here.
Well, not exactly. The production server serves several users as minute so a level 10 log would produce so much output it would be unusable. Here's what I have. I upped the log level on an internal only server and booted everyone off - then uploaded the file. This should be the same, right? I've attached the log from that operation. If this is not sufficient, I can try to replicate it in my test domain environment, but it's tied up right now. I might also try to come in on a weekend when the use would be low and the output not so high. Thanks for the help, Danny
[2005/07/14 14:16:40, 5] smbd/uid.c:change_to_root_user(296) change_to_root_user: now uid=(0,0) gid=(0,0) [2005/07/14 14:16:40, 3] smbd/error.c:error_packet(129) error packet at smbd/notify.c(55) cmd=160 (SMBnttrans) NT_STATUS_CANCELLED [2005/07/14 14:16:40, 6] lib/util_sock.c:write_socket(449) write_socket(22,75) [2005/07/14 14:16:40, 6] lib/util_sock.c:write_socket(452) write_socket(22,75) wrote 75 [2005/07/14 14:16:40, 3] smbd/notify_kernel.c:kernel_remove_notify(144) kernel_remove_notify: fd=28 [2005/07/14 14:16:40, 3] smbd/nttrans.c:reply_ntcancel(1523) reply_ntcancel: cancel called on mid = 3971. [2005/07/14 14:16:40, 10] lib/util_sock.c:read_smb_length_return_keepalive(505) got smb length of 41 [2005/07/14 14:16:40, 6] smbd/process.c:process_smb(1091) got message type 0x0 of len 0x29 [2005/07/14 14:16:40, 3] smbd/process.c:process_smb(1092) Transaction 92 of length 45 [2005/07/14 14:16:40, 5] lib/util.c:show_msg(461) [2005/07/14 14:16:40, 5] lib/util.c:show_msg(471) size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51207 smb_tid=2 smb_pid=65279 smb_uid=101 smb_mid=5763 smt_wct=3 smb_vwv[ 0]= 7116 (0x1BCC) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2005/07/14 14:16:40, 3] smbd/process.c:switch_message(887) switch message SMBclose (pid 29010) conn 0x82d7bf0 [2005/07/14 14:16:40, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (1091, 513) - sec_ctx_stack_ndx = 0 [2005/07/14 14:16:40, 5] auth/auth_util.c:debug_nt_user_token(491) NT user token of user S-1-5-21-175737297-2311997533-1601259624-3182 contains 9 SIDs SID[ 0]: S-1-5-21-175737297-2311997533-1601259624-3182 SID[ 1]: S-1-5-21-175737297-2311997533-1601259624-513 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-175737297-2311997533-1601259624-1029 SID[ 6]: S-1-5-21-175737297-2311997533-1601259624-1033 SID[ 7]: S-1-5-21-175737297-2311997533-1601259624-1035 SID[ 8]: S-1-5-21-175737297-2311997533-1601259624-1067 [2005/07/14 14:16:40, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 1091 Primary group is 513 and contains 5 supplementary groups Group[ 0]: 14 Group[ 1]: 16 Group[ 2]: 17 Group[ 3]: 33 Group[ 4]: 513 [2005/07/14 14:16:40, 5] smbd/uid.c:change_to_user(281) change_to_user uid=(1091,1091) gid=(0,513) [2005/07/14 14:16:40, 3] smbd/reply.c:reply_close(2758) close directory fnum=7116 [2005/07/14 14:16:40, 5] smbd/files.c:file_free(385) freed files structure 7116 (2 used) [2005/07/14 14:16:40, 5] lib/util.c:show_msg(461) [2005/07/14 14:16:40, 5] lib/util.c:show_msg(471) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51201 smb_tid=2 smb_pid=65279 smb_uid=101 smb_mid=5763 smt_wct=0 smb_bcc=0 [2005/07/14 14:16:40, 6] lib/util_sock.c:write_socket(449) write_socket(22,39) [2005/07/14 14:16:40, 6] lib/util_sock.c:write_socket(452) write_socket(22,39) wrote 39 [2005/07/14 14:16:40, 10] lib/util_sock.c:read_smb_length_return_keepalive(505) got smb length of 36 [2005/07/14 14:16:40, 6] smbd/process.c:process_smb(1091) got message type 0x0 of len 0x24 [2005/07/14 14:16:40, 3] smbd/process.c:process_smb(1092) Transaction 93 of length 40 [2005/07/14 14:16:40, 5] lib/util.c:show_msg(461) [2005/07/14 14:16:40, 5] lib/util.c:show_msg(471) size=36 smb_com=0xa4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51207 smb_tid=2 smb_pid=888 smb_uid=101 smb_mid=4032 smt_wct=0 smb_bcc=0 [2005/07/14 14:16:40, 3] smbd/process.c:switch_message(887) switch message SMBntcancel (pid 29010) conn 0x82d7bf0 [2005/07/14 14:16:40, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2005/07/14 14:16:40, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2005/07/14 14:16:40, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2005/07/14 14:16:40, 5] smbd/uid.c:change_to_root_user(296) change_to_root_user: now uid=(0,0) gid=(0,0) [2005/07/14 14:16:40, 3] smbd/error.c:error_packet(129) error packet at smbd/notify.c(55) cmd=160 (SMBnttrans) NT_STATUS_CANCELLED [2005/07/14 14:16:40, 6] lib/util_sock.c:write_socket(449) write_socket(22,75) [2005/07/14 14:16:40, 6] lib/util_sock.c:write_socket(452) write_socket(22,75) wrote 75 [2005/07/14 14:16:40, 3] smbd/notify_kernel.c:kernel_remove_notify(144) kernel_remove_notify: fd=29 [2005/07/14 14:16:40, 3] smbd/nttrans.c:reply_ntcancel(1523) reply_ntcancel: cancel called on mid = 4032. [2005/07/14 14:16:40, 10] lib/util_sock.c:read_smb_length_return_keepalive(505) got smb length of 41 [2005/07/14 14:16:40, 6] smbd/process.c:process_smb(1091) got message type 0x0 of len 0x29 [2005/07/14 14:16:40, 3] smbd/process.c:process_smb(1092) Transaction 94 of length 45 [2005/07/14 14:16:40, 5] lib/util.c:show_msg(461) [2005/07/14 14:16:40, 5] lib/util.c:show_msg(471) size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51207 smb_tid=2 smb_pid=65279 smb_uid=101 smb_mid=5824 smt_wct=3 smb_vwv[ 0]= 7115 (0x1BCB) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2005/07/14 14:16:40, 3] smbd/process.c:switch_message(887) switch message SMBclose (pid 29010) conn 0x82d7bf0 [2005/07/14 14:16:40, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (1091, 513) - sec_ctx_stack_ndx = 0 [2005/07/14 14:16:40, 5] auth/auth_util.c:debug_nt_user_token(491) NT user token of user S-1-5-21-175737297-2311997533-1601259624-3182 contains 9 SIDs SID[ 0]: S-1-5-21-175737297-2311997533-1601259624-3182 SID[ 1]: S-1-5-21-175737297-2311997533-1601259624-513 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-175737297-2311997533-1601259624-1029 SID[ 6]: S-1-5-21-175737297-2311997533-1601259624-1033 SID[ 7]: S-1-5-21-175737297-2311997533-1601259624-1035 SID[ 8]: S-1-5-21-175737297-2311997533-1601259624-1067 [2005/07/14 14:16:40, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 1091 Primary group is 513 and contains 5 supplementary groups Group[ 0]: 14 Group[ 1]: 16 Group[ 2]: 17 Group[ 3]: 33 Group[ 4]: 513 [2005/07/14 14:16:40, 5] smbd/uid.c:change_to_user(281) change_to_user uid=(1091,1091) gid=(0,513) [2005/07/14 14:16:40, 3] smbd/reply.c:reply_close(2758) close directory fnum=7115 [2005/07/14 14:16:40, 5] smbd/files.c:file_free(385) freed files structure 7115 (1 used) [2005/07/14 14:16:40, 5] lib/util.c:show_msg(461) [2005/07/14 14:16:40, 5] lib/util.c:show_msg(471) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51201 smb_tid=2 smb_pid=65279 smb_uid=101 smb_mid=5824 smt_wct=0 smb_bcc=0 [2005/07/14 14:16:40, 6] lib/util_sock.c:write_socket(449) write_socket(22,39) [2005/07/14 14:16:40, 6] lib/util_sock.c:write_socket(452) write_socket(22,39) wrote 39 [2005/07/14 14:16:46, 3] smbd/sec_ctx.c:set_sec_ctx(288) [2005/07/14 14:16:46, 10] smbd/process.c:async_processing(282) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 async_processing: Doing async processing. [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_nt_user_token(486) [2005/07/14 14:16:46, 5] smbd/oplock.c:receive_local_message(107) NT user token: (NULL) receive_local_message: doing select with timeout of 1 ms [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_unix_user_token(505) [2005/07/14 14:16:46, 3] smbd/sec_ctx.c:set_sec_ctx(288) UNIX token of user 0 setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 Primary group is 0 and contains 0 supplementary groups [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 [2005/07/14 14:16:46, 5] smbd/uid.c:change_to_root_user(296) Primary group is 0 and contains 0 supplementary groups change_to_root_user: now uid=(0,0) gid=(0,0) [2005/07/14 14:16:46, 5] smbd/uid.c:change_to_root_user(296) [2005/07/14 14:16:46, 2] smbd/server.c:exit_server(571) change_to_root_user: now uid=(0,0) gid=(0,0) Closing connections [2005/07/14 14:16:46, 2] smbd/server.c:exit_server(571) Closing connections [2005/07/14 14:16:46, 4] smbd/vfs.c:vfs_ChDir(654) [2005/07/14 14:16:46, 3] smbd/connection.c:yield_connection(69) vfs_ChDir to /tmp Yielding connection to [2005/07/14 14:16:46, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_nt_user_token(486) [2005/07/14 14:16:46, 5] smbd/oplock.c:receive_local_message(107) NT user token: (NULL) receive_local_message: doing select with timeout of 1 ms [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 [2005/07/14 14:16:46, 3] smbd/server.c:exit_server(614) Primary group is 0 and contains 0 supplementary groups [2005/07/14 14:16:46, 5] smbd/uid.c:change_to_root_user(296) change_to_root_user: now uid=(0,0) gid=(0,0) [2005/07/14 14:16:46, 3] smbd/service.c:close_cnum(836) isdb00684xp (192.168.1.209) closed connection to service IPC$ [2005/07/14 14:16:46, 3] smbd/connection.c:yield_connection(69) Yielding connection to IPC$ Server exit (Caught TERM signal) [2005/07/14 14:16:46, 4] smbd/vfs.c:vfs_ChDir(654) vfs_ChDir to / [2005/07/14 14:16:46, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2005/07/14 14:16:46, 5] smbd/uid.c:change_to_root_user(296) change_to_root_user: now uid=(0,0) gid=(0,0) [2005/07/14 14:16:46, 4] smbd/vfs.c:vfs_ChDir(654) vfs_ChDir to /data/genvol [2005/07/14 14:16:46, 10] locking/locking.c:del_share_entry(597) del_share_entry: num_share_modes = 1 [2005/07/14 14:16:46, 10] locking/locking.c:del_share_entry(602) del_share_entry: deleted share_mode_entry[0]: pid = 29010, share_mode = 0x8020, desired_access = 0x20089, port = 0x8034, type= 0x3, file_id = 11, dev = 0x6804, inode = 2697145 [2005/07/14 14:16:46, 10] locking/locking.c:del_share_entry(612) del_share_entry: deleting entry 0 [2005/07/14 14:16:46, 10] locking/locking.c:del_share_entry(634) del_share_entry: Remaining table. [2005/07/14 14:16:46, 10] smbd/close.c:close_normal_file(201) close_normal_file: share_entry_count = 0 for file CE6-15-05.pdf [2005/07/14 14:16:46, 10] smbd/oplock_linux.c:linux_release_kernel_oplock(196) linux_release_kernel_oplock: file CE6-15-05.pdf, dev = 6804, inode = 2697145 file_id = 11 has kernel oplock state of 1. [2005/07/14 14:16:46, 10] locking/posix.c:posix_locking_close_file(1241) posix_locking_close_file: file CE6-15-05.pdf has no outstanding locks. [2005/07/14 14:16:46, 2] smbd/close.c:close_normal_file(270) helpdesk closed file CE6-15-05.pdf (numopen=0) [2005/07/14 14:16:46, 5] smbd/files.c:file_free(385) freed files structure 7125 (0 used) [2005/07/14 14:16:46, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2005/07/14 14:16:46, 5] smbd/uid.c:change_to_root_user(296) change_to_root_user: now uid=(0,0) gid=(0,0) [2005/07/14 14:16:46, 1] smbd/service.c:close_cnum(836) isdb00684xp (192.168.1.209) closed connection to service genvol [2005/07/14 14:16:46, 3] smbd/connection.c:yield_connection(69) Yielding connection to genvol [2005/07/14 14:16:46, 4] smbd/vfs.c:vfs_ChDir(654) vfs_ChDir to / [2005/07/14 14:16:46, 3] smbd/sec_ctx.c:set_sec_ctx(288) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_nt_user_token(486) NT user token: (NULL) [2005/07/14 14:16:46, 5] auth/auth_util.c:debug_unix_user_token(505) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2005/07/14 14:16:46, 5] smbd/uid.c:change_to_root_user(296) change_to_root_user: now uid=(0,0) gid=(0,0) [2005/07/14 14:16:46, 5] auth/auth_util.c:free_server_info(1344) attempting to free (and zero) a server_info structure [2005/07/14 14:16:46, 5] auth/auth_util.c:free_server_info(1344) attempting to free (and zero) a server_info structure [2005/07/14 14:16:46, 3] smbd/connection.c:yield_connection(69) Yielding connection to [2005/07/14 14:16:46, 5] smbd/oplock.c:receive_local_message(107) receive_local_message: doing select with timeout of 1 ms [2005/07/14 14:16:46, 3] smbd/server.c:exit_server(614) Server exit (Caught TERM signal)
-- To unsubscribe from this list go to the following URL and read the instructions: https://lists.samba.org/mailman/listinfo/samba