You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by "Goyal, Arpit" <ar...@sap.com> on 2016/10/16 19:54:50 UTC

[camel-ftp] Can't catch Invalid SFTP port exception

I am trying to handle all the exception use cases of SFTP for logging purposes. In case user has given invalid Port address for sftp server even when using pollStrategy attribute ->

1) We are not able to get the exception back in the code.
2) Exchange comes back null.
3) Associated below code to logger and see the exception logged though. (Partial stack given first; complete exception later)

I am intentionally giving wrong PORT (2222) instead of the correct port (22). What are we missing here?

Other Cases:

-          Valid Port - the poll strategy 'begin' & 'commit' are called.

-          Invalid User or Invalid Password - 'rollback' method is invoked with GenericFileOperationFailedException.

Regards,
Arpit.

Exception:
--------------
org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
                at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
                at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
                at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
                at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
                at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
                at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
                at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
                at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
                at java.lang.Thread.run(Thread.java:812)
Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
                at com.jcraft.jsch.Util.createSocket(Util.java:389)
                at com.jcraft.jsch.Session.connect(Session.java:215)
                at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
                ... 13 more

Sample Program:
--------------------

public class ConsumerTemplateAndSftpIssues {

  private static final String DIRECT_START = "direct:start";

  public static void main(String[] args) throws Exception {
    BasicConfigurator.configure();

    DefaultCamelContext c = new DefaultCamelContext();

    SimpleRegistry sr = new SimpleRegistry();
    c.setRegistry(sr);

    sr.put("customPoll", new PollingConsumerPollStrategy(){

      @Override
      public boolean begin(Consumer consumer, Endpoint endpoint) {
        return true;
      }

      @Override
      public void commit(Consumer consumer, Endpoint endpoint, int polledMessages) {
        System.out.println(endpoint.getEndpointUri());
      }

      @Override
      public boolean rollback(Consumer consumer, Endpoint endpoint, int retryCounter, Exception cause) throws Exception {
        System.out.println(endpoint.getEndpointUri() + " Cause exception with message " + cause.getMessage());
        throw cause;
      }
    });
    RouteBuilder r1 = new RouteBuilder() {
      @Override
      public void configure() throws Exception {
        /* Can't use from("sftp://...") because business logic triggering */
        RouteDefinition from = from(DIRECT_START);

        /* Processor reads data from sftp -- invalid port test */
        from.process(new Processor() {

          @Override
          public void process(Exchange exchange) throws Exception {
            ConsumerTemplate template = exchange.getContext().createConsumerTemplate();
            template.start();
            try {
              Exchange ex = template.receive("sftp://test.rebex.net:2222/?" + "username=demo&" + "password=password&" + "stepwise=false&" + "disconnect=true&"
                  + "reconnectDelay=5000&"
                  + "useList=false&" + "ignoreFileNotFoundOrPermissionError=false&" + "throwExceptionOnConnectFailed=true&" + "fileName=readme.txt&"
                  + "consumer.bridgeErrorHandler=true&" + "autoCreate=false&" + "pollStrategy=#customPoll", 60000);
              if (ex != null && ex.getException() == null) {
                exchange.getOut().setBody(ex.getIn().getBody(String.class));
              } else {
                 System.out.println("****************************EXCHANGE IS NULL****************************");
              }
            }finally {
              template.stop();
            }
          }
        });
      }
    };

    c.addRoutes(r1);
    ProducerTemplate createProducerTemplate = c.createProducerTemplate();
    try {
      c.start();
      createProducerTemplate.start();

      Exchange result = createProducerTemplate.request(DIRECT_START, new Processor() {

        @Override
        public void process(Exchange exchange) throws Exception {
          exchange.getIn().setBody("HELLO WORLD");
        }
      });
      System.out.println(result.getOut().getBody());
    } finally {
      c.stop();
    }
  }
}



Complete log of the sample program:
------------------------------------------------
1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: initialDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 1000
1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: timeUnit on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: MILLISECONDS
1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: scheduledExecutorService on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: null
1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: useFixedDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: true
1580 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: delay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 500
1589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ScheduledThreadPool for source: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with name: sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo. -> org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
1589 [main] DEBUG org.apache.camel.impl.DefaultScheduledPollConsumerScheduler  - Scheduling poll (fixed delay) with initialDelay: 1000, delay: 500 (milliseconds) for: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
2603 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Parameters for Generic file process strategy {readLockMinAge=0, readLockMarkerFile=true, readLock=none, fastExistsCheck=false, readLockRemoveOnCommit=false, readLockTimeout=20000, readLockRemoveOnRollback=true, readLockLoggingLevel=WARN, readLockDeleteOrphanLockFiles=true, readLockMinLength=1, readLockCheckInterval=5000}
2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Using Generic file process strategy: org.apache.camel.component.file.strategy.GenericFileNoOpProcessStrategy@6f24b1ce
2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
2647 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
17664 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
32668 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
47671 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
57676 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Could not connect to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]. Will try to recover.
org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
                at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
                at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
                at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
                at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
                at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
                at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
                at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
                at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
                at java.lang.Thread.run(Thread.java:812)
Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
                at com.jcraft.jsch.Util.createSocket(Util.java:389)
                at com.jcraft.jsch.Session.connect(Session.java:215)
                at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
                ... 13 more
57703 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Trying to recover connection to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with a fresh client.
57704 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
57705 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
72707 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
87711 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
102713 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
****************************EXCHANGE IS NULL****************************
359542 [main] DEBUG org.apache.camel.impl.SharedPollingConsumerServicePool  - Stopping service pool: org.apache.camel.impl.SharedPollingConsumerServicePool@6f4a47c7
359543 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
359544 [main] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Stopping consumer: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
HELLO WORLD
359566 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutting down
359570 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Starting to graceful shutdown 1 routes (timeout 300 seconds)
359571 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ThreadPool for source: org.apache.camel.impl.DefaultShutdownStrategy@1224144a with name: ShutdownTask. -> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0][ShutdownTask]
359577 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - There are 1 routes to shutdown
359579 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 suspension deferred.
359580 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 preparing to shutdown complete.
359581 [Camel (camel-1) thread #1 - ShutdownTask] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 shutdown complete, was consuming from: Endpoint[direct://start]
359582 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Graceful shutdown of 1 routes completed in 0 seconds
359582 [main] DEBUG org.apache.camel.impl.DefaultAsyncProcessorAwaitManager  - Shutting down with no inflight threads.
359583 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedSuspendableRoute@bae7dc0
359583 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=routes,name="route1"
359583 [main] DEBUG org.apache.camel.impl.RouteService  - Stopping services on route: route1
359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Consumer[direct://start]
359584 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=consumers,name=DirectConsumer(0x52af26ee)
359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]
359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
359586 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down services on route: route1
359588 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedCamelContext@415b0b49
359588 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=context,name="camel-1"
359589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1][ShutdownTask]
359589 [main] DEBUG org.apache.camel.impl.DefaultInflightRepository  - Shutting down with no inflight exchanges.
359589 [main] DEBUG org.apache.camel.impl.SharedProducerServicePool  - Stopping service pool: org.apache.camel.impl.SharedProducerServicePool@1e965684
359590 [main] DEBUG org.apache.camel.util.EventHelper  - Ignoring notifying event Stopped CamelContext: camel-1. The EventNotifier has not been started yet: org.apache.camel.impl.DefaultRuntimeEndpointRegistry@311bf055
359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultTypeConverter
359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedProducerServicePool
359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRuntimeEndpointRegistry
359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="sftp"
359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRestRegistry
359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultAsyncProcessorAwaitManager
359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultPackageScanClassResolver
359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=errorhandlers,name="DefaultErrorHandlerBuilder(ref:CamelDefaultErrorHandlerBuilder)"
359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=processors,name="process1"
359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultEndpointRegistry
359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogTracer
359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="direct"
359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogDebugger
359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultInflightRepository
359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=endpoints,name="direct://start"
359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedPollingConsumerServicePool
359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultShutdownStrategy
359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultExecutorServiceManager
359595 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Clearing cache[size=2, hits=61, misses=46, evicted=0]
359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) uptime 5 minutes
359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutdown in 0.035 seconds
sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=password&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo Cause exception with message Cannot connect to sftp://demo@test.rebex.net:2222

