Attachment 12076 Details for Bug 11905 – debug level 10 of failing client

debug level 10 of failing client

samba_debug_failed_client.txt (text/plain), 38.98 KB, created by andrew on 2016-05-06 05:38:42 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: andrew

Created: 2016-05-06 05:38:42 UTC

Size: 38.98 KB

patch

obsolete

>[2016/05/06 10:37:56.514653, 10, pid=9978, effective(0, 0), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
>  got smb length of 76
>[2016/05/06 10:37:56.514739,  6, pid=9978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1877(process_smb)
>  got message type 0x0 of len 0x4c
>[2016/05/06 10:37:56.514785,  3, pid=9978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1879(process_smb)
>  Transaction 7 of length 80 (0 toread)
>[2016/05/06 10:37:56.514848,  5, pid=9978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.514869,  5, pid=9978, effective(0, 0), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=76
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=448
>  smt_wct=15
>  smb_vwv[ 0]=    8 (0x8)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  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]=    8 (0x8)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=11
>[2016/05/06 10:37:56.515359, 10, pid=9978, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 EC 03 00 00 00   00 00 00                 ........ ...
>[2016/05/06 10:37:56.515420,  3, pid=9978, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1489(switch_message)
>  switch message SMBtrans2 (pid 9978) conn 0x8134bc960
>[2016/05/06 10:37:56.515491,  4, pid=9978, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
>  setting sec ctx (1002, 1002) - sec_ctx_stack_ndx = 0
>[2016/05/06 10:37:56.515554,  5, pid=9978, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:63(security_token_debug)
>  Security token SIDs (7):
>    SID[  0]: S-1-5-21-4127461147-3627497618-4263181281-1000
>    SID[  1]: S-1-5-21-4127461147-3627497618-4263181281-513
>    SID[  2]: S-1-22-2-1002
>    SID[  3]: S-1-1-0
>    SID[  4]: S-1-5-2
>    SID[  5]: S-1-5-11
>    SID[  6]: S-1-22-1-1002
>   Privileges (0x               0):
>   Rights (0x               0):
>[2016/05/06 10:37:56.515750,  5, pid=9978, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token)
>  UNIX token of user 1002
>  Primary group is 1002 and contains 1 supplementary groups
>  Group[  0]: 1002
>[2016/05/06 10:37:56.515882,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/uid.c:363(change_to_user_internal)
>  Impersonated user: uid=(0,1002), gid=(0,1002)
>[2016/05/06 10:37:56.515927,  4, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:858(vfs_ChDir)
>  vfs_ChDir to /media
>[2016/05/06 10:37:56.515996,  4, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:869(vfs_ChDir)
>  vfs_ChDir got /media
>[2016/05/06 10:37:56.516038,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:5518(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
>[2016/05/06 10:37:56.516112,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:257(unix_convert)
>  unix_convert called on file ""
>[2016/05/06 10:37:56.516157,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:291(unix_convert)
>  conversion finished "" -> .
>[2016/05/06 10:37:56.516194,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1161(check_reduced_name)
>  check_reduced_name [.] [/media]
>[2016/05/06 10:37:56.516244, 10, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1221(check_reduced_name)
>  check_reduced_name realpath [.] -> [/media]
>[2016/05/06 10:37:56.516280,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1294(check_reduced_name)
>  check_reduced_name: . reduced to /media
>[2016/05/06 10:37:56.516323, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/files.c:744(file_name_hash)
>  file_name_hash: /media/. hash 0xfe4c393d
>[2016/05/06 10:37:56.516382,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:5661(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo . (fnum [fsp is NULL]) level=1004 call=5 total_data=0
>[2016/05/06 10:37:56.516495,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4596(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: . (fnum [fsp is NULL]) level=1004 max_data=40
>[2016/05/06 10:37:56.516541,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:600(dos_mode)
>  dos_mode: .
>[2016/05/06 10:37:56.516585,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:242(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2016/05/06 10:37:56.516623,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:36(dos_mode_debug_print)
>  dos_mode returning d
>[2016/05/06 10:37:56.516672, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4840(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2016/05/06 10:37:56.516714,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4850(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Thu Apr  7 01:07:03 2016
>   access: Thu Apr  7 01:07:03 2016
>   write: Fri May  6 10:37:50 2016
>   change: Fri May  6 10:37:50 2016
>   mode: 10
>[2016/05/06 10:37:56.516823,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1011(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 16582
>[2016/05/06 10:37:56.516881,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1013(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2016/05/06 10:37:56.516921,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.516941,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=448
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2016/05/06 10:37:56.517244, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 00 00 F4 C7 DB   F9 15 90 D1 01 80 05 CB   ........ ........
>  [0010] F9 15 90 D1 01 E8 C1 62   84 2F A7 D1 01 E8 C1 62   .......b ./.....b
>  [0020] 84 2F A7 D1 01 10 00 00   00 00 00 00 00           ./...... .....
>[2016/05/06 10:37:56.564573, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
>  got smb length of 76
>[2016/05/06 10:37:56.564665,  6, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1877(process_smb)
>  got message type 0x0 of len 0x4c
>[2016/05/06 10:37:56.564703,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1879(process_smb)
>  Transaction 8 of length 80 (0 toread)
>[2016/05/06 10:37:56.564736,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.564756,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=76
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=512
>  smt_wct=15
>  smb_vwv[ 0]=    8 (0x8)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   24 (0x18)
>  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]=    8 (0x8)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=11
>[2016/05/06 10:37:56.565234, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 ED 03 00 00 00   00 00 00                 ........ ...
>[2016/05/06 10:37:56.565300,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1489(switch_message)
>  switch message SMBtrans2 (pid 9978) conn 0x8134bc960
>[2016/05/06 10:37:56.565341,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2016/05/06 10:37:56.565405,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:5518(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1005
>[2016/05/06 10:37:56.565457,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:257(unix_convert)
>  unix_convert called on file ""
>[2016/05/06 10:37:56.565516,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:291(unix_convert)
>  conversion finished "" -> .
>[2016/05/06 10:37:56.565560,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1161(check_reduced_name)
>  check_reduced_name [.] [/media]
>[2016/05/06 10:37:56.565606, 10, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1221(check_reduced_name)
>  check_reduced_name realpath [.] -> [/media]
>[2016/05/06 10:37:56.565647,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1294(check_reduced_name)
>  check_reduced_name: . reduced to /media
>[2016/05/06 10:37:56.565717, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/files.c:744(file_name_hash)
>  file_name_hash: /media/. hash 0xfe4c393d
>[2016/05/06 10:37:56.565775,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:5661(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo . (fnum [fsp is NULL]) level=1005 call=5 total_data=0
>[2016/05/06 10:37:56.565817,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4596(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: . (fnum [fsp is NULL]) level=1005 max_data=24
>[2016/05/06 10:37:56.565853,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:600(dos_mode)
>  dos_mode: .
>[2016/05/06 10:37:56.565896,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:242(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2016/05/06 10:37:56.565933,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:36(dos_mode_debug_print)
>  dos_mode returning d
>[2016/05/06 10:37:56.565975, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4862(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_STANDARD_INFORMATION
>[2016/05/06 10:37:56.566037,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1011(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 24, useable_space = 16582
>[2016/05/06 10:37:56.566102,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1013(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 24, paramsize = 2, datasize = 24
>[2016/05/06 10:37:56.566145,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.566165,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=84
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=512
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   24 (0x18)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   24 (0x18)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=29
>[2016/05/06 10:37:56.566488, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(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 01 00 00   00 00 01 00 00           ........ .....
>[2016/05/06 10:37:56.610467, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
>  got smb length of 70
>[2016/05/06 10:37:56.610551,  6, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1877(process_smb)
>  got message type 0x0 of len 0x46
>[2016/05/06 10:37:56.610589,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1879(process_smb)
>  Transaction 9 of length 74 (0 toread)
>[2016/05/06 10:37:56.610623,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.610642,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=70
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=576
>  smt_wct=15
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=  560 (0x230)
>  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]=    2 (0x2)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    3 (0x3)
>  smb_bcc=5
>[2016/05/06 10:37:56.611298, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 05 01                                    ..... 
>[2016/05/06 10:37:56.611388,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1489(switch_message)
>  switch message SMBtrans2 (pid 9978) conn 0x8134bc960
>[2016/05/06 10:37:56.611453,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2016/05/06 10:37:56.611517,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:3837(call_trans2qfsinfo)
>  call_trans2qfsinfo: level = 261
>[2016/05/06 10:37:56.611584,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:3250(smbd_do_qfsinfo)
>  smbd_do_qfsinfo: level = 261
>[2016/05/06 10:37:56.611680,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1011(send_trans2_replies)
>  t2_rep: params_sent_thistime = 0, data_sent_thistime = 20, useable_space = 16584
>[2016/05/06 10:37:56.611729,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1013(send_trans2_replies)
>  t2_rep: params_to_send = 0, data_to_send = 20, paramsize = 0, datasize = 20
>[2016/05/06 10:37:56.611785,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.611819,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=76
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=576
>  smt_wct=10
>  smb_vwv[ 0]=    0 (0x0)
>  smb_vwv[ 1]=   20 (0x14)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    0 (0x0)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   20 (0x14)
>  smb_vwv[ 7]=   56 (0x38)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=21
>[2016/05/06 10:37:56.612403, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 2F 00 01 00 FF 00 00   00 08 00 00 00 4E 00 54   ./...... .....N.T
>  [0010] 00 46 00 53 00                                    .F.S. 
>[2016/05/06 10:37:56.612575,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:3855(call_trans2qfsinfo)
>  SMBtrans2 info_level = 261
>[2016/05/06 10:37:56.647779, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
>  got smb length of 94
>[2016/05/06 10:37:56.647869,  6, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1877(process_smb)
>  got message type 0x0 of len 0x5e
>[2016/05/06 10:37:56.647906,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1879(process_smb)
>  Transaction 10 of length 98 (0 toread)
>[2016/05/06 10:37:56.647940,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.647959,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=94
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=640
>  smt_wct=15
>  smb_vwv[ 0]=   26 (0x1A)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   40 (0x28)
>  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]=   26 (0x1A)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=29
>[2016/05/06 10:37:56.648625, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 EC 03 00 00 00   00 5C 00 70 00 65 00 6E   ........ .\.p.e.n
>  [0010] 00 64 00 72 00 69 00 76   00 65 00 00 00           .d.r.i.v .e...
>[2016/05/06 10:37:56.648775,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1489(switch_message)
>  switch message SMBtrans2 (pid 9978) conn 0x8134bc960
>[2016/05/06 10:37:56.648840,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2016/05/06 10:37:56.648911,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:5518(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
>[2016/05/06 10:37:56.648983,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:257(unix_convert)
>  unix_convert called on file "pendrive"
>[2016/05/06 10:37:56.649050, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/statcache.c:244(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [PENDRIVE]
>[2016/05/06 10:37:56.649110,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:449(unix_convert)
>  unix_convert begin: name = pendrive, dirpath = , start = pendrive
>[2016/05/06 10:37:56.649200, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled pendrive ?
>[2016/05/06 10:37:56.649251, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component pendrive (len 8) ?
>[2016/05/06 10:37:56.649317, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled pendrive ?
>[2016/05/06 10:37:56.649378, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component pendrive (len 8) ?
>[2016/05/06 10:37:56.649569,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/statcache.c:143(stat_cache_add)
>  stat_cache_add: Added entry (8134b77a0:size 8) PENDRIVE -> PENDRIVE
>[2016/05/06 10:37:56.649628,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/statcache.c:143(stat_cache_add)
>  stat_cache_add: Added entry (8134b7730:size 8) PENDRIVE -> PENDRIVE
>[2016/05/06 10:37:56.649687,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:1004(unix_convert)
>  conversion finished pendrive -> PENDRIVE
>[2016/05/06 10:37:56.649747,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1161(check_reduced_name)
>  check_reduced_name [PENDRIVE] [/media]
>[2016/05/06 10:37:56.649827, 10, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1221(check_reduced_name)
>  check_reduced_name realpath [PENDRIVE] -> [/media/PENDRIVE]
>[2016/05/06 10:37:56.649881,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1294(check_reduced_name)
>  check_reduced_name: PENDRIVE reduced to /media/PENDRIVE
>[2016/05/06 10:37:56.649949, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/files.c:744(file_name_hash)
>  file_name_hash: /media/PENDRIVE hash 0x142965b7
>[2016/05/06 10:37:56.650009,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:5661(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo PENDRIVE (fnum [fsp is NULL]) level=1004 call=5 total_data=0
>[2016/05/06 10:37:56.650051,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4596(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: PENDRIVE (fnum [fsp is NULL]) level=1004 max_data=40
>[2016/05/06 10:37:56.650087,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:600(dos_mode)
>  dos_mode: PENDRIVE
>[2016/05/06 10:37:56.650132,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:242(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2016/05/06 10:37:56.650174,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:36(dos_mode_debug_print)
>  dos_mode returning d
>[2016/05/06 10:37:56.650224, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4840(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_BASIC_INFORMATION
>[2016/05/06 10:37:56.650285,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4850(smbd_do_qfilepathinfo)
>  SMB_QFBI - create: Tue Jan  1 01:00:00 1980
>   access: Tue Jan  1 01:00:00 1980
>   write: Tue Jan  1 01:00:00 1980
>   change: Tue Jan  1 01:00:00 1980
>   mode: 10
>[2016/05/06 10:37:56.650395,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1011(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 40, useable_space = 16582
>[2016/05/06 10:37:56.650435,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1013(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 40, paramsize = 2, datasize = 40
>[2016/05/06 10:37:56.650474,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.650493,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=100
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=640
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   40 (0x28)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   40 (0x28)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=45
>[2016/05/06 10:37:56.650793, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 00 00 00 70 29   10 4C E7 A8 01 00 70 29   ......p) .L....p)
>  [0010] 10 4C E7 A8 01 00 70 29   10 4C E7 A8 01 00 70 29   .L....p) .L....p)
>  [0020] 10 4C E7 A8 01 10 00 00   00 00 00 00 00           .L...... .....
>[2016/05/06 10:37:56.657382, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
>  got smb length of 94
>[2016/05/06 10:37:56.657426,  6, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1877(process_smb)
>  got message type 0x0 of len 0x5e
>[2016/05/06 10:37:56.657458,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1879(process_smb)
>  Transaction 11 of length 98 (0 toread)
>[2016/05/06 10:37:56.657489,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.657507,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=94
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=704
>  smt_wct=15
>  smb_vwv[ 0]=   26 (0x1A)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    2 (0x2)
>  smb_vwv[ 3]=   24 (0x18)
>  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]=   26 (0x1A)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    5 (0x5)
>  smb_bcc=29
>[2016/05/06 10:37:56.657874, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 ED 03 00 00 00   00 5C 00 70 00 65 00 6E   ........ .\.p.e.n
>  [0010] 00 64 00 72 00 69 00 76   00 65 00 00 00           .d.r.i.v .e...
>[2016/05/06 10:37:56.657954,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1489(switch_message)
>  switch message SMBtrans2 (pid 9978) conn 0x8134bc960
>[2016/05/06 10:37:56.657989,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2016/05/06 10:37:56.658023,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:5518(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1005
>[2016/05/06 10:37:56.658059,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:257(unix_convert)
>  unix_convert called on file "pendrive"
>[2016/05/06 10:37:56.658095, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/statcache.c:283(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [PENDRIVE] -> [PENDRIVE]
>[2016/05/06 10:37:56.658142,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1161(check_reduced_name)
>  check_reduced_name [PENDRIVE] [/media]
>[2016/05/06 10:37:56.658187, 10, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1221(check_reduced_name)
>  check_reduced_name realpath [PENDRIVE] -> [/media/PENDRIVE]
>[2016/05/06 10:37:56.658220,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1294(check_reduced_name)
>  check_reduced_name: PENDRIVE reduced to /media/PENDRIVE
>[2016/05/06 10:37:56.658261, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/files.c:744(file_name_hash)
>  file_name_hash: /media/PENDRIVE hash 0x142965b7
>[2016/05/06 10:37:56.658301,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:5661(call_trans2qfilepathinfo)
>  call_trans2qfilepathinfo PENDRIVE (fnum [fsp is NULL]) level=1005 call=5 total_data=0
>[2016/05/06 10:37:56.658336,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4596(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: PENDRIVE (fnum [fsp is NULL]) level=1005 max_data=24
>[2016/05/06 10:37:56.658369,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:600(dos_mode)
>  dos_mode: PENDRIVE
>[2016/05/06 10:37:56.658401,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:242(dos_mode_from_sbuf)
>  dos_mode_from_sbuf returning d
>[2016/05/06 10:37:56.658433,  8, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/dosmode.c:36(dos_mode_debug_print)
>  dos_mode returning d
>[2016/05/06 10:37:56.658468, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:4862(smbd_do_qfilepathinfo)
>  smbd_do_qfilepathinfo: SMB_FILE_STANDARD_INFORMATION
>[2016/05/06 10:37:56.658502,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1011(send_trans2_replies)
>  t2_rep: params_sent_thistime = 2, data_sent_thistime = 24, useable_space = 16582
>[2016/05/06 10:37:56.658534,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1013(send_trans2_replies)
>  t2_rep: params_to_send = 2, data_to_send = 24, paramsize = 2, datasize = 24
>[2016/05/06 10:37:56.658566,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.658583,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=84
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=704
>  smt_wct=10
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=   24 (0x18)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    2 (0x2)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   24 (0x18)
>  smb_vwv[ 7]=   60 (0x3C)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=29
>[2016/05/06 10:37:56.658882, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(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 01 00 00   00 00 01 00 00           ........ .....
>[2016/05/06 10:37:56.668084, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
>  got smb length of 70
>[2016/05/06 10:37:56.668131,  6, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1877(process_smb)
>  got message type 0x0 of len 0x46
>[2016/05/06 10:37:56.668163,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1879(process_smb)
>  Transaction 12 of length 74 (0 toread)
>[2016/05/06 10:37:56.668194,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.668212,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=70
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=768
>  smt_wct=15
>  smb_vwv[ 0]=    2 (0x2)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=  560 (0x230)
>  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]=    2 (0x2)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    3 (0x3)
>  smb_bcc=5
>[2016/05/06 10:37:56.668575, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 02 01                                    ..... 
>[2016/05/06 10:37:56.668620,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1489(switch_message)
>  switch message SMBtrans2 (pid 9978) conn 0x8134bc960
>[2016/05/06 10:37:56.668654,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2016/05/06 10:37:56.668687,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:3837(call_trans2qfsinfo)
>  call_trans2qfsinfo: level = 258
>[2016/05/06 10:37:56.668726,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:3250(smbd_do_qfsinfo)
>  smbd_do_qfsinfo: level = 258
>[2016/05/06 10:37:56.668772,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:3418(smbd_do_qfsinfo)
>  smbd_do_qfsinfo : SMB_QUERY_FS_VOLUME_INFO namelen = 9, vol=usb_media serv=usb_media
>[2016/05/06 10:37:56.668811,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1011(send_trans2_replies)
>  t2_rep: params_sent_thistime = 0, data_sent_thistime = 36, useable_space = 16584
>[2016/05/06 10:37:56.668843,  9, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:1013(send_trans2_replies)
>  t2_rep: params_to_send = 0, data_to_send = 36, paramsize = 0, datasize = 36
>[2016/05/06 10:37:56.668874,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.668892,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=92
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=136
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=768
>  smt_wct=10
>  smb_vwv[ 0]=    0 (0x0)
>  smb_vwv[ 1]=   36 (0x24)
>  smb_vwv[ 2]=    0 (0x0)
>  smb_vwv[ 3]=    0 (0x0)
>  smb_vwv[ 4]=   56 (0x38)
>  smb_vwv[ 5]=    0 (0x0)
>  smb_vwv[ 6]=   36 (0x24)
>  smb_vwv[ 7]=   56 (0x38)
>  smb_vwv[ 8]=    0 (0x0)
>  smb_vwv[ 9]=    0 (0x0)
>  smb_bcc=37
>[2016/05/06 10:37:56.669196, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 00 00 00 00 00   00 24 38 3B 6E 12 00 00   ........ .$8;n...
>  [0010] 00 00 00 75 00 73 00 62   00 5F 00 6D 00 65 00 64   ...u.s.b ._.m.e.d
>  [0020] 00 69 00 61 00                                    .i.a. 
>[2016/05/06 10:37:56.669316,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:3855(call_trans2qfsinfo)
>  SMBtrans2 info_level = 258
>[2016/05/06 10:37:56.703757, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive)
>  got smb length of 104
>[2016/05/06 10:37:56.703833,  6, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1877(process_smb)
>  got message type 0x0 of len 0x68
>[2016/05/06 10:37:56.703868,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1879(process_smb)
>  Transaction 13 of length 108 (0 toread)
>[2016/05/06 10:37:56.703901,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.703920,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=104
>  smb_com=0x32
>  smb_rcls=0
>  smb_reh=0
>  smb_err=0
>  smb_flg=24
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=832
>  smt_wct=15
>  smb_vwv[ 0]=   36 (0x24)
>  smb_vwv[ 1]=    0 (0x0)
>  smb_vwv[ 2]=   10 (0xA)
>  smb_vwv[ 3]=16384 (0x4000)
>  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]=   36 (0x24)
>  smb_vwv[10]=   68 (0x44)
>  smb_vwv[11]=    0 (0x0)
>  smb_vwv[12]=    0 (0x0)
>  smb_vwv[13]=    1 (0x1)
>  smb_vwv[14]=    1 (0x1)
>  smb_bcc=39
>[2016/05/06 10:37:56.704297, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>  [0000] 00 00 00 16 00 56 05 06   00 02 01 00 00 00 00 5C   .....V.. .......\
>  [0010] 00 70 00 65 00 6E 00 64   00 72 00 69 00 76 00 65   .p.e.n.d .r.i.v.e
>  [0020] 00 5C 00 2A 00 00 00                              .\.*... 
>[2016/05/06 10:37:56.704414,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:1489(switch_message)
>  switch message SMBtrans2 (pid 9978) conn 0x8134bc960
>[2016/05/06 10:37:56.704452,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/uid.c:384(change_to_user)
>  Skipping user change - already user
>[2016/05/06 10:37:56.704498,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/trans2.c:2502(call_trans2findfirst)
>  call_trans2findfirst: dirtype = 16, maxentries = 1366, close_after_first=0, close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x102, max_data_bytes = 16384
>[2016/05/06 10:37:56.704556,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:257(unix_convert)
>  unix_convert called on file "pendrive/*"
>[2016/05/06 10:37:56.704598, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/statcache.c:244(stat_cache_lookup)
>  stat_cache_lookup: lookup failed for name [PENDRIVE/*]
>[2016/05/06 10:37:56.704632, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/statcache.c:283(stat_cache_lookup)
>  stat_cache_lookup: lookup succeeded for name [PENDRIVE] -> [PENDRIVE]
>[2016/05/06 10:37:56.704693,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:449(unix_convert)
>  unix_convert begin: name = PENDRIVE/*, dirpath = PENDRIVE, start = *
>[2016/05/06 10:37:56.704738,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:184(check_parent_exists)
>  check_parent_exists: name = PENDRIVE/*, dirpath = PENDRIVE, start = *
>[2016/05/06 10:37:56.704773, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/mangle_hash2.c:418(is_mangled)
>  is_mangled * ?
>[2016/05/06 10:37:56.704805, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/mangle_hash2.c:357(is_mangled_component)
>  is_mangled_component * (len 1) ?
>[2016/05/06 10:37:56.704838,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:649(unix_convert)
>  Wildcard *
>[2016/05/06 10:37:56.704871,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1161(check_reduced_name)
>  check_reduced_name [PENDRIVE/*] [/media]
>[2016/05/06 10:37:56.704932,  3, pid=9978, effective(1002, 1002), real(0, 0), class=vfs] ../source3/smbd/vfs.c:1215(check_reduced_name)
>[2016/05/06 10:37:56.704970,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:1078(check_name)
>  check_name: name PENDRIVE/* failed with NT_STATUS_INVALID_PARAMETER
>[2016/05/06 10:37:56.705004,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/filename.c:1431(filename_convert_internal)
>  filename_convert_internal: check_name failed for name PENDRIVE/* with NT_STATUS_INVALID_PARAMETER
>[2016/05/06 10:37:56.705041,  3, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/error.c:82(error_packet_set)
>  NT error packet at ../source3/smbd/trans2.c(2568) cmd=50 (SMBtrans2) NT_STATUS_INVALID_PARAMETER
>[2016/05/06 10:37:56.705077,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:168(show_msg)
>[2016/05/06 10:37:56.705095,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/util.c:178(show_msg)
>  size=35
>  smb_com=0x32
>  smb_rcls=13
>  smb_reh=0
>  smb_err=49152
>  smb_flg=136
>  smb_flg2=51207
>  smb_tid=28608
>  smb_pid=4736
>  smb_uid=59483
>  smb_mid=832
>  smt_wct=0
>  smb_bcc=0
>[2016/05/06 10:37:56.705269, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../lib/util/util.c:559(dump_data)
>[2016/05/06 10:38:17.900855, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/events.c:426(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(deadtime) 0x0 called
>[2016/05/06 10:38:17.900942, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/events.c:437(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(deadtime) 0x0 rescheduled
>[2016/05/06 10:38:17.900988, 10, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/lib/events.c:426(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(housekeeping) 0x0 called
>[2016/05/06 10:38:17.901053,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/process.c:2798(housekeeping_fn)
>  housekeeping
>[2016/05/06 10:38:17.901098,  4, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx)
>  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
>[2016/05/06 10:38:17.901136,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
>  Security token: (NULL)
>[2016/05/06 10:38:17.901176,  5, pid=9978, effective(1002, 1002), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token)
>  UNIX token of user 0
>  Primary group is 0 and contains 0 supplementary groups
>[2016/05/06 10:38:17.901253,  5, pid=9978, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user)
>  change_to_root_user: now uid=(0,0) gid=(0,0)
>[2016/05/06 10:38:17.979199,  6, pid=9978, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2152(lp_file_list_changed)
>  lp_file_list_changed()
>  file /usr/local/etc/smb4.conf -> /usr/local/etc/smb4.conf  last mod_time: Fri May  6 10:33:11 2016
>  
>[2016/05/06 10:38:17.979311, 10, pid=9978, effective(0, 0), real(0, 0)] ../source3/lib/events.c:437(smbd_idle_event_handler)
>  smbd_idle_event_handler: idle_evt(housekeeping) 0x0 rescheduled
>

Actions: View

Attachments on bug 11905: 12076 | 12077 | 12078 | 12079