Bug 5341 - smbclient 3.2 transfer stops at 647Mbyte
Summary: smbclient 3.2 transfer stops at 647Mbyte
Status: RESOLVED FIXED
Alias: None
Product: Samba 3.2
Classification: Unclassified
Component: Client tools (show other bugs)
Version: 3.2.0
Hardware: Sparc Solaris
: P3 minor
Target Milestone: ---
Assignee: Samba Bugzilla Account
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2008-03-20 10:45 UTC by Karoly VEGH
Modified: 2008-03-28 10:21 UTC (History)
0 users

See Also:


Attachments
proposed patch (2.11 KB, patch)
2008-03-21 07:41 UTC, Volker Lendecke
no flags Details
next patch :-) (2.21 KB, patch)
2008-03-21 13:59 UTC, Volker Lendecke
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Karoly VEGH 2008-03-20 10:45:30 UTC
Threadstarter report:
http://lists.samba.org/archive/samba/2008-March/139357.html

Short desc: smbclient 3.0.25 didn't perform over 40mbyte/s, following the suggestions I tried 3.2, which performed way better (60-70 mbyte/s), but transfer stops at 647 mbyte. 

Details: 
OS: 
root@asp1dbrac012:~# uname -a 
SunOS asp1dbrac012 5.10 Generic_125100-10 sun4v sparc SUNW,Sun-Fire-T200
root@asp1dbrac012:~# 

smbclient version: 
root@asp1dbrac012:/tmp/smbtest# ./smbclient -V
creating lame upcase table
creating lame lowcase table
Version 3.2.0pre2
root@asp1dbrac012:/tmp/smbtest# 

compiled from source: http://repo.or.cz/w/Samba.git?a=snapshot;h=refs/heads/v3-2-stable;sf=tgz
(no special parameters, as suggested in the thread, autogen.sh ; ./configure ; make) with gcc version 3.4.3. 

command line and output: 

root@asp1dbrac012:/orabin/system# ./smbclient //target_ip/share -s /etc/sfw/smb.conf -I target_ip -A auth_file -c'prompt; ls ; mget *;'
creating lame upcase table
creating lame lowcase table
Domain=[INTNET] OS=[Windows Server 2003 3790 Service Pack 2] Server=[Windows Server 2003 5.2]
  .                                   D       0  Fri Mar  7 13:18:16 2008
  ..                                  D       0  Fri Mar  7 13:18:16 2008
  LARGEFILE.dat                          A 13563025258  Fri Mar  7 13:37:39 2008

                64715 blocks of size 33554432. 16498 blocks available
getting file \LARGEFILE.dat of size 13563025258 as LARGEFILE.dat (59526.3 kb/s) (average 59526.3 kb/s)
root@asp1dbrac012:/orabin/system# 
root@asp1dbrac012:/orabin/system# ls -l LARGEFILE.dat 
-rw-r--r--   1 root     root     678123370 Mar 20 13:47 LARGEFILE.dat
root@asp1dbrac012:/orabin/system# 

that is only ~670mbytes have arrived. 

I tried truss'ing the process, but it looks like it just thinks it is really the 
end of file and stops transferring: 

