SFTP with Public/Private Key pair failing with Authentication type 16 error - VisualCron - Forum

Community forum

beechc
2014-06-11T13:55:14Z
I am having a recurring issue with an Authentication type 16 failed error when using VisualCron (7.17) to push a file to a remote server. I am able to connect with no issue using Filezilla and the same key combination without reporting any errors.

The connection uses a public/private key combination for authentication and successfully connects; receiving the remote fingerprint and then reporting "Authentication succeeded". I saw a couple of old threads on the same topic (v5 and v6), but no resolution on them. Hoping reopening this topic may help.

After connecting even with the error I am able to push a file successfully, and remotely delete it from the server. Making me think it is a false error of some sort in VC. I get the same reported issue in VC Explorer when connecting to the server.

My previous look through the threads indicate it is a keyboard authentication issue, but changing the encoding setting does nothing to resolve. Another search indicated the following "Unknown principal - A principal referenced by the request (either the owner, group, or who field of an ACL), was unknown."

Below is the log result of the transaction manually invoked to connect and push a small txt file to the remote server.

6/11/2014 9:35:17 AM Info Job started: CIBC Test Connectivity [DEV]
6/11/2014 9:35:17 AM Debug Job (185) was added to processlist: CIBC Test Connectivity [DEV]
6/11/2014 9:35:17 AM Info User 'VisualCron Default Admin' - Ran Job: CIBC Test Connectivity [DEV]
6/11/2014 9:35:17 AM Debug SendJobStats->Ended (6/11/2014 9:35:17 AM)
6/11/2014 9:35:17 AM Info Skipping Condition check because the Job was run manually.
6/11/2014 9:35:17 AM Debug Next action: ActionContinue
6/11/2014 9:35:17 AM Debug Calling GetNextTaskProcess()
6/11/2014 9:35:17 AM Debug Next Task is: FTP/FTPS/SFTP
6/11/2014 9:35:17 AM Debug Next action: ActionContinue
6/11/2014 9:35:17 AM Debug Calling StartTaskProcess() with Task: FTP/FTPS/SFTP (0)
6/11/2014 9:35:17 AM Debug JobProcessClass->Run2->Before enter (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug JobProcessClass->Run2->Entering (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug JobProcessClass->Run2->Exiting (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug Task (57076) was added to processlist: FTP/FTPS/SFTP
6/11/2014 9:35:17 AM Info Task started: FTP/FTPS/SFTP (57076)
6/11/2014 9:35:17 AM Debug JobProcessClass->TaskProcessStarted->Before enter LockWaitQueue (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug JobProcessClass->TaskProcessStarted->Entering LockWaitQueue (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug JobProcessClass->TaskProcessStarted->Exiting LockWaitQueue (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug JobProcessClass->TaskProcessStarted->Before enter LockWaitQueue (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug JobProcessClass->TaskProcessStarted->Entering LockWaitQueue (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug JobProcessClass->TaskProcessStarted->Exiting LockWaitQueue (FTP/FTPS/SFTP)
6/11/2014 9:35:17 AM Debug Entering wait loop. FTP/FTPS/SFTP (57076)
6/11/2014 9:35:17 AM Debug FTP Command Count: 1
6/11/2014 9:35:17 AM Debug Starting FTP command: 1 of 1
6/11/2014 9:35:17 AM Debug Connect->Start (SFTP (SSH - Secure Shell) - CIBC [DEV] [wmt-bt-dul-ibm@ssh.dev.efts.cibc.ca:22])
6/11/2014 9:35:17 AM Debug SetAuthentication->Start (SFTP (SSH - Secure Shell) - CIBC [DEV] [wmt-bt-dul-ibm@ssh.dev.efts.cibc.ca:22])
6/11/2014 9:35:17 AM Debug SetAuthentication->PrivateKeyPath: C:\VisualCron\CIBC\Keys\doculink_cibc_private.ppk (SFTP (SSH - Secure Shell) - CIBC [DEV] [wmt-bt-dul-ibm@ssh.dev.efts.cibc.ca:22])
6/11/2014 9:35:17 AM Debug SetAuthentication->PrivateKeyPath exists (SFTP (SSH - Secure Shell) - CIBC [DEV] [wmt-bt-dul-ibm@ssh.dev.efts.cibc.ca:22])
6/11/2014 9:35:17 AM Debug Connect->Before open (SFTP (SSH - Secure Shell) - CIBC [DEV] [wmt-bt-dul-ibm@ssh.dev.efts.cibc.ca:22])
6/11/2014 9:35:18 AM Debug SFTP_OnAuthenticationKeyboard
6/11/2014 9:35:24 AM Debug Connect->After open (SFTP (SSH - Secure Shell) - CIBC [DEV] [wmt-bt-dul-ibm@ssh.dev.efts.cibc.ca:22])
6/11/2014 9:35:24 AM Debug Destination folder: /CONF_MF
6/11/2014 9:35:24 AM Debug Destination folder: /CONF_MF
6/11/2014 9:35:24 AM Debug DateCheck (C:\VisualCron\CIBC\UploadTest.txt), dteOlderThan: 0001-01-01 00:00:00, dteNewerThan: 0001-01-01 00:00:00, fi.LastWriteTime: 2014-05-16 10:41:20, fi.LastWriteTime.ToLocalTime: 2014-05-16 10:41:20
6/11/2014 9:35:24 AM Debug ActiveDestinationFolder: /CONF_MF
6/11/2014 9:35:25 AM Debug Commands done
6/11/2014 9:35:25 AM Debug Before dispose
6/11/2014 9:35:25 AM Debug Disposing timer
6/11/2014 9:35:25 AM Debug Trying to disconnect
6/11/2014 9:35:25 AM Debug Stopping watch
6/11/2014 9:35:25 AM Debug Before GetOutput
6/11/2014 9:35:25 AM Debug Before RaiseTaskCompleted
6/11/2014 9:35:25 AM Info Task completed: FTP/FTPS/SFTP (57076)
6/11/2014 9:35:25 AM Debug JobProcessClass->TaskProcessCompleted->Before enter (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug JobProcessClass->TaskProcessCompleted->Entering (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug JobProcessClass->TaskProcessCompleted->Exiting (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug JobProcessClass->WaitForJobsToComplete->Before enter LockWaitQueue
6/11/2014 9:35:25 AM Debug JobProcessClass->WaitForJobsToComplete->Entering LockWaitQueue
6/11/2014 9:35:25 AM Debug JobProcessClass->WaitForJobsToComplete->Exiting LockWaitQueue
6/11/2014 9:35:25 AM Debug JobProcessClass->TaskProcessCompleted->Before enter (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug JobProcessClass->TaskProcessCompleted->Entering (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug Setting previous task in TaskProcessCompleted: FTP/FTPS/SFTP (99384a87-7a26-4445-b878-280ae9f42a7e) in job: CIBC Test Connectivity [DEV]
6/11/2014 9:35:25 AM Debug Process status - About to SendTaskProcess (57076)
6/11/2014 9:35:25 AM Debug Sleep ended because Task ended.FTP/FTPS/SFTP (57076)
6/11/2014 9:35:25 AM Debug JobProcessClass->Run->Before enter (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug Process status - About to RemoveTaskProcess (57076)
6/11/2014 9:35:25 AM Debug RemoveTaskProcess->Task (57076) was removed from processlist: FTP/FTPS/SFTP
6/11/2014 9:35:25 AM Debug JobProcessClass->Run->Entering (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug JobProcessClass->TaskProcessCompleted->Exiting (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug JobProcessClass->Run->Exiting (FTP/FTPS/SFTP)
6/11/2014 9:35:25 AM Debug JobProcessClass->WaitForJobsToComplete->Before enter LockWaitQueue
6/11/2014 9:35:25 AM Debug TaskWaitQueue.Dequeued.FTP/FTPS/SFTP (57076)
6/11/2014 9:35:25 AM Debug JobProcessClass->WaitForJobsToComplete->Entering LockWaitQueue
6/11/2014 9:35:25 AM Debug JobProcessClass->WaitForJobsToComplete->Exiting LockWaitQueue
6/11/2014 9:35:25 AM Debug PrevTaskProcess(FTP/FTPS/SFTP)->ExitCodeResult: Failure (ECCId: 746c95ce-d394-491c-925c-8bd50e4daa8ePId: 57076, Exit code: 77777)
6/11/2014 9:35:25 AM Debug Found 1 matching flows. (57076)
6/11/2014 9:35:25 AM Debug WaitingForTasks=false, Job 'CIBC Test Connectivity [DEV]'
6/11/2014 9:35:25 AM Debug End of loop - iterating again.FTP/FTPS/SFTP (57076)
6/11/2014 9:35:25 AM Debug Job (185) was removed from processlist: CIBC Test Connectivity [DEV]

Any help or guidance would be appreciated.



bbusse
2014-06-11T16:04:33Z
Do you also own the SFTP server, or is it from a 3rd party?

I'm curious, because I always try to troubleshoot based on knowing what exact products are involved. What SFTP server software is being used on the other end that VC is connecting to, what version, etc...

This shouldn't matter, but i've ran into issues with some slightly altered OpenSSL standards like that of WS_FTP Server, they implement some custom options that cause issues with some SFTP clients on linux. So knowing the product involved is crucial to troubleshooting.

Brian
beechc
2014-06-12T14:18:58Z
I am awaiting the information from the third party. Unfortunately it isn't my server.
KJDavie
2014-06-16T22:01:24Z
Hi we used to get this error from our Banks SFTP Site (as recently as February. They have it fixed at the moment (probably a timing issue 😉 ).

Annoying as it is really a warning (still *works*)

It is a topic to try to influence with the SFTP host, but isn't always easy to get them to fix / move.

We have had to change our error handling in VisualCron

Screen Prints from Feb Attached.
KJDavie attached the following image(s):
Support
2014-06-17T08:18:23Z
Uncheck "Auto authentication" and uncheck "Keyboard authentication".
Henrik
Support
http://www.visualcron.com 
Please like  VisualCron on facebook!
beechc
2014-08-06T11:33:16Z
Thank you changing these settings has resolved the error being reported on connection.
Scroll to Top