You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@camel.apache.org by "George Daswani (JIRA)" <ji...@apache.org> on 2015/10/13 20:52:05 UTC
[jira] [Commented] (CAMEL-9218) FTP2 - SFTP stops polling when it
encounters an error
[ https://issues.apache.org/jira/browse/CAMEL-9218?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14955460#comment-14955460 ]
George Daswani commented on CAMEL-9218:
---------------------------------------
1) SERVICEMIX LOG of ORIGINAL
2015-10-10 04:14:30,512 | WARN | tns-prod.appl.test.org/request_out | SftpConsumer | 141 - org.apache.camel.camel-core - 2.15.2 | Consumer Consumer[sftp://tns-prod.appl.test.org/request_out?antInclude=*.xml%2C*.XML%3B&binary=true&ciphers=aes128-ctr&consumer.delay=60000&disconnect=false&ignoreFileNotFoundOrPermissionError=true&localWorkDirectory=E%3A%5Cservices%5Cam%5Cdata%5Ceds%5Cdownload&maximumReconnectAttempts=0&move=done&preferredAuthentications=publickey&privateKeyFile=E%3A%5CGateways%5CSecurity%5CKeys%5CAM_IDM_OIM-PrivKey.openssh&reconnectDelay=27000&username=ess_am] failed polling endpoint: Endpoint[sftp://tns-prod.appl.test.org/request_out?antInclude=*.xml%2C*.XML%3B&binary=true&ciphers=aes128-ctr&consumer.delay=60000&disconnect=false&ignoreFileNotFoundOrPermissionError=true&localWorkDirectory=E%3A%5Cservices%5Cam%5Cdata%5Ceds%5Cdownload&maximumReconnectAttempts=0&move=done&preferredAuthentications=publickey&privateKeyFile=E%3A%5CGateways%5CSecurity%5CKeys%5CAM_IDM_OIM-PrivKey.openssh&reconnectDelay=27000&username=ess_am]. Will try again at next poll. Caused by: [org.apache.camel.component.file.GenericFileOperationFailedException - Cannot change directory to: request_out]
org.apache.camel.component.file.GenericFileOperationFailedException: Cannot change directory to: request_out
at org.apache.camel.component.file.remote.SftpOperations.doChangeDirectory(SftpOperations.java:542)[246:org.apache.camel.camel-ftp:2.15.2]
at org.apache.camel.component.file.remote.SftpOperations.changeCurrentDirectory(SftpOperations.java:530)[246:org.apache.camel.camel-ftp:2.15.2]
at org.apache.camel.component.file.remote.SftpConsumer.doPollDirectory(SftpConsumer.java:80)[246:org.apache.camel.camel-ftp:2.15.2]
at org.apache.camel.component.file.remote.SftpConsumer.pollDirectory(SftpConsumer.java:52)[246:org.apache.camel.camel-ftp:2.15.2]
at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:119)[141:org.apache.camel.camel-core:2.15.2]
at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)[141:org.apache.camel.camel-core:2.15.2]
at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)[141:org.apache.camel.camel-core:2.15.2]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_51]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)[:1.8.0_51]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)[:1.8.0_51]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)[:1.8.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_51]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_51]
Caused by: 4:
at com.jcraft.jsch.ChannelSftp.cd(ChannelSftp.java:359)[245:org.apache.servicemix.bundles.jsch:0.1.51.1]
at org.apache.camel.component.file.remote.SftpOperations.doChangeDirectory(SftpOperations.java:540)[246:org.apache.camel.camel-ftp:2.15.2]
... 13 more
Caused by: java.io.IOException: inputstream is closed
at com.jcraft.jsch.ChannelSftp.fill(ChannelSftp.java:2884)[245:org.apache.servicemix.bundles.jsch:0.1.51.1]
at com.jcraft.jsch.ChannelSftp.header(ChannelSftp.java:2908)[245:org.apache.servicemix.bundles.jsch:0.1.51.1]
at com.jcraft.jsch.ChannelSftp._realpath(ChannelSftp.java:2328)[245:org.apache.servicemix.bundles.jsch:0.1.51.1]
at com.jcraft.jsch.ChannelSftp.cd(ChannelSftp.java:342)[245:org.apache.servicemix.bundles.jsch:0.1.51.1]
... 14 more
2) CONSUMER LOOKS LIKE IT AUTOMATICALLY RECONNECTS but it doesn't actually poll for files anymore
2015-10-10 04:15:30,558 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> Connecting to tns-prod.appl.test.org port 22
2015-10-10 04:15:30,589 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> Connection established
2015-10-10 04:15:30,605 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> Remote version string: SSH-2.0-OpenSSH_5.2p1_q16.g2731d16-hpn13v6
2015-10-10 04:15:30,605 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> Local version string: SSH-2.0-JSCH-0.1.51
2015-10-10 04:15:30,605 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256
2015-10-10 04:15:30,605 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> CheckKexes: diffie-hellman-group14-sha1
2015-10-10 04:15:30,714 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> SSH_MSG_KEXINIT sent
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> SSH_MSG_KEXINIT received
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server: gss-gex-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-group1-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-group14-sha1-toWM5Slw5Ew8Mqkay+al2g==,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server: ssh-rsa,ssh-dss
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server: none,zlib@openssh.com
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server: none,zlib@openssh.com
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server:
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server:
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client: diffie-hellman-group1-sha1,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha1
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client: ssh-rsa,ssh-dss
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client: aes128-ctr
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client: aes128-ctr
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client: none
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client: none
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client:
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client:
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: server->client aes128-ctr hmac-md5 none
2015-10-10 04:15:30,730 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> kex: client->server aes128-ctr hmac-md5 none
2015-10-10 04:15:30,745 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> SSH_MSG_KEXDH_INIT sent
2015-10-10 04:15:30,745 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> expecting SSH_MSG_KEXDH_REPLY
2015-10-10 04:15:30,792 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> ssh_rsa_verify: signature true
2015-10-10 04:15:30,792 | WARN | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> Permanently added 'tns-prod.appl.test.org' (RSA) to the list of known hosts.
2015-10-10 04:15:30,792 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> SSH_MSG_NEWKEYS sent
2015-10-10 04:15:30,792 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> SSH_MSG_NEWKEYS received
2015-10-10 04:15:30,792 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> SSH_MSG_SERVICE_REQUEST sent
2015-10-10 04:15:30,808 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> SSH_MSG_SERVICE_ACCEPT received
2015-10-10 04:15:31,027 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> Authentications that can continue: publickey
2015-10-10 04:15:31,027 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> Next authentication method: publickey
2015-10-10 04:15:31,933 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | JSCH -> Authentication succeeded (publickey).
2015-10-10 04:15:32,464 | INFO | tns-prod.appl.test.org/request_out | SftpOperations | 246 - org.apache.camel.camel-ftp - 2.15.2 | Connected to sftp://ess_am@tns-prod.appl.test.org:22
3) Even though BUNDLE is still started, we have to force it to RESTART in order for the CONSUMER to start producing files.
> FTP2 - SFTP stops polling when it encounters an error
> -----------------------------------------------------
>
> Key: CAMEL-9218
> URL: https://issues.apache.org/jira/browse/CAMEL-9218
> Project: Camel
> Issue Type: Bug
> Components: camel-ftp
> Affects Versions: 2.15.2
> Environment: Windows Server 2008 R2
> Java JDK 1.8.0_45
> Apache ServceMix 6.0
> Reporter: George Daswani
> Labels: sftp
>
> FTP2 - SFTP stops polling after it runs into an exception, even after reconnect.
> Sequence:
> 1) Camel gets an "inpustream is closed" exception
> 2) Camel SFTP consumer automatically reconnects
> 3) Even though it had reconnected, it stops polling for files
> 4) Even though bundle is in "start" state, we have to "restart" in order for Camel Route consumer to start polling again
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)