24928:  recv(4, "\001\0 9FF S M B .\0\0\0".., 65597, 0) = 65597
24928:  write(6, " e\0 d\0  \0 -\0  \0 S\0".., 65534)   = 65534
24928:  send(4, "\0\0\0 7FF S M B .\0\0\0".., 59, 0)    = 59
24928:  pollsys(0xFFBFEFA8, 2, 0xFFBFF050, 0x00000000)  = 1
24928:  ioctl(4, FIONREAD, 0xFFBFF0C4)                  = 0
24928:  recv(4, "\001\0 9FF S M B .\0\0\0".., 65597, 0) = 65597
24928:  write(6, " a\0  \0 -\0  \0 H\0 o\0".., 65534)   = 65534
24928:  send(4, "\0\0\0 7FF S M B .\0\0\0".., 59, 0)    = 59
24928:  pollsys(0xFFBFEFA8, 2, 0xFFBFF050, 0x00000000)  = 1
24928:  ioctl(4, FIONREAD, 0xFFBFF0C4)                  = 0
24928:  recv(4, "\001\0 9FF S M B .\0\0\0".., 65597, 0) = 65597
24928:  write(6, " 4\0 5\0 3\0 8\0 |\0 T\0".., 65534)   = 65534
24928:  pollsys(0xFFBFEFA8, 2, 0xFFBFF050, 0x00000000)  = 1
24928:  ioctl(4, FIONREAD, 0xFFBFF0C4)                  = 0
24928:  recv(4, "\0\0A8 {FF S M B .\0\0\0".., 43135, 0) = 43135
24928:  write(6, " 8\0 9\0 9\0 |\0 D\0E4\0".., 43072)   = 43072
24928:  write(4, "\0\0\0 )FF S M B04\0\0\0".., 45)      = 45
24928:  pollsys(0xFFBFED40, 1, 0xFFBFEDD0, 0x00000000)  = 1
24928:  read(4, "\0\0\0 #", 4)                          = 4
24928:  pollsys(0xFFBFEDB8, 1, 0xFFBFEE48, 0x00000000)  = 1
24928:  read(4, "FF S M B04\0\0\0\08801C8".., 35)       = 35
24928:  close(6)                                        = 0
getting file \ATUSER.dat of size 13563025258 as ATUSER.dat (36266.7 kb/s) (average 36266.7 kb/s)
24928:  write(3, " g e t t i n g   f i l e".., 97)      = 97
24928:  write(4, "\0\0\0 #FF S M B q\0\0\0".., 39)      = 39
24928:  pollsys(0xFFBFF120, 1, 0xFFBFF1B0, 0x00000000)  = 1
24928:  read(4, "\0\0\0 #", 4)                          = 4
24928:  pollsys(0xFFBFF198, 1, 0xFFBFF228, 0x00000000)  = 1
24928:  read(4, "FF S M B q\0\0\0\08801C8".., 35)       = 35
24928:  close(4)                                        = 0
24928:  _exit(0)

smb.conf:

root@asp1dbrac012:~# egrep -v ^'#|;' /etc/sfw/smb.conf 
[global]
   server string = Samba Server
   security = user
   log file = /var/samba/log/log.%m
   max log size = 50
   socket options = TCP_NODELAY 
   dns proxy = no 
root@asp1dbrac012:~# 

I have executed the same commandline with "-d 5" to see more: 


---------------------------------8<----------------------------------
creating lame upcase table
creating lame lowcase table
INFO: Current debug levels:
  all: True/5
  tdb: False/0
  printdrivers: False/0
  lanman: False/0
  smb: False/0
  rpc_parse: False/0
  rpc_srv: False/0
  rpc_cli: False/0
  passdb: False/0
  sam: False/0
  auth: False/0
  winbind: False/0
  vfs: False/0
  idmap: False/0
  quota: False/0
  acls: False/0
  locking: False/0
  msdfs: False/0
  dmapi: False/0
  registry: False/0
lp_load: refreshing parameters
Initialising global parameters
params.c:pm_process() - Processing configuration file "/etc/sfw/smb.conf"
Processing section "[global]"
doing parameter server string = Samba Server
doing parameter security = user
doing parameter log file = /var/samba/log/log.%m
doing parameter max log size = 50
doing parameter socket options = TCP_NODELAY
doing parameter dns proxy = no
pm_process() returned Yes
Attempting to register new charset UCS-2LE
Registered charset UCS-2LE
Attempting to register new charset UTF-16LE
Registered charset UTF-16LE
Attempting to register new charset UCS-2BE
Registered charset UCS-2BE
Attempting to register new charset UTF-16BE
Registered charset UTF-16BE
Attempting to register new charset UTF8
Registered charset UTF8
Attempting to register new charset UTF-8
Registered charset UTF-8
Attempting to register new charset ASCII
Registered charset ASCII
Attempting to register new charset 646
Registered charset 646
Attempting to register new charset ISO-8859-1
Registered charset ISO-8859-1
Attempting to register new charset UCS2-HEX
Registered charset UCS2-HEX
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
map_file: Failed to load /usr/local/samba/lib/valid.dat - No such file or directory
creating default valid table
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
Substituting charset '646' for LOCALE
[...output about irrelevant interfaces cut ...]
added interface nxge2 ip=10.122.19.199 bcast=10.122.31.255 netmask=255.255.240.0
Netbios name list:-
my_netbios_names[0]="ASP1DBRAC012"
Client started (version 3.2.0pre2).
Connecting to 10.122.19.150 at port 445
socket option SO_KEEPALIVE = 0
socket option SO_REUSEADDR = 0
socket option SO_BROADCAST = 0
socket option TCP_NODELAY = 1
socket option IPTOS_LOWDELAY = 0
socket option IPTOS_THROUGHPUT = 0
socket option SO_SNDBUF = 400000
socket option SO_RCVBUF = 401096
Could not test socket option SO_SNDLOWAT.
Could not test socket option SO_RCVLOWAT.
Could not test socket option SO_SNDTIMEO.
Could not test socket option SO_RCVTIMEO.
 session request ok
