Bug 6196 - Unable to serve files with colons to Linux CIFS/VFS client
Unable to serve files with colons to Linux CIFS/VFS client
Status: RESOLVED FIXED
Product: Samba 3.3
Classification: Unclassified
Component: File services
3.3.2
x64 Linux
: P3 normal
: ---
Assigned To: Jeremy Allison
Samba QA Contact
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2009-03-18 17:42 UTC by Michael Jennings
Modified: 2015-12-18 15:37 UTC (History)
1 user (show)

See Also:


Attachments
Patch for 3.3.x and 3.2.x (813 bytes, patch)
2009-03-18 21:57 UTC, Jeremy Allison
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Michael Jennings 2009-03-18 17:42:24 UTC
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.
Comment 1 Michael Jennings 2009-03-18 17:43:40 UTC
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.
Comment 2 Jeremy Allison 2009-03-18 18:38:23 UTC
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.


Comment 3 Michael Jennings 2009-03-18 18:46:05 UTC
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.
Comment 4 Jeremy Allison 2009-03-18 18:56:18 UTC
Ok, that's definitely progress. I'll see if I can reproduce this and get back to you asap.
Jeremy.
Comment 5 Jeremy Allison 2009-03-18 21:57:46 UTC
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.
Comment 6 Jeremy Allison 2009-03-18 23:01:51 UTC
FYI: I'm adding a torture test to make sure we don't regress on this.
Jeremy.
Comment 7 Michael Jennings 2009-03-19 13:49:02 UTC
Sure enough, that did the trick.  Thanks again for all your help, Jeremy. :)
Comment 8 samba.pasilli 2011-03-02 14:45:33 UTC
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).
Comment 9 Volker Lendecke 2011-03-03 04:09:53 UTC
Re-opened at reporters request
Comment 10 Björn Jacke 2015-12-18 15:37:11 UTC
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)