search

AgNO3 / jcifs-ng

A cleaned-up and improved version of the jCIFS library
GNU Lesser General Public License v2.1
318 stars 103 forks source link

Error when calling SmbFile.copyTo: The system cannot find the file specified #297

Open jgribonvald opened 2 years ago

jgribonvald commented 2 years ago

Hi,

I tested on version 2.0.8 like 2.1.7 and I'm getting this error when calling SmbFile.copyTo(). Here is the log from 2.1.7:

jcifs.smb.SmbException: The system cannot find the file specified.
    at jcifs.smb.SmbFile.copyTo(SmbFile.java:1409)

from 2.0.8:

jcifs.smb.SmbException: The system cannot find the path specified.
        at jcifs.smb.SmbTransportImpl.checkStatus2(SmbTransportImpl.java:1413)
        at jcifs.smb.SmbTransportImpl.checkStatus(SmbTransportImpl.java:1524)
        at jcifs.smb.SmbTransportImpl.sendrecv(SmbTransportImpl.java:984)
        at jcifs.smb.SmbTransportImpl.send(SmbTransportImpl.java:1495)
        at jcifs.smb.SmbSessionImpl.send(SmbSessionImpl.java:400)
        at jcifs.smb.SmbTreeImpl.send(SmbTreeImpl.java:465)
        at jcifs.smb.SmbTreeConnection.send0(SmbTreeConnection.java:399)
        at jcifs.smb.SmbTreeConnection.send(SmbTreeConnection.java:314)
        at jcifs.smb.SmbTreeConnection.send(SmbTreeConnection.java:294)
        at jcifs.smb.SmbTreeHandleImpl.send(SmbTreeHandleImpl.java:130)
        at jcifs.smb.SmbTreeHandleImpl.send(SmbTreeHandleImpl.java:117)
        at jcifs.smb.SmbFile.queryPath(SmbFile.java:761)
        at jcifs.smb.SmbFile.copyRecursive(SmbFile.java:1349)
        at jcifs.smb.SmbFile.copyTo(SmbFile.java:1413)
jgribonvald commented 2 years ago

It's something odd, because when I entering in remote debugging mode I don't have the problem if it takes some times to arrive to the exception part... I tried to set to 0 the jcifs.smb.client.attrExpirationPeriod but it doesn't change anything as I thougth about a cache problem...

jgribonvald commented 2 years ago

After some more search I've found the potential cause of the error: command=SMB2_CREATE,status=0,flags=0x0000,mid=61,wordCount=0,byteCount=184,name=persoelement\Travail\Documentation\myfile.odg,resolveDfs=false

there is a missing \ in the path as it should be perso\element\Travail\Documentation\myfile.odg The thing is that I don't understand where this \ is removed as the param passed to copyTo method is more longer and contains the smb://my.server.org/commonpath/group_path/perso/element/Travail/Documentation/myfile.odg

@mbechler do you have any idea of where this missing file separator could come ?

mbechler commented 2 years ago

Thanks for digging into this. My best guess would be DFS resolving/caching, which unfortunately is not much fun to debug.

jgribonvald commented 2 years ago

@mbechler I don't have DFS system involved into my test.

I'm on SmbResourceLocatorImpl.getUNCPath() and with the synchronized canonicalizePath(), it seems that the problem comes here but I dont know why.

mbechler commented 2 years ago

Okay, but then group_path is also missing from the path. Unfortunately, I also don't see where a path separator could get lost somewhere in canonicalizePath(). Are you constructing that path somehow relative to another SmbFile? One of the legacy ideocracyies of the code the caller must make sure that directories are specified with a trailing slash (at least in some cases)

jgribonvald commented 2 years ago

@mbechler I don't rebuild something, and from remote debug the getUNCPath return a path with a missing path separator and I don't understand how it's possible when I read the code, expet maybe due to the synchronized, but...

mbechler commented 2 years ago

Ah, I think that actually comes from the source path (i.e. the SmbFile itself) not the destination passed as parameter, what is that path?

jgribonvald commented 2 years ago

Ah, I think that actually comes from the source path (i.e. the SmbFile itself) not the destination passed as parameter, what is that path?

Yes that's it, effectively I'm not watching at the good place... I will go to watch where this isn't well provided....

