Tobias Glemser
2005-Jan-13 14:47 UTC
[Samba] When opening a file it takes up to half a minute!
Greetings,
in our small network with about 10 Clients I got a problem when opening
files or directories. If there were no actions between server and client
for about 2 minutes or more, the very first action (open file, change path,
etc) needs a long long time.
The problem occurs on some clients (win 2k/xp), but not on every client. I
tried a working smb configuration from home, but still no success.
Because the clients are all imaged and have the very same configuration I
don't suppose it's a client problem. Also, I used one client at home
without any problems. We also used another switch and changed patch cables
to exclude all outside factors.
The problem occurs on two different server with no identical hardware
besides the raid controller (3ware), but with an identical installation
(mondo imaged).
Version:
[root@server]# smbd -V
Version 3.0.10
The problem occurred in previous versions beginning with 3.0.8, too. smbd
was installed trough rpm packages provided by Mandrake Linux.
I traced the problem by sniffing the network and increasing debugging to 5.
Here is the smb.conf, which has been changed lot's of times to see which
configuration might work (without socket options, without charset
conversion, etc).
#################
[global]
log file = /var/log/samba/log.%m
passwd chat debug = Yes
obey pam restrictions = Yes
socket options = SO_KEEPALIVE TCP_NODELAY SO_SNDBUF=8192 SO_RCVBUF
8192
encrypt passwords = Yes
public = yes
allow hosts = 192.168.5.
dns proxy = No
server string = Server
unix password sync = No
dos charset = 850
workgroup = WORKGROUP
os level = 65
update encrypted = Yes
unix charset = ISO8859-1
pam password change = Yes
[homes]
comment = Home Verzeichnis
read only = No
browseable = No
[share]
comment = Share
path = /home/server/share/
read only = No
#################
Here is a snippet of a debug=5 log with the lag (beetween 13:12:22 and
13:12:50) while opening a file
#########################
[2005/01/13 13:12:22, 4] smbd/uid.c:change_to_user(194)
change_to_user: Skipping user change - already user
[2005/01/13 13:12:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2346)
call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
[2005/01/13 13:12:22, 5] smbd/filename.c:unix_convert(108)
unix_convert called on file "Projects/somepath/somefile.doc"
[2005/01/13 13:12:22, 5] smbd/statcache.c:stat_cache_add(135)
stat_cache_add: Added entry (83d3f90:size29)
PROJEKTE/SOMEPATH/SOMEFILE.DOC -> Projects/somepath/somefile.doc
[2005/01/13 13:12:22, 5] smbd/filename.c:unix_convert(174)
conversion finished Projects/somepath/somefile.doc ->
Projekte/somepath/somefile.doc
[2005/01/13 13:12:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2380)
call_trans2qfilepathinfo Projects/somepath/somefile.doc (fnum = -1)
level=1004 call=5 total_data=0
[2005/01/13 13:12:22, 5] smbd/trans2.c:call_trans2qfilepathinfo(2506)
SMB_QFBI - create: Wed May 19 15:59:50 2004
access: Thu Jan 13 02:19:58 2005
write: Wed May 19 15:59:50 2004
change: Wed May 19 15:59:50 2004
mode: 20
[2005/01/13 13:12:22, 3] smbd/process.c:process_smb(1091)
Transaction 470 of length 162
[2005/01/13 13:12:22, 5] lib/util.c:show_msg(464)
[2005/01/13 13:12:22, 5] lib/util.c:show_msg(474)
size=158
smb_com=0x32
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=24
smb_flg2=51207
smb_tid=1
smb_pid=3736
smb_uid=100
smb_mid=43458
smt_wct=15
smb_vwv[ 0]= 90 (0x5A)
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]= 90 (0x5A)
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=93
[2005/01/13 13:12:22, 3] smbd/process.c:switch_message(886)
switch message SMBtrans2 (pid 18133) conn 0x83d5578
[2005/01/13 13:12:22, 4] smbd/uid.c:change_to_user(194)
change_to_user: Skipping user change - already user
[2005/01/13 13:12:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2346)
call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
[2005/01/13 13:12:22, 5] smbd/filename.c:unix_convert(108)
unix_convert called on file "Projects/somepath/somefile.doc"
[2005/01/13 13:12:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2380)
call_trans2qfilepathinfo Projects/somepath/somefile.doc (fnum = -1)
level=1004 call=5 total_data=0
[2005/01/13 13:12:22, 5] smbd/trans2.c:call_trans2qfilepathinfo(2506)
SMB_QFBI - create: Wed May 19 15:59:50 2004
access: Thu Jan 13 02:19:58 2005
write: Wed May 19 15:59:50 2004
change: Wed May 19 15:59:50 2004
mode: 20
[2005/01/13 13:12:50, 3] smbd/process.c:process_smb(1091)
Transaction 471 of length 248
[2005/01/13 13:12:50, 5] lib/util.c:show_msg(464)
[2005/01/13 13:12:50, 5] lib/util.c:show_msg(474)
size=244
smb_com=0x73
smb_rcls=0
smb_reh=0
smb_err=0
smb_flg=24
smb_flg2=51207
smb_tid=0
smb_pid=65279
smb_uid=0
smb_mid=43522
smt_wct=12
smb_vwv[ 0]= 255 (0xFF)
smb_vwv[ 1]= 244 (0xF4)
smb_vwv[ 2]=16644 (0x4104)
smb_vwv[ 3]= 50 (0x32)
smb_vwv[ 4]= 1 (0x1)
smb_vwv[ 5]= 0 (0x0)
smb_vwv[ 6]= 0 (0x0)
smb_vwv[ 7]= 83 (0x53)
smb_vwv[ 8]= 0 (0x0)
smb_vwv[ 9]= 0 (0x0)
smb_vwv[10]= 212 (0xD4)
smb_vwv[11]=40960 (0xA000)
smb_bcc=185
[2005/01/13 13:12:50, 3] smbd/process.c:switch_message(886)
switch message SMBsesssetupX (pid 18133) conn 0x0
#########################
Here is a example communications sniffed with ethereal with a lag while
changing a directory:
##############
No Time Source Destination
Protocol Info
217 0.0000 192.168.5.90 192.168.5.151
SMB Trans2 Request, FIND_FIRST2, Pattern: \Projects\somedir\somefile.htm
218 0.000398 192.168.5.151 192.168.5.90
SMB Trans2 Response, FIND_FIRST2, Files: somefile.htm
219 0.004181 192.168.5.90 192.168.5.151
SMB NT Create AndX Request, Path: \Projects\somedir\somefile.htm
220 0.044126 192.168.5.151 192.168.5.90
TCP netbios-ssn > 3390 [ACK] Seq=12490 Ack=2572 Win=5840 Len=0
221 1.188814 192.168.5.90 192.168.0.1
ICMP Echo (ping) request
222 1.343192 192.168.5.90 192.168.5.151
SMB Trans2 Request, QUERY_PATH_INFO, Query File Basic Info, Path:
\Projects
223 1.343364 192.168.5.151 192.168.5.90
TCP netbios-ssn > 3390 [ACK] Seq=12490 Ack=2670 Win=5840 Len=0
some mail traffic in between...
238 17.336031 192.168.5.151 192.168.5.90
SMB NT Create AndX Response, FID: 0x16da
239 17.336121 192.168.5.151 192.168.5.90
SMB Trans2 Response, QUERY_PATH_INFO
240 17.336163 192.168.5.90 192.168.5.151
TCP 3390 > netbios-ssn [ACK] Seq=2670 Ack=12701 Win=64512 [CHECKSUM
INCORRECT]
##############
Thanks for reading until here :)
Would be great if s.o. would got a point for me to go on with.
Thanks in advance!
Toby
Reasonably Related Threads
Wisdom of the Ancients