RE: [camel-ftp] Can't catch Invalid SFTP port exception

Posted by "Goyal, Arpit" <ar...@sap.com>.
Thanks Claus for the clarification. If you are able to recall and point me to the fix, that would be great. I would like to understand.

-----Original Message-----
From: Claus Ibsen [mailto:claus.ibsen@gmail.com] 
Sent: Tuesday, October 18, 2016 1:54 PM
To: users@camel.apache.org
Subject: Re: [camel-ftp] Can't catch Invalid SFTP port exception

Try with Camel 2.18.0 release. We may have fixed something about this.
There is a vague memory of mine looking into and fixing something with
consumer template and bridge.



On Sun, Oct 16, 2016 at 9:54 PM, Goyal, Arpit <ar...@sap.com> wrote:
> I am trying to handle all the exception use cases of SFTP for logging purposes. In case user has given invalid Port address for sftp server even when using pollStrategy attribute ->
>
> 1) We are not able to get the exception back in the code.
> 2) Exchange comes back null.
> 3) Associated below code to logger and see the exception logged though. (Partial stack given first; complete exception later)
>
> I am intentionally giving wrong PORT (2222) instead of the correct port (22). What are we missing here?
>
> Other Cases:
>
> -          Valid Port - the poll strategy 'begin' & 'commit' are called.
>
> -          Invalid User or Invalid Password - 'rollback' method is invoked with GenericFileOperationFailedException.
>
> Regards,
> Arpit.
>
> Exception:
> --------------
> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>                 at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>                 at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>                 at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>                 at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>                 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>                 at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>                 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>                 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>                 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>                 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>                 at java.lang.Thread.run(Thread.java:812)
> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>                 at com.jcraft.jsch.Util.createSocket(Util.java:389)
>                 at com.jcraft.jsch.Session.connect(Session.java:215)
>                 at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>                 ... 13 more
>
> Sample Program:
> --------------------
>
> public class ConsumerTemplateAndSftpIssues {
>
>   private static final String DIRECT_START = "direct:start";
>
>   public static void main(String[] args) throws Exception {
>     BasicConfigurator.configure();
>
>     DefaultCamelContext c = new DefaultCamelContext();
>
>     SimpleRegistry sr = new SimpleRegistry();
>     c.setRegistry(sr);
>
>     sr.put("customPoll", new PollingConsumerPollStrategy(){
>
>       @Override
>       public boolean begin(Consumer consumer, Endpoint endpoint) {
>         return true;
>       }
>
>       @Override
>       public void commit(Consumer consumer, Endpoint endpoint, int polledMessages) {
>         System.out.println(endpoint.getEndpointUri());
>       }
>
>       @Override
>       public boolean rollback(Consumer consumer, Endpoint endpoint, int retryCounter, Exception cause) throws Exception {
>         System.out.println(endpoint.getEndpointUri() + " Cause exception with message " + cause.getMessage());
>         throw cause;
>       }
>     });
>     RouteBuilder r1 = new RouteBuilder() {
>       @Override
>       public void configure() throws Exception {
>         /* Can't use from("sftp://...") because business logic triggering */
>         RouteDefinition from = from(DIRECT_START);
>
>         /* Processor reads data from sftp -- invalid port test */
>         from.process(new Processor() {
>
>           @Override
>           public void process(Exchange exchange) throws Exception {
>             ConsumerTemplate template = exchange.getContext().createConsumerTemplate();
>             template.start();
>             try {
>               Exchange ex = template.receive("sftp://test.rebex.net:2222/?" + "username=demo&" + "password=password&" + "stepwise=false&" + "disconnect=true&"
>                   + "reconnectDelay=5000&"
>                   + "useList=false&" + "ignoreFileNotFoundOrPermissionError=false&" + "throwExceptionOnConnectFailed=true&" + "fileName=readme.txt&"
>                   + "consumer.bridgeErrorHandler=true&" + "autoCreate=false&" + "pollStrategy=#customPoll", 60000);
>               if (ex != null && ex.getException() == null) {
>                 exchange.getOut().setBody(ex.getIn().getBody(String.class));
>               } else {
>                  System.out.println("****************************EXCHANGE IS NULL****************************");
>               }
>             }finally {
>               template.stop();
>             }
>           }
>         });
>       }
>     };
>
>     c.addRoutes(r1);
>     ProducerTemplate createProducerTemplate = c.createProducerTemplate();
>     try {
>       c.start();
>       createProducerTemplate.start();
>
>       Exchange result = createProducerTemplate.request(DIRECT_START, new Processor() {
>
>         @Override
>         public void process(Exchange exchange) throws Exception {
>           exchange.getIn().setBody("HELLO WORLD");
>         }
>       });
>       System.out.println(result.getOut().getBody());
>     } finally {
>       c.stop();
>     }
>   }
> }
>
>
>
> Complete log of the sample program:
> ------------------------------------------------
> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: initialDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 1000
> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: timeUnit on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: MILLISECONDS
> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: scheduledExecutorService on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: null
> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: useFixedDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: true
> 1580 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: delay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 500
> 1589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ScheduledThreadPool for source: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with name: sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo. -> org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 1589 [main] DEBUG org.apache.camel.impl.DefaultScheduledPollConsumerScheduler  - Scheduling poll (fixed delay) with initialDelay: 1000, delay: 500 (milliseconds) for: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 2603 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Parameters for Generic file process strategy {readLockMinAge=0, readLockMarkerFile=true, readLock=none, fastExistsCheck=false, readLockRemoveOnCommit=false, readLockTimeout=20000, readLockRemoveOnRollback=true, readLockLoggingLevel=WARN, readLockDeleteOrphanLockFiles=true, readLockMinLength=1, readLockCheckInterval=5000}
> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Using Generic file process strategy: org.apache.camel.component.file.strategy.GenericFileNoOpProcessStrategy@6f24b1ce
> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
> 2647 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 17664 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 32668 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 47671 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 57676 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Could not connect to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]. Will try to recover.
> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>                 at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>                 at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>                 at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>                 at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>                 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>                 at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>                 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>                 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>                 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>                 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>                 at java.lang.Thread.run(Thread.java:812)
> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>                 at com.jcraft.jsch.Util.createSocket(Util.java:389)
>                 at com.jcraft.jsch.Session.connect(Session.java:215)
>                 at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>                 ... 13 more
> 57703 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Trying to recover connection to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with a fresh client.
> 57704 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
> 57705 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 72707 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 87711 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 102713 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> ****************************EXCHANGE IS NULL****************************
> 359542 [main] DEBUG org.apache.camel.impl.SharedPollingConsumerServicePool  - Stopping service pool: org.apache.camel.impl.SharedPollingConsumerServicePool@6f4a47c7
> 359543 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 359544 [main] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Stopping consumer: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> HELLO WORLD
> 359566 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutting down
> 359570 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Starting to graceful shutdown 1 routes (timeout 300 seconds)
> 359571 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ThreadPool for source: org.apache.camel.impl.DefaultShutdownStrategy@1224144a with name: ShutdownTask. -> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0][ShutdownTask]
> 359577 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - There are 1 routes to shutdown
> 359579 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 suspension deferred.
> 359580 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 preparing to shutdown complete.
> 359581 [Camel (camel-1) thread #1 - ShutdownTask] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 shutdown complete, was consuming from: Endpoint[direct://start]
> 359582 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Graceful shutdown of 1 routes completed in 0 seconds
> 359582 [main] DEBUG org.apache.camel.impl.DefaultAsyncProcessorAwaitManager  - Shutting down with no inflight threads.
> 359583 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedSuspendableRoute@bae7dc0
> 359583 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=routes,name="route1"
> 359583 [main] DEBUG org.apache.camel.impl.RouteService  - Stopping services on route: route1
> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Consumer[direct://start]
> 359584 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=consumers,name=DirectConsumer(0x52af26ee)
> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]
> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
> 359586 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down services on route: route1
> 359588 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedCamelContext@415b0b49
> 359588 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=context,name="camel-1"
> 359589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1][ShutdownTask]
> 359589 [main] DEBUG org.apache.camel.impl.DefaultInflightRepository  - Shutting down with no inflight exchanges.
> 359589 [main] DEBUG org.apache.camel.impl.SharedProducerServicePool  - Stopping service pool: org.apache.camel.impl.SharedProducerServicePool@1e965684
> 359590 [main] DEBUG org.apache.camel.util.EventHelper  - Ignoring notifying event Stopped CamelContext: camel-1. The EventNotifier has not been started yet: org.apache.camel.impl.DefaultRuntimeEndpointRegistry@311bf055
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultTypeConverter
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedProducerServicePool
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRuntimeEndpointRegistry
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="sftp"
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRestRegistry
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultAsyncProcessorAwaitManager
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultPackageScanClassResolver
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=errorhandlers,name="DefaultErrorHandlerBuilder(ref:CamelDefaultErrorHandlerBuilder)"
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=processors,name="process1"
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultEndpointRegistry
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogTracer
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="direct"
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogDebugger
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultInflightRepository
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=endpoints,name="direct://start"
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedPollingConsumerServicePool
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultShutdownStrategy
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultExecutorServiceManager
> 359595 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Clearing cache[size=2, hits=61, misses=46, evicted=0]
> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) uptime 5 minutes
> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutdown in 0.035 seconds
> sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=password&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo Cause exception with message Cannot connect to sftp://demo@test.rebex.net:2222