jgribonvald commented 2 years ago

I didn't figure that the name in command=SMB2_CREATE,status=0,flags=0x0000,mid=61,wordCount=0,byteCount=184,name=persoelement\Travail\Documentation\myfile.odg,resolveDfs=false have a problem, it mix the start of the destination path with the from path, the perso part if from dest !

jgribonvald commented 2 years ago

So in the copyTo I have at one time the sh.resourceLoc.unc set with the missing separator and concatining the dest directory start path with the source path. Note that the source path is truncated and doesn't start with a file separator, so maybe the problem comes from here ?

jgribonvald commented 2 years ago

@mbechler So ok got where the problem come: from SmbResourceLocatorImpl.handleDFSReferral on 

if ( !dr.getPath().isEmpty() ) {
            dunc = "\\" + dr.getPath() + dunc;
        }

there is a missing \\ before + dunc

But I don't understand why it adds the destination dr.path (DfsReferaldata) to the source path wheras this.unc is already good.

So it seems there is a DFS resolving that cause a problem, do you know why it do a such thing ?

EDIT: at the beginning of the handleDFSReferral this test fail, that should be the cause:

if ( Objects.equals(this.dfsReferral, dr) ) {
            return this.unc;
        }

when I inspect latter the result is true, expect on remains.

jgribonvald commented 2 years ago

@mbechler if it can helps folowwing is the trace log (anonymized):

smb.SmbFile.[] - queryPath: \source_dir\Profs-6EMEC\6EMEC\Travail\Documentation\MYFILE.odg
smb.SmbSessionImpl.[] - Acquire session 2 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=2]
transport.Transport.[] - Acquire transport 2 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=2]
transport.Transport.[] - Release transport 1 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=1]
smb.SmbSessionImpl.[] - Release session 1 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=1]
smb.SmbSessionImpl.[] - Acquire session 2 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=2]
transport.Transport.[] - Acquire transport 2 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=2]
transport.Transport.[] - Release transport 1 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=1]
smb.SmbTreeConnection.[] - Already connected
smb.SmbTreeConnection.[] - Acquire tree connection 2 jcifs.smb.SmbTreeConnectionTrace@37209df3
smb.SmbSessionImpl.[] - Release session 1 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=1]
smb.SmbSessionImpl.[] - Acquire session 2 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=2]
transport.Transport.[] - Acquire transport 2 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=2]
smb.SmbTreeImpl.[] - Acquire tree 38 SmbTree[share=an_id,service=null,tid=1,inDfs=false,inDomainDfs=true,connectionState=2,usage=38]
smb.SmbTreeConnection.[] - Need to adjust request path \source_dir\Profs-6EMEC\6EMEC\Travail\Documentation\MYFILE.odg (full: \my.dns\an_id\source_dir\Profs-6EMEC\6EMEC\Travail\Documentation\MYFILE.odg) -> DfsReferralData[pathConsumed=26,server=server01.my.dns,share=an_id,link=null,path=destination_dir,ttl=0,expiration=1645029230239,remain=288908]
smb.SmbResourceLocatorImpl.[] - UNC is '\source_dir\Profs-6EMEC\6EMEC\Travail\Documentation\MYFILE.odg'
smb.SmbResourceLocatorImpl.[] - Consumed '\source_dir\Profs-6EMEC\'
smb.SmbResourceLocatorImpl.[] - Remaining '6EMEC\Travail\Documentation\MYFILE.odg'
smb.SmbTreeImpl.[] - Release tree 37 SmbTree[share=an_id,service=null,tid=1,inDfs=false,inDomainDfs=true,connectionState=2,usage=37]
transport.Transport.[] - Release transport 1 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=1]
smb.SmbSessionImpl.[] - Release session 1 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=1]
smb.SmbTreeConnection.[] - Release tree connection 1 jcifs.smb.SmbTreeConnectionTrace@37209df3
smb.SmbTreeImpl.[] - Acquire tree 38 SmbTree[share=an_id,service=null,tid=1,inDfs=false,inDomainDfs=true,connectionState=2,usage=38]
smb.SmbSessionImpl.[] - Acquire session 2 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=2]
transport.Transport.[] - Acquire transport 2 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=2]
smb.SmbSessionImpl.[] - Acquire session 3 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=3]
transport.Transport.[] - Acquire transport 3 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=3]
transport.Transport.[] - Release transport 2 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=2]
smb.SmbSessionImpl.[] - Release session 2 SmbSession[credentials=DOMAIN\user.name,targetHost=server01.my.dns,targetDomain=null,uid=0,connectionState=2,usage=2]
transport.Transport.[] - Acquire transport 3 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=3]
transport.Transport.[] - Acquire transport 4 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=4]
transport.Transport.[] - Release transport 3 Transport1[server01.my.dns/192.168.1.138:445,state=3,signingEnforced=false,usage=3]
smb.SmbSessionImpl.[] - Request [command=SMB2_CREATE,status=0,flags=0x0000,mid=0,wordCount=0,byteCount=0,name=destination_dir6EMEC\Travail\Documentation\MYFILE.odg,resolveDfs=false]
smb.SmbTransportImpl.[] - Sending [command=SMB2_CREATE,status=0,flags=0x0000,mid=0,wordCount=0,byteCount=0,name=destination_dir6EMEC\Travail\Documentation\MYFILE.odg,resolveDfs=false]
smb.SmbTransportImpl.[] - jcifs.internal.smb2.create.Smb2CreateRequest costs 1 avail 512 (Transport1)
smb.SmbTransportImpl.[] - jcifs.internal.smb2.create.Smb2CloseRequest costs 1 avail 511 (Transport1)
smb.SmbTransportImpl.[] - Request credits 1
smb.SmbTransportImpl.[] - Sending [command=SMB2_CREATE,status=0,flags=0x0000,mid=0,wordCount=0,byteCount=0,name=destination_dir6EMEC\Travail\Documentation\MYFILE.odg,resolveDfs=false]
create.Smb2CreateRequest.[] - Opening destination_dir6EMEC\Travail\Documentation\MYFILE.odg

