[Samba] Re: Re: Change time causes profile corruption
Danny Paul
jdpaul at gocolumbiamo.com
Thu Jul 14 19:29:20 GMT 2005
> 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
-------------- next part --------------
[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)
More information about the samba
mailing list