-- 
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2

Re: [camel-ftp] Can't catch Invalid SFTP port exception

Posted by Claus Ibsen <cl...@gmail.com>.
Try with Camel 2.18.0 release. We may have fixed something about this.
There is a vague memory of mine looking into and fixing something with
consumer template and bridge.



On Sun, Oct 16, 2016 at 9:54 PM, Goyal, Arpit <ar...@sap.com> wrote:
> I am trying to handle all the exception use cases of SFTP for logging purposes. In case user has given invalid Port address for sftp server even when using pollStrategy attribute ->
>
> 1) We are not able to get the exception back in the code.
> 2) Exchange comes back null.
> 3) Associated below code to logger and see the exception logged though. (Partial stack given first; complete exception later)
>
> I am intentionally giving wrong PORT (2222) instead of the correct port (22). What are we missing here?
>
> Other Cases:
>
> -          Valid Port - the poll strategy 'begin' & 'commit' are called.
>
> -          Invalid User or Invalid Password - 'rollback' method is invoked with GenericFileOperationFailedException.
>
> Regards,
> Arpit.
>
> Exception:
> --------------
> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>                 at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>                 at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>                 at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>                 at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>                 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>                 at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>                 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>                 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>                 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>                 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>                 at java.lang.Thread.run(Thread.java:812)
> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>                 at com.jcraft.jsch.Util.createSocket(Util.java:389)
>                 at com.jcraft.jsch.Session.connect(Session.java:215)
>                 at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>                 ... 13 more
>
> Sample Program:
> --------------------
>
> public class ConsumerTemplateAndSftpIssues {
>
>   private static final String DIRECT_START = "direct:start";
>
>   public static void main(String[] args) throws Exception {
>     BasicConfigurator.configure();
>
>     DefaultCamelContext c = new DefaultCamelContext();
>
>     SimpleRegistry sr = new SimpleRegistry();
>     c.setRegistry(sr);
>
>     sr.put("customPoll", new PollingConsumerPollStrategy(){
>
>       @Override
>       public boolean begin(Consumer consumer, Endpoint endpoint) {
>         return true;
>       }
>
>       @Override
>       public void commit(Consumer consumer, Endpoint endpoint, int polledMessages) {
>         System.out.println(endpoint.getEndpointUri());
>       }
>
>       @Override
>       public boolean rollback(Consumer consumer, Endpoint endpoint, int retryCounter, Exception cause) throws Exception {
>         System.out.println(endpoint.getEndpointUri() + " Cause exception with message " + cause.getMessage());
>         throw cause;
>       }
>     });
>     RouteBuilder r1 = new RouteBuilder() {
>       @Override
>       public void configure() throws Exception {
>         /* Can't use from("sftp://...") because business logic triggering */
>         RouteDefinition from = from(DIRECT_START);
>
>         /* Processor reads data from sftp -- invalid port test */
>         from.process(new Processor() {
>
>           @Override
>           public void process(Exchange exchange) throws Exception {
>             ConsumerTemplate template = exchange.getContext().createConsumerTemplate();
>             template.start();
>             try {
>               Exchange ex = template.receive("sftp://test.rebex.net:2222/?" + "username=demo&" + "password=password&" + "stepwise=false&" + "disconnect=true&"
>                   + "reconnectDelay=5000&"
>                   + "useList=false&" + "ignoreFileNotFoundOrPermissionError=false&" + "throwExceptionOnConnectFailed=true&" + "fileName=readme.txt&"
>                   + "consumer.bridgeErrorHandler=true&" + "autoCreate=false&" + "pollStrategy=#customPoll", 60000);
>               if (ex != null && ex.getException() == null) {
>                 exchange.getOut().setBody(ex.getIn().getBody(String.class));
>               } else {
>                  System.out.println("****************************EXCHANGE IS NULL****************************");
>               }
>             }finally {
>               template.stop();
>             }
>           }
>         });
>       }
>     };
>
>     c.addRoutes(r1);
>     ProducerTemplate createProducerTemplate = c.createProducerTemplate();
>     try {
>       c.start();
>       createProducerTemplate.start();
>
>       Exchange result = createProducerTemplate.request(DIRECT_START, new Processor() {
>
>         @Override
>         public void process(Exchange exchange) throws Exception {
>           exchange.getIn().setBody("HELLO WORLD");
>         }
>       });
>       System.out.println(result.getOut().getBody());
>     } finally {
>       c.stop();
>     }
>   }
> }
>
>
>
> Complete log of the sample program:
> ------------------------------------------------
> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: initialDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 1000
> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: timeUnit on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: MILLISECONDS
> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: scheduledExecutorService on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: null
> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: useFixedDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: true
> 1580 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: delay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 500
> 1589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ScheduledThreadPool for source: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with name: sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo. -> org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 1589 [main] DEBUG org.apache.camel.impl.DefaultScheduledPollConsumerScheduler  - Scheduling poll (fixed delay) with initialDelay: 1000, delay: 500 (milliseconds) for: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 2603 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Parameters for Generic file process strategy {readLockMinAge=0, readLockMarkerFile=true, readLock=none, fastExistsCheck=false, readLockRemoveOnCommit=false, readLockTimeout=20000, readLockRemoveOnRollback=true, readLockLoggingLevel=WARN, readLockDeleteOrphanLockFiles=true, readLockMinLength=1, readLockCheckInterval=5000}
> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Using Generic file process strategy: org.apache.camel.component.file.strategy.GenericFileNoOpProcessStrategy@6f24b1ce
> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
> 2647 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 17664 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 32668 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 47671 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 57676 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Could not connect to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]. Will try to recover.
> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>                 at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>                 at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>                 at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>                 at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>                 at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>                 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>                 at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>                 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>                 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>                 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>                 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>                 at java.lang.Thread.run(Thread.java:812)
> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>                 at com.jcraft.jsch.Util.createSocket(Util.java:389)
>                 at com.jcraft.jsch.Session.connect(Session.java:215)
>                 at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>                 ... 13 more
> 57703 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Trying to recover connection to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with a fresh client.
> 57704 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
> 57705 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 72707 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 87711 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 102713 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> ****************************EXCHANGE IS NULL****************************
> 359542 [main] DEBUG org.apache.camel.impl.SharedPollingConsumerServicePool  - Stopping service pool: org.apache.camel.impl.SharedPollingConsumerServicePool@6f4a47c7
> 359543 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 359544 [main] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Stopping consumer: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> HELLO WORLD
> 359566 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutting down
> 359570 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Starting to graceful shutdown 1 routes (timeout 300 seconds)
> 359571 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ThreadPool for source: org.apache.camel.impl.DefaultShutdownStrategy@1224144a with name: ShutdownTask. -> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0][ShutdownTask]
> 359577 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - There are 1 routes to shutdown
> 359579 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 suspension deferred.
> 359580 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 preparing to shutdown complete.
> 359581 [Camel (camel-1) thread #1 - ShutdownTask] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 shutdown complete, was consuming from: Endpoint[direct://start]
> 359582 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Graceful shutdown of 1 routes completed in 0 seconds
> 359582 [main] DEBUG org.apache.camel.impl.DefaultAsyncProcessorAwaitManager  - Shutting down with no inflight threads.
> 359583 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedSuspendableRoute@bae7dc0
> 359583 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=routes,name="route1"
> 359583 [main] DEBUG org.apache.camel.impl.RouteService  - Stopping services on route: route1
> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Consumer[direct://start]
> 359584 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=consumers,name=DirectConsumer(0x52af26ee)
> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]
> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
> 359586 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down services on route: route1
> 359588 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedCamelContext@415b0b49
> 359588 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=context,name="camel-1"
> 359589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1][ShutdownTask]
> 359589 [main] DEBUG org.apache.camel.impl.DefaultInflightRepository  - Shutting down with no inflight exchanges.
> 359589 [main] DEBUG org.apache.camel.impl.SharedProducerServicePool  - Stopping service pool: org.apache.camel.impl.SharedProducerServicePool@1e965684
> 359590 [main] DEBUG org.apache.camel.util.EventHelper  - Ignoring notifying event Stopped CamelContext: camel-1. The EventNotifier has not been started yet: org.apache.camel.impl.DefaultRuntimeEndpointRegistry@311bf055
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultTypeConverter
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedProducerServicePool
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRuntimeEndpointRegistry
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="sftp"
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRestRegistry
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultAsyncProcessorAwaitManager
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultPackageScanClassResolver
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=errorhandlers,name="DefaultErrorHandlerBuilder(ref:CamelDefaultErrorHandlerBuilder)"
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=processors,name="process1"
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultEndpointRegistry
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogTracer
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="direct"
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogDebugger
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultInflightRepository
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=endpoints,name="direct://start"
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedPollingConsumerServicePool
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultShutdownStrategy
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultExecutorServiceManager
> 359595 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Clearing cache[size=2, hits=61, misses=46, evicted=0]
> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) uptime 5 minutes
> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutdown in 0.035 seconds
> sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=password&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo Cause exception with message Cannot connect to sftp://demo@test.rebex.net:2222



