Bug 11905 - filename_convert_internal: checkname failed NT_STATUS_INVALID_PARAMETER
Summary: filename_convert_internal: checkname failed NT_STATUS_INVALID_PARAMETER
Status: RESOLVED INVALID
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: File services (show other bugs)
Version: unspecified
Hardware: All All
: P5 normal (vote)
Target Milestone: ---
Assignee: Jeremy Allison
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-05-06 05:38 UTC by andrew
Modified: 2016-05-11 21:29 UTC (History)
1 user (show)

See Also:

Attachments
debug level 10 of failing client (38.98 KB, text/plain)
2016-05-06 05:38 UTC, andrew 		no flags Details
debug level 10 of failing client (host arcfmpc ip: 10.1.201.136) (254.25 KB, text/plain)
2016-05-06 05:57 UTC, andrew 		no flags Details
debug level 10 of successfull client log.hostname (299.95 KB, text/plain)
2016-05-06 05:58 UTC, andrew 		no flags Details
debug level 10 of successful client log.ipaddress (95.94 KB, text/plain)
2016-05-06 05:59 UTC, andrew 		no flags Details
View All Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description andrew 2016-05-06 05:38:42 UTC 
Created attachment 12076 [details]
debug level 10 of failing client

I have a PCBSD machine with /media shared using samba.

Any microsoft clients can successfully connect to /media and browse directories I have created there. 

When I plug in a usb device, I mount it into /media  eg: one labelled "PENDRIVE" becomes /media/PENDRIVE

Some clients can successfully read /media/PENDRIVE, others cannot, including win7 and another PCBSD laptop. Although the clients that cannot view the directory, can successfully copy a file from there using the complete filename eg: if mapped as the U: drive on a microsoft win7 client I can copy u:\pendrive\claim.pdf from there

I looked at the logs under /var/log/samba, specifically log.hostname and noticed that for the client that fails there is

