Locking does not appear to be the problem. Testing with: kernel oplocks = no posix locking = no
has no affect. So I'm pretty much dead in the water here. How do people serve files to Windows clients over a WAN? -- James On 10/6/07, James Lamanna <[EMAIL PROTECTED]> wrote: > So, after watching the TCPDump output, I've noticed the following issue: > The transfer will start, and cruise along for a while, then it will > pause for several seconds after the client has sent an ack. So for > some reason, there is a huge delay in getting the next packet to send. > Is this a locking problem? Oplocks are all off. > > -- James > > On 10/6/07, James Lamanna <[EMAIL PROTECTED]> wrote: > > Some more forensics: > > > > Looking at a log file I notice there is an 8s delay between send_file > > of a block of 16k and any further processing. What would cause this? > > There's something really, really strange going on. > > > > Thanks. > > > > -- James > > > > [2007/10/06 10:31:02, 3] smbd/reply.c:send_file_readX(2618) > > send_file_readX: sendfile fnum=4574 max=15360 nread=15423 > > > > ---- 8 second delay to transfer 16k??????? ---- > > > > [2007/10/06 10:31:10, 10] > > lib/util_sock.c:read_smb_length_return_keepalive(623) > > got smb length of 55 > > [2007/10/06 10:31:10, 6] smbd/process.c:process_smb(1067) > > got message type 0x0 of len 0x37 > > [2007/10/06 10:31:10, 3] smbd/process.c:process_smb(1068) > > Transaction 53 of length 59 > > [2007/10/06 10:31:10, 5] lib/util.c:show_msg(484) > > [2007/10/06 10:31:10, 5] lib/util.c:show_msg(494) > > size=55 > > smb_com=0x2e > > smb_rcls=0 > > smb_reh=0 > > smb_err=0 > > smb_flg=8 > > smb_flg2=51201 > > smb_tid=1 > > smb_pid=28073 > > smb_uid=101 > > smb_mid=54 > > smt_wct=10 > > smb_vwv[ 0]= 255 (0xFF) > > smb_vwv[ 1]= 0 (0x0) > > smb_vwv[ 2]= 4574 (0x11DE) > > smb_vwv[ 3]=56320 (0xDC00) > > smb_vwv[ 4]= 8 (0x8) > > smb_vwv[ 5]=16384 (0x4000) > > smb_vwv[ 6]=16384 (0x4000) > > smb_vwv[ 7]= 0 (0x0) > > smb_vwv[ 8]= 0 (0x0) > > smb_vwv[ 9]= 0 (0x0) > > smb_bcc=0 > > [2007/10/06 10:31:10, 3] smbd/process.c:switch_message(926) > > switch message SMBreadX (pid 1307) conn 0x555555ad4480 > > [2007/10/06 10:31:10, 4] smbd/uid.c:change_to_user(183) > > change_to_user: Skipping user change - already user > > [2007/10/06 10:31:10, 10] locking/brlock.c:brl_get_locks_internal(1648) > > brl_get_locks_internal: 0 current locks on dev=64769, inode=550024983 > > [2007/10/06 10:31:10, 4] smbd/uid.c:change_to_user(183) > > change_to_user: Skipping user change - already user > > [2007/10/06 10:31:10, 10] locking/brlock.c:brl_get_locks_internal(1648) > > brl_get_locks_internal: 0 current locks on dev=64769, inode=550024983 > > [2007/10/06 10:31:10, 10] locking/posix.c:is_posix_locked(285) > > is_posix_locked: File Finance/Monthly_reports/Aug07.xls, offset = > > 580608, count = 16384, type = READ > > [2007/10/06 10:31:10, 10] locking/posix.c:posix_lock_in_range(173) > > posix_lock_in_range: offset_out = 580608, count_out = 16384 > > [2007/10/06 10:31:10, 8] locking/posix.c:posix_fcntl_getlock(235) > > posix_fcntl_getlock 28 580608 16384 0 > > [2007/10/06 10:31:10, 8] lib/util.c:fcntl_getlock(2028) > > fcntl_getlock fd=28 offset=580608 count=16384 type=0 > > [2007/10/06 10:31:10, 3] lib/util.c:fcntl_getlock(2052) > > fcntl_getlock: fd 28 is returned info 2 pid 0 > > [2007/10/06 10:31:10, 8] locking/posix.c:posix_fcntl_getlock(265) > > posix_fcntl_getlock: Lock query call successful > > [2007/10/06 10:31:10, 10] locking/brlock.c:brl_locktest(1133) > > brl_locktest: posix start=580608 len=16384 unlocked for fnum 4574 > > file Finance/Monthly_reports/Aug07.xls > > [2007/10/06 10:31:10, 10] locking/locking.c:is_locked(137) > > is_locked: flavour = WINDOWS_LOCK brl start=580608 len=16384 > > unlocked for fnum 4574 file Finance/Monthly_reports/Aug07.xls > > > > > > -- TCPDump Log ---- > > > > 10:31:11.036969 IP (tos 0x0, ttl 64, id 19011, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 3993:3993(0) ack 698305 win 3072 <nop,nop,timestamp 86477455 > > 615322904> > > 10:31:11.037001 IP (tos 0x0, ttl 64, id 19012, offset 0, flags [DF], > > length: 111) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: P > > 3993:4052(59) ack 698305 win 3072 <nop,nop,timestamp 86477455 > > 615322904> > > 10:31:11.321918 IP (tos 0x0, ttl 64, id 19013, offset 0, flags [DF], > > length: 111) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: P > > 3993:4052(59) ack 698305 win 3072 <nop,nop,timestamp 86477526 > > 615322904> > > 10:31:11.329388 IP (tos 0x0, ttl 60, id 60434, offset 0, flags [DF], > > length: 64) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 699753:699753(0) ack 4052 win 2520 <nop,nop,timestamp 615322978 > > 86477526,nop,nop,[|tcp]> > > 10:31:12.594715 IP (tos 0x0, ttl 60, id 60436, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 698305:699753(1448) ack 4052 win 2520 <nop,nop,timestamp 615323292 > > 86477526> > > 10:31:12.633854 IP (tos 0x0, ttl 64, id 19014, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 699753 win 3072 <nop,nop,timestamp 86477854 > > 615323292> > > 10:31:12.648924 IP (tos 0x0, ttl 60, id 60437, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 699753:701201(1448) ack 4052 win 2520 <nop,nop,timestamp 615323306 > > 86477854> > > 10:31:12.648961 IP (tos 0x0, ttl 64, id 19015, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 701201 win 3072 <nop,nop,timestamp 86477858 > > 615323306> > > 10:31:12.671920 IP (tos 0x0, ttl 60, id 60439, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 702649:704097(1448) ack 4052 win 2520 <nop,nop,timestamp 615323310 > > 86477858> > > 10:31:12.671954 IP (tos 0x0, ttl 64, id 19016, offset 0, flags [DF], > > length: 64) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . > > 4052:4052(0) ack 701201 win 3072 <nop,nop,timestamp 86477864 > > 615323306,nop,nop,[|tcp]> > > 10:31:12.886614 IP (tos 0x0, ttl 60, id 60441, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 701201:702649(1448) ack 4052 win 2520 <nop,nop,timestamp 615323365 > > 86477864> > > 10:31:12.886656 IP (tos 0x0, ttl 64, id 19017, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 704097 win 2731 <nop,nop,timestamp 86477917 > > 615323365> > > 10:31:12.901704 IP (tos 0x0, ttl 60, id 60442, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 704097:705545(1448) ack 4052 win 2520 <nop,nop,timestamp 615323369 > > 86477917> > > 10:31:12.901737 IP (tos 0x0, ttl 64, id 19018, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 705545 win 3072 <nop,nop,timestamp 86477921 > > 615323369> > > 10:31:13.138582 IP (tos 0x0, ttl 60, id 60444, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 705545:706993(1448) ack 4052 win 2520 <nop,nop,timestamp 615323428 > > 86477921> > > 10:31:13.138617 IP (tos 0x0, ttl 64, id 19019, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 706993 win 3072 <nop,nop,timestamp 86477980 > > 615323428> > > 10:31:13.153675 IP (tos 0x0, ttl 60, id 60445, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 706993:708441(1448) ack 4052 win 2520 <nop,nop,timestamp 615323432 > > 86477980> > > 10:31:13.193828 IP (tos 0x0, ttl 64, id 19020, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 708441 win 3072 <nop,nop,timestamp 86477994 > > 615323432> > > 10:31:13.216789 IP (tos 0x0, ttl 60, id 60447, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 709889:711337(1448) ack 4052 win 2520 <nop,nop,timestamp 615323446 > > 86477994> > > 10:31:13.216828 IP (tos 0x0, ttl 64, id 19021, offset 0, flags [DF], > > length: 64) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . > > 4052:4052(0) ack 708441 win 3072 <nop,nop,timestamp 86478000 > > 615323432,nop,nop,[|tcp]> > > 10:31:14.778329 IP (tos 0x0, ttl 60, id 60451, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: P > > 708441:709889(1448) ack 4052 win 2520 <nop,nop,timestamp 615323838 > > 86478000> > > 10:31:14.778406 IP (tos 0x0, ttl 64, id 19022, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 711337 win 2731 <nop,nop,timestamp 86478390 > > 615323838> > > 10:31:18.153746 IP (tos 0x0, ttl 60, id 60456, offset 0, flags [DF], > > length: 1500) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: . > > 711337:712785(1448) ack 4052 win 2520 <nop,nop,timestamp 615324682 > > 86478390> > > 10:31:18.153820 IP (tos 0x0, ttl 64, id 19023, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 712785 win 3072 <nop,nop,timestamp 86479234 > > 615324682> > > 10:31:18.166113 IP (tos 0x0, ttl 60, id 60457, offset 0, flags [DF], > > length: 995) 10.20.100.30.microsoft-ds > 10.20.200.15.41344: P > > 712785:713728(943) ack 4052 win 2520 <nop,nop,timestamp 615324686 > > 86479234> > > 10:31:18.166148 IP (tos 0x0, ttl 64, id 19024, offset 0, flags [DF], > > length: 52) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: . [tcp sum > > ok] 4052:4052(0) ack 713728 win 3072 <nop,nop,timestamp 86479237 > > 615324686> > > 10:31:18.166374 IP (tos 0x0, ttl 64, id 19025, offset 0, flags [DF], > > length: 111) 10.20.200.15.41344 > 10.20.100.30.microsoft-ds: P > > 4052:4111(59) ack 713728 win 3072 <nop,nop,timestamp 86479237 > > 615324686> > > > > On 10/5/07, James Lamanna <[EMAIL PROTECTED]> wrote: > > > Hi, > > > I've noticed that over a WAN (T1) I'm getting incredibly slow file > > > copy performance. > > > Using smbclient on a linux machine on one size of the WAN, > > > As you can imagine, this makes all of our file shares unusable over the > > > WAN. > > > It's not an issue with WAN performance, because using scp to transfer > > > the same file, I get speeds of ~145k/s. > > > A tcpdump of the file copy of ~2MB file that actually > > > times out with the following error is up at: > > > http://emagiccards.com/james/copyfileusingsmbclient.tar.bz2 > > > > > > -- Timeout Error -- > > > > > > Short read when getting file \Finance\monthly_reports\Aug07.xls. Only > > > got 967680 bytes. > > > Error Call timed out: server did not respond after 20000 milliseconds > > > closing remote file > > > > > > -- Scp Results -- > > > scp [EMAIL PROTECTED]:/export/data/Finance/Monthly_reports/Aug07.xls . > > > Aug07.xls 100% 2269KB 174.5KB/s 00:13 > > > > > > > > > -- File server samba config -- > > > > > > workgroup = XXXXXXXXX > > > netbios name = FS0 > > > enable privileges = yes > > > server string = FS0 > > > > > > log file = /var/log/samba/log.%m > > > max log size = 50 > > > #log level = 3 passdb:5 auth:10 > > > log level = 10 > > > > > > hosts allow = 10.20.0.0/16 192.168.0.0/16 127.0.0.0/8 > > > > > > map to guest = Bad User > > > guest account = nobody > > > security = user > > > encrypt passwords = yes > > > smb passwd file = /etc/samba/private/smbpasswd > > > wins server = 10.20.100.45 > > > wins support = no > > > > > > name resolve order = wins lmhosts host bcast > > > wins support = no > > > dns proxy = no > > > > > > use sendfile = yes > > > max xmit = 16644 > > > socket options = IPTOS_LOWDELAY TCP_NODELAY SO_SNDBUF=8192 > > > interfaces = lo eth1 > > > > > > hide unreadable = yes > > > hide dot files = yes > > > > > > [TTData] > > > path = /export/data > > > browseable = yes > > > writeable = yes > > > default case = lower > > > preserve case = yes > > > show preserve case = yes > > > case sensitive = no > > > write list = @"Domain Users" @root > > > create mask = 0775 > > > directory mask = 0775 > > > oplocks = no > > > level2 oplocks = no > > > > > > -- To unsubscribe from this list go to the following URL and read the instructions: https://lists.samba.org/mailman/listinfo/samba
