samba server log level 10 data interpretation help - Samba

This is a discussion on samba server log level 10 data interpretation help - Samba ; Hi, I have this part of the samba server log at log level 10. Based on the log, I was looking for the confirmation that the whether samba server received a request Write Andx (0x2f 47) with mid 0xB634 and ...

+ Reply to Thread
Results 1 to 2 of 2

Thread: samba server log level 10 data interpretation help

  1. samba server log level 10 data interpretation help

    Hi,

    I have this part of the samba server log at log level 10.
    Based on the log, I was looking for the confirmation that the whether
    samba server
    received a request Write Andx (0x2f 47) with mid 0xB634 and pid 0x56D5
    and responded to that request and that was the last request it received and
    responded before client to this samba server disconnected.


    [2008/06/16 08:40:15, 6] smbd/process.crocess_smb(1067)
    got message type 0x0 of len 0xe040
    [2008/06/16 08:40:15, 3] smbd/process.crocess_smb(1068)
    Transaction 13724 of length 57412
    [2008/06/16 08:40:15, 5] lib/util.c:show_msg(506)
    [2008/06/16 08:40:15, 5] lib/util.c:show_msg(516)
    size=57408
    smb_com=0x2f
    smb_rcls=0
    smb_reh=0
    smb_err=0
    smb_flg=0
    smb_flg2=49153
    smb_tid=4
    smb_pid=22229
    smb_uid=0
    smb_mid=46644
    smt_wct=14
    smb_vwv[ 0]= 255 (0xFF)
    smb_vwv[ 1]= 0 (0x0)
    smb_vwv[ 2]= 5755 (0x167B)
    smb_vwv[ 3]=49152 (0xC000)
    smb_vwv[ 4]= 6 (0x6)
    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]=57344 (0xE000)
    smb_vwv[11]= 64 (0x40)
    smb_vwv[12]= 0 (0x0)
    smb_vwv[13]= 0 (0x0)
    smb_bcc=57345
    [2008/06/16 08:40:15, 10] lib/util.c:dump_data(2286)
    [000] 00 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F ./////// ////////
    [010] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [020] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [030] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [040] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [050] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [060] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [070] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [080] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [090] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [0A0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [0B0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [0C0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [0D0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [0E0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [0F0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [100] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [110] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [120] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [130] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [140] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [150] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [160] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [170] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [180] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [190] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [1A0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [1B0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [1C0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [1D0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [1E0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [1F0] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// ////////
    [2008/06/16 08:40:15, 3] smbd/process.c:switch_message(926)
    switch message SMBwriteX (pid 26808) conn 0x2aaaafd4a50
    [2008/06/16 08:40:15, 3] smbd/sec_ctx.c:set_sec_ctx(241)
    setting sec ctx (99, 99) - sec_ctx_stack_ndx = 0
    [2008/06/16 08:40:15, 5] auth/auth_util.c:debug_nt_user_token(454)
    NT user token of user S-1-22-1-99
    contains 5 SIDs
    SID[ 0]: S-1-22-1-99
    SID[ 1]: S-1-22-2-99
    SID[ 2]: S-1-1-0
    SID[ 3]: S-1-5-2
    SID[ 4]: S-1-5-32-546
    SE_PRIV 0x0 0x0 0x0 0x0
    [2008/06/16 08:40:15, 5] auth/auth_util.c:debug_unix_user_token(474)
    UNIX token of user 99
    Primary group is 99 and contains 1 supplementary groups
    Group[ 0]: 99
    [2008/06/16 08:40:15, 5] smbd/uid.c:change_to_user(273)
    change_to_user uid=(99,99) gid=(0,99)
    [2008/06/16 08:40:15, 4] smbd/vfs.c:vfs_ChDir(665)
    vfs_ChDir to /SAMBA4
    [2008/06/16 08:40:15, 10] locking/locking.c:is_locked(99)
    is_locked: optimisation - exclusive oplock on file
    p1/d1/dcXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXX/d11/d12XXXXXXXXXXX/
    d27XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
    /f1aXXXXX
    [2008/06/16 08:40:15, 10] locking/locking.c:is_locked(137)
    is_locked: flavour = POSIX_LOCK brl start=442368 len=57344 unlocked for fnum
    5755 file
    p1/d1/dcXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXX/d11/d12XXXXXXXXXXX/
    d27XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
    /f1aXXXXX
    [2008/06/16 08:40:15, 10] smbd/fileio.c:real_write_file(137)
    real_write_file
    (p1/d1/dcXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXX/d11/d12XXXXXXXXXXX
    /d27XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXX
    X/f1aXXXXX): pos = 442368, size = 57344, returned 57344
    [2008/06/16 08:40:15, 3] smbd/reply.c:reply_write_and_X(3154)
    writeX fnum=5755 num=57344 wrote=57344
    [2008/06/16 08:40:15, 5] lib/util.c:show_msg(506)
    [2008/06/16 08:40:15, 5] lib/util.c:show_msg(516)
    size=47
    smb_com=0x2f
    smb_rcls=0
    smb_reh=0
    smb_err=0
    smb_flg=128
    smb_flg2=49153
    smb_tid=4
    smb_pid=22229
    smb_uid=0
    smb_mid=46644
    smt_wct=6
    smb_vwv[ 0]= 255 (0xFF)
    smb_vwv[ 1]= 0 (0x0)
    smb_vwv[ 2]=57344 (0xE000)
    smb_vwv[ 3]= 0 (0x0)
    smb_vwv[ 4]= 0 (0x0)
    smb_vwv[ 5]= 0 (0x0)
    smb_bcc=0
    [2008/06/16 08:40:15, 10] lib/util_sock.c:read_smb_length_return_keepalive(623)
    got smb length of 70419
    [2008/06/16 08:40:36, 10] lib/util_sock.c:read_data(525)
    read_data: read of 15700 returned 0. Error = Success
    [2008/06/16 08:40:36, 3] smbd/process.c:timeout_processing(1328)
    timeout_processing: End of file from client (client has disconnected).



    There is a corrosponding cifs client log to go with this.

    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: sends on sock 00000000021b4d00,
    sndbuf 34776, rcvbuf 87380 of length 57408 stuck for 15 seconds, mid: 13494
    pid: 22229, cmd: 47,
    error: -11


    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: No task to wake, unknown frame
    received! NumMids 19, Mid 13494, Pid: 54614, cmd: 47

    Jun 16 08:40:35 LAC0039 kernel: CIFS VFS: server not responding

    Jun 16 08:40:36 LAC0039 kernel: CIFS VFS: Reconnect after server stopped
    responding
    Jun 16 08:40:36 LAC0039 kernel: CIFS VFS: Reconnecting tcp session


    So I am suspecting there is a bug in either cifs client or the tcp/ip layer
    on the client machine where it looks like a request is not sent over
    the socket with
    error EAGAIN yet it ends up on the samba server and gets a response.

    Regards,

    Shirish


  2. Re: samba server log level 10 data interpretation help

    What seems to be happening is, cifs is sending commands whose mid
    and pid in smb header can be seen on samba log. Then comes this
    write andx command for which cifs logs 'stuck on socket error'
    yet I see that request on samba server and a response sent by
    samba server and there is a corrosponding "unknown frame received'
    response logged by cifs (with matching mid and pid in smb header).

    After this write andx command for which socket returned error EAGAIN,
    cifs does send few more requests and receives success on the socket but
    there is no log of these requests on samba server.

    So cifs is thinking the requests have been sent successfully yet
    samba server has not received any of those and does not respond and
    cifs timesout and reconnects.

    Here is the supporting cifs log entries and samba server log mixed


    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid: 13490, pid: 22241,
    cmd: 50

    1670833 size=198
    1670834 smb_com=0x32
    1670835 smb_rcls=0
    1670836 smb_reh=0
    1670837 smb_err=0
    1670838 smb_flg=0
    1670839 smb_flg2=49153
    1670840 smb_tid=4
    1670841 smb_pid=22241
    1670842 smb_uid=0
    1670843 smb_mid=45620
    1670844 smt_wct=15
    1670845 smb_vwv[ 0]= 132 (0x84)
    1670846 smb_vwv[ 1]= 0 (0x0)
    1670847 smb_vwv[ 2]= 2 (0x2)
    1670848 smb_vwv[ 3]= 4000 (0xFA0)
    1670849 smb_vwv[ 4]= 0 (0x0)
    1670850 smb_vwv[ 5]= 0 (0x0)
    1670851 smb_vwv[ 6]= 0 (0x0)
    1670852 smb_vwv[ 7]= 0 (0x0)
    1670853 smb_vwv[ 8]= 0 (0x0)
    1670854 smb_vwv[ 9]= 132 (0x84)
    1670855 smb_vwv[10]= 66 (0x42)
    1670856 smb_vwv[11]= 0 (0x0)
    1670857 smb_vwv[12]= 0 (0x0)
    1670858 smb_vwv[13]= 1 (0x1)
    1670859 smb_vwv[14]= 5 (0x5)
    1670860 smb_bcc=133
    1670861 [2008/06/16 08:40:15, 10] lib/util.c:dump_data(2286)
    1670862 [000] 00 00 02 00 00 00 00 2F 00 70 00 64 00 2F 00 64
    ......../ .p.d./.d
    1670863 [010] 00 35 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..5.X.X.X .X.X.X.X
    1670864 [020] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670865 [030] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670866 [040] 00 2F 00 64 00 31 00 61 00 58 00 58 00 2F 00 64
    ../.d.1.a .X.X./.d
    1670867 [050] 00 31 00 63 00 58 00 58 00 58 00 58 00 58 00 58
    ..1.c.X.X .X.X.X.X
    1670868 [060] 00 58 00 58 00 58 00 58 00 2F 00 66 00 33 00 33
    ..X.X.X.X ./.f.3.3
    1670869 [070] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670870 [080] 00 58 00 00 00 .X...
    1670871 [2008/06/16 08:40:15, 3] smbd/process.c:switch_message(926)
    1670872 switch message SMBtrans2 (pid 26808) conn 0x2aaaafd4a50


    1670906 size=35
    1670907 smb_com=0x32
    1670908 smb_rcls=52
    1670909 smb_reh=0
    1670910 smb_err=49152
    1670911 smb_flg=128
    1670912 smb_flg2=49217
    1670913 smb_tid=4
    1670914 smb_pid=22241
    1670915 smb_uid=0
    1670916 smb_mid=45620
    1670917 smt_wct=0
    1670918 smb_bcc=0


    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid: 13491, pid: 22426,
    cmd: 50

    1670927 size=616
    1670928 smb_com=0x32
    1670929 smb_rcls=0
    1670930 smb_reh=0
    1670931 smb_err=0
    1670932 smb_flg=0
    1670933 smb_flg2=49153
    1670934 smb_tid=2
    1670935 smb_pid=22426
    1670936 smb_uid=0
    1670937 smb_mid=45876
    1670938 smt_wct=15
    1670939 smb_vwv[ 0]= 550 (0x226)
    1670940 smb_vwv[ 1]= 0 (0x0)
    1670941 smb_vwv[ 2]= 2 (0x2)
    1670942 smb_vwv[ 3]= 4000 (0xFA0)
    1670943 smb_vwv[ 4]= 0 (0x0)
    1670944 smb_vwv[ 5]= 0 (0x0)
    1670945 smb_vwv[ 6]= 0 (0x0)
    1670946 smb_vwv[ 7]= 0 (0x0)
    1670947 smb_vwv[ 8]= 0 (0x0)
    1670948 smb_vwv[ 9]= 550 (0x226)
    1670949 smb_vwv[10]= 66 (0x42)
    1670950 smb_vwv[11]= 0 (0x0)
    1670951 smb_vwv[12]= 0 (0x0)
    1670952 smb_vwv[13]= 1 (0x1)
    1670953 smb_vwv[14]= 5 (0x5)
    1670954 smb_bcc=551
    1670955 [2008/06/16 08:40:15, 10] lib/util.c:dump_data(2286)
    1670956 [000] 00 00 02 00 00 00 00 2F 00 70 00 35 00 2F 00 64
    ......../ .p.5./.d
    1670957 [010] 00 34 00 58 00 2F 00 64 00 61 00 58 00 58 00 58
    ..4.X./.d .a.X.X.X
    1670958 [020] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670959 [030] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670960 [040] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670961 [050] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670962 [060] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670963 [070] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670964 [080] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670965 [090] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X
    1670966 [0A0] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..X.X.X.X .X.X.X.X

    1671034 [2008/06/16 08:40:15, 5] lib/util.c:show_msg(516)
    1671035 size=160
    1671036 smb_com=0x32
    1671037 smb_rcls=0
    1671038 smb_reh=0
    1671039 smb_err=0
    1671040 smb_flg=128
    1671041 smb_flg2=49217
    1671042 smb_tid=2
    1671043 smb_pid=22426
    1671044 smb_uid=0
    1671045 smb_mid=45876
    1671046 smt_wct=10
    1671047 smb_vwv[ 0]= 2 (0x2)
    1671048 smb_vwv[ 1]= 100 (0x64)
    1671049 smb_vwv[ 2]= 0 (0x0)
    1671050 smb_vwv[ 3]= 2 (0x2)
    1671051 smb_vwv[ 4]= 56 (0x38)
    1671052 smb_vwv[ 5]= 0 (0x0)
    1671053 smb_vwv[ 6]= 100 (0x64)
    1671054 smb_vwv[ 7]= 60 (0x3C)
    1671055 smb_vwv[ 8]= 0 (0x0)
    1671056 smb_vwv[ 9]= 0 (0x0)
    1671057 smb_bcc=105
    1671058 [2008/06/16 08:40:15, 10] lib/util.c:dump_data(2286)
    1671059 [000] 00 00 00 00 00 AD 30 11 00 00 00 00 00 00 00 02
    .......0. ........
    1671060 [010] 00 00 00 00 00 80 74 EA 1E AE CF C8 01 80 93 F4
    .......t. ........
    1671061 [020] 18 AE CF C8 01 80 74 EA 1E AE CF C8 01 63 00 00
    .......t. .....c..
    1671062 [030] 00 00 00 00 00 63 00 00 00 00 00 00 00 00 00 00
    ......c.. ........
    1671063 [040] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    ......... ........
    1671064 [050] 00 89 EA 01 00 00 00 00 00 F6 01 00 00 00 00 00
    ......... ........
    1671065 [060] 00 01 00 00 00 00 00 00 00 ........ .

    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid: 13492, pid: 22232,
    cmd: 50,

    1671073 [2008/06/16 08:40:15, 5] lib/util.c:show_msg(516)
    1671074 size=114
    1671075 smb_com=0x32
    1671076 smb_rcls=0
    1671077 smb_reh=0
    1671078 smb_err=0
    1671079 smb_flg=0
    1671080 smb_flg2=49153
    1671081 smb_tid=4
    1671082 smb_pid=22232
    1671083 smb_uid=0
    1671084 smb_mid=46132
    1671085 smt_wct=15
    1671086 smb_vwv[ 0]= 48 (0x30)
    1671087 smb_vwv[ 1]= 0 (0x0)
    1671088 smb_vwv[ 2]= 2 (0x2)
    1671089 smb_vwv[ 3]= 4000 (0xFA0)
    1671090 smb_vwv[ 4]= 0 (0x0)
    1671091 smb_vwv[ 5]= 0 (0x0)
    1671092 smb_vwv[ 6]= 0 (0x0)
    1671093 smb_vwv[ 7]= 0 (0x0)
    1671094 smb_vwv[ 8]= 0 (0x0)
    1671095 smb_vwv[ 9]= 48 (0x30)
    1671096 smb_vwv[10]= 66 (0x42)
    1671097 smb_vwv[11]= 0 (0x0)
    1671098 smb_vwv[12]= 0 (0x0)
    1671099 smb_vwv[13]= 1 (0x1)
    1671100 smb_vwv[14]= 5 (0x5)
    1671101 smb_bcc=49
    1671102 [2008/06/16 08:40:15, 10] lib/util.c:dump_data(2286)
    1671103 [000] 00 00 02 00 00 00 00 2F 00 70 00 34 00 2F 00 64
    ......../ .p.4./.d
    1671104 [010] 00 34 00 58 00 58 00 58 00 58 00 58 00 58 00 58
    ..4.X.X.X .X.X.X.X
    1671105 [020] 00 58 00 58 00 58 00 58 00 58 00 58 00 58 00 00
    ..X.X.X.X .X.X.X..
    1671106 [030] 00 .
    1671107 [2008/06/16 08:40:15, 3] smbd/process.c:switch_message(926)
    1671108 switch message SMBtrans2 (pid 26808) conn 0x2aaaafd4a50
    1671109 [2008/06/16 08:40:15, 3] smbd/sec_ctx.c:set_sec_ctx(241)
    1671110 setting sec ctx (99, 99) - sec_ctx_stack_ndx = 0

    1671154 size=160
    1671155 smb_com=0x32
    1671156 smb_rcls=0
    1671157 smb_reh=0
    1671158 smb_err=0
    1671159 smb_flg=128
    1671160 smb_flg2=49217
    1671161 smb_tid=4
    1671162 smb_pid=22232
    1671163 smb_uid=0
    1671164 smb_mid=46132
    1671165 smt_wct=10
    1671166 smb_vwv[ 0]= 2 (0x2)
    1671167 smb_vwv[ 1]= 100 (0x64)
    1671168 smb_vwv[ 2]= 0 (0x0)
    1671169 smb_vwv[ 3]= 2 (0x2)
    1671170 smb_vwv[ 4]= 56 (0x38)
    1671171 smb_vwv[ 5]= 0 (0x0)
    1671172 smb_vwv[ 6]= 100 (0x64)
    1671173 smb_vwv[ 7]= 60 (0x3C)
    1671174 smb_vwv[ 8]= 0 (0x0)
    1671175 smb_vwv[ 9]= 0 (0x0)
    1671176 smb_bcc=105
    1671177 [2008/06/16 08:40:15, 10] lib/util.c:dump_data(2286)
    1671178 [000] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    ......... ........
    1671179 [010] 00 00 00 00 00 00 0B 83 1F AE CF C8 01 80 A7 93
    ......... ........
    1671180 [020] F7 AD CF C8 01 00 0B 83 1F AE CF C8 01 63 00 00
    ......... .....c..
    1671181 [030] 00 00 00 00 00 63 00 00 00 00 00 00 00 01 00 00
    ......c.. ........
    1671182 [040] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
    ......... ........
    1671183 [050] 00 F3 BD 03 00 00 00 00 00 ED 01 00 00 00 00 00
    ......... ........
    1671184 [060] 00 03 00 00 00 00 00 00 00 ........ .


    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send2 success mid: 13493,
    pid: 22437,
    cmd: 4,

    1671192 [2008/06/16 08:40:15, 5] lib/util.c:show_msg(516)
    1671193 size=41
    1671194 smb_com=0x4
    1671195 smb_rcls=0
    1671196 smb_reh=0
    1671197 smb_err=0
    1671198 smb_flg=0
    1671199 smb_flg2=49153
    1671200 smb_tid=2
    1671201 smb_pid=22437
    1671202 smb_uid=0
    1671203 smb_mid=46388
    1671204 smt_wct=3
    1671205 smb_vwv[ 0]= 5760 (0x1680)
    1671206 smb_vwv[ 1]=65535 (0xFFFF)
    1671207 smb_vwv[ 2]=65535 (0xFFFF)
    1671208 smb_bcc=0
    1671209 [2008/06/16 08:40:15, 3] smbd/process.c:switch_message(926)
    1671210 switch message SMBclose (pid 26808) conn 0x2aaaafd1cd0

    1671260 [2008/06/16 08:40:15, 2] smbd/close.c:close_normal_file(406)
    1671261 nobody closed file
    pe/d5XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX/f8 (numopen=200)
    NT_STATUS_OK
    1671262 [2008/06/16 08:40:15, 5] smbd/files.c:file_free(454)
    1671263 freed files structure 5760 (748 used)
    1671264 [2008/06/16 08:40:15, 5] lib/util.c:show_msg(506)
    1671265 [2008/06/16 08:40:15, 5] lib/util.c:show_msg(516)
    1671266 size=35
    1671267 smb_com=0x4
    1671268 smb_rcls=0
    1671269 smb_reh=0
    1671270 smb_err=0
    1671271 smb_flg=128
    1671272 smb_flg2=49153
    1671273 smb_tid=2
    1671274 smb_pid=22437
    1671275 smb_uid=0
    1671276 smb_mid=46388
    1671277 smt_wct=0
    1671278 smb_bcc=0


    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: sends on sock 00000000021b4d00,
    sndbuf 34776, rcvbuf 87380 of length 57408 stuck for 15 seconds,
    mid: 13494 pid: 22229, c md: 47, error: -11
    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: smb_send2 Error -11 sending data on
    socket to server
    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: SendReceive2 returns -11
    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: Send error Write2 = -11
    Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: Write2 ret -11, wrote 0

    1671287 size=57408
    1671288 smb_com=0x2f
    1671289 smb_rcls=0
    1671290 smb_reh=0
    1671291 smb_err=0
    1671292 smb_flg=0
    1671293 smb_flg2=49153
    1671294 smb_tid=4
    1671295 smb_pid=22229
    1671296 smb_uid=0
    1671297 smb_mid=46644
    1671298 smt_wct=14
    1671299 smb_vwv[ 0]= 255 (0xFF)
    1671300 smb_vwv[ 1]= 0 (0x0)
    1671301 smb_vwv[ 2]= 5755 (0x167B)
    1671302 smb_vwv[ 3]=49152 (0xC000)
    1671303 smb_vwv[ 4]= 6 (0x6)
    1671304 smb_vwv[ 5]=65535 (0xFFFF)
    1671305 smb_vwv[ 6]=65535 (0xFFFF)
    1671306 smb_vwv[ 7]= 0 (0x0)
    1671307 smb_vwv[ 8]= 0 (0x0)
    1671308 smb_vwv[ 9]= 0 (0x0)
    1671309 smb_vwv[10]=57344 (0xE000)
    1671310 smb_vwv[11]= 64 (0x40)
    1671311 smb_vwv[12]= 0 (0x0)
    1671312 smb_vwv[13]= 0 (0x0)
    1671313 smb_bcc=57345
    1671314 [2008/06/16 08:40:15, 10] lib/util.c:dump_data(2286)
    1671315 [000] 00 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F
    ../////// ////////
    1671316 [010] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F
    //////// ////////
    1671317 [020] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F
    //////// ////////
    1671318 [030] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F
    //////// ////////
    1671319 [040] 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F 2F //////// //


    1671374 [2008/06/16 08:40:15, 3] smbd/reply.c:reply_write_and_X(3154)
    1671375 writeX fnum=5755 num=57344 wrote=57344
    1671376 [2008/06/16 08:40:15, 5] lib/util.c:show_msg(506)
    1671377 [2008/06/16 08:40:15, 5] lib/util.c:show_msg(516)
    1671378 size=47
    1671379 smb_com=0x2f
    1671380 smb_rcls=0
    1671381 smb_reh=0
    1671382 smb_err=0
    1671383 smb_flg=128
    1671384 smb_flg2=49153
    1671385 smb_tid=4
    1671386 smb_pid=22229
    1671387 smb_uid=0
    1671388 smb_mid=46644
    1671389 smt_wct=6
    1671390 smb_vwv[ 0]= 255 (0xFF)
    1671391 smb_vwv[ 1]= 0 (0x0)
    1671392 smb_vwv[ 2]=57344 (0xE000)
    1671393 smb_vwv[ 3]= 0 (0x0)
    1671394 smb_vwv[ 4]= 0 (0x0)
    1671395 smb_vwv[ 5]= 0 (0x0)
    1671396 smb_bcc=0
    [2008/06/16 08:40:15, 10] lib/util_sock.c:read_smb_length_return_keepalive(623)
    got smb length of 70419
    [2008/06/16 08:40:36, 10] lib/util_sock.c:read_data(525)
    read_data: read of 15700 returned 0. Error = Success
    [2008/06/16 08:40:36, 3] smbd/process.c:timeout_processing(1328)
    timeout_processing: End of file from client (client has disconnected).

    None of these requests are logged on the server

    13574 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send2 success mid:
    13519, pid: 22229, cmd: 47,
    13575 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13495, pid: 22245, cmd: 50,
    13576 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13496, pid: 22237, cmd: 50,
    13577 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13497, pid: 22243, cmd: 50,
    13578 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13498, pid: 22422, cmd: 50,
    13579 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13499, pid: 22435, cmd: 50,
    13580 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13500, pid: 22234, cmd: 50,
    13581 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13501, pid: 22439, cmd: 50,
    13582 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13502, pid: 22233, cmd: 50,
    13583 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13503, pid: 22441, cmd: 50,
    13584 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13504, pid: 22423, cmd: 50,
    13585 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13505, pid: 22242, cmd: 50,
    13586 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13506, pid: 22244, cmd: 50,
    13587 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13507, pid: 22432, cmd: 50,
    13588 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13508, pid: 22231, cmd: 50,
    13589 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13509, pid: 22430, cmd: 50,
    13590 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13510, pid: 22433, cmd: 50,
    13591 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13511, pid: 22421, cmd: 50,
    13592 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: No task to wake,
    unknown frame received! NumMids 19, Mid 13494, Pid: 54614, cmd: 47
    13593 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send2 success mid:
    13512, pid: 22436, cmd: 47,
    13594 Jun 16 08:40:15 LAC0039 kernel: CIFS VFS: send success mid:
    13513, pid: 22427, cmd: 50,


+ Reply to Thread