-- 
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2

RE: [camel-ftp] Can't catch Invalid SFTP port exception

Posted by "Goyal, Arpit" <ar...@sap.com>.
Yes - it is part of the URL in the below code and it didn't work - I am more and more inclined there is some bug here; but not an expert. 

"consumer.bridgeErrorHandler=true&"

Regards,
Arpit.

-----Original Message-----
From: Quinn Stevenson [mailto:quinn@pronoia-solutions.com] 
Sent: Tuesday, October 18, 2016 8:10 AM
To: users@camel.apache.org
Subject: Re: [camel-ftp] Can't catch Invalid SFTP port exception

Have you tried enabling the bridge error handler feature (consumer.bridgeErrorHandler)? http://camel.apache.org/file2.html <http://camel.apache.org/file2.html>

> On Oct 18, 2016, at 7:33 AM, Goyal, Arpit <ar...@sap.com> wrote:
> 
> Anyone having idea about what's wrong here?
> 
> Sent from my iPhone
> 
>> On Oct 16, 2016, at 12:55 PM, Goyal, Arpit <ar...@sap.com> wrote:
>> 
>> I am trying to handle all the exception use cases of SFTP for logging purposes. In case user has given invalid Port address for sftp server even when using pollStrategy attribute ->
>> 
>> 1) We are not able to get the exception back in the code.
>> 2) Exchange comes back null.
>> 3) Associated below code to logger and see the exception logged though. (Partial stack given first; complete exception later)
>> 
>> I am intentionally giving wrong PORT (2222) instead of the correct port (22). What are we missing here?
>> 
>> Other Cases:
>> 
>> -          Valid Port - the poll strategy 'begin' & 'commit' are called.
>> 
>> -          Invalid User or Invalid Password - 'rollback' method is invoked with GenericFileOperationFailedException.
>> 
>> Regards,
>> Arpit.
>> 
>> Exception:
>> --------------
>> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>>               at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>>               at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>>               at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>>               at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>>               at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>               at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>>               at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>>               at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>>               at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>>               at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>>               at java.lang.Thread.run(Thread.java:812)
>> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>>               at com.jcraft.jsch.Util.createSocket(Util.java:389)
>>               at com.jcraft.jsch.Session.connect(Session.java:215)
>>               at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>>               ... 13 more
>> 
>> Sample Program:
>> --------------------
>> 
>> public class ConsumerTemplateAndSftpIssues {
>> 
>> private static final String DIRECT_START = "direct:start";
>> 
>> public static void main(String[] args) throws Exception {
>>   BasicConfigurator.configure();
>> 
>>   DefaultCamelContext c = new DefaultCamelContext();
>> 
>>   SimpleRegistry sr = new SimpleRegistry();
>>   c.setRegistry(sr);
>> 
>>   sr.put("customPoll", new PollingConsumerPollStrategy(){
>> 
>>     @Override
>>     public boolean begin(Consumer consumer, Endpoint endpoint) {
>>       return true;
>>     }
>> 
>>     @Override
>>     public void commit(Consumer consumer, Endpoint endpoint, int polledMessages) {
>>       System.out.println(endpoint.getEndpointUri());
>>     }
>> 
>>     @Override
>>     public boolean rollback(Consumer consumer, Endpoint endpoint, int retryCounter, Exception cause) throws Exception {
>>       System.out.println(endpoint.getEndpointUri() + " Cause exception with message " + cause.getMessage());
>>       throw cause;
>>     }
>>   });
>>   RouteBuilder r1 = new RouteBuilder() {
>>     @Override
>>     public void configure() throws Exception {
>>       /* Can't use from("sftp://...") because business logic triggering */
>>       RouteDefinition from = from(DIRECT_START);
>> 
>>       /* Processor reads data from sftp -- invalid port test */
>>       from.process(new Processor() {
>> 
>>         @Override
>>         public void process(Exchange exchange) throws Exception {
>>           ConsumerTemplate template = exchange.getContext().createConsumerTemplate();
>>           template.start();
>>           try {
>>             Exchange ex = template.receive("sftp://test.rebex.net:2222/?" + "username=demo&" + "password=password&" + "stepwise=false&" + "disconnect=true&"
>>                 + "reconnectDelay=5000&"
>>                 + "useList=false&" + "ignoreFileNotFoundOrPermissionError=false&" + "throwExceptionOnConnectFailed=true&" + "fileName=readme.txt&"
>>                 + "consumer.bridgeErrorHandler=true&" + "autoCreate=false&" + "pollStrategy=#customPoll", 60000);
>>             if (ex != null && ex.getException() == null) {
>>               exchange.getOut().setBody(ex.getIn().getBody(String.class));
>>             } else {
>>                System.out.println("****************************EXCHANGE IS NULL****************************");
>>             }
>>           }finally {
>>             template.stop();
>>           }
>>         }
>>       });
>>     }
>>   };
>> 
>>   c.addRoutes(r1);
>>   ProducerTemplate createProducerTemplate = c.createProducerTemplate();
>>   try {
>>     c.start();
>>     createProducerTemplate.start();
>> 
>>     Exchange result = createProducerTemplate.request(DIRECT_START, new Processor() {
>> 
>>       @Override
>>       public void process(Exchange exchange) throws Exception {
>>         exchange.getIn().setBody("HELLO WORLD");
>>       }
>>     });
>>     System.out.println(result.getOut().getBody());
>>   } finally {
>>     c.stop();
>>   }
>> }
>> }
>> 
>> 
>> 
>> Complete log of the sample program:
>> ------------------------------------------------
>> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: initialDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 1000
>> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: timeUnit on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: MILLISECONDS
>> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: scheduledExecutorService on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: null
>> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: useFixedDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: true
>> 1580 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: delay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 500
>> 1589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ScheduledThreadPool for source: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with name: sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo. -> org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
>> 1589 [main] DEBUG org.apache.camel.impl.DefaultScheduledPollConsumerScheduler  - Scheduling poll (fixed delay) with initialDelay: 1000, delay: 500 (milliseconds) for: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
>> 2603 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Parameters for Generic file process strategy {readLockMinAge=0, readLockMarkerFile=true, readLock=none, fastExistsCheck=false, readLockRemoveOnCommit=false, readLockTimeout=20000, readLockRemoveOnRollback=true, readLockLoggingLevel=WARN, readLockDeleteOrphanLockFiles=true, readLockMinLength=1, readLockCheckInterval=5000}
>> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Using Generic file process strategy: org.apache.camel.component.file.strategy.GenericFileNoOpProcessStrategy@6f24b1ce
>> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
>> 2647 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 17664 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 32668 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 47671 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 57676 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Could not connect to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]. Will try to recover.
>> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>>               at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>>               at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>>               at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>>               at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>>               at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>               at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>>               at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>>               at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>>               at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>>               at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>>               at java.lang.Thread.run(Thread.java:812)
>> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>>               at com.jcraft.jsch.Util.createSocket(Util.java:389)
>>               at com.jcraft.jsch.Session.connect(Session.java:215)
>>               at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>>               ... 13 more
>> 57703 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Trying to recover connection to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with a fresh client.
>> 57704 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
>> 57705 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 72707 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 87711 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 102713 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> ****************************EXCHANGE IS NULL****************************
>> 359542 [main] DEBUG org.apache.camel.impl.SharedPollingConsumerServicePool  - Stopping service pool: org.apache.camel.impl.SharedPollingConsumerServicePool@6f4a47c7
>> 359543 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
>> 359544 [main] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Stopping consumer: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
>> HELLO WORLD
>> 359566 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutting down
>> 359570 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Starting to graceful shutdown 1 routes (timeout 300 seconds)
>> 359571 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ThreadPool for source: org.apache.camel.impl.DefaultShutdownStrategy@1224144a with name: ShutdownTask. -> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0][ShutdownTask]
>> 359577 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - There are 1 routes to shutdown
>> 359579 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 suspension deferred.
>> 359580 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 preparing to shutdown complete.
>> 359581 [Camel (camel-1) thread #1 - ShutdownTask] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 shutdown complete, was consuming from: Endpoint[direct://start]
>> 359582 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Graceful shutdown of 1 routes completed in 0 seconds
>> 359582 [main] DEBUG org.apache.camel.impl.DefaultAsyncProcessorAwaitManager  - Shutting down with no inflight threads.
>> 359583 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedSuspendableRoute@bae7dc0
>> 359583 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=routes,name="route1"
>> 359583 [main] DEBUG org.apache.camel.impl.RouteService  - Stopping services on route: route1
>> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Consumer[direct://start]
>> 359584 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=consumers,name=DirectConsumer(0x52af26ee)
>> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
>> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]
>> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
>> 359586 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down services on route: route1
>> 359588 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedCamelContext@415b0b49
>> 359588 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=context,name="camel-1"
>> 359589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1][ShutdownTask]
>> 359589 [main] DEBUG org.apache.camel.impl.DefaultInflightRepository  - Shutting down with no inflight exchanges.
>> 359589 [main] DEBUG org.apache.camel.impl.SharedProducerServicePool  - Stopping service pool: org.apache.camel.impl.SharedProducerServicePool@1e965684
>> 359590 [main] DEBUG org.apache.camel.util.EventHelper  - Ignoring notifying event Stopped CamelContext: camel-1. The EventNotifier has not been started yet: org.apache.camel.impl.DefaultRuntimeEndpointRegistry@311bf055
>> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultTypeConverter
>> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedProducerServicePool
>> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRuntimeEndpointRegistry
>> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="sftp"
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRestRegistry
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultAsyncProcessorAwaitManager
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultPackageScanClassResolver
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=errorhandlers,name="DefaultErrorHandlerBuilder(ref:CamelDefaultErrorHandlerBuilder)"
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=processors,name="process1"
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultEndpointRegistry
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogTracer
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="direct"
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogDebugger
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultInflightRepository
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=endpoints,name="direct://start"
>> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedPollingConsumerServicePool
>> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultShutdownStrategy
>> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultExecutorServiceManager
>> 359595 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Clearing cache[size=2, hits=61, misses=46, evicted=0]
>> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) uptime 5 minutes
>> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutdown in 0.035 seconds
>> sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=password&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo Cause exception with message Cannot connect to sftp://demo@test.rebex.net:2222


