Per previous e-mail with Jeremy, after attempting with CIFS kernel module 1.55 and Samba 3.3.2, I'm submitting level 10 debug logs to assist in diagnosis. Background: One of my customers at LBL has numerous data files which are being downloaded to a cluster here at the lab. These files have timestamps in the filenames which use the HH:MM:SS format. I'm attempting to serve these files using CIFS. The server is running Samba 3.3.2, and the client has been upgraded to kernel 2.6.28.7 (cifs.ko version 1.55), and the problem persists. Files with ':' characters in the filenames appear in directories but cannot be directly accessed: root@client ~ #> cat /server/raid006/apo_staging/marvels/54723/engineering/MARVELS1.2008-09-13T23\:20\:25.420.fits cat: /server/raid006/apo_staging/marvels/54723/engineering/MARVELS1.2008-09-13T23:20:25.420.fits: No such file or directory UNIX extensions are turned on.
Debug log snippit: [2009/03/18 15:24:52, 10] lib/util_sock.c:read_smb_length_return_keepalive(1187) got smb length of 242 [2009/03/18 15:24:52, 6] smbd/process.c:process_smb(1551) got message type 0x0 of len 0xf2 [2009/03/18 15:24:52, 3] smbd/process.c:process_smb(1554) Transaction 10 of length 246 (0 toread) [2009/03/18 15:24:52, 5] lib/util.c:show_msg(667) [2009/03/18 15:24:52, 5] lib/util.c:show_msg(677) size=242 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=561 smb_uid=100 smb_mid=1147 smt_wct=15 smb_vwv[ 0]= 176 (0xB0) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) 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]= 176 (0xB0) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=177 [2009/03/18 15:24:52, 10] lib/util.c:dump_data(2255) [000] 00 00 02 00 00 00 00 2F 00 72 00 61 00 69 00 64 ......./ .r.a.i.d [010] 00 30 00 30 00 36 00 2F 00 61 00 70 00 6F 00 5F .0.0.6./ .a.p.o._ [020] 00 73 00 74 00 61 00 67 00 69 00 6E 00 67 00 2F .s.t.a.g .i.n.g./ [030] 00 6D 00 61 00 72 00 76 00 65 00 6C 00 73 00 2F .m.a.r.v .e.l.s./ [040] 00 35 00 34 00 37 00 32 00 33 00 2F 00 65 00 6E .5.4.7.2 .3./.e.n [050] 00 67 00 69 00 6E 00 65 00 65 00 72 00 69 00 6E .g.i.n.e .e.r.i.n [060] 00 67 00 2F 00 4D 00 41 00 52 00 56 00 45 00 4C .g./.M.A .R.V.E.L [070] 00 53 00 31 00 2E 00 32 00 30 00 30 00 38 00 2D .S.1...2 .0.0.8.- [080] 00 30 00 39 00 2D 00 31 00 33 00 54 00 32 00 33 .0.9.-.1 .3.T.2.3 [090] 00 3A F0 32 00 30 00 3A F0 32 00 35 00 2E 00 34 .:.2.0.: .2.5...4 [0A0] 00 32 00 30 00 2E 00 66 00 69 00 74 00 73 00 00 .2.0...f .i.t.s.. [0B0] 00 . [2009/03/18 15:24:52, 3] smbd/process.c:switch_message(1378) switch message SMBtrans2 (pid 28846) conn 0x7f80c072b650 [2009/03/18 15:24:52, 4] smbd/uid.c:change_to_user(213) change_to_user: Skipping user change - already user [2009/03/18 15:24:52, 3] smbd/trans2.c:call_trans2qfilepathinfo(3943) call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 512 [2009/03/18 15:24:52, 5] smbd/filename.c:unix_convert(148) unix_convert called on file "raid006/apo_staging/marvels/54723/engineering/MARVELS1.2008-09-13T23ïº20ïº25.420.fits" [2009/03/18 15:24:52, 5] smbd/filename.c:unix_convert(303) unix_convert begin: name = raid006/apo_staging/marvels/54723/engineering/MARVELS1.2008-09-13T23ïº20ïº25.420.fits, dirpath = , start = raid006/apo_staging/marvels/54723/engineering/MARVELS1.2008-09-13T23ïº20ïº25.420.fits [2009/03/18 15:24:52, 3] smbd/trans2.c:call_trans2qfilepathinfo(4028) call_trans2qfilepathinfo: SMB_VFS_LSTAT of raid006/apo_staging/marvels/54723/engineering/MARVELS1.2008-09-13T23ïº20ïº25.420.fits failed (No such file or directory) [2009/03/18 15:24:52, 3] smbd/error.c:reply_unix_error(154) unix_error_packet: error string = No such file or directory [2009/03/18 15:24:52, 3] smbd/error.c:error_packet_set(61) error packet at smbd/trans2.c(4029) cmd=50 (SMBtrans2) NT_STATUS_OBJECT_NAME_NOT_FOUND [2009/03/18 15:24:52, 5] lib/util.c:show_msg(667) [2009/03/18 15:24:52, 5] lib/util.c:show_msg(677) size=35 smb_com=0x32 smb_rcls=52 smb_reh=0 smb_err=49152 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=561 smb_uid=100 smb_mid=1147 smt_wct=0 smb_bcc=0 I think that's the entire transaction; please let me know if more context is needed.
Ey up. Look at the incoming filename from the client.... Instead of ':' (maps to the two bytes 0x3A 0x00 as little endian ucs2) it is sending : 0x3A 0xF0 This is not the ":" character, it is 0xF03A which is in the "private use" unicode area. As I recall Steve uses the private use mapping in cifsfs when talking to Windows servers to store UNIX characters that can't be mapped on Windows. This looks like the client is confused about what kind of server it's talking to. Jeremy.
If I use the "nomapchars" option on the client to disable any not-valid-on-windows char remapping (at least that's what the man page says it should do), here's the new debug log: [2009/03/18 16:43:00, 10] lib/util_sock.c:read_smb_length_return_keepalive(1187) got smb length of 242 [2009/03/18 16:43:00, 6] smbd/process.c:process_smb(1551) got message type 0x0 of len 0xf2 [2009/03/18 16:43:00, 3] smbd/process.c:process_smb(1554) Transaction 25 of length 246 (0 toread) [2009/03/18 16:43:00, 5] lib/util.c:show_msg(667) [2009/03/18 16:43:00, 5] lib/util.c:show_msg(677) size=242 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=1113 smb_uid=100 smb_mid=26 smt_wct=15 smb_vwv[ 0]= 176 (0xB0) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) 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]= 176 (0xB0) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=177 [2009/03/18 16:43:00, 10] lib/util.c:dump_data(2255) [000] 00 00 02 00 00 00 00 2F 00 72 00 61 00 69 00 64 ......./ .r.a.i.d [010] 00 30 00 30 00 36 00 2F 00 61 00 70 00 6F 00 5F .0.0.6./ .a.p.o._ [020] 00 73 00 74 00 61 00 67 00 69 00 6E 00 67 00 2F .s.t.a.g .i.n.g./ [030] 00 6D 00 61 00 72 00 76 00 65 00 6C 00 73 00 2F .m.a.r.v .e.l.s./ [040] 00 35 00 34 00 37 00 32 00 33 00 2F 00 65 00 6E .5.4.7.2 .3./.e.n [050] 00 67 00 69 00 6E 00 65 00 65 00 72 00 69 00 6E .g.i.n.e .e.r.i.n [060] 00 67 00 2F 00 4D 00 41 00 52 00 56 00 45 00 4C .g./.M.A .R.V.E.L [070] 00 53 00 31 00 2E 00 32 00 30 00 30 00 38 00 2D .S.1...2 .0.0.8.- [080] 00 30 00 39 00 2D 00 31 00 33 00 54 00 32 00 33 .0.9.-.1 .3.T.2.3 [090] 00 3A 00 32 00 30 00 3A 00 32 00 35 00 2E 00 34 .:.2.0.: .2.5...4 [0A0] 00 32 00 30 00 2E 00 66 00 69 00 74 00 73 00 00 .2.0...f .i.t.s.. [0B0] 00 . [2009/03/18 16:43:00, 3] smbd/process.c:switch_message(1378) switch message SMBtrans2 (pid 23350) conn 0x7f80c072ced0 [2009/03/18 16:43:00, 4] smbd/uid.c:change_to_user(213) change_to_user: Skipping user change - already user [2009/03/18 16:43:00, 3] smbd/trans2.c:call_trans2qfilepathinfo(3943) call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 512 [2009/03/18 16:43:00, 3] smbd/error.c:error_packet_set(61) error packet at smbd/trans2.c(3954) cmd=50 (SMBtrans2) NT_STATUS_INVALID_PARAMETER [2009/03/18 16:43:00, 5] lib/util.c:show_msg(667) [2009/03/18 16:43:00, 5] lib/util.c:show_msg(677) size=35 smb_com=0x32 smb_rcls=13 smb_reh=0 smb_err=49152 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=1113 smb_uid=100 smb_mid=26 smt_wct=0 smb_bcc=0 Different error, and different UCS2 chars in the packet, but still unreadable.
Ok, that's definitely progress. I'll see if I can reproduce this and get back to you asap. Jeremy.
Created attachment 3999 [details] Patch for 3.3.x and 3.2.x This fixes it for me here. Looks like the pathname parsing for POSIX paths got broken when the code for doing Windows streams parsing got added. Can you test it and confirm ? Thanks, Jeremy.
FYI: I'm adding a torture test to make sure we don't regress on this. Jeremy.
Sure enough, that did the trick. Thanks again for all your help, Jeremy. :)
Please reopen. Buggy again with version 3.4.3 (3.4.3-3.6.1-2426-SUSE-SL11.2). (reported broken also on ubuntu 10.10 http://ubuntuforums.org/showthread.php?t=1618257).
Re-opened at reporters request
closing as there came no more input here and the original issue was fied. (apart from that i suspect that no posix extensions had been used by the latest commenter)