size=183
smb_com=0x72
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=0
smb_pid=2524
smb_uid=0
smb_mid=1
smt_wct=17
smb_vwv[ 0]=    9 (0x9)
smb_vwv[ 1]=12803 (0x3203)
smb_vwv[ 2]=  256 (0x100)
smb_vwv[ 3]= 1024 (0x400)
smb_vwv[ 4]=   65 (0x41)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=  256 (0x100)
smb_vwv[ 7]=    0 (0x0)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=64768 (0xFD00)
smb_vwv[10]=  499 (0x1F3)
smb_vwv[11]=52864 (0xCE80)
smb_vwv[12]= 3358 (0xD1E)
smb_vwv[13]=37442 (0x9242)
smb_vwv[14]=51338 (0xC88A)
smb_vwv[15]=    1 (0x1)
smb_vwv[16]=    0 (0x0)
smb_bcc=114
size=183
smb_com=0x72
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=0
smb_pid=2524
smb_uid=0
smb_mid=1
smt_wct=17
smb_vwv[ 0]=    9 (0x9)
smb_vwv[ 1]=12803 (0x3203)
smb_vwv[ 2]=  256 (0x100)
smb_vwv[ 3]= 1024 (0x400)
smb_vwv[ 4]=   65 (0x41)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=  256 (0x100)
smb_vwv[ 7]=    0 (0x0)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=64768 (0xFD00)
smb_vwv[10]=  499 (0x1F3)
smb_vwv[11]=52864 (0xCE80)
smb_vwv[12]= 3358 (0xD1E)
smb_vwv[13]=37442 (0x9242)
smb_vwv[14]=51338 (0xC88A)
smb_vwv[15]=    1 (0x1)
smb_vwv[16]=    0 (0x0)
smb_bcc=114
Doing spnego session setup (blob length=114)
got OID=1 2 840 48018 1 2 2
got OID=1 2 840 113554 1 2 2
got OID=1 2 840 113554 1 2 2 3
got OID=1 3 6 1 4 1 311 2 2 10
got principal=rospsw070150$@INTNET.LOCAL
size=428
smb_com=0x73
smb_rcls=22
smb_reh=0
smb_err=49152
smb_flg=136
smb_flg2=51201
smb_tid=0
smb_pid=2524
smb_uid=30720
smb_mid=2
smt_wct=4
smb_vwv[ 0]=  255 (0xFF)
smb_vwv[ 1]=  428 (0x1AC)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=  257 (0x101)
smb_bcc=385
size=428
smb_com=0x73
smb_rcls=22
smb_reh=0
smb_err=49152
smb_flg=136
smb_flg2=51201
smb_tid=0
smb_pid=2524
smb_uid=30720
smb_mid=2
smt_wct=4
smb_vwv[ 0]=  255 (0xFF)
smb_vwv[ 1]=  428 (0x1AC)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=  257 (0x101)
smb_bcc=385
Got challenge flags:
Got NTLMSSP neg_flags=0x62898215
  NTLMSSP_NEGOTIATE_UNICODE
  NTLMSSP_REQUEST_TARGET
  NTLMSSP_NEGOTIATE_SIGN
  NTLMSSP_NEGOTIATE_NTLM
  NTLMSSP_NEGOTIATE_ALWAYS_SIGN
  NTLMSSP_NEGOTIATE_NTLM2
  NTLMSSP_CHAL_TARGET_INFO
  NTLMSSP_NEGOTIATE_128
  NTLMSSP_NEGOTIATE_KEY_EXCH