Re: [camel-ftp] Can't catch Invalid SFTP port exception

Posted by Quinn Stevenson <qu...@pronoia-solutions.com>.
Have you tried enabling the bridge error handler feature (consumer.bridgeErrorHandler)? http://camel.apache.org/file2.html <http://camel.apache.org/file2.html>

> On Oct 18, 2016, at 7:33 AM, Goyal, Arpit <ar...@sap.com> wrote:
> 
> Anyone having idea about what's wrong here?
> 
> Sent from my iPhone
> 
>> On Oct 16, 2016, at 12:55 PM, Goyal, Arpit <ar...@sap.com> wrote:
>> 
>> I am trying to handle all the exception use cases of SFTP for logging purposes. In case user has given invalid Port address for sftp server even when using pollStrategy attribute ->
>> 
>> 1) We are not able to get the exception back in the code.
>> 2) Exchange comes back null.
>> 3) Associated below code to logger and see the exception logged though. (Partial stack given first; complete exception later)
>> 
>> I am intentionally giving wrong PORT (2222) instead of the correct port (22). What are we missing here?
>> 
>> Other Cases:
>> 
>> -          Valid Port - the poll strategy 'begin' & 'commit' are called.
>> 
>> -          Invalid User or Invalid Password - 'rollback' method is invoked with GenericFileOperationFailedException.
>> 
>> Regards,
>> Arpit.
>> 
>> Exception:
>> --------------
>> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>>               at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>>               at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>>               at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>>               at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>>               at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>               at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>>               at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>>               at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>>               at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>>               at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>>               at java.lang.Thread.run(Thread.java:812)
>> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>>               at com.jcraft.jsch.Util.createSocket(Util.java:389)
>>               at com.jcraft.jsch.Session.connect(Session.java:215)
>>               at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>>               ... 13 more
>> 
>> Sample Program:
>> --------------------
>> 
>> public class ConsumerTemplateAndSftpIssues {
>> 
>> private static final String DIRECT_START = "direct:start";
>> 
>> public static void main(String[] args) throws Exception {
>>   BasicConfigurator.configure();
>> 
>>   DefaultCamelContext c = new DefaultCamelContext();
>> 
>>   SimpleRegistry sr = new SimpleRegistry();
>>   c.setRegistry(sr);
>> 
>>   sr.put("customPoll", new PollingConsumerPollStrategy(){
>> 
>>     @Override
>>     public boolean begin(Consumer consumer, Endpoint endpoint) {
>>       return true;
>>     }
>> 
>>     @Override
>>     public void commit(Consumer consumer, Endpoint endpoint, int polledMessages) {
>>       System.out.println(endpoint.getEndpointUri());
>>     }
>> 
>>     @Override
>>     public boolean rollback(Consumer consumer, Endpoint endpoint, int retryCounter, Exception cause) throws Exception {
>>       System.out.println(endpoint.getEndpointUri() + " Cause exception with message " + cause.getMessage());
>>       throw cause;
>>     }
>>   });
>>   RouteBuilder r1 = new RouteBuilder() {
>>     @Override
>>     public void configure() throws Exception {
>>       /* Can't use from("sftp://...") because business logic triggering */
>>       RouteDefinition from = from(DIRECT_START);
>> 
>>       /* Processor reads data from sftp -- invalid port test */
>>       from.process(new Processor() {
>> 
>>         @Override
>>         public void process(Exchange exchange) throws Exception {
>>           ConsumerTemplate template = exchange.getContext().createConsumerTemplate();
>>           template.start();
>>           try {
>>             Exchange ex = template.receive("sftp://test.rebex.net:2222/?" + "username=demo&" + "password=password&" + "stepwise=false&" + "disconnect=true&"
>>                 + "reconnectDelay=5000&"
>>                 + "useList=false&" + "ignoreFileNotFoundOrPermissionError=false&" + "throwExceptionOnConnectFailed=true&" + "fileName=readme.txt&"
>>                 + "consumer.bridgeErrorHandler=true&" + "autoCreate=false&" + "pollStrategy=#customPoll", 60000);
>>             if (ex != null && ex.getException() == null) {
>>               exchange.getOut().setBody(ex.getIn().getBody(String.class));
>>             } else {
>>                System.out.println("****************************EXCHANGE IS NULL****************************");
>>             }
>>           }finally {
>>             template.stop();
>>           }
>>         }
>>       });
>>     }
>>   };
>> 
>>   c.addRoutes(r1);
>>   ProducerTemplate createProducerTemplate = c.createProducerTemplate();
>>   try {
>>     c.start();
>>     createProducerTemplate.start();
>> 
>>     Exchange result = createProducerTemplate.request(DIRECT_START, new Processor() {
>> 
>>       @Override
>>       public void process(Exchange exchange) throws Exception {
>>         exchange.getIn().setBody("HELLO WORLD");
>>       }
>>     });
>>     System.out.println(result.getOut().getBody());
>>   } finally {
>>     c.stop();
>>   }
>> }
>> }
>> 
>> 
>> 
>> Complete log of the sample program:
>> ------------------------------------------------
>> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: initialDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 1000
>> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: timeUnit on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: MILLISECONDS
>> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: scheduledExecutorService on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: null
>> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: useFixedDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: true
>> 1580 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: delay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 500
>> 1589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ScheduledThreadPool for source: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with name: sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo. -> org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
>> 1589 [main] DEBUG org.apache.camel.impl.DefaultScheduledPollConsumerScheduler  - Scheduling poll (fixed delay) with initialDelay: 1000, delay: 500 (milliseconds) for: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
>> 2603 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Parameters for Generic file process strategy {readLockMinAge=0, readLockMarkerFile=true, readLock=none, fastExistsCheck=false, readLockRemoveOnCommit=false, readLockTimeout=20000, readLockRemoveOnRollback=true, readLockLoggingLevel=WARN, readLockDeleteOrphanLockFiles=true, readLockMinLength=1, readLockCheckInterval=5000}
>> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Using Generic file process strategy: org.apache.camel.component.file.strategy.GenericFileNoOpProcessStrategy@6f24b1ce
>> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
>> 2647 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 17664 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 32668 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 47671 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 57676 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Could not connect to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]. Will try to recover.
>> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>>               at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>>               at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>>               at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>>               at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>>               at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>>               at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>               at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>>               at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>>               at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>>               at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>>               at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>>               at java.lang.Thread.run(Thread.java:812)
>> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>>               at com.jcraft.jsch.Util.createSocket(Util.java:389)
>>               at com.jcraft.jsch.Session.connect(Session.java:215)
>>               at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>>               ... 13 more
>> 57703 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Trying to recover connection to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with a fresh client.
>> 57704 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
>> 57705 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 72707 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 87711 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> 102713 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
>> ****************************EXCHANGE IS NULL****************************
>> 359542 [main] DEBUG org.apache.camel.impl.SharedPollingConsumerServicePool  - Stopping service pool: org.apache.camel.impl.SharedPollingConsumerServicePool@6f4a47c7
>> 359543 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
>> 359544 [main] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Stopping consumer: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
>> HELLO WORLD
>> 359566 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutting down
>> 359570 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Starting to graceful shutdown 1 routes (timeout 300 seconds)
>> 359571 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ThreadPool for source: org.apache.camel.impl.DefaultShutdownStrategy@1224144a with name: ShutdownTask. -> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0][ShutdownTask]
>> 359577 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - There are 1 routes to shutdown
>> 359579 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 suspension deferred.
>> 359580 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 preparing to shutdown complete.
>> 359581 [Camel (camel-1) thread #1 - ShutdownTask] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 shutdown complete, was consuming from: Endpoint[direct://start]
>> 359582 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Graceful shutdown of 1 routes completed in 0 seconds
>> 359582 [main] DEBUG org.apache.camel.impl.DefaultAsyncProcessorAwaitManager  - Shutting down with no inflight threads.
>> 359583 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedSuspendableRoute@bae7dc0
>> 359583 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=routes,name="route1"
>> 359583 [main] DEBUG org.apache.camel.impl.RouteService  - Stopping services on route: route1
>> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Consumer[direct://start]
>> 359584 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=consumers,name=DirectConsumer(0x52af26ee)
>> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
>> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]
>> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
>> 359586 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down services on route: route1
>> 359588 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedCamelContext@415b0b49
>> 359588 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=context,name="camel-1"
>> 359589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1][ShutdownTask]
>> 359589 [main] DEBUG org.apache.camel.impl.DefaultInflightRepository  - Shutting down with no inflight exchanges.
>> 359589 [main] DEBUG org.apache.camel.impl.SharedProducerServicePool  - Stopping service pool: org.apache.camel.impl.SharedProducerServicePool@1e965684
>> 359590 [main] DEBUG org.apache.camel.util.EventHelper  - Ignoring notifying event Stopped CamelContext: camel-1. The EventNotifier has not been started yet: org.apache.camel.impl.DefaultRuntimeEndpointRegistry@311bf055
>> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultTypeConverter
>> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedProducerServicePool
>> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRuntimeEndpointRegistry
>> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="sftp"
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRestRegistry
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultAsyncProcessorAwaitManager
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultPackageScanClassResolver
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=errorhandlers,name="DefaultErrorHandlerBuilder(ref:CamelDefaultErrorHandlerBuilder)"
>> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=processors,name="process1"
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultEndpointRegistry
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogTracer
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="direct"
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogDebugger
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultInflightRepository
>> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=endpoints,name="direct://start"
>> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedPollingConsumerServicePool
>> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultShutdownStrategy
>> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultExecutorServiceManager
>> 359595 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Clearing cache[size=2, hits=61, misses=46, evicted=0]
>> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) uptime 5 minutes
>> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutdown in 0.035 seconds
>> sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=password&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo Cause exception with message Cannot connect to sftp://demo@test.rebex.net:2222


