Welcome to the VanDyke Software Forums

Join the discussion today!


Go Back   VanDyke Software Forums > File Transfer

Reply
 
Thread Tools Display Modes
  #1  
Old 10-17-2017, 02:44 PM
EricS EricS is offline
Registered User
 
Join Date: Jun 2016
Posts: 10
Transfer fails on permission error:

Client insists the file is being transferred by the user who created it, that user has full permission to the destination directory but transfer fails as follows:

2017-10-17 12:30:26 VShellSSH2 auth 167 - - xdomainx\xuserx - - 0 0 0 0 - - "00167: Client specified user name xuserx, resolved as xdomainx\xuserx"
2017-10-17 12:30:26 VShellSSH2 auth 167 10.1.19.239 50066 xdomainx\xuserx - - 0 0 0 0 - - "00167: none for user xdomainx\xuserx rejected because it is unavailable"
2017-10-17 12:30:26 VShellSSH2 auth 167 10.1.19.239 50066 xdomainx\xuserx - - 0 0 0 0 - - "00167: password for user xdomainx\xuserx accepted"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV: CHANNEL_OPEN[session]"
2017-10-17 12:30:26 VShellSSH2 conn 167 10.1.19.239 50066 xdomainx\xuserx - - 0 0 0 0 - - "00167: Session channel open request accepted"
2017-10-17 12:30:26 VShellSSH2 conn 167 10.1.19.239 50066 xdomainx\xuserx - - 0 0 0 0 - - "00167: Received request to start subsystem sftp (Built-in Subsystem)"
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xuserx - - 0 0 0 0 10.1.17.157 22 "00167: SFTP subsystem initialized; remote version is 3"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - xdomainx\xuserx - - 0 0 0 0 - - "00167: Queued worker thread to load user environment"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: Worker thread starting user environment load. User name=xuserx Logon Server=domaincontroller Profile Path=''"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: Worker thread finished user environment load"
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xuserx - - 0 0 0 0 10.1.17.157 22 "00167: Sending VERSION packet to remote (3)"
2017-10-17 12:30:26 VShellSSH2 auth 167 - - xdomainx\xuserx - - 0 0 0 0 - - "00167: Using home directory 'D:\Transport\FSO_Test' (Alias: FSO_FTP_TEST) for user xdomainx\xuserx"
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xuserx - - 0 0 0 0 10.1.17.157 22 "00167: Failed to open '/GCHANDRI2017-10-17-12.30.21.236JRNL1_-_DSUN.txt': Access is denied."
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xuserx - - 0 0 0 0 10.1.17.157 22 "00167: SFTP subsystem terminated"
2017-10-17 12:30:26 VShellSSH2 conn 167 10.1.19.239 50066 xdomainx\xuserx - - 0 0 0 0 - - "00167: Session channel has been closed (pid: none)
Reply With Quote
  #2  
Old 10-17-2017, 03:13 PM
bgagnon bgagnon is online now
VanDyke Technical Support
 
Join Date: Oct 2008
Posts: 3,181
Hi EricS,

What version of VShell is installed?

Quote:
Client insists the file is being transferred by the user who created it, that user has full permission to the destination directory but transfer fails as follows:
They are attempting to upload a file to VShell, correct?

Were NTFS permissions checked? (Not just those that might be enabled in the Common / Virtual Roots category of VShell's control panel -- because those won't allow permissions that are not allowed by NTFS.)

What is the SFTP client? (If you post all lines of the session from the debug log, this information is included.)

If it's a command-line client, what is the syntax they are using?
__________________
Thanks,
--Brenda

VanDyke Software
Technical Support
support@vandyke.com
(505) 332-5730
Reply With Quote
  #3  
Old 10-17-2017, 04:09 PM
EricS EricS is offline
Registered User
 
Join Date: Jun 2016
Posts: 10
Quote:
Originally Posted by bgagnon View Post
Hi EricS,

What version of VShell is installed?
Version 4.2.4 (x64 build 1255) - Official Release - December 8, 2016


Quote:
Originally Posted by bgagnon View Post
They are attempting to upload a file to VShell, correct?
Correct.

Quote:
Originally Posted by bgagnon View Post
Were NTFS permissions checked?
Yes, the user has full permission to the folder.

Quote:
Originally Posted by bgagnon View Post
What is the SFTP client?
SecureFx

Full(er) log:

