SFTP Outbound Adapter does not send to remote host

[peter0601]

Hi together,

i pretty much followed the example provided in spring examples for the sftp stuff. But I have the problem that the outbound adapter does not connect to the remote host.

Here is my config

<int:channel id="ftpOutbound"/>
    
    <beans:bean id="sftpSessionFactory" class="org.springframework.integration.sftp.session.DefaultSftpSessionFactory">
        <beans:property name="host" value="192.168.1.28"/>
        <beans:property name="port" value="22"/>
        <beans:property name="user" value="esm"/>
        <beans:property name="password" value="esm"/>
    </beans:bean>
    
    <int-sftp:outbound-channel-adapter id="sftpOutboundAdapter"
                                       session-factory="sftpSessionFactory"
                                       channel="ftpOutbound"
                                       remote-directory="/home/esm/upload/"
                                       remote-filename-generator-expression="'foo'"/>

And this is the controller class which I use to create a message and send it to the channel.

@Controller
@RequestMapping(value = "/StartTesting/*")
public class StartTesting {
    
    @Autowired
    private MessageChannel ftpOutbound;
    
    @RequestMapping(value = "Run", method = RequestMethod.GET)
    @ResponseBody
    public String run(HttpServletRequest request) {
        
//        String s = "HelloremoteServer";
        File f = new File("test.txt");
        Message<File> message = MessageBuilder.withPayload(f).build();
        ftpOutbound.send(message);
        return "Done";
        
    }

}

Here is what the logging shows me:

20:44:30,664 DEBUG DispatcherServlet:912 - Last-Modified value for [/ArkadonQueueProducer/StartTesting/Run] is: -1
20:44:30,675 DEBUG DirectChannel:224 - preSend on channel 'ftpOutbound', message: [Payload=test.txt][Headers={timestamp=1362080670675, id=588afa41-be54-419d-8d9a-51cd624223e6}]
20:44:30,676 DEBUG FileTransferringMessageHandler:67 - org.springframework.integration.file.remote.handler.FileTransferringMessageHandler#0 received message: [Payload=test.txt][Headers={timestamp=1362080670675, id=588afa41-be54-419d-8d9a-51cd624223e6}]
20:44:30,676 DEBUG DirectChannel:237 - postSend (sent=true) on channel 'ftpOutbound', message: [Payload=test.txt][Headers={timestamp=1362080670675, id=588afa41-be54-419d-8d9a-51cd624223e6}]
20:44:30,682 DEBUG RequestResponseBodyMethodProcessor:150 - Written [Done] as "text/html" using [org.springframework.http.converter.StringHttpMessageConverter@63226d58]

As you can see i commented out the String variable in the controller. If I would use the String payload instead of the file payload the log file would show me this:

20:31:23,586 DEBUG DispatcherServlet:912 - Last-Modified value for [/ArkadonQueueProducer/StartTesting/Run] is: -1
20:31:23,598 DEBUG DirectChannel:224 - preSend on channel 'ftpOutbound', message: [Payload=HelloremoteServer][Headers={timestamp=1362079883598, id=d39dd603-ef9e-4245-9fb8-5950658292b5}]
20:31:23,599 DEBUG FileTransferringMessageHandler:67 - org.springframework.integration.file.remote.handler.FileTransferringMessageHandler#0 received message: [Payload=HelloremoteServer][Headers={timestamp=1362079883598, id=d39dd603-ef9e-4245-9fb8-5950658292b5}]
20:31:23,639  INFO jsch:52 - Connecting to 192.168.1.28 port 22
20:31:23,642  INFO jsch:52 - Connection established
...
...
...
20:31:23,953  INFO jsch:52 - Authentications that can continue: password
20:31:23,953  INFO jsch:52 - Next authentication method: password
20:31:23,964  INFO jsch:52 - Authentication succeeded (password).
20:31:24,225 DEBUG SimplePool:182 - Obtained new org.springframework.integration.sftp.session.SftpSession@3d35f763.
20:31:24,227 DEBUG CachingSessionFactory:109 - Releasing Session back to the pool.
20:31:24,227 DEBUG SimplePool:210 - Releasing org.springframework.integration.sftp.session.SftpSession@3d35f763 back to the pool
20:31:24,228 DEBUG ExceptionHandlerExceptionResolver:132 - Resolving exception from handler [public java.lang.String de.arkadon.arkadonqueueproducer.StartTesting.run(javax.servlet.http.HttpServletRequest)]: org.springframework.integration.MessageDeliveryException: Error handling message for file [/opt/tomcat6/temp/foo.tmp]
20:31:24,231 DEBUG ResponseStatusExceptionResolver:132 - Resolving exception from handler [public java.lang.String de.arkadon.arkadonqueueproducer.StartTesting.run(javax.servlet.http.HttpServletRequest)]: org.springframework.integration.MessageDeliveryException: Error handling message for file [/opt/tomcat6/temp/foo.tmp]
20:31:24,231 DEBUG DefaultHandlerExceptionResolver:132 - Resolving exception from handler [public java.lang.String de.arkadon.arkadonqueueproducer.StartTesting.run(javax.servlet.http.HttpServletRequest)]: org.springframework.integration.MessageDeliveryException: Error handling message for file [/opt/tomcat6/temp/foo.tmp]
20:31:24,234 DEBUG DispatcherServlet:943 - Could not complete request