...

smb.SmbTransportImpl.[] - Error code: 0xC000003A for Smb2CreateRequest
smb.SmbTransportImpl.[] - Adding credits 2
smb.SmbSessionImpl.[] - Send failed
jcifs.smb.SmbException: The system cannot find the path specified.
        at jcifs.smb.SmbTransportImpl.checkStatus2(SmbTransportImpl.java:1467)
        at jcifs.smb.SmbTransportImpl.checkStatus(SmbTransportImpl.java:1578)
        at jcifs.smb.SmbTransportImpl.sendrecv(SmbTransportImpl.java:1027)
        at jcifs.smb.SmbTransportImpl.send(SmbTransportImpl.java:1549)
        at jcifs.smb.SmbSessionImpl.send(SmbSessionImpl.java:409)
        at jcifs.smb.SmbTreeImpl.send(SmbTreeImpl.java:472)
        at jcifs.smb.SmbTreeConnection.send0(SmbTreeConnection.java:404)
        at jcifs.smb.SmbTreeConnection.send(SmbTreeConnection.java:318)
        at jcifs.smb.SmbTreeConnection.send(SmbTreeConnection.java:298)
        at jcifs.smb.SmbTreeHandleImpl.send(SmbTreeHandleImpl.java:130)
        at jcifs.smb.SmbTreeHandleImpl.send(SmbTreeHandleImpl.java:117)
        at jcifs.smb.SmbFile.withOpen(SmbFile.java:1761)
        at jcifs.smb.SmbFile.withOpen(SmbFile.java:1730)
        at jcifs.smb.SmbFile.queryPath(SmbFile.java:779)
        at jcifs.smb.SmbFile.exists(SmbFile.java:865)
        at jcifs.smb.SmbFile.copyTo(SmbFile.java:1408)

In fact I'm not sure of what should be done, I guessing if that's the remaining part that isn't good, in my mind the SMB2 CREATE Request should be [command=SMB2_CREATE,status=0,flags=0x0000,mid=0,wordCount=0,byteCount=0,name=destination_dir\MYFILE.odg,resolveDfs=false] instead of [command=SMB2_CREATE,status=0,flags=0x0000,mid=0,wordCount=0,byteCount=0,name=destination_dir6EMEC\Travail\Documentation\MYFILE.odg,resolveDfs=false], so in my mind the calculation done from here