NTLMSSP: Set final flags:
Got NTLMSSP neg_flags=0x60088215
  NTLMSSP_NEGOTIATE_UNICODE
  NTLMSSP_REQUEST_TARGET
  NTLMSSP_NEGOTIATE_SIGN
  NTLMSSP_NEGOTIATE_NTLM
  NTLMSSP_NEGOTIATE_ALWAYS_SIGN
  NTLMSSP_NEGOTIATE_NTLM2
  NTLMSSP_NEGOTIATE_128
  NTLMSSP_NEGOTIATE_KEY_EXCH
NTLMSSP challenge set by NTLM2
challenge is: 
[000] AB EB 3E F7 03 6F E9 7C                           ..>..o.| 
NTLMSSP Sign/Seal - Initialising with flags:
Got NTLMSSP neg_flags=0x60088215
  NTLMSSP_NEGOTIATE_UNICODE
  NTLMSSP_REQUEST_TARGET
  NTLMSSP_NEGOTIATE_SIGN
  NTLMSSP_NEGOTIATE_NTLM
  NTLMSSP_NEGOTIATE_ALWAYS_SIGN
  NTLMSSP_NEGOTIATE_NTLM2
  NTLMSSP_NEGOTIATE_128
  NTLMSSP_NEGOTIATE_KEY_EXCH
size=180
smb_com=0x73
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=0
smb_pid=2524
smb_uid=30720
smb_mid=3
smt_wct=4
smb_vwv[ 0]=  255 (0xFF)
smb_vwv[ 1]=  180 (0xB4)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=    9 (0x9)
smb_bcc=137
size=180
smb_com=0x73
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=0
smb_pid=2524
smb_uid=30720
smb_mid=3
smt_wct=4
smb_vwv[ 0]=  255 (0xFF)
smb_vwv[ 1]=  180 (0xB4)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=    9 (0x9)
smb_bcc=137
Domain=[INTNET] OS=[Windows Server 2003 3790 Service Pack 2] Server=[Windows Server 2003 5.2]
 session setup ok
size=56
smb_com=0x75
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16390
smb_pid=2524
smb_uid=30720
smb_mid=4
smt_wct=7
smb_vwv[ 0]=  255 (0xFF)
smb_vwv[ 1]=   56 (0x38)
smb_vwv[ 2]=    1 (0x1)
smb_vwv[ 3]=  511 (0x1FF)
smb_vwv[ 4]=    0 (0x0)
smb_vwv[ 5]=  511 (0x1FF)
smb_vwv[ 6]=    0 (0x0)
smb_bcc=7
size=114
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=8
smb_flg2=51201
smb_tid=16390
smb_pid=2524
smb_uid=30720
smb_mid=5
smt_wct=15
smb_vwv[ 0]=   46 (0x2E)
smb_vwv[ 1]=    0 (0x0)
smb_vwv[ 2]=    2 (0x2)
smb_vwv[ 3]=16644 (0x4104)
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]=   46 (0x2E)
smb_vwv[10]=   68 (0x44)
smb_vwv[11]=    0 (0x0)
smb_vwv[12]=  114 (0x72)
smb_vwv[13]=    1 (0x1)
smb_vwv[14]=   16 (0x10)
smb_bcc=49
size=35
smb_com=0x32
smb_rcls=14
smb_reh=0
smb_err=49152
smb_flg=136
smb_flg2=51201
smb_tid=16390
smb_pid=2524
smb_uid=30720
smb_mid=5
smt_wct=0
smb_bcc=0
size=35
smb_com=0x32
smb_rcls=14
smb_reh=0
smb_err=49152
smb_flg=136
smb_flg2=51201
smb_tid=16390
smb_pid=2524
smb_uid=30720
smb_mid=5
smt_wct=0
smb_bcc=0
size=35
smb_com=0x71
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16390
smb_pid=2524
smb_uid=30720
smb_mid=6
smt_wct=0
smb_bcc=0
size=62
smb_com=0x75
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=7
smt_wct=7
smb_vwv[ 0]=  255 (0xFF)
smb_vwv[ 1]=   62 (0x3E)
smb_vwv[ 2]=    1 (0x1)
smb_vwv[ 3]=  169 (0xA9)
smb_vwv[ 4]=   18 (0x12)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=    0 (0x0)
smb_bcc=13
 tconx ok
