[
https://issues.apache.org/jira/browse/VFS-766?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Jasper Teng updated VFS-766:
----------------------------
Affects Version/s: 2.6.0
Description:
Issue: When trying to sftp, it hangs inside FileSystemManager.resolveFile(...).
Libs in classpath used for testing:
* commons-vfs2-2.6.0.jar / commons-vfs2-2.5.0.jar
* commons-vfs2-jackrabbit2-2.5.0.jar
* jackrabbit-webdav-2.20.0.jar
Issue Log file (2.5.0):
{noformat}
25 Mar, 20:00:37,825 INFO main [SftpClientFactory$JSchLogger.log()] [65017ms]
Connection established
25 Mar, 20:00:38,013 INFO main [SftpClientFactory$JSchLogger.log()] [65205ms]
Remote version string: SSH-2.0-ProVide
25 Mar, 20:00:38,017 INFO main [SftpClientFactory$JSchLogger.log()] [65209ms]
Local version string: SSH-2.0-JSCH-0.1.52
...snip...
25 Mar, 20:01:02,802 INFO main [SftpClientFactory$JSchLogger.log()] [89994ms]
kex: server->client aes128-ctr hmac-md5 none
25 Mar, 20:01:02,809 INFO main [SftpClientFactory$JSchLogger.log()] [90001ms]
kex: client->server aes128-ctr hmac-md5 none
25 Mar, 20:01:06,359 INFO main [SftpClientFactory$JSchLogger.log()] [93551ms]
SSH_MSG_KEXDH_INIT sent
25 Mar, 20:01:06,363 INFO main [SftpClientFactory$JSchLogger.log()] [93555ms]
expecting SSH_MSG_KEXDH_REPLY
25 Mar, 20:01:10,410 INFO main [SftpClientFactory$JSchLogger.log()] [97602ms]
ssh_rsa_verify: signature true
25 Mar, 20:01:10,427 WARN main [SftpClientFactory$JSchLogger.log()] [97619ms]
Permanently added 'mask.mask.mask' (RSA) to the list of known hosts.
25 Mar, 20:01:10,438 INFO main [SftpClientFactory$JSchLogger.log()] [97630ms]
SSH_MSG_NEWKEYS sent
25 Mar, 20:01:10,625 INFO main [SftpClientFactory$JSchLogger.log()] [97817ms]
SSH_MSG_NEWKEYS received
25 Mar, 20:01:10,709 INFO main [SftpClientFactory$JSchLogger.log()] [97901ms]
SSH_MSG_SERVICE_REQUEST sent
25 Mar, 20:01:10,897 INFO main [SftpClientFactory$JSchLogger.log()] [98089ms]
SSH_MSG_SERVICE_ACCEPT received
25 Mar, 20:01:11,098 INFO main [SftpClientFactory$JSchLogger.log()] [98290ms]
Authentications that can continue: publickey,keyboard-interactive,password
25 Mar, 20:01:11,102 INFO main [SftpClientFactory$JSchLogger.log()] [98294ms]
Next authentication method: publickey
25 Mar, 20:01:11,114 INFO main [SftpClientFactory$JSchLogger.log()] [98306ms]
Authentications that can continue: password
25 Mar, 20:01:11,119 INFO main [SftpClientFactory$JSchLogger.log()] [98311ms]
Next authentication method: password
25 Mar, 20:01:11,735 INFO main [SftpClientFactory$JSchLogger.log()] [98927ms]
Authentication succeeded (password).{noformat}
Issue Log file (2.6.0):
{noformat}
26 Mar, 09:42:07,781 INFO main [SftpClientFactory$JSchLogger.log()] [20400ms]
Connection established
26 Mar, 09:42:07,971 INFO main [SftpClientFactory$JSchLogger.log()] [20590ms]
Remote version string: SSH-2.0-ProVide
26 Mar, 09:42:07,975 INFO main [SftpClientFactory$JSchLogger.log()] [20594ms]
Local version string: SSH-2.0-JSCH-0.1.52 ...snip...26 Mar, 09:42:33,250 INFO
main [SftpClientFactory$JSchLogger.log()] [45869ms] kex: server->client
aes128-ctr hmac-md5 none
26 Mar, 09:42:33,258 INFO main [SftpClientFactory$JSchLogger.log()] [45877ms]
kex: client->server aes128-ctr hmac-md5 none
26 Mar, 09:42:36,710 INFO main [SftpClientFactory$JSchLogger.log()] [49329ms]
SSH_MSG_KEXDH_INIT sent
26 Mar, 09:42:36,716 INFO main [SftpClientFactory$JSchLogger.log()] [49335ms]
expecting SSH_MSG_KEXDH_REPLY
26 Mar, 09:42:40,635 INFO main [SftpClientFactory$JSchLogger.log()] [53254ms]
ssh_rsa_verify: signature true
26 Mar, 09:42:40,653 INFO main [SftpClientFactory$JSchLogger.log()] [53272ms]
Host 'mask.mask.mask' is known and matches the RSA host key
26 Mar, 09:42:40,660 INFO main [SftpClientFactory$JSchLogger.log()] [53279ms]
SSH_MSG_NEWKEYS sent
26 Mar, 09:42:40,845 INFO main [SftpClientFactory$JSchLogger.log()] [53464ms]
SSH_MSG_NEWKEYS received
26 Mar, 09:42:40,953 INFO main [SftpClientFactory$JSchLogger.log()] [53572ms]
SSH_MSG_SERVICE_REQUEST sent
26 Mar, 09:42:41,153 INFO main [SftpClientFactory$JSchLogger.log()] [53772ms]
SSH_MSG_SERVICE_ACCEPT received
26 Mar, 09:42:41,356 INFO main [SftpClientFactory$JSchLogger.log()] [53975ms]
Authentications that can continue: publickey,keyboard-interactive,password
26 Mar, 09:42:41,359 INFO main [SftpClientFactory$JSchLogger.log()] [53978ms]
Next authentication method: publickey
26 Mar, 09:42:41,370 INFO main [SftpClientFactory$JSchLogger.log()] [53989ms]
Authentications that can continue: password
26 Mar, 09:42:41,374 INFO main [SftpClientFactory$JSchLogger.log()] [53993ms]
Next authentication method: password
26 Mar, 09:42:42,388 INFO main [SftpClientFactory$JSchLogger.log()] [55007ms]
Authentication succeeded (password).
{noformat}
Additional Important Notes:
* commons-vfs2-2.4.1.jar works
* issues can only be reproduced on certain sftp servers
Non issue log file (2.6.0):
{noformat}
26 Mar, 09:47:39,035 INFO main [SftpClientFactory$JSchLogger.log()] [1778ms]
Connection established
26 Mar, 09:47:39,045 INFO main [SftpClientFactory$JSchLogger.log()] [1788ms]
Remote version string: SSH-2.0-OpenSSH_6.2
26 Mar, 09:47:39,045 INFO main [SftpClientFactory$JSchLogger.log()] [1788ms]
Local version string: SSH-2.0-JSCH-0.1.52
...snip...
26 Mar, 09:47:41,603 INFO main [SftpClientFactory$JSchLogger.log()] [4346ms]
kex: server->client aes128-ctr hmac-md5 none
26 Mar, 09:47:41,604 INFO main [SftpClientFactory$JSchLogger.log()] [4347ms]
kex: client->server aes128-ctr hmac-md5 none
26 Mar, 09:47:41,607 INFO main [SftpClientFactory$JSchLogger.log()] [4350ms]
SSH_MSG_KEXDH_INIT sent
26 Mar, 09:47:41,607 INFO main [SftpClientFactory$JSchLogger.log()] [4350ms]
expecting SSH_MSG_KEXDH_REPLY
26 Mar, 09:47:41,615 INFO main [SftpClientFactory$JSchLogger.log()] [4358ms]
ssh_rsa_verify: signature true
26 Mar, 09:47:41,616 INFO main [SftpClientFactory$JSchLogger.log()] [4359ms]
Host 'mask.mask.mask' is known and matches the RSA host key
26 Mar, 09:47:41,616 INFO main [SftpClientFactory$JSchLogger.log()] [4359ms]
SSH_MSG_NEWKEYS sent
26 Mar, 09:47:41,616 INFO main [SftpClientFactory$JSchLogger.log()] [4359ms]
SSH_MSG_NEWKEYS received
26 Mar, 09:47:41,621 INFO main [SftpClientFactory$JSchLogger.log()] [4364ms]
SSH_MSG_SERVICE_REQUEST sent
26 Mar, 09:47:41,621 INFO main [SftpClientFactory$JSchLogger.log()] [4364ms]
SSH_MSG_SERVICE_ACCEPT received
26 Mar, 09:47:41,626 INFO main [SftpClientFactory$JSchLogger.log()] [4369ms]
Authentications that can continue: publickey,keyboard-interactive,password
26 Mar, 09:47:41,626 INFO main [SftpClientFactory$JSchLogger.log()] [4369ms]
Next authentication method: publickey
26 Mar, 09:47:41,627 INFO main [SftpClientFactory$JSchLogger.log()] [4370ms]
Authentications that can continue: keyboard-interactive,password
26 Mar, 09:47:41,627 INFO main [SftpClientFactory$JSchLogger.log()] [4370ms]
Next authentication method: keyboard-interactive
26 Mar, 09:47:41,635 INFO main [SftpClientFactory$JSchLogger.log()] [4378ms]
Authentication succeeded (keyboard-interactive).{noformat}
was:
Issue: When trying to sftp, it hangs inside FileSystemManager.resolveFile(...).
Libs in classpath:
* commons-vfs2-2.5.0.jar
* commons-vfs2-jackrabbit2-2.5.0.jar
* jackrabbit-webdav-2.20.0.jar
Log file:
{noformat}
25 Mar, 20:00:37,825 INFO main [SftpClientFactory$JSchLogger.log()] [65017ms]
Connection established
25 Mar, 20:00:38,013 INFO main [SftpClientFactory$JSchLogger.log()] [65205ms]
Remote version string: SSH-2.0-ProVide
25 Mar, 20:00:38,017 INFO main [SftpClientFactory$JSchLogger.log()] [65209ms]
Local version string: SSH-2.0-JSCH-0.1.52
...snip...
25 Mar, 20:01:02,802 INFO main [SftpClientFactory$JSchLogger.log()] [89994ms]
kex: server->client aes128-ctr hmac-md5 none
25 Mar, 20:01:02,809 INFO main [SftpClientFactory$JSchLogger.log()] [90001ms]
kex: client->server aes128-ctr hmac-md5 none
25 Mar, 20:01:06,359 INFO main [SftpClientFactory$JSchLogger.log()] [93551ms]
SSH_MSG_KEXDH_INIT sent
25 Mar, 20:01:06,363 INFO main [SftpClientFactory$JSchLogger.log()] [93555ms]
expecting SSH_MSG_KEXDH_REPLY
25 Mar, 20:01:10,410 INFO main [SftpClientFactory$JSchLogger.log()] [97602ms]
ssh_rsa_verify: signature true
25 Mar, 20:01:10,427 WARN main [SftpClientFactory$JSchLogger.log()] [97619ms]
Permanently added 'mask.mask.mask' (RSA) to the list of known hosts.
25 Mar, 20:01:10,438 INFO main [SftpClientFactory$JSchLogger.log()] [97630ms]
SSH_MSG_NEWKEYS sent
25 Mar, 20:01:10,625 INFO main [SftpClientFactory$JSchLogger.log()] [97817ms]
SSH_MSG_NEWKEYS received
25 Mar, 20:01:10,709 INFO main [SftpClientFactory$JSchLogger.log()] [97901ms]
SSH_MSG_SERVICE_REQUEST sent
25 Mar, 20:01:10,897 INFO main [SftpClientFactory$JSchLogger.log()] [98089ms]
SSH_MSG_SERVICE_ACCEPT received
25 Mar, 20:01:11,098 INFO main [SftpClientFactory$JSchLogger.log()] [98290ms]
Authentications that can continue: publickey,keyboard-interactive,password
25 Mar, 20:01:11,102 INFO main [SftpClientFactory$JSchLogger.log()] [98294ms]
Next authentication method: publickey
25 Mar, 20:01:11,114 INFO main [SftpClientFactory$JSchLogger.log()] [98306ms]
Authentications that can continue: password
25 Mar, 20:01:11,119 INFO main [SftpClientFactory$JSchLogger.log()] [98311ms]
Next authentication method: password
25 Mar, 20:01:11,735 INFO main [SftpClientFactory$JSchLogger.log()] [98927ms]
Authentication succeeded (password).{noformat}
> SftpClientFactory hangs at FileSystemManager.resolveFile(...)
> -------------------------------------------------------------
>
> Key: VFS-766
> URL: https://issues.apache.org/jira/browse/VFS-766
> Project: Commons VFS
> Issue Type: Bug
> Affects Versions: 2.5.0, 2.6.0
> Reporter: Jasper Teng
> Priority: Critical
>
> Issue: When trying to sftp, it hangs inside
> FileSystemManager.resolveFile(...).
>
> Libs in classpath used for testing:
> * commons-vfs2-2.6.0.jar / commons-vfs2-2.5.0.jar
> * commons-vfs2-jackrabbit2-2.5.0.jar
> * jackrabbit-webdav-2.20.0.jar
>
> Issue Log file (2.5.0):
> {noformat}
> 25 Mar, 20:00:37,825 INFO main [SftpClientFactory$JSchLogger.log()]
> [65017ms] Connection established
> 25 Mar, 20:00:38,013 INFO main [SftpClientFactory$JSchLogger.log()]
> [65205ms] Remote version string: SSH-2.0-ProVide
> 25 Mar, 20:00:38,017 INFO main [SftpClientFactory$JSchLogger.log()]
> [65209ms] Local version string: SSH-2.0-JSCH-0.1.52
> ...snip...
> 25 Mar, 20:01:02,802 INFO main [SftpClientFactory$JSchLogger.log()]
> [89994ms] kex: server->client aes128-ctr hmac-md5 none
> 25 Mar, 20:01:02,809 INFO main [SftpClientFactory$JSchLogger.log()]
> [90001ms] kex: client->server aes128-ctr hmac-md5 none
> 25 Mar, 20:01:06,359 INFO main [SftpClientFactory$JSchLogger.log()]
> [93551ms] SSH_MSG_KEXDH_INIT sent
> 25 Mar, 20:01:06,363 INFO main [SftpClientFactory$JSchLogger.log()]
> [93555ms] expecting SSH_MSG_KEXDH_REPLY
> 25 Mar, 20:01:10,410 INFO main [SftpClientFactory$JSchLogger.log()]
> [97602ms] ssh_rsa_verify: signature true
> 25 Mar, 20:01:10,427 WARN main [SftpClientFactory$JSchLogger.log()]
> [97619ms] Permanently added 'mask.mask.mask' (RSA) to the list of known hosts.
> 25 Mar, 20:01:10,438 INFO main [SftpClientFactory$JSchLogger.log()]
> [97630ms] SSH_MSG_NEWKEYS sent
> 25 Mar, 20:01:10,625 INFO main [SftpClientFactory$JSchLogger.log()]
> [97817ms] SSH_MSG_NEWKEYS received
> 25 Mar, 20:01:10,709 INFO main [SftpClientFactory$JSchLogger.log()]
> [97901ms] SSH_MSG_SERVICE_REQUEST sent
> 25 Mar, 20:01:10,897 INFO main [SftpClientFactory$JSchLogger.log()]
> [98089ms] SSH_MSG_SERVICE_ACCEPT received
> 25 Mar, 20:01:11,098 INFO main [SftpClientFactory$JSchLogger.log()]
> [98290ms] Authentications that can continue:
> publickey,keyboard-interactive,password
> 25 Mar, 20:01:11,102 INFO main [SftpClientFactory$JSchLogger.log()]
> [98294ms] Next authentication method: publickey
> 25 Mar, 20:01:11,114 INFO main [SftpClientFactory$JSchLogger.log()]
> [98306ms] Authentications that can continue: password
> 25 Mar, 20:01:11,119 INFO main [SftpClientFactory$JSchLogger.log()]
> [98311ms] Next authentication method: password
> 25 Mar, 20:01:11,735 INFO main [SftpClientFactory$JSchLogger.log()]
> [98927ms] Authentication succeeded (password).{noformat}
>
> Issue Log file (2.6.0):
> {noformat}
> 26 Mar, 09:42:07,781 INFO main [SftpClientFactory$JSchLogger.log()]
> [20400ms] Connection established
> 26 Mar, 09:42:07,971 INFO main [SftpClientFactory$JSchLogger.log()]
> [20590ms] Remote version string: SSH-2.0-ProVide
> 26 Mar, 09:42:07,975 INFO main [SftpClientFactory$JSchLogger.log()]
> [20594ms] Local version string: SSH-2.0-JSCH-0.1.52 ...snip...26 Mar,
> 09:42:33,250 INFO main [SftpClientFactory$JSchLogger.log()] [45869ms] kex:
> server->client aes128-ctr hmac-md5 none
> 26 Mar, 09:42:33,258 INFO main [SftpClientFactory$JSchLogger.log()]
> [45877ms] kex: client->server aes128-ctr hmac-md5 none
> 26 Mar, 09:42:36,710 INFO main [SftpClientFactory$JSchLogger.log()]
> [49329ms] SSH_MSG_KEXDH_INIT sent
> 26 Mar, 09:42:36,716 INFO main [SftpClientFactory$JSchLogger.log()]
> [49335ms] expecting SSH_MSG_KEXDH_REPLY
> 26 Mar, 09:42:40,635 INFO main [SftpClientFactory$JSchLogger.log()]
> [53254ms] ssh_rsa_verify: signature true
> 26 Mar, 09:42:40,653 INFO main [SftpClientFactory$JSchLogger.log()]
> [53272ms] Host 'mask.mask.mask' is known and matches the RSA host key
> 26 Mar, 09:42:40,660 INFO main [SftpClientFactory$JSchLogger.log()]
> [53279ms] SSH_MSG_NEWKEYS sent
> 26 Mar, 09:42:40,845 INFO main [SftpClientFactory$JSchLogger.log()]
> [53464ms] SSH_MSG_NEWKEYS received
> 26 Mar, 09:42:40,953 INFO main [SftpClientFactory$JSchLogger.log()]
> [53572ms] SSH_MSG_SERVICE_REQUEST sent
> 26 Mar, 09:42:41,153 INFO main [SftpClientFactory$JSchLogger.log()]
> [53772ms] SSH_MSG_SERVICE_ACCEPT received
> 26 Mar, 09:42:41,356 INFO main [SftpClientFactory$JSchLogger.log()]
> [53975ms] Authentications that can continue:
> publickey,keyboard-interactive,password
> 26 Mar, 09:42:41,359 INFO main [SftpClientFactory$JSchLogger.log()]
> [53978ms] Next authentication method: publickey
> 26 Mar, 09:42:41,370 INFO main [SftpClientFactory$JSchLogger.log()]
> [53989ms] Authentications that can continue: password
> 26 Mar, 09:42:41,374 INFO main [SftpClientFactory$JSchLogger.log()]
> [53993ms] Next authentication method: password
> 26 Mar, 09:42:42,388 INFO main [SftpClientFactory$JSchLogger.log()]
> [55007ms] Authentication succeeded (password).
> {noformat}
>
> Additional Important Notes:
> * commons-vfs2-2.4.1.jar works
> * issues can only be reproduced on certain sftp servers
>
> Non issue log file (2.6.0):
>
> {noformat}
> 26 Mar, 09:47:39,035 INFO main [SftpClientFactory$JSchLogger.log()] [1778ms]
> Connection established
> 26 Mar, 09:47:39,045 INFO main [SftpClientFactory$JSchLogger.log()] [1788ms]
> Remote version string: SSH-2.0-OpenSSH_6.2
> 26 Mar, 09:47:39,045 INFO main [SftpClientFactory$JSchLogger.log()] [1788ms]
> Local version string: SSH-2.0-JSCH-0.1.52
> ...snip...
> 26 Mar, 09:47:41,603 INFO main [SftpClientFactory$JSchLogger.log()] [4346ms]
> kex: server->client aes128-ctr hmac-md5 none
> 26 Mar, 09:47:41,604 INFO main [SftpClientFactory$JSchLogger.log()] [4347ms]
> kex: client->server aes128-ctr hmac-md5 none
> 26 Mar, 09:47:41,607 INFO main [SftpClientFactory$JSchLogger.log()] [4350ms]
> SSH_MSG_KEXDH_INIT sent
> 26 Mar, 09:47:41,607 INFO main [SftpClientFactory$JSchLogger.log()] [4350ms]
> expecting SSH_MSG_KEXDH_REPLY
> 26 Mar, 09:47:41,615 INFO main [SftpClientFactory$JSchLogger.log()] [4358ms]
> ssh_rsa_verify: signature true
> 26 Mar, 09:47:41,616 INFO main [SftpClientFactory$JSchLogger.log()] [4359ms]
> Host 'mask.mask.mask' is known and matches the RSA host key
> 26 Mar, 09:47:41,616 INFO main [SftpClientFactory$JSchLogger.log()] [4359ms]
> SSH_MSG_NEWKEYS sent
> 26 Mar, 09:47:41,616 INFO main [SftpClientFactory$JSchLogger.log()] [4359ms]
> SSH_MSG_NEWKEYS received
> 26 Mar, 09:47:41,621 INFO main [SftpClientFactory$JSchLogger.log()] [4364ms]
> SSH_MSG_SERVICE_REQUEST sent
> 26 Mar, 09:47:41,621 INFO main [SftpClientFactory$JSchLogger.log()] [4364ms]
> SSH_MSG_SERVICE_ACCEPT received
> 26 Mar, 09:47:41,626 INFO main [SftpClientFactory$JSchLogger.log()] [4369ms]
> Authentications that can continue: publickey,keyboard-interactive,password
> 26 Mar, 09:47:41,626 INFO main [SftpClientFactory$JSchLogger.log()] [4369ms]
> Next authentication method: publickey
> 26 Mar, 09:47:41,627 INFO main [SftpClientFactory$JSchLogger.log()] [4370ms]
> Authentications that can continue: keyboard-interactive,password
> 26 Mar, 09:47:41,627 INFO main [SftpClientFactory$JSchLogger.log()] [4370ms]
> Next authentication method: keyboard-interactive
> 26 Mar, 09:47:41,635 INFO main [SftpClientFactory$JSchLogger.log()] [4378ms]
> Authentication succeeded (keyboard-interactive).{noformat}
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