The question for me is now: Why does spring only initiate the ssh protocal handshake with my server when using the String payload whereas there is no error with the file payload but on the other hand no file on my remote server!
The best thing is, if I use FileZilla to connect to my sftp remote host, everything works fine. I can upload and download files as normal so password, username, hostname or any other credentials should be a problem.

Any help would be greatly appreciated!!!

Cheers and thanks in advance to the community
Peter

[Gary Russell]

The file has to actually exist; if there is no file on disk corresponding to File("test.txt"), there's nothing to send; this is not treated as an error.

So, you actually have to write something into the file (or create it as an empty file at least) for anything to get transferred.

[peter0601]

Hi Gary,

well that is an explanation. :-)
Thx a lot for pointing out my mistake.

Cheers
Peter

[peter0601]

Hi,

actually the file already exists... and still the controller does not find a file to upload.
I mean there must be something emberassing easy that I just do not see...

I changed the code to grab some pdf file directly from my home folder... the absolute path is retrieved successfully as you can see in the log following the code snippet.

       try {
                    File f2 = new File("/home/pburger/export.pdf");
                    System.out.println("absolut path:" + f2.getAbsolutePath());
                    Message<File> message = MessageBuilder.withPayload(f2).build();
                    ftpOutbound.send(message);
                    return "Done";
        } catch (Exception ex) {
            Logger.getLogger(StartTesting.class.getName()).log(Level.SEVERE, null, ex);
        } finally{
            return "really Done";
        }

And here the log file:

08:14:48,405 DEBUG RequestMappingHandlerMapping:219 - Looking up handler method for path /StartTesting/Run
08:14:48,407 DEBUG RequestMappingHandlerMapping:226 - Returning handler method [public java.lang.String de.arkadon.arkadonqueueproducer.StartTesting.run(javax.servlet.http.HttpServletRequest)]
08:14:48,408 DEBUG DispatcherServlet:912 - Last-Modified value for [/ArkadonQueueProducer/StartTesting/Run] is: -1
absolut path:/home/pburger/export.pdf
08:14:48,420 DEBUG DirectChannel:224 - preSend on channel 'ftpOutbound', message: [Payload=/home/pburger/export.pdf][Headers={timestamp=1362122088420, id=d809bf17-9ad8-434a-897c-8045585baf14}]
08:14:48,420 DEBUG FileTransferringMessageHandler:67 - org.springframework.integration.file.remote.handler.FileTransferringMessageHandler#0 received message: [Payload=/home/pburger/export.pdf][Headers={timestamp=1362122088420, id=d809bf17-9ad8-434a-897c-8045585baf14}]
08:14:48,429  INFO jsch:52 - Connecting to 10.1.10.11 port 22
08:14:48,430  INFO jsch:52 - Connection established
08:14:48,440  INFO jsch:52 - Remote version string: SSH-2.0-OpenSSH_5.9p1 Debian-5ubuntu1
08:14:48,440  INFO jsch:52 - Local version string: SSH-2.0-JSCH-0.1.45
08:14:48,440  INFO jsch:52 - CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256
08:14:48,451  INFO jsch:52 - aes256-ctr is not available.
08:14:48,451  INFO jsch:52 - aes192-ctr is not available.
08:14:48,452  INFO jsch:52 - aes256-cbc is not available.
08:14:48,452  INFO jsch:52 - aes192-cbc is not available.
08:14:48,452  INFO jsch:52 - arcfour256 is not available.
08:14:48,453  INFO jsch:52 - CheckKexes: diffie-hellman-group14-sha1
08:14:48,456  INFO jsch:52 - diffie-hellman-group14-sha1 is not available.
08:14:48,456  INFO jsch:52 - SSH_MSG_KEXINIT sent
08:14:48,456  INFO jsch:52 - SSH_MSG_KEXINIT received
08:14:48,457  INFO jsch:52 - kex: server->client aes128-ctr hmac-md5 none
08:14:48,457  INFO jsch:52 - kex: client->server aes128-ctr hmac-md5 none
08:14:48,460  INFO jsch:52 - SSH_MSG_KEXDH_INIT sent
08:14:48,461  INFO jsch:52 - expecting SSH_MSG_KEXDH_REPLY
08:14:48,477  INFO jsch:52 - ssh_rsa_verify: signature true
08:14:48,480  WARN jsch:55 - Permanently added '10.1.10.11' (RSA) to the list of known hosts.
08:14:48,480  INFO jsch:52 - SSH_MSG_NEWKEYS sent
08:14:48,482  INFO jsch:52 - SSH_MSG_NEWKEYS received
08:14:48,485  INFO jsch:52 - SSH_MSG_SERVICE_REQUEST sent
08:14:48,486  INFO jsch:52 - SSH_MSG_SERVICE_ACCEPT received
08:14:48,488  INFO jsch:52 - Authentications that can continue: publickey,keyboard-interactive,password
08:14:48,489  INFO jsch:52 - Next authentication method: publickey
08:14:48,490  INFO jsch:52 - Authentications that can continue: password
08:14:48,490  INFO jsch:52 - Next authentication method: password
08:14:48,504  INFO jsch:52 - Authentication succeeded (password).
08:14:48,806 DEBUG SimplePool:182 - Obtained new org.springframework.integration.sftp.session.SftpSession@7bde3bb0.
08:14:48,814 DEBUG CachingSessionFactory:109 - Releasing Session back to the pool.
08:14:48,814 DEBUG SimplePool:210 - Releasing org.springframework.integration.sftp.session.SftpSession@7bde3bb0 back to the pool
08:14:48,823 DEBUG RequestResponseBodyMethodProcessor:150 - Written [really Done] as "text/html" using [org.springframework.http.converter.StringHttpMessageConverter@d508040]
08:14:48,826 DEBUG DispatcherServlet:999 - Null ModelAndView returned to DispatcherServlet with name 'spring': assuming HandlerAdapter completed request handling
08:14:48,827 DEBUG DispatcherServlet:951 - Successfully completed request
Mrz 01, 2013 8:14:48 AM de.arkadon.arkadonqueueproducer.StartTesting run
SEVERE: null
org.springframework.integration.MessageDeliveryException: Error handling message for file [/home/pburger/export.pdf]
	at org.springframework.integration.file.remote.handler.FileTransferringMessageHandler.handleMessageInternal(FileTransferringMessageHandler.java:183)
	at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:73)
	at org.springframework.integration.dispatcher.UnicastingDispatcher.doDispatch(UnicastingDispatcher.java:115)
	at org.springframework.integration.dispatcher.UnicastingDispatcher.dispatch(UnicastingDispatcher.java:102)
	at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:77)
	at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:157)
	at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:128)
	at de.arkadon.arkadonqueueproducer.StartTesting.run(StartTesting.java:54)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:219)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:745)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:686)
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:920)
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:816)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:801)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861)
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606)
	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
	at java.lang.Thread.run(Thread.java:722)
