-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Hi Tobias,
thank you for reply! Tobias Bluhm schrieb: > Another shot in the dark . . . . > > and I don't believe you've stated what fs type your using, but have you > tried storing the data using other fs types or playing with the mount > options? For the Linux server, I have tested with the following filesystems: *) ext2 *) ext3 *) reiserfs *) xfs In my tests, all filesystems were mounted with standard mount-options: mount -t <fstype> /dev/data/test /mountpoint On the kernel 2.4 based systems I did not use enhanced features like ACL or XATTR. On the kernel 2.6 based system (SuSE Linux) I did also test with an ACL and XATTR enabled reiserfs. None of my tests with these different filesystem types showed any significant application performance difference. With all of these different filesystems I get the same strange file access pattern. The data files are not very big: the whole share has about 250MB of size and the files which take longest to load (e.g. "arc.adf" or "pal.adf") are about 2MB of size, each. Under Solaris, all these files are loaded by the application in about 12 seconds alltogether: the application loads them with a blocksize of 4K, block by block sequentially. There is a short peak in filesystem I/O and network traffic when files are loaded from the Solaris server by the application. With the various Linux samba servers, the same action takes several minutes: the applications reads the files with a blocksize of 512 Bytes and seems to read each single block several times, not sequentially but intermixed with other blocks like this: [...] read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 1536, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 2048, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 1536, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 1024, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 2048, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 1536, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 1024, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 2048, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 1024, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 2048, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 1024, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 2048, size = 512, returned 512 read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 1536, size = 512, returned 512 [...] I can see very low filesystem I/O (about 40kB/s) and some network traffic (a few 100kB/s, but that's a rough estimation from what I can see with tcpdump) between the windows client and the Linux server, but that goes on for several minutes. Note: it's the _application_ (Windows XP + ArcView) which does request the files in that strange way. You can see that if you look at the SMB read request messages in the samba logfiles. Example: [...] [2006/07/10 11:28:25, 10] smbd/process.c:setup_select_timeout(1372) change_notify_timeout: -1 [2006/07/10 11:28:25, 10] smbd/process.c:run_events(299) run_events: No events [2006/07/10 11:28:25, 10] lib/util_sock.c:read_smb_length_return_keepalive(618) got smb length of 59 [2006/07/10 11:28:25, 6] smbd/process.c:process_smb(1193) got message type 0x0 of len 0x3b [2006/07/10 11:28:25, 3] smbd/process.c:process_smb(1194) Transaction 3815 of length 63 [2006/07/10 11:28:25, 5] lib/util.c:show_msg(454) [2006/07/10 11:28:25, 5] lib/util.c:show_msg(464) size=59 smb_com=0x2e smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=51207 smb_tid=2 smb_pid=65279 smb_uid=105 smb_mid=44611 smt_wct=12 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]=57054 (0xDEDE) smb_vwv[ 2]= 6251 (0x186B) smb_vwv[ 3]=53248 (0xD000) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 512 (0x200) smb_vwv[ 6]= 512 (0x200) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 512 (0x200) smb_vwv[10]= 0 (0x0) smb_vwv[11]= 0 (0x0) smb_bcc=0 [2006/07/10 11:28:25, 3] smbd/process.c:switch_message(993) switch message SMBreadX (pid 2689) conn 0x844ae08 [2006/07/10 11:28:25, 4] smbd/uid.c:change_to_user(222) change_to_user: Skipping user change - already user [2006/07/10 11:28:25, 10] locking/locking.c:is_locked(109) is_locked: brl start=53248 len=512 unlocked for file daten/covers/dhm_offset/o1000c/arc.adf [2006/07/10 11:28:25, 10] locking/posix.c:is_posix_locked(706) is_posix_locked: File daten/covers/dhm_offset/o1000c/arc.adf, offset = 53248, count = 512, type = READ [2006/07/10 11:28:25, 10] locking/posix.c:posix_lock_in_range(642) posix_lock_in_range: offset_out = 53248, count_out = 512 [2006/07/10 11:28:25, 8] locking/posix.c:posix_fcntl_lock(659) posix_fcntl_lock 33 12 53248 512 0 [2006/07/10 11:28:25, 8] lib/util.c:fcntl_lock(1820) fcntl_lock 33 12 53248 512 0 [2006/07/10 11:28:25, 8] locking/posix.c:posix_fcntl_lock(689) posix_fcntl_lock: Lock call failed [2006/07/10 11:28:25, 10] locking/locking.c:is_locked(121) is_locked: posix start=53248 len=512 unlocked for file daten/covers/dhm_offset/o1000c/arc.adf [2006/07/10 11:28:25, 10] smbd/aio.c:schedule_aio_read_and_X(213) schedule_aio_read_and_X: read size (512) too small for minimum aio_read of 0 [2006/07/10 11:28:25, 10] smbd/fileio.c:read_file(105) read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 53248, size = 512, returned 512 [2006/07/10 11:28:25, 3] smbd/reply.c:send_file_readX(2613) send_file_readX fnum=6251 max=512 nread=512 [2006/07/10 11:28:25, 5] lib/util.c:show_msg(454) [2006/07/10 11:28:25, 5] lib/util.c:show_msg(464) size=571 smb_com=0x2e smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51201 smb_tid=2 smb_pid=65279 smb_uid=105 smb_mid=44611 smt_wct=12 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]=65535 (0xFFFF) smb_vwv[ 3]= 0 (0x0) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 512 (0x200) smb_vwv[ 6]= 59 (0x3B) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 0 (0x0) smb_vwv[11]= 0 (0x0) smb_bcc=512 [2006/07/10 11:28:25, 10] lib/util.c:dump_data(2058) [000] 00 00 02 51 00 00 02 22 00 00 01 F4 00 00 01 F5 ...Q..." ........ [010] 00 00 00 02 4A 57 45 60 4A AE 12 80 4A 57 45 60 ....JWE` J...JWE` [020] 4A AE 1A 50 00 00 04 42 00 00 00 14 00 00 5A 8B J..P...B ......Z. [030] 00 00 02 51 00 00 02 50 00 00 02 1F 00 00 01 F4 ...Q...P ........ [040] 00 00 00 02 4A 57 45 60 4A AE 12 80 4A 57 35 C0 ....JWE` J...JW5. [050] 4A AE 12 80 00 00 04 43 00 00 00 14 00 00 5A C4 J......C ......Z. [060] 00 00 02 52 00 00 02 23 00 00 01 F5 00 00 01 F6 ...R...# ........ [070] 00 00 00 02 4A 57 55 00 4A AE 12 80 4A 57 55 00 ....JWU. J...JWU. [080] 4A AE 1A 50 00 00 04 44 00 00 00 14 00 00 5A 8C J..P...D ......Z. [090] 00 00 02 52 00 00 02 51 00 00 02 20 00 00 01 F5 ...R...Q ... .... [0A0] 00 00 00 02 4A 57 55 00 4A AE 12 80 4A 57 45 60 ....JWU. J...JWE` [0B0] 4A AE 12 80 00 00 04 45 00 00 00 14 00 00 5A C5 J......E ......Z. [0C0] 00 00 02 53 00 00 02 24 00 00 01 F6 00 00 01 F7 ...S...$ ........ [0D0] 00 00 00 02 4A 57 64 A0 4A AE 12 80 4A 57 64 A0 ....JWd. J...JWd. [0E0] 4A AE 1A 50 00 00 04 46 00 00 00 14 00 00 5A 8D J..P...F ......Z. [0F0] 00 00 02 53 00 00 02 52 00 00 02 21 00 00 01 F6 ...S...R ...!.... [100] 00 00 00 02 4A 57 64 A0 4A AE 12 80 4A 57 55 00 ....JWd. J...JWU. [110] 4A AE 12 80 00 00 04 47 00 00 00 14 00 00 5A C6 J......G ......Z. [120] 00 00 02 54 00 00 02 25 00 00 01 F7 00 00 01 F8 ...T...% ........ [130] 00 00 00 02 4A 57 74 40 4A AE 12 80 4A 57 74 40 ....JWt@ J...JWt@ [140] 4A AE 1A 50 00 00 04 48 00 00 00 14 00 00 5A 8E J..P...H ......Z. [150] 00 00 02 54 00 00 02 53 00 00 02 22 00 00 01 F7 ...T...S ...".... [160] 00 00 00 02 4A 57 74 40 4A AE 12 80 4A 57 64 A0 ....JWt@ J...JWd. [170] 4A AE 12 80 00 00 04 49 00 00 00 14 00 00 5A C7 J......I ......Z. [180] 00 00 02 55 00 00 02 26 00 00 01 F8 00 00 01 F9 ...U...& ........ [190] 00 00 00 02 4A 57 83 E0 4A AE 12 80 4A 57 83 E0 ....JW.. J...JW.. [1A0] 4A AE 1A 50 00 00 04 4A 00 00 00 14 00 00 5A 8F J..P...J ......Z. [1B0] 00 00 02 55 00 00 02 54 00 00 02 23 00 00 01 F8 ...U...T ...#.... [1C0] 00 00 00 02 4A 57 83 E0 4A AE 12 80 4A 57 74 40 ....JW.. J...JWt@ [1D0] 4A AE 12 80 00 00 04 4B 00 00 00 14 00 00 5A C8 J......K ......Z. [1E0] 00 00 02 56 00 00 02 27 00 00 01 F9 00 00 01 FA ...V...' ........ [1F0] 00 00 00 02 4A 57 93 80 4A AE 12 80 4A 57 93 80 ....JW.. J...JW.. [...] Under Solaris, it looks like this (same file, same file offset 53248, but different blocksize): [...] [2006/06/21 04:16:44, 10] smbd/process.c:setup_select_timeout(1372) change_notify_timeout: 60 [2006/06/21 04:16:44, 10] smbd/process.c:run_events(299) run_events: No events [2006/06/21 04:16:44, 10] lib/util_sock.c:read_smb_length_return_keepalive(618) got smb length of 59 [2006/06/21 04:16:44, 6] smbd/process.c:process_smb(1193) got message type 0x0 of len 0x3b [2006/06/21 04:16:44, 3] smbd/process.c:process_smb(1194) Transaction 8834 of length 63 [2006/06/21 04:16:44, 5] lib/util.c:show_msg(454) [2006/06/21 04:16:44, 5] lib/util.c:show_msg(464) size=59 smb_com=0x2e smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=24 smb_flg2=59399 smb_tid=2 smb_pid=65279 smb_uid=104 smb_mid=33090 smt_wct=12 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]=57054 (0xDEDE) smb_vwv[ 2]= 8303 (0x206F) smb_vwv[ 3]=53248 (0xD000) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 4096 (0x1000) smb_vwv[ 6]= 4096 (0x1000) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 4096 (0x1000) smb_vwv[10]= 0 (0x0) smb_vwv[11]= 0 (0x0) smb_bcc=0 [2006/06/21 04:16:44, 3] smbd/process.c:switch_message(993) switch message SMBreadX (pid 25093) conn 0x8350a28 [2006/06/21 04:16:44, 4] smbd/uid.c:change_to_user(222) change_to_user: Skipping user change - already user [2006/06/21 04:16:44, 10] locking/locking.c:is_locked(109) is_locked: brl start=53248 len=4096 unlocked for file daten/covers/dhm_offset/o1000c/arc.adf [2006/06/21 04:16:44, 10] locking/posix.c:is_posix_locked(706) is_posix_locked: File daten/covers/dhm_offset/o1000c/arc.adf, offset = 53248, count = 4096, type = WRITE [2006/06/21 04:16:44, 10] locking/posix.c:posix_lock_in_range(642) posix_lock_in_range: offset_out = 53248, count_out = 4096 [2006/06/21 04:16:44, 8] locking/posix.c:posix_fcntl_lock(659) posix_fcntl_lock 27 33 53248 4096 1 [2006/06/21 04:16:44, 8] lib/util.c:fcntl_lock(1820) fcntl_lock 27 33 53248 4096 1 [2006/06/21 04:16:44, 8] locking/posix.c:posix_fcntl_lock(689) posix_fcntl_lock: Lock call failed [2006/06/21 04:16:44, 10] locking/locking.c:is_locked(121) is_locked: posix start=53248 len=4096 unlocked for file daten/covers/dhm_offset/o1000c/arc.adf [2006/06/21 04:16:44, 10] smbd/fileio.c:read_file(105) read_file (daten/covers/dhm_offset/o1000c/arc.adf): pos = 53248, size = 4096, returned 4096 [2006/06/21 04:16:44, 3] smbd/reply.c:send_file_readX(2613) send_file_readX fnum=8303 max=4096 nread=4096 [2006/06/21 04:16:44, 5] lib/util.c:show_msg(454) [2006/06/21 04:16:44, 5] lib/util.c:show_msg(464) size=4155 smb_com=0x2e smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51201 smb_tid=2 smb_pid=65279 smb_uid=104 smb_mid=33090 smt_wct=12 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]=65535 (0xFFFF) smb_vwv[ 3]= 0 (0x0) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 4096 (0x1000) smb_vwv[ 6]= 59 (0x3B) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 0 (0x0) smb_vwv[11]= 0 (0x0) smb_bcc=4096 [2006/06/21 04:16:44, 10] lib/util.c:dump_data(2058) [000] 00 00 02 51 00 00 02 22 00 00 01 F4 00 00 01 F5 ...Q..." ........ [010] 00 00 00 02 4A 57 45 60 4A AE 12 80 4A 57 45 60 ....JWE` J...JWE` [020] 4A AE 1A 50 00 00 04 42 00 00 00 14 00 00 5A 8B J..P...B ......Z. [030] 00 00 02 51 00 00 02 50 00 00 02 1F 00 00 01 F4 ...Q...P ........ [040] 00 00 00 02 4A 57 45 60 4A AE 12 80 4A 57 35 C0 ....JWE` J...JW5. [050] 4A AE 12 80 00 00 04 43 00 00 00 14 00 00 5A C4 J......C ......Z. [060] 00 00 02 52 00 00 02 23 00 00 01 F5 00 00 01 F6 ...R...# ........ [070] 00 00 00 02 4A 57 55 00 4A AE 12 80 4A 57 55 00 ....JWU. J...JWU. [080] 4A AE 1A 50 00 00 04 44 00 00 00 14 00 00 5A 8C J..P...D ......Z. [090] 00 00 02 52 00 00 02 51 00 00 02 20 00 00 01 F5 ...R...Q ... .... [0A0] 00 00 00 02 4A 57 55 00 4A AE 12 80 4A 57 45 60 ....JWU. J...JWE` [0B0] 4A AE 12 80 00 00 04 45 00 00 00 14 00 00 5A C5 J......E ......Z. [0C0] 00 00 02 53 00 00 02 24 00 00 01 F6 00 00 01 F7 ...S...$ ........ [0D0] 00 00 00 02 4A 57 64 A0 4A AE 12 80 4A 57 64 A0 ....JWd. J...JWd. [0E0] 4A AE 1A 50 00 00 04 46 00 00 00 14 00 00 5A 8D J..P...F ......Z. [0F0] 00 00 02 53 00 00 02 52 00 00 02 21 00 00 01 F6 ...S...R ...!.... [100] 00 00 00 02 4A 57 64 A0 4A AE 12 80 4A 57 55 00 ....JWd. J...JWU. [110] 4A AE 12 80 00 00 04 47 00 00 00 14 00 00 5A C6 J......G ......Z. [120] 00 00 02 54 00 00 02 25 00 00 01 F7 00 00 01 F8 ...T...% ........ [130] 00 00 00 02 4A 57 74 40 4A AE 12 80 4A 57 74 40 ....JWt@ J...JWt@ [140] 4A AE 1A 50 00 00 04 48 00 00 00 14 00 00 5A 8E J..P...H ......Z. [150] 00 00 02 54 00 00 02 53 00 00 02 22 00 00 01 F7 ...T...S ...".... [160] 00 00 00 02 4A 57 74 40 4A AE 12 80 4A 57 64 A0 ....JWt@ J...JWd. [170] 4A AE 12 80 00 00 04 49 00 00 00 14 00 00 5A C7 J......I ......Z. [180] 00 00 02 55 00 00 02 26 00 00 01 F8 00 00 01 F9 ...U...& ........ [190] 00 00 00 02 4A 57 83 E0 4A AE 12 80 4A 57 83 E0 ....JW.. J...JW.. [1A0] 4A AE 1A 50 00 00 04 4A 00 00 00 14 00 00 5A 8F J..P...J ......Z. [1B0] 00 00 02 55 00 00 02 54 00 00 02 23 00 00 01 F8 ...U...T ...#.... [1C0] 00 00 00 02 4A 57 83 E0 4A AE 12 80 4A 57 74 40 ....JW.. J...JWt@ [1D0] 4A AE 12 80 00 00 04 4B 00 00 00 14 00 00 5A C8 J......K ......Z. [1E0] 00 00 02 56 00 00 02 27 00 00 01 F9 00 00 01 FA ...V...' ........ [1F0] 00 00 00 02 4A 57 93 80 4A AE 12 80 4A 57 93 80 ....JW.. J...JW.. [...] Note the difference: * read blocksize (Linux = 512, Solaris = 4096) * locking count (Linux = 512, Solaris = 4096) * locking type (Linux = READ, Solaris = WRITE) * Under Linux, there is a "schedule_aio_read_and_X" error message, which is missing under Solaris Can anyone explain these differences? The main question IMHO still ist: why does the application request the files differently when changing the Samba server operating system (and the Samba servers itself are configured identically)? IMHO the client shouldn't even know the server's operating system, should it? Is there some sort of handshake between SMB server and client which tells the client how to read the files? What could lead to different results in such a handshake which then could explain the symptoms? Operating system functionality? Any ideas, anyone? - - andreas - -- Andreas Haumer | mailto:[EMAIL PROTECTED] *x Software + Systeme | http://www.xss.co.at/ Karmarschgasse 51/2/20 | Tel: +43-1-6060114-0 A-1100 Vienna, Austria | Fax: +43-1-6060114-71 -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.3 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFEs4fLxJmyeGcXPhERAoK7AKCWlXYpT8BdWR7GNaCR5crZpnQR7wCgsAB0 E7Laofi5zKAK1dbl1O1pAFI= =2LVN -----END PGP SIGNATURE----- -- To unsubscribe from this list go to the following URL and read the instructions: https://lists.samba.org/mailman/listinfo/samba