[removed]
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] SSH2Core version 7.5.0.1255"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Changing state from STATE_NOT_CONNECTED to STATE_EXPECT_KEX_INIT"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Using protocol SSH2"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV : Remote Identifier = 'SSH-2.0-libssh2_1.1'"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote can re-key"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote sends language in password change requests"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote sends algorithm name in PK_OK packets"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote sends algorithm name in public key packets"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote sends algorithm name in signatures"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote sends error text in open failure packets"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote sends name in service accept packets"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote includes port number in x11 open packets"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote uses 160 bit keys for SHA1 MAC"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote supports new diffie-hellman group exchange messages"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote correctly handles unknown SFTP extensions"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote correctly encodes OID for gssapi"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote correctly uses connected addresses in forwarded-tcpip requests"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote can do SFTP version 4"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote uses SHA1 hash in RSA signatures for x.509v3"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote x.509v3 uses ASN.1 encoding for DSA signatures"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] CAP : Remote correctly handles zlib@openssh.com"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] SEND : KEXINIT"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV : Read kexinit"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Available Remote Kex Methods = diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Selected Kex Method = diffie-hellman-group-exchange-sha1"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Available Remote Host Key Algos = ssh-rsa,ssh-dss"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Selected Host Key Algo = ssh-dss"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Available Remote Send Ciphers = aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour,cast128-cbc,3des-cbc"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Selected Send Cipher = aes256-cbc"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Available Remote Recv Ciphers = aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour,cast128-cbc,3des-cbc"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Selected Recv Cipher = aes256-cbc"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Available Remote Send Macs = hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Selected Send Mac = hmac-sha1"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Available Remote Recv Macs = hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Selected Recv Mac = hmac-sha1"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Available Remote Compressors = none,zlib"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Selected Compressor = none"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Available Remote Decompressors = none,zlib"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Selected Decompressor = none"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Changing state from STATE_EXPECT_KEX_INIT to STATE_KEY_EXCHANGE"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV : KEXDH_GEX_REQUEST"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] SEND : KEXDH_GEX_GROUP"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV : KEXDH_INIT"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] SEND : KEXDH_REPLY"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Changing state from STATE_KEY_EXCHANGE to STATE_READY_FOR_NEW_KEYS"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] SEND : NEWKEYS"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Changing state from STATE_READY_FOR_NEW_KEYS to STATE_EXPECT_NEWKEYS"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV : NEWKEYS"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Changing state from STATE_EXPECT_NEWKEYS to STATE_CONNECTION"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV: SERVICE_REQUEST[ssh-userauth]"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] SEND: SERVICE_ACCEPT[ssh-userauth]"
2017-10-17 12:30:26 VShellSSH2 auth 167 - - xdomainx\xusernamex - - 0 0 0 0 - - "00167: Client specified user name xusernamex, resolved as xdomainx\xusernamex"
2017-10-17 12:30:26 VShellSSH2 auth 167 10.1.19.239 50066 xdomainx\xusernamex - - 0 0 0 0 - - "00167: none for user xdomainx\xusernamex rejected because it is unavailable"
2017-10-17 12:30:26 VShellSSH2 auth 167 10.1.19.239 50066 xdomainx\xusernamex - - 0 0 0 0 - - "00167: password for user xdomainx\xusernamex accepted"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV: CHANNEL_OPEN[session]"
2017-10-17 12:30:26 VShellSSH2 conn 167 10.1.19.239 50066 xdomainx\xusernamex - - 0 0 0 0 - - "00167: Session channel open request accepted"
2017-10-17 12:30:26 VShellSSH2 conn 167 10.1.19.239 50066 xdomainx\xusernamex - - 0 0 0 0 - - "00167: Received request to start subsystem sftp (Built-in Subsystem)"
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xusernamex - - 0 0 0 0 10.1.17.157 22 "00167: SFTP subsystem initialized; remote version is 3"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - xdomainx\xusernamex - - 0 0 0 0 - - "00167: Queued worker thread to load user environment"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: Worker thread starting user environment load. User name=xusernamex Logon Server=USWDCS002 Profile Path=''"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: Worker thread finished user environment load"
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xusernamex - - 0 0 0 0 10.1.17.157 22 "00167: Sending VERSION packet to remote (3)"
2017-10-17 12:30:26 VShellSSH2 auth 167 - - xdomainx\xusernamex - - 0 0 0 0 - - "00167: Using home directory 'D:\Transport\FSO_Test' (Alias: FSO_FTP_TEST) for user xdomainx\xusernamex"
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xusernamex - - 0 0 0 0 10.1.17.157 22 "00167: Failed to open '/GCHANDRI2017-10-17-12.30.21.236JRNL1_-_DSUN.txt': Access is denied."
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xusernamex - - 0 0 0 0 10.1.17.157 22 "00167: SFTP subsystem terminated"
2017-10-17 12:30:26 VShellSSH2 conn 167 10.1.19.239 50066 xdomainx\xusernamex - - 0 0 0 0 - - "00167: Session channel has been closed (pid: none)"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Changing state from STATE_CONNECTION to STATE_CLOSING"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV: Disconnect packet (reason: 11: Disconnected by application. Shutdown )"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Changing state from STATE_CLOSING to STATE_CLOSED"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] Connected for 0 seconds, 3370 bytes sent, 1553 bytes received"
2017-10-17 12:30:26 VShellSSH2 conn 167 - - - - - 0 0 0 0 - - "00167: The transport was aborted with a disconnect packet: Disconnected by application. Shutdown"
2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV: TCP/IP close"