dos_clean_name [(NULL)]
prompting is now off
size=86
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=8
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=8
smt_wct=15
smb_vwv[ 0]=   18 (0x12)
smb_vwv[ 1]=    0 (0x0)
smb_vwv[ 2]=   10 (0xA)
smb_vwv[ 3]=16644 (0x4104)
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]=   18 (0x12)
smb_vwv[10]=   68 (0x44)
smb_vwv[11]=    0 (0x0)
smb_vwv[12]=   86 (0x56)
smb_vwv[13]=    1 (0x1)
smb_vwv[14]=    1 (0x1)
smb_bcc=21
size=388
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=8
smt_wct=10
smb_vwv[ 0]=   10 (0xA)
smb_vwv[ 1]=  320 (0x140)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=   10 (0xA)
smb_vwv[ 4]=   56 (0x38)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=  320 (0x140)
smb_vwv[ 7]=   68 (0x44)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=    0 (0x0)
smb_bcc=333
size=388
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=8
smt_wct=10
smb_vwv[ 0]=   10 (0xA)
smb_vwv[ 1]=  320 (0x140)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=   10 (0xA)
smb_vwv[ 4]=   56 (0x38)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=  320 (0x140)
smb_vwv[ 7]=   68 (0x44)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=    0 (0x0)
smb_bcc=333
received 3 entries (eos=1)
size=45
smb_com=0x80
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=9
smt_wct=5
smb_vwv[ 0]=64715 (0xFCCB)
smb_vwv[ 1]=32768 (0x8000)
smb_vwv[ 2]= 1024 (0x400)
smb_vwv[ 3]=16498 (0x4072)
smb_vwv[ 4]=    0 (0x0)
smb_bcc=0
Total bytes listed: 13563025258
size=86
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=8
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=10
smt_wct=15
smb_vwv[ 0]=   18 (0x12)
smb_vwv[ 1]=    0 (0x0)
smb_vwv[ 2]=   10 (0xA)
smb_vwv[ 3]=16644 (0x4104)
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]=   18 (0x12)
smb_vwv[10]=   68 (0x44)
smb_vwv[11]=    0 (0x0)
smb_vwv[12]=   86 (0x56)
smb_vwv[13]=    1 (0x1)
smb_vwv[14]=    1 (0x1)
smb_bcc=21
size=188
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=10
smt_wct=10
smb_vwv[ 0]=   10 (0xA)
smb_vwv[ 1]=  120 (0x78)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=   10 (0xA)
smb_vwv[ 4]=   56 (0x38)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=  120 (0x78)
smb_vwv[ 7]=   68 (0x44)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=    0 (0x0)
smb_bcc=133
size=188
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=10
smt_wct=10
smb_vwv[ 0]=   10 (0xA)
smb_vwv[ 1]=  120 (0x78)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=   10 (0xA)
smb_vwv[ 4]=   56 (0x38)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=  120 (0x78)
smb_vwv[ 7]=   68 (0x44)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=    0 (0x0)
smb_bcc=133
received 1 entries (eos=1)
size=65
smb_com=0x2d
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=11
smt_wct=15
smb_vwv[ 0]=  255 (0xFF)
smb_vwv[ 1]=   65 (0x41)
smb_vwv[ 2]=32781 (0x800D)
smb_vwv[ 3]=    0 (0x0)
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]=    0 (0x0)
smb_vwv[10]=    0 (0x0)
smb_vwv[11]=    1 (0x1)
smb_vwv[12]=    0 (0x0)
smb_vwv[13]=    0 (0x0)
smb_vwv[14]=    0 (0x0)
smb_bcc=0
size=72
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=8
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=12
smt_wct=15
smb_vwv[ 0]=    4 (0x4)
smb_vwv[ 1]=    0 (0x0)
smb_vwv[ 2]=    2 (0x2)
smb_vwv[ 3]=16644 (0x4104)
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]=    4 (0x4)
smb_vwv[10]=   68 (0x44)
smb_vwv[11]=    0 (0x0)
smb_vwv[12]=   72 (0x48)
smb_vwv[13]=    1 (0x1)
smb_vwv[14]=    7 (0x7)
smb_bcc=7
size=168
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=12
smt_wct=10
smb_vwv[ 0]=    2 (0x2)
smb_vwv[ 1]=  108 (0x6C)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=    2 (0x2)
smb_vwv[ 4]=   56 (0x38)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=  108 (0x6C)
smb_vwv[ 7]=   60 (0x3C)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=    0 (0x0)
smb_bcc=113
size=168
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=12
smt_wct=10
smb_vwv[ 0]=    2 (0x2)
smb_vwv[ 1]=  108 (0x6C)
smb_vwv[ 2]=    0 (0x0)
smb_vwv[ 3]=    2 (0x2)
smb_vwv[ 4]=   56 (0x38)
smb_vwv[ 5]=    0 (0x0)
smb_vwv[ 6]=  108 (0x6C)
smb_vwv[ 7]=   60 (0x3C)
smb_vwv[ 8]=    0 (0x0)
smb_vwv[ 9]=    0 (0x0)
smb_bcc=113
getting file \LARGEFILE.dat of size 13563025258 as LARGEFILE.dat size=35
smb_com=0x4
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=10361
smt_wct=0
smb_bcc=0
(49847.9 kb/s) (average 49847.9 kb/s)
size=35
smb_com=0x71
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=136
smb_flg2=51201
smb_tid=16391
smb_pid=2524
smb_uid=30720
smb_mid=10362
smt_wct=0
smb_bcc=0
  .                                   D       0  Fri Mar  7 13:18:16 2008
  ..                                  D       0  Fri Mar  7 13:18:16 2008
  LARGEFILE.dat                          A 13563025258  Fri Mar  7 13:37:39 2008

		64715 blocks of size 33554432. 16498 blocks available