[2016/05/03 11:10:23.908156,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [PENDRIVE/*] [/media]
[2016/05/03 11:10:23.908245,  3] ../source3/smbd/vfs.c:1215(check_reduced_name)
  check_reduced_name: couldn't get realpath for PENDRIVE/*
[2016/05/03 11:10:23.908302,  3] ../source3/smbd/filename.c:1431(filename_convert_internal)
  filename_convert_internal: check_name failed for name PENDRIVE/* with NT_STATUS_INVALID_PARAMETER
[2016/05/03 11:10:23.908363,  3] ../source3/smbd/error.c:82(error_packet_set)
  NT error packet at ../source3/smbd/trans2.c(2568) cmd=50 (SMBtrans2) NT_STATUS_INVALID_PARAMETER


included below are excerpts from the log.hostname from both clients doing "dir u:\pendrive"


thanks in advance
andrew perry



smb.conf:

B
[global]
    workgroup = samba
    encrypt passwords = yes
    wins support = no
    log level = 3 
    max log size = 1000
    read only = no
	log file = /var/log/samba4/log.%m
	max log size = 2500

#[homes] 
#    browsable = no
#    map archive = yes
#[printers] 
#    path = /var/tmp
#    printable = yes
#    min print space = 2000
#[test]
#    browsable = yes
#    read only = yes
#    path = /usr/local/samba/tmp
[usb_media]
	comment = usb_media
	path = /media
	public = no
	writeable = no
	valid users = counter andrew
Comment 1 andrew 2016-05-06 05:41:21 UTC 
excerpts from the logs (log level 3) from m$ clients that work and fail, both doing "dir u:\pendrive"

client that fails:


[2016/05/03 11:10:23.878721,  3] ../source3/smbd/process.c:1879(process_smb)
  Transaction 34 of length 80 (0 toread)
[2016/05/03 11:10:23.878817,  3] ../source3/smbd/process.c:1489(switch_message)
  switch message SMBtrans2 (pid 38324) conn 0x8134bc7e0
[2016/05/03 11:10:23.878891,  3] ../source3/smbd/trans2.c:5518(call_trans2qfilepathinfo)
  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
[2016/05/03 11:10:23.878965,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [.] [/media]
[2016/05/03 11:10:23.879002,  3] ../source3/smbd/vfs.c:1294(check_reduced_name)
  check_reduced_name: . reduced to /media
[2016/05/03 11:10:23.879067,  3] ../source3/smbd/trans2.c:5661(call_trans2qfilepathinfo)
  call_trans2qfilepathinfo . (fnum [fsp is NULL]) level=1004 call=5 total_data=0
[2016/05/03 11:10:23.883313,  3] ../source3/smbd/process.c:1879(process_smb)
  Transaction 35 of length 80 (0 toread)
[2016/05/03 11:10:23.883368,  3] ../source3/smbd/process.c:1489(switch_message)
  switch message SMBtrans2 (pid 38324) conn 0x8134bc7e0
[2016/05/03 11:10:23.883396,  3] ../source3/smbd/trans2.c:5518(call_trans2qfilepathinfo)
  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1005
[2016/05/03 11:10:23.883428,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [.] [/media]
[2016/05/03 11:10:23.883473,  3] ../source3/smbd/vfs.c:1294(check_reduced_name)
  check_reduced_name: . reduced to /media
[2016/05/03 11:10:23.883542,  3] ../source3/smbd/trans2.c:5661(call_trans2qfilepathinfo)
  call_trans2qfilepathinfo . (fnum [fsp is NULL]) level=1005 call=5 total_data=0
[2016/05/03 11:10:23.887618,  3] ../source3/smbd/process.c:1879(process_smb)
  Transaction 36 of length 74 (0 toread)
[2016/05/03 11:10:23.887670,  3] ../source3/smbd/process.c:1489(switch_message)
  switch message SMBtrans2 (pid 38324) conn 0x8134bc7e0
[2016/05/03 11:10:23.887704,  3] ../source3/smbd/trans2.c:3837(call_trans2qfsinfo)
  call_trans2qfsinfo: level = 261
[2016/05/03 11:10:23.887731,  3] ../source3/smbd/trans2.c:3250(smbd_do_qfsinfo)
  smbd_do_qfsinfo: level = 261
[2016/05/03 11:10:23.892257,  3] ../source3/smbd/process.c:1879(process_smb)
  Transaction 37 of length 98 (0 toread)
[2016/05/03 11:10:23.892314,  3] ../source3/smbd/process.c:1489(switch_message)
  switch message SMBtrans2 (pid 38324) conn 0x8134bc7e0
[2016/05/03 11:10:23.892353,  3] ../source3/smbd/trans2.c:5518(call_trans2qfilepathinfo)
  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
[2016/05/03 11:10:23.892406,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [PENDRIVE] [/media]
[2016/05/03 11:10:23.892455,  3] ../source3/smbd/vfs.c:1294(check_reduced_name)
  check_reduced_name: PENDRIVE reduced to /media/PENDRIVE
[2016/05/03 11:10:23.892494,  3] ../source3/smbd/trans2.c:5661(call_trans2qfilepathinfo)
  call_trans2qfilepathinfo PENDRIVE (fnum [fsp is NULL]) level=1004 call=5 total_data=0
[2016/05/03 11:10:23.896595,  3] ../source3/smbd/process.c:1879(process_smb)
  Transaction 38 of length 98 (0 toread)
[2016/05/03 11:10:23.896645,  3] ../source3/smbd/process.c:1489(switch_message)
  switch message SMBtrans2 (pid 38324) conn 0x8134bc7e0
[2016/05/03 11:10:23.896672,  3] ../source3/smbd/trans2.c:5518(call_trans2qfilepathinfo)
  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1005
[2016/05/03 11:10:23.896720,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [PENDRIVE] [/media]
[2016/05/03 11:10:23.896782,  3] ../source3/smbd/vfs.c:1294(check_reduced_name)
  check_reduced_name: PENDRIVE reduced to /media/PENDRIVE
[2016/05/03 11:10:23.896813,  3] ../source3/smbd/trans2.c:5661(call_trans2qfilepathinfo)
  call_trans2qfilepathinfo PENDRIVE (fnum [fsp is NULL]) level=1005 call=5 total_data=0
[2016/05/03 11:10:23.901473,  3] ../source3/smbd/process.c:1879(process_smb)
  Transaction 39 of length 74 (0 toread)
[2016/05/03 11:10:23.901526,  3] ../source3/smbd/process.c:1489(switch_message)
  switch message SMBtrans2 (pid 38324) conn 0x8134bc7e0
[2016/05/03 11:10:23.901554,  3] ../source3/smbd/trans2.c:3837(call_trans2qfsinfo)
  call_trans2qfsinfo: level = 258
[2016/05/03 11:10:23.901585,  3] ../source3/smbd/trans2.c:3250(smbd_do_qfsinfo)
  smbd_do_qfsinfo: level = 258
[2016/05/03 11:10:23.907885,  3] ../source3/smbd/process.c:1879(process_smb)
  Transaction 40 of length 108 (0 toread)
[2016/05/03 11:10:23.907987,  3] ../source3/smbd/process.c:1489(switch_message)
  switch message SMBtrans2 (pid 38324) conn 0x8134bc7e0
[2016/05/03 11:10:23.908044,  3] ../source3/smbd/trans2.c:2502(call_trans2findfirst)
  call_trans2findfirst: dirtype = 16, maxentries = 1366, close_after_first=0, close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x102, max_data_bytes = 16384
[2016/05/03 11:10:23.908156,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [PENDRIVE/*] [/media]
[2016/05/03 11:10:23.908245,  3] ../source3/smbd/vfs.c:1215(check_reduced_name)
  check_reduced_name: couldn't get realpath for PENDRIVE/*
[2016/05/03 11:10:23.908302,  3] ../source3/smbd/filename.c:1431(filename_convert_internal)
  filename_convert_internal: check_name failed for name PENDRIVE/* with NT_STATUS_INVALID_PARAMETER
[2016/05/03 11:10:23.908363,  3] ../source3/smbd/error.c:82(error_packet_set)
  NT error packet at ../source3/smbd/trans2.c(2568) cmd=50 (SMBtrans2) NT_STATUS_INVALID_PARAMETER





client that succeeds:

[2016/05/03 11:11:07.116271,  3] ../source3/smbd/trans2.c:3250(smbd_do_qfsinfo)
  smbd_do_qfsinfo: level = 1001
[2016/05/03 11:11:07.116559,  3] ../source3/smbd/trans2.c:3250(smbd_do_qfsinfo)
  smbd_do_qfsinfo: level = 1005
[2016/05/03 11:11:07.160329,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [PENDRIVE] [/media]
[2016/05/03 11:11:07.160539,  3] ../source3/smbd/vfs.c:1294(check_reduced_name)
  check_reduced_name: PENDRIVE reduced to /media/PENDRIVE
[2016/05/03 11:11:07.160811,  3] ../source3/smbd/dosmode.c:196(unix_mode)
  unix_mode(PENDRIVE) returning 0744
[2016/05/03 11:11:07.180735,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [PENDRIVE] [/media]
[2016/05/03 11:11:07.181042,  3] ../source3/smbd/vfs.c:1294(check_reduced_name)
  check_reduced_name: PENDRIVE reduced to /media/PENDRIVE
[2016/05/03 11:11:07.182696,  3] ../source3/smbd/dir.c:630(dptr_create)
  creating new dirptr 0 for path PENDRIVE, expect_close = 0
[2016/05/03 11:11:07.183081,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/. fname=. (.)
[2016/05/03 11:11:07.183460,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/.. fname=.. (..)
[2016/05/03 11:11:07.183796,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/System Volume Information fname=System Volume Information (System Volume Information)
[2016/05/03 11:11:07.184104,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/andrew fname=andrew (andrew)
[2016/05/03 11:11:07.184394,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01166.JPG fname=DSC01166.JPG (DSC01166.JPG)
[2016/05/03 11:11:07.184677,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01167.JPG fname=DSC01167.JPG (DSC01167.JPG)
[2016/05/03 11:11:07.184968,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01171.JPG fname=DSC01171.JPG (DSC01171.JPG)
[2016/05/03 11:11:07.185245,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01172.JPG fname=DSC01172.JPG (DSC01172.JPG)
[2016/05/03 11:11:07.185523,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01178.JPG fname=DSC01178.JPG (DSC01178.JPG)
[2016/05/03 11:11:07.185800,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01158.JPG fname=DSC01158.JPG (DSC01158.JPG)
[2016/05/03 11:11:07.186079,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01161.JPG fname=DSC01161.JPG (DSC01161.JPG)
[2016/05/03 11:11:07.186355,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01162.JPG fname=DSC01162.JPG (DSC01162.JPG)
[2016/05/03 11:11:07.186669,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/DSC01159.JPG fname=DSC01159.JPG (DSC01159.JPG)
[2016/05/03 11:11:07.186964,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0014.JPG fname=IMG_0014.JPG (IMG_0014.JPG)
[2016/05/03 11:11:07.187243,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0015.JPG fname=IMG_0015.JPG (IMG_0015.JPG)
[2016/05/03 11:11:07.187518,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0016.JPG fname=IMG_0016.JPG (IMG_0016.JPG)
[2016/05/03 11:11:07.187795,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0017.JPG fname=IMG_0017.JPG (IMG_0017.JPG)
[2016/05/03 11:11:07.188051,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0018.JPG fname=IMG_0018.JPG (IMG_0018.JPG)
[2016/05/03 11:11:07.188308,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0010.JPG fname=IMG_0010.JPG (IMG_0010.JPG)
[2016/05/03 11:11:07.188559,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0011.JPG fname=IMG_0011.JPG (IMG_0011.JPG)
[2016/05/03 11:11:07.188862,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0013.JPG fname=IMG_0013.JPG (IMG_0013.JPG)
[2016/05/03 11:11:07.189129,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0012.JPG fname=IMG_0012.JPG (IMG_0012.JPG)
[2016/05/03 11:11:07.189377,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/IMG_0014A.JPG fname=IMG_0014A.JPG (IMG_0014A.JPG)
[2016/05/03 11:11:07.189624,  3] ../source3/smbd/dir.c:1181(smbd_dirptr_get_entry)
  smbd_dirptr_get_entry mask=[*] found PENDRIVE/Claim.pdf fname=Claim.pdf (Claim.pdf)
[2016/05/03 11:11:07.222698,  3] ../source3/smbd/vfs.c:1161(check_reduced_name)
  check_reduced_name [PENDRIVE] [/media]
[2016/05/03 11:11:07.222974,  3] ../source3/smbd/vfs.c:1294(check_reduced_name)
  check_reduced_name: PENDRIVE reduced to /media/PENDRIVE
[2016/05/03 11:11:07.224127,  3] ../source3/smbd/trans2.c:3250(smbd_do_qfsinfo)
  smbd_do_qfsinfo: level = 1007
[2016/05/03 11:11:07.224314,  3] ../source3/lib/sysquotas.c:433(sys_get_quota)
  sys_get_vfs_quota() failed for mntpath[PENDRIVE] bdev[(null)] qtype[2] id[1002]: Operation not supported
[2016/05/03 11:11:07.224456,  3] ../source3/lib/sysquotas.c:433(sys_get_quota)
  sys_get_vfs_quota() failed for mntpath[PENDRIVE] bdev[(null)] qtype[4] id[1002]: Operation not supported
Comment 2 Jeremy Allison 2016-05-06 05:45:29 UTC 
No excerpts please, *full* debug 10 level log of success and fail clients.
Comment 3 andrew 2016-05-06 05:57:26 UTC 
Created attachment 12077 [details]
debug level 10 of failing client  (host arcfmpc ip: 10.1.201.136)

there are logs for the hostname and ip address so including both
Comment 4 andrew 2016-05-06 05:58:33 UTC 
Created attachment 12078 [details]
debug level 10 of successfull client log.hostname
Comment 5 andrew 2016-05-06 05:59:17 UTC 
Created attachment 12079 [details]
debug level 10 of successful client log.ipaddress
Comment 6 andrew 2016-05-06 06:00:53 UTC 
ok sorry about the "excerpts"

the attachments now include the logs from the successful and unsuccessful clients

i've included both log.hostname and log.ipaddress for each

the successful client is techtools 10.1.2.119
the unsuccessful client is arcfmpc 10.1.201.136
Comment 7 andrew 2016-05-10 03:37:59 UTC 
(In reply to Jeremy Allison from comment #2)
sorry about the excerpts, I've since added the logs you asked for. Let me know if I need to add anything else
Comment 8 Jeremy Allison 2016-05-11 15:10:40 UTC 
The clients that are working are using SMB2, the clients that are failing are using SMB1. Just an interesting data point.
Comment 9 Jeremy Allison 2016-05-11 15:23:47 UTC 
Ah, I see the problem. Your realpath() system call is broken on this system. Note that when we call realpath("PENDRIVE/*", &resolved_name) and the filename '*' doesn't exist Samba expects realpath to return ENOENT.

See here:

http://pubs.opengroup.org/onlinepubs/009695399/functions/realpath.html

for the POSIX spec details. When Samba gets ENOENT, then it will strip off the last component and try again. Your system PCBSD is returning EINVAL instead of ENOENT. Note that the opengroup link states:

[EINVAL]
    The file_name argument is a null pointer.

as the only reason for an EINVAL return.

The SMB2 code paths drives this differently so doesn't get the same problem, but this is not a Samba bug, but in your PCBSD usb device filesystem driver.
Comment 10 andrew 2016-05-11 21:29:41 UTC 
(In reply to Jeremy Allison from comment #9)
thanks Jeremy for taking the time to look into this.