Re: [camel-ftp] Can't catch Invalid SFTP port exception

Posted by "Goyal, Arpit" <ar...@sap.com>.
Anyone having idea about what's wrong here?

Sent from my iPhone

> On Oct 16, 2016, at 12:55 PM, Goyal, Arpit <ar...@sap.com> wrote:
> 
> I am trying to handle all the exception use cases of SFTP for logging purposes. In case user has given invalid Port address for sftp server even when using pollStrategy attribute ->
> 
> 1) We are not able to get the exception back in the code.
> 2) Exchange comes back null.
> 3) Associated below code to logger and see the exception logged though. (Partial stack given first; complete exception later)
> 
> I am intentionally giving wrong PORT (2222) instead of the correct port (22). What are we missing here?
> 
> Other Cases:
> 
> -          Valid Port - the poll strategy 'begin' & 'commit' are called.
> 
> -          Invalid User or Invalid Password - 'rollback' method is invoked with GenericFileOperationFailedException.
> 
> Regards,
> Arpit.
> 
> Exception:
> --------------
> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>                at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>                at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>                at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>                at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>                at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>                at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>                at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>                at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>                at java.lang.Thread.run(Thread.java:812)
> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>                at com.jcraft.jsch.Util.createSocket(Util.java:389)
>                at com.jcraft.jsch.Session.connect(Session.java:215)
>                at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>                ... 13 more
> 
> Sample Program:
> --------------------
> 
> public class ConsumerTemplateAndSftpIssues {
> 
>  private static final String DIRECT_START = "direct:start";
> 
>  public static void main(String[] args) throws Exception {
>    BasicConfigurator.configure();
> 
>    DefaultCamelContext c = new DefaultCamelContext();
> 
>    SimpleRegistry sr = new SimpleRegistry();
>    c.setRegistry(sr);
> 
>    sr.put("customPoll", new PollingConsumerPollStrategy(){
> 
>      @Override
>      public boolean begin(Consumer consumer, Endpoint endpoint) {
>        return true;
>      }
> 
>      @Override
>      public void commit(Consumer consumer, Endpoint endpoint, int polledMessages) {
>        System.out.println(endpoint.getEndpointUri());
>      }
> 
>      @Override
>      public boolean rollback(Consumer consumer, Endpoint endpoint, int retryCounter, Exception cause) throws Exception {
>        System.out.println(endpoint.getEndpointUri() + " Cause exception with message " + cause.getMessage());
>        throw cause;
>      }
>    });
>    RouteBuilder r1 = new RouteBuilder() {
>      @Override
>      public void configure() throws Exception {
>        /* Can't use from("sftp://...") because business logic triggering */
>        RouteDefinition from = from(DIRECT_START);
> 
>        /* Processor reads data from sftp -- invalid port test */
>        from.process(new Processor() {
> 
>          @Override
>          public void process(Exchange exchange) throws Exception {
>            ConsumerTemplate template = exchange.getContext().createConsumerTemplate();
>            template.start();
>            try {
>              Exchange ex = template.receive("sftp://test.rebex.net:2222/?" + "username=demo&" + "password=password&" + "stepwise=false&" + "disconnect=true&"
>                  + "reconnectDelay=5000&"
>                  + "useList=false&" + "ignoreFileNotFoundOrPermissionError=false&" + "throwExceptionOnConnectFailed=true&" + "fileName=readme.txt&"
>                  + "consumer.bridgeErrorHandler=true&" + "autoCreate=false&" + "pollStrategy=#customPoll", 60000);
>              if (ex != null && ex.getException() == null) {
>                exchange.getOut().setBody(ex.getIn().getBody(String.class));
>              } else {
>                 System.out.println("****************************EXCHANGE IS NULL****************************");
>              }
>            }finally {
>              template.stop();
>            }
>          }
>        });
>      }
>    };
> 
>    c.addRoutes(r1);
>    ProducerTemplate createProducerTemplate = c.createProducerTemplate();
>    try {
>      c.start();
>      createProducerTemplate.start();
> 
>      Exchange result = createProducerTemplate.request(DIRECT_START, new Processor() {
> 
>        @Override
>        public void process(Exchange exchange) throws Exception {
>          exchange.getIn().setBody("HELLO WORLD");
>        }
>      });
>      System.out.println(result.getOut().getBody());
>    } finally {
>      c.stop();
>    }
>  }
> }
> 
> 
> 
> Complete log of the sample program:
> ------------------------------------------------
> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: initialDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 1000
> 1578 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: timeUnit on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: MILLISECONDS
> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: scheduledExecutorService on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: null
> 1579 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: useFixedDelay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: true
> 1580 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Configured property: delay on bean: org.apache.camel.impl.DefaultScheduledPollConsumerScheduler@1b919693 with value: 500
> 1589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ScheduledThreadPool for source: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with name: sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo. -> org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 1589 [main] DEBUG org.apache.camel.impl.DefaultScheduledPollConsumerScheduler  - Scheduling poll (fixed delay) with initialDelay: 1000, delay: 500 (milliseconds) for: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 2603 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Parameters for Generic file process strategy {readLockMinAge=0, readLockMarkerFile=true, readLock=none, fastExistsCheck=false, readLockRemoveOnCommit=false, readLockTimeout=20000, readLockRemoveOnRollback=true, readLockLoggingLevel=WARN, readLockDeleteOrphanLockFiles=true, readLockMinLength=1, readLockCheckInterval=5000}
> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpEndpoint  - Using Generic file process strategy: org.apache.camel.component.file.strategy.GenericFileNoOpProcessStrategy@6f24b1ce
> 2609 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
> 2647 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 17664 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 32668 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 47671 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 57676 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Could not connect to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]. Will try to recover.
> org.apache.camel.component.file.GenericFileOperationFailedException: Cannot connect to sftp://demo@test.rebex.net:2222
>                at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:146)
>                at org.apache.camel.component.file.remote.RemoteFileConsumer.connectIfNecessary(RemoteFileConsumer.java:203)
>                at org.apache.camel.component.file.remote.RemoteFileConsumer.recoverableConnectIfNecessary(RemoteFileConsumer.java:171)
>                at org.apache.camel.component.file.remote.RemoteFileConsumer.prePollCheck(RemoteFileConsumer.java:59)
>                at org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:106)
>                at org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174)
>                at org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101)
>                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>                at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>                at java.lang.Thread.run(Thread.java:812)
> Caused by: com.jcraft.jsch.JSchException: timeout: socket is not established
>                at com.jcraft.jsch.Util.createSocket(Util.java:389)
>                at com.jcraft.jsch.Session.connect(Session.java:215)
>                at org.apache.camel.component.file.remote.SftpOperations.connect(SftpOperations.java:118)
>                ... 13 more
> 57703 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Trying to recover connection to: Endpoint[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo] with a fresh client.
> 57704 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Not connected/logged in, connecting to: sftp://demo@test.rebex.net:2222
> 57705 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 72707 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 87711 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> 102713 [Camel (camel-1) thread #0 - sftp://test.rebex.net:2222/] DEBUG org.apache.camel.component.file.remote.SftpOperations  - Using StrickHostKeyChecking: no
> ****************************EXCHANGE IS NULL****************************
> 359542 [main] DEBUG org.apache.camel.impl.SharedPollingConsumerServicePool  - Stopping service pool: org.apache.camel.impl.SharedPollingConsumerServicePool@6f4a47c7
> 359543 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.SizedScheduledExecutorService@51891008[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> 359544 [main] DEBUG org.apache.camel.component.file.remote.SftpConsumer  - Stopping consumer: Consumer[sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=xxxxxx&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo]
> HELLO WORLD
> 359566 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutting down
> 359570 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Starting to graceful shutdown 1 routes (timeout 300 seconds)
> 359571 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Created new ThreadPool for source: org.apache.camel.impl.DefaultShutdownStrategy@1224144a with name: ShutdownTask. -> org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0][ShutdownTask]
> 359577 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - There are 1 routes to shutdown
> 359579 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 suspension deferred.
> 359580 [Camel (camel-1) thread #1 - ShutdownTask] DEBUG org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 preparing to shutdown complete.
> 359581 [Camel (camel-1) thread #1 - ShutdownTask] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Route: route1 shutdown complete, was consuming from: Endpoint[direct://start]
> 359582 [main] INFO org.apache.camel.impl.DefaultShutdownStrategy  - Graceful shutdown of 1 routes completed in 0 seconds
> 359582 [main] DEBUG org.apache.camel.impl.DefaultAsyncProcessorAwaitManager  - Shutting down with no inflight threads.
> 359583 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedSuspendableRoute@bae7dc0
> 359583 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=routes,name="route1"
> 359583 [main] DEBUG org.apache.camel.impl.RouteService  - Stopping services on route: route1
> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Consumer[direct://start]
> 359584 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=consumers,name=DirectConsumer(0x52af26ee)
> 359584 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]
> 359585 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down child service on route: route1 -> Channel[DelegateSync[com.tutorial.sample.camel.sftp.samples.ConsumerTemplateAndSftpIssues$2$1@41e1e210]]
> 359586 [main] DEBUG org.apache.camel.impl.RouteService  - Shutting down services on route: route1
> 359588 [main] DEBUG org.apache.camel.support.TimerListenerManager  - Removed TimerListener: org.apache.camel.management.mbean.ManagedCamelContext@415b0b49
> 359588 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=context,name="camel-1"
> 359589 [main] DEBUG org.apache.camel.impl.DefaultExecutorServiceManager  - Forcing shutdown of ExecutorService: org.apache.camel.util.concurrent.RejectableThreadPoolExecutor@f58853c[Running, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1][ShutdownTask]
> 359589 [main] DEBUG org.apache.camel.impl.DefaultInflightRepository  - Shutting down with no inflight exchanges.
> 359589 [main] DEBUG org.apache.camel.impl.SharedProducerServicePool  - Stopping service pool: org.apache.camel.impl.SharedProducerServicePool@1e965684
> 359590 [main] DEBUG org.apache.camel.util.EventHelper  - Ignoring notifying event Stopped CamelContext: camel-1. The EventNotifier has not been started yet: org.apache.camel.impl.DefaultRuntimeEndpointRegistry@311bf055
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultTypeConverter
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedProducerServicePool
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRuntimeEndpointRegistry
> 359592 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="sftp"
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultRestRegistry
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultAsyncProcessorAwaitManager
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultPackageScanClassResolver
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=errorhandlers,name="DefaultErrorHandlerBuilder(ref:CamelDefaultErrorHandlerBuilder)"
> 359593 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=processors,name="process1"
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultEndpointRegistry
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogTracer
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=components,name="direct"
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=tracer,name=BacklogDebugger
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultInflightRepository
> 359594 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=endpoints,name="direct://start"
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=SharedPollingConsumerServicePool
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultShutdownStrategy
> 359595 [main] DEBUG org.apache.camel.management.DefaultManagementAgent  - Unregistered MBean with ObjectName: org.apache.camel:context=camel-1,type=services,name=DefaultExecutorServiceManager
> 359595 [main] DEBUG org.apache.camel.util.IntrospectionSupport  - Clearing cache[size=2, hits=61, misses=46, evicted=0]
> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) uptime 5 minutes
> 359600 [main] INFO org.apache.camel.impl.DefaultCamelContext  - Apache Camel 2.16.3 (CamelContext: camel-1) is shutdown in 0.035 seconds
> sftp://test.rebex.net:2222/?autoCreate=false&consumer.bridgeErrorHandler=true&disconnect=true&fileName=readme.txt&ignoreFileNotFoundOrPermissionError=false&password=password&pollStrategy=%23customPoll&reconnectDelay=5000&stepwise=false&streamDownload=true&throwExceptionOnConnectFailed=true&useList=false&username=demo Cause exception with message Cannot connect to sftp://demo@test.rebex.net:2222