------------------------------->8----------------------------------------

...if questions arise or more information is required, feel free to contact me at karoly.vegh at gmail.com
Comment 1 Karoly VEGH 2008-03-21 06:40:16 UTC
tried compiling with Sun Studio too - same results. 
Comment 2 Volker Lendecke 2008-03-21 06:42:33 UTC
I know it's going to generate huge amounts of logfile, but can you run it with debuglevel 11, and post the last, say, 2 megabytes of logfile somewhere? (it should shrink LOTS with bzip2)

Thanks,

Volker
Comment 3 Volker Lendecke 2008-03-21 06:50:08 UTC
Ah, and a sniff along with that huge logfile would be very handy, too. That's at least what I'm trying to generate right now here.
Comment 5 Volker Lendecke 2008-03-21 07:06:12 UTC
That log looks weird, it does contain debug level 11 messages, but I would expect a lot more. Is it possible that you dropped stderr?

Volker
Comment 6 Karoly VEGH 2008-03-21 07:32:07 UTC
new report: http://web.utanet.at/charlie/sol/smbrep_bugid_5341.tar
contains 4 files bzip2'd with the outputs of the following commands: 

smbtest-snoop-V.txt.bz2: snoop -V  -d nxge2  >/tmp/smbrep/smbtest-snoop-V.txt 2>&1
smbtest-snoop-vV.txt.bz2: snoop -vV  -d nxge2 >/tmp/smbrep/smbtest-snoop-vV.txt 2>&1
smbtest-snoop-xV.txt.bz2: snoop -xV  -d nxge2 >/tmp/smbrep/smbtest-snoop-xV.txt 2>&1
smbtest_sol_3.2-d11.txt.bz2: /tmp/smbtest/Samba/source/bin/smbclient //<target_ip>/<share> -d 11 -s /etc/sfw/smb.conf -I <target_ip> -A <authfile> -c'prompt; ls ; mget *;' >/tmp/smbrep/smbtest_sol_3.2-d11.txt 2>&1