Last edited by bgagnon; 10-17-2017 at 04:35 PM.
Reply With Quote
  #4  
Old 10-17-2017, 04:43 PM
bgagnon bgagnon is online now
VanDyke Technical Support
 
Join Date: Oct 2008
Posts: 3,181
Hi EricS,

As a note, that's not SecureFX's remote identifier.

2017-10-17 12:30:26 VShellSSH2 dbg 167 - - - - - 0 0 0 0 - - "00167: [LOCAL DEBUG] RECV : Remote Identifier = 'SSH-2.0-libssh2_1.1'"


What's happening is that the client, by prepending "/" to the filename is trying to access one level higher than their configured virtual root. The "/" virtual root is not usually a location you can write to in VShell.

2017-10-17 12:30:26 VShellSSH2 auth 167 - - xdomainx\xusernamex - - 0 0 0 0 - - "00167: Using home directory 'D:\Transport\FSO_Test' (Alias: FSO_FTP_TEST) for user xdomainx\xusernamex"
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xusernamex - - 0 0 0 0 10.1.17.157 22 "00167: Failed to open '/GCHANDRI2017-10-17-12.30.21.236JRNL1_-_DSUN.txt': Access is denied."

They would need to use either ./ (to specify home directory) or the configured alias name (/FSO_FTP_Test/Filename.txt).
__________________
Thanks,
--Brenda

VanDyke Software
Technical Support
support@vandyke.com
(505) 332-5730

Last edited by jdev; 10-17-2017 at 05:30 PM.
Reply With Quote
  #5  
Old 10-18-2017, 10:13 AM
EricS EricS is offline
Registered User
 
Join Date: Jun 2016
Posts: 10
Quote:
Originally Posted by bgagnon View Post
Hi EricS,

As a note, that's not SecureFX's remote identifier.
Thanks, turns out that run was sent from the PeopleSoft App.

Quote:
Originally Posted by bgagnon View Post
What's happening is that the client, by prepending "/" to the filename is trying to access one level higher than their configured virtual root. The "/" virtual root is not usually a location you can write to in VShell.

2017-10-17 12:30:26 VShellSSH2 auth 167 - - xdomainx\xusernamex - - 0 0 0 0 - - "00167: Using home directory 'D:\Transport\FSO_Test' (Alias: FSO_FTP_TEST) for user xdomainx\xusernamex"
2017-10-17 12:30:26 VShellSSH2 sftp 167 10.1.19.239 50066 xusernamex - - 0 0 0 0 10.1.17.157 22 "00167: Failed to open '/GCHANDRI2017-10-17-12.30.21.236JRNL1_-_DSUN.txt': Access is denied."

They would need to use either ./ (to specify home directory) or the configured alias name (/FSO_FTP_Test/Filename.txt).
Thanks, I'll relay that and see what we can get.

Eric
Reply With Quote
  #6  
Old 10-20-2017, 11:53 AM
EricS EricS is offline
Registered User
 
Join Date: Jun 2016
Posts: 10
All good.

That was the issue, thanks for your help.

Eric
Reply With Quote
  #7  
Old 10-20-2017, 12:44 PM
bgagnon bgagnon is online now
VanDyke Technical Support
 
Join Date: Oct 2008
Posts: 3,181
Hi Eric,

Thanks for posting the update! Have a great weekend!
__________________
Thanks,
--Brenda

VanDyke Software
Technical Support
support@vandyke.com
(505) 332-5730
Reply With Quote
Reply


Currently Active Users Viewing This Thread: 1 (0 members and 1 guests)
 
Thread Tools
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off

Forum Jump


All times are GMT -6. The time now is 02:37 PM.