I have attached parts of samba server and cifs client logs. Wonder what samba server is doing between 12:55:00 and 12:55:21, there is nothing logged on the server during that period.
On 6/5/08, Volker Lendecke <[EMAIL PROTECTED]> wrote: > On Thu, Jun 05, 2008 at 10:09:24AM -0500, Shirish Pargaonkar wrote: > > I downloaded ltp-full-20080131.tgz few months back and > > built it and using network/nfs/nfs_fsstress/fsstress. > > Ok, this might give Steve French something tasty for the > weekend :-) > > > I just recreated the problem a while ago against XP > > server, this time there were single commands per tcp > > packet. So I think the problem is server at some point > > just does not respond to cifs client in time (for whatever > > reasons) for cifs client to decide to reconnect declaring > > server not responding. > > The question is -- is theres still traffic going back and > forth, or is everything stalled? If there's still traffic, > it might be necessary to fix the timeout handling of the > individual smb inside cifsfs to look at whether the server > is alive vs an individual timeout. Much like what Windows > does with the SMBecho requests. > > > I suspect the same for samba server. In case of samba > > server, I had turned on log level to 3 to see whether any > > messages are logged by samba server as to why it is not > > responding to cifs client smb requests but found nothing > > significant in the log file that was generated. > > A sniff of this might still be very valuable, even if it is > huge. > > Volker > >
This is the samba log [2008/06/05 12:55:00, 3] smbd/process.c:process_smb(1068) Transaction 329315 of length 352 [2008/06/05 12:55:00, 3] smbd/process.c:switch_message(926) switch message SMBtrans2 (pid 2510) conn 0x2aaaafd3f80 [2008/06/05 12:55:00, 3] smbd/trans2.c:call_trans2qfilepathinfo(3256) call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 512 [2008/06/05 12:55:00, 3] smbd/trans2.c:call_trans2qfilepathinfo(3307) call_trans2qfilepathinfo p13/d1XXXXXXXX/d12XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/d1c/d20XXXXXXXXXXXXXXXXXXXX/d30XXXX/d40XXXXXXXXXXXXXXXXXX/d70 (fnum = -1) level=512 call=5 total_data=0 [2008/06/05 12:55:00, 3] smbd/process.c:process_smb(1068) Transaction 329316 of length 218 [2008/06/05 12:55:00, 3] smbd/process.c:switch_message(926) switch message SMBtrans2 (pid 2510) conn 0x2aaaafd3f80 [2008/06/05 12:55:00, 3] smbd/trans2.c:call_trans2qfilepathinfo(3256) call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 512 [2008/06/05 12:55:00, 3] smbd/trans2.c:call_trans2qfilepathinfo(3288) call_trans2qfilepathinfo: SMB_VFS_LSTAT of p7/d27XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/d32XXXXXXXXXXX/fab failed (No such file or directory) [2008/06/05 12:55:00, 3] smbd/error.c:unix_error_packet(56) unix_error_packet: error string = No such file or directory [2008/06/05 12:55:00, 3] smbd/error.c:error_packet_set(106) error packet at smbd/trans2.c(3289) cmd=50 (SMBtrans2) NT_STATUS_OBJECT_NAME_NOT_FOUND [2008/06/05 12:55:00, 3] smbd/process.c:process_smb(1068) Transaction 329317 of length 57412 [2008/06/05 12:55:00, 3] smbd/process.c:switch_message(926) switch message SMBwriteX (pid 2510) conn 0x2aaaafd14e0 [2008/06/05 12:55:00, 3] smbd/sec_ctx.c:set_sec_ctx(241) setting sec ctx (99, 99) - sec_ctx_stack_ndx = 0 [2008/06/05 12:55:00, 3] smbd/dosmode.c:unix_mode(142) unix_mode(p10/d6XXXXXXXXXXXXXX/d11XXXXXXXXXXXXXXXX/d70XXXXXXXXXXXXXXXXX/d19XXXXXXXX/f8fXXXX) returning 0744 [2008/06/05 12:55:00, 3] smbd/reply.c:reply_write_and_X(3154) writeX fnum=13411 num=57344 wrote=57344 [2008/06/05 12:55:21, 3] smbd/process.c:timeout_processing(1328) timeout_processing: End of file from client (client has disconnected). [2008/06/05 12:55:21, 3] smbd/sec_ctx.c:set_sec_ctx(241) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) nobody closed file p11/d7XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/d14XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/d1b/f9fXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX ( numopen=2133) NT_STATUS_OK [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) nobody closed file pf/dbXXXXXXXXXXXXXXXXXXXXXXX/d19XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/f30XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX (numopen=2132) NT_STATUS_OK [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) nobody closed file p5/d6X/d52XXXXXXXXXXXXXXXXXXXXXX/f17XXXXXXXXXXX (numopen=2131) NT_STATUS_OK [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) nobody closed file p6/d13X/d1dXXXXXXXXXXXXXXXXXXX/f8aXX (numopen=2130) NT_STATUS_OK [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) nobody closed file pc/d8XXX/d14XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/d2bX/d37XXXXXXXXXXXXXXXXXXXXXXXXXX X/d5bX/d7a/f5fXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX (numopen=2129) NT_STATUS_OK [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) nobody closed file p6/d13X/d1dXXXXXXXXXXXXXXXXXXX/f8aXX (numopen=2128) NT_STATUS_OK [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) nobody closed file p0/d1/f95XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX (numopen=2127) NT_STATUS_OK [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) nobody closed file p11/d7XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/d14XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/d21/f8eXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXX (numopen=2126) NT_STATUS_OK [2008/06/05 12:55:21, 2] smbd/close.c:close_normal_file(406) And this is the cifs log Jun 5 12:55:00 LAC0039 kernel: CIFS VFS: Frame receivedNumMids 4, Mid 63705, Pid: 59933, cmd: 50 Jun 5 12:55:00 LAC0039 kernel: CIFS VFS: Frame receivedNumMids 3, Mid 63706, Pid: 64541, cmd: 50 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: Frame receivedNumMids 2, Mid 63707, Pid: 61469, cmd: 50 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: sends on sock 0000000012094100, sndbuf 34776, rcvbuf 176640 of length 57408 stuck for 15 seconds, mid: 63708 pid: 8200, cmd: 47, error: -11 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 Error -11 sending data on socket to server Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: SendReceive2 returns -11 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: Send error Write2 = -11 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: Write2 ret -11, wrote 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: sends on sock 0000000012094100, sndbuf 34776, rcvbuf 176640 of length 48368 stuck for 15 seconds, mid: 63748 pid: 8200, cmd: 47, error: -11 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 Error -11 sending data on socket to server Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: SendReceive2 returns -11 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: Send error Write2 = -11 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: Write2 ret -11, wrote 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63749, pid: 8200, cmd: 4, length: 45, i: 6 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63709, pid: 7662, cmd: 50, length: 170, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63710, pid: 9231, cmd: 4, length: 45, i: 1 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63711, pid: 9232, cmd: 47, length: 4733, i: 3 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63712, pid: 8187, cmd: 50, length: 396, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63713, pid: 8199, cmd: 50, length: 490, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63714, pid: 8190, cmd: 50, length: 132, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63715, pid: 7660, cmd: 50, length: 376, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63716, pid: 8186, cmd: 50, length: 88, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63717, pid: 7661, cmd: 50, length: 96, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63718, pid: 8202, cmd: 4, length: 45, i: 1 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63719, pid: 7669, cmd: 50, length: 92, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63720, pid: 8194, cmd: 50, length: 1250, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63721, pid: 8198, cmd: 50, length: 364, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63722, pid: 8184, cmd: 50, length: 216, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63723, pid: 7666, cmd: 50, length: 372, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63724, pid: 8192, cmd: 50, length: 170, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63725, pid: 7672, cmd: 50, length: 814, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63726, pid: 8191, cmd: 50, length: 90, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63727, pid: 7674, cmd: 50, length: 476, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63728, pid: 8189, cmd: 47, length: 1234, i: 2 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63729, pid: 7667, cmd: 50, length: 140, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63730, pid: 8196, cmd: 50, length: 120, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63731, pid: 8197, cmd: 7, length: 460, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63732, pid: 8188, cmd: 50, length: 96, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63733, pid: 8195, cmd: 4, length: 45, i: 1 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63734, pid: 8193, cmd: 50, length: 200, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63735, pid: 7657, cmd: 4, length: 45, i: 1 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63736, pid: 7663, cmd: 50, length: 128, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63737, pid: 7673, cmd: 50, length: 140, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63738, pid: 7670, cmd: 50, length: 104, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63739, pid: 7659, cmd: 50, length: 696, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63740, pid: 7671, cmd: 50, length: 450, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63741, pid: 7665, cmd: 50, length: 364, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63742, pid: 7668, cmd: 50, length: 108, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63743, pid: 8203, cmd: 46, length: 63, i: 1 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63744, pid: 7675, cmd: 162, length: 162, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63745, pid: 7658, cmd: 50, length: 122, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63746, pid: 7676, cmd: 50, length: 368, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send successful ssocket: 0000000012094100, mid:63747, pid: 7664, cmd: 162, length: 226, i: 0 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: smb_send2 successful ssocket: 0000000012094100, mid:63750, pid: 8201, cmd: 47, length: 24644, i: 7 Jun 5 12:55:01 LAC0039 kernel: CIFS VFS: No task to wake, unknown frame received! NumMids 41, Mid 63708, Pid: 2080, cmd: 47 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: server not responding Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 4 mid 63749 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error in Close = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63709 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 4 mid 63710 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error in Close = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 47 mid 63711 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error Write2 = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Write2 ret -11, wrote 0 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63712 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63713 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63714 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63715 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63716 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63717 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 4 mid 63718 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error in Close = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63719 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63720 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63721 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63722 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63723 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63724 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63725 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63726 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63727 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 47 mid 63728 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error Write2 = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63729 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63730 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 7 mid 63731 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63732 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 4 mid 63733 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error in Close = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63734 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 4 mid 63735 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error in Close = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63736 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63737 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63738 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63739 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63740 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63741 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63742 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 46 mid 63743 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error in read = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 162 mid 63744 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63745 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 50 mid 63746 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response for cmd 162 mid 63747 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: No response to cmd 47 mid 63750 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Send error Write2 = -11 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Write2 ret -11, wrote 0 Jun 5 12:55:21 LAC0039 kernel: CIFS VFS: Reconnect after server stopped responding
-- To unsubscribe from this list go to the following URL and read the instructions: https://lists.samba.org/mailman/listinfo/samba