smb.SmbResourceLocatorImpl.[] - UNC is '\source_dir\Profs-6EMEC\6EMEC\Travail\Documentation\MYFILE.odg'
smb.SmbResourceLocatorImpl.[] - Consumed '\source_dir\Profs-6EMEC\'
smb.SmbResourceLocatorImpl.[] - Remaining '6EMEC\Travail\Documentation\MYFILE.odg'

is wrong and should be 

smb.SmbResourceLocatorImpl.[] - UNC is '\source_dir\Profs-6EMEC\6EMEC\Travail\Documentation\MYFILE.odg'
smb.SmbResourceLocatorImpl.[] - Consumed '\source_dir\Profs-6EMEC\6EMEC\Travail\Documentation\'
smb.SmbResourceLocatorImpl.[] - Remaining 'MYFILE.odg'
jgribonvald commented 2 years ago

I don't know if we can compare with a simple upload in this case I have this thing:

smb.SmbResourceLocatorImpl.[] - UNC is '\destination_dir\user.name\perso\'
smb.SmbResourceLocatorImpl.[] - Consumed '\destination_dir'
smb.SmbResourceLocatorImpl.[] - Remaining '\user.name\perso\'

If that the rigth way it should do, that's mean that the resolved DFS is the wrong one, so the filelocator passed is wrong.

mbechler commented 2 years ago

Probably won't be able to have a closer look till the weekend, but:

There is a known issue #291 that recursive links are not properly handled, maybe this is something similar.

jgribonvald commented 2 years ago

Probably won't be able to have a closer look till the weekend, but:

  • so there actually is DFS in place, right?

Yes, the hoster of the windows system didn't say me all things...

  • are you aware/can you find out what the actual DFS link structure for the revelevant location is (the referall shown would indicate \my.dns\an_id\source_dir\Profs-6EMEC\ points to \server01.my.dns\an_id\destination_dir)

I don't have access to the file system, but here is what I can obtains from log: Need to adjust request path \source_dir\Profs-6EMEC\6EMEC\Travail\Documentation (full: \my.dns\an_id\source_dir\Profs-6EMEC\6EMEC\Travail\Documentation\) -> DfsReferralData[pathConsumed=35,server=server01.my.dns,share=an_id,link=null,path=source_dir,ttl=0,expiration=1645036001398,remain=291389]

  • the lengths of the redacted elements could be interesting

what do you mean by the redacted elements ? I see that at one point there is a removal of a string lenth, so you mean that the length is wrong as the resolved location isn't the same, and so the length should be calculated from the pointed (DFS) location ?

There is a known issue #291 that recursive links are not properly handled, maybe this is something similar.

mbechler commented 2 years ago
  • the lengths of the redacted elements could be interesting

what do you mean by the redacted elements ?

The folder/server names you replaced, e.g. server01.my.dns, an_id or source_dir. Referrals specify the prefix as number of characters (e.g. pathConsumed=35 above), so that may be relevant to understand what is going on.

Figuring this out is going to need more information. With information about the referral structure (on windows that would be available in the properties dialog under DFS) I might be able to replicate the setup, and possible the issue. A Trace-level log of jcifs.smb.DfsImpl would also be helpful.

jgribonvald commented 2 years ago
  • the lengths of the redacted elements could be interesting

what do you mean by the redacted elements ?

The folder/server names you replaced, e.g. server01.my.dns, an_id or source_dir. Referrals specify the prefix as number of characters (e.g. pathConsumed=35 above), so that may be relevant to understand what is going on.

Figuring this out is going to need more information. With information about the referral structure (on windows that would be available in the properties dialog under DFS) I might be able to replicate the setup, and possible the issue. A Trace-level log of jcifs.smb.DfsImpl would also be helpful.

@mbechler I fixed a part of the problem but not the result, as I'm having an other problem with the same result. So there is a "/" missing in the path here:

if ( !dr.getPath().isEmpty() ) {
            dunc = "\\" + dr.getPath() + dunc;
        }

But now I have a problem as the DFS replaced isn't the good one, it use a wrong path, in my case I have a strange thing the DFS path should not be replaced, as it should be the server that will do it. I'm not totaliy sure but it seems that the DFS is used only for referals path and that's the main server that will do the path replacement/redirection. I will provide you an example...