Caused by: org.springframework.integration.MessagingException: Failed to write to '/home/esm/upload/foo.writing' while uploading the file
	at org.springframework.integration.file.remote.handler.FileTransferringMessageHandler.sendFileToRemoteDirectory(FileTransferringMessageHandler.java:266)
	at org.springframework.integration.file.remote.handler.FileTransferringMessageHandler.handleMessageInternal(FileTransferringMessageHandler.java:172)
	... 36 more
Caused by: org.springframework.core.NestedIOException: failed to write file; nested exception is 2: No such file
	at org.springframework.integration.sftp.session.SftpSession.write(SftpSession.java:127)
	at org.springframework.integration.file.remote.session.CachingSessionFactory$CachedSession.write(CachingSessionFactory.java:129)
	at org.springframework.integration.file.remote.handler.FileTransferringMessageHandler.sendFileToRemoteDirectory(FileTransferringMessageHandler.java:259)
	... 37 more
Caused by: 2: No such file
	at com.jcraft.jsch.ChannelSftp.throwStatusError(ChannelSftp.java:2491)
	at com.jcraft.jsch.ChannelSftp._put(ChannelSftp.java:528)
	at com.jcraft.jsch.ChannelSftp.put(ChannelSftp.java:480)
	at com.jcraft.jsch.ChannelSftp.put(ChannelSftp.java:439)
	at org.springframework.integration.sftp.session.SftpSession.write(SftpSession.java:124)
	... 39 more

What does go wrong here?

Thx
Peter

[Gary Russell]

Right, but this time you are seeing SFTP activity.

Caused by: org.springframework.core.NestedIOException: failed to write file; nested exception is 2: No such file
at org.springframework.integration.sftp.session.SftpS ession.write(SftpSession.java:127)

Notice that the error is in the session "write" method. By this time, the local file is being accessed by its input stream (so it passed the local "exists" test). This error is coming from the remote side; probably means the directory doesn't exist, or you don't have permission, etc.

[peter0601]

Hi Gary,

thanks again for your help.
I've found the error right at the moment.

the following line was the problem... or the solution!!!

remote-directory="/upload/"

Beforehand I had the configuration set to:

remote-directory="/home/esm/upload/" but the sftp server told me by connecting with fileZilla that my root directy is /home/esm/ already.

Thanks again for helping me out with this!
U made my day... probably the weekend!!! :-D

Cheers

[Gary Russell]

Right - most admins won't give you access to entire filesystem - your session gets 'chroot'ed to your home directory.