additional info: jumbo frames were mentioned in the first report, have already disabled them again, running with normal MTU now, all the 3.2 tests were done without jumbo frames. 

HTH. 
Comment 7 Volker Lendecke 2008-03-21 07:33:38 UTC
I think I know what it is. Thanks for the logfile! size_t is only 32 bit. Working on a patch, give me a bit.

Volker
Comment 8 Volker Lendecke 2008-03-21 07:41:13 UTC
Created attachment 3193 [details]
proposed patch

Can you try the attached patch?

Thanks!

Volker
Comment 9 Volker Lendecke 2008-03-21 07:48:44 UTC
BTW, I could have found it even without the logfile....

vlendec@delphin:~> echo 'obase=16;13563025258'|bc
3286B576A
vlendec@delphin:~> echo 'ibase=16;286B576A'|bc
678123370

I just suspected the bug to be in the async engine, which seems to work fine.

Volker
Comment 10 Karoly VEGH 2008-03-21 11:22:27 UTC
The patch seems to work just fine, thanks. I was able to get 60+ mbytes/s steadily, no breakdown anymore, no stop until all of the 13Gbyte file has arrived. 

The only thing I recognized in the output was: 

Domain=[INTNET] OS=[Windows Server 2003 3790 Service Pack 2] Server=[Windows Server 2003 5.2]
  .                                   D       0  Fri Mar  7 13:18:16 2008
  ..                                  D       0  Fri Mar  7 13:18:16 2008
  LARGEFILE.dat                          A 13563025258  Fri Mar  7 13:37:39 2008

                64715 blocks of size 33554432. 16326 blocks available
getting file \LARGEFILE.dat of size 13563025258 as LARGEFILE.dat (2701.0 kb/s) (average 2701.0 kb/s)


...wel, the average is miscounted I guess, the transfer took 234 seconds long, so: 

root@asp1dbrac012:/tmp/smbtest# echo 13563025258 / 234 | bc 
57961646
root@asp1dbrac012:/tmp/smbtest# 

(I had a script running every second counting the growth of the file, it showed very similar average results too) 

but the functionality and the performance is definitely here. 

Being no developer I don't change the bugreport status - but from my side it is tested and fixed. 

Thanks a lot for the quick response and help.

Comment 11 Volker Lendecke 2008-03-21 13:59:01 UTC
Created attachment 3194 [details]
next patch :-)

Second patch, to be applied after the first one. This should get the bytes/second calculation right.

For the curious only one question remains -- why only 57MB/sec? We should be able to saturate the GigE with these patches. Is it possible that your disks or CPU on some side are a limiting factor?

Volker
Comment 12 Volker Lendecke 2008-03-21 19:17:07 UTC
Closing, the bug as such is fixed.

Volker
Comment 13 Karoly VEGH 2008-03-28 05:59:44 UTC
new output with both patches: 

# /opt/smbtest/bin/smbclient //<target_ip>/<share> -s /etc/sfw/smb.conf -I <target_ip> -A <authfile> -c'prompt; ls ; mget *;' 
Domain=[INTNET] OS=[Windows Server 2003 3790 Service Pack 2] Server=[Windows Server 2003 5.2]
  .                                   D       0  Fri Mar  7 13:18:16 2008
  ..                                  D       0  Fri Mar  7 13:18:16 2008
  LARGEFILE.dat                          A 13563025258  Fri Mar  7 13:37:39 2008

       64715 blocks of size 33554432. 25220 blocks available
getting file \ATUSER.dat of size 13563025258 as ATUSER.dat (15478857594096.8 kb/s) (average 15478857602323.1 kb/s)
# 

isn't this a bit too much for speed? 
Comment 14 Volker Lendecke 2008-03-28 06:01:37 UTC
:-)))


I'll take a look :-)

Volker
Comment 15 Volker Lendecke 2008-03-28 10:21:16 UTC
Had forgotten some more OFF_T. With 8dd64580 I pushed a fix to v3-2-test, Karolin merged it to v3-2-stable with b9c19c5f. It should show up on repo.or.cz soon.

Volker