You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by Kalpak Gadre <ka...@gmail.com> on 2011/12/14 13:44:25 UTC

SFTP endpoint disconnect=true causes problem

Hi,

I am working with a route which transfers files over SFTP. The route had 
trouble in case where there was inactivity for more than SSH session 
timeout period. Whenever an exchange was initiated after long duration 
of inactivity, it would fail due to "Connection reset by peer" which I 
assume is because SSH server dropped the session due to inactivity.

To fix this problem, I added disconnect=true to ensure that every 
transfer reconnects to the SSH session. After adding this though, I am 
seeing issues transferring files. Here are log snippets,

2011-12-12 18:01:24,159 | DEBUG | Wrote [/tmp/NSE/FILE_20111212.txt] to 
[Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]] 

2011-12-12 18:01:24,159 | TRACE | postWriteCheck disconnect from: 
Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user] 

2011-12-12 18:01:24,159 | DEBUG | Disconnecting from: 
Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user] 

2011-12-12 18:01:24,159 | INFO  | JSCH -> Disconnecting from 10.0.0.1 
port 22
2011-12-12 18:01:24,159 | INFO  | JSCH -> Caught an exception, leaving 
main loop due to socket closed

Although the log suggests that the file is written and then route is 
trying to disconnect as a part of postWriteCheck, the file is not 
written on the server. Not sure if it is due to unsafe disconnect from 
the SSH server.

Any suggestions what could be wrong?

Thanks,

Kalpak

Re: SFTP endpoint disconnect=true causes problem

Posted by Claus Ibsen <cl...@gmail.com>.
On Fri, Dec 16, 2011 at 10:41 AM, Kalpak Gadre <ka...@gmail.com> wrote:
>
>> On Fri, Dec 16, 2011 at 10:14 AM, Kalpak Gadre<ka...@gmail.com>  wrote:
>>>
>>> Hi Claus,
>>>
>>> Thanks for the input.
>>>
>>> If I am not wrong, the JSCH provides a logging interface to the client
>>> application, Camel uses this interface and outputs all the logs starting
>>> with "JSCH ->"
>>>
>>> I looked at the JSCH code to figure where the exception was originating
>>> from, but most of the exceptions are simply logged with exception
>>> messages
>>> and without stack trace in JSCH.
>>>
>>> I cannot find out stack trace, unless I make changes in JSCH library and
>>> recompile to improve loggin. Maybe that is the way to go?
>>>
>> Maybe JSCH itself has additional logging? I wonder if logs from the
>> transport layer is possible?
>> Or maybe you can see anything on the other side (eg from the server).
>> Maybe there is some error code returned there.
>>
>> Also you are welcome to double check the camel code, about the
>> disconnect option. Maybe there is a slight mistake there? Although
>> that may seem a bit odd as invoking disconnect should possible all
>> there is needed.
>
>
> This error is encountered only in the client's environment (As always is the
> case ;). Unfortunately, I do not have access to their SSH server to check
> this. Also, I do not fancy it could be issue with disconnect, as the same
> thing works perfectly fine on my local environment.
>
> A remote possibility I was thinking of was if JSCH is handling
> transportation of data in a separate thread and Camel writes file and
> disconnects, but JSCH is still writing that file in a separate thread on the
> stream. This is just a theory, maybe I can enable thread names in logging to
> ensure that log statements originate from the same thread.
>
> On the other hand, another way to fix the problem of session timeout could
> be redelivery? I think if I could make the route try to redeliver in case it
> encounters an error, I wont need to use disconnect=true. I hope it is
> possible to configure to attempt redelivery on the failure to deliver on an
> initial attempt?
>

If you enable redelivery on the Camel error handler, it will try
uploading the file again.
And the ftp producer ought to detect the exception from last attempt,
and cause the session to be re-created.
So that may remedy the issue you have.



>
>>> Thanks,
>>>
>>> Kalpak
>>>
>>>
>>>
>>>> On Wed, Dec 14, 2011 at 1:44 PM, Kalpak Gadre<ka...@gmail.com>
>>>>  wrote:
>>>>>
>>>>> Hi,
>>>>>
>>>>> I am working with a route which transfers files over SFTP. The route
>>>>> had
>>>>> trouble in case where there was inactivity for more than SSH session
>>>>> timeout
>>>>> period. Whenever an exchange was initiated after long duration of
>>>>> inactivity, it would fail due to "Connection reset by peer" which I
>>>>> assume
>>>>> is because SSH server dropped the session due to inactivity.
>>>>>
>>>>> To fix this problem, I added disconnect=true to ensure that every
>>>>> transfer
>>>>> reconnects to the SSH session. After adding this though, I am seeing
>>>>> issues
>>>>> transferring files. Here are log snippets,
>>>>>
>>>>> 2011-12-12 18:01:24,159 | DEBUG | Wrote [/tmp/NSE/FILE_20111212.txt] to
>>>>>
>>>>>
>>>>> [Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]]
>>>>> 2011-12-12 18:01:24,159 | TRACE | postWriteCheck disconnect from:
>>>>>
>>>>>
>>>>> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
>>>>> 2011-12-12 18:01:24,159 | DEBUG | Disconnecting from:
>>>>>
>>>>>
>>>>> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
>>>>> 2011-12-12 18:01:24,159 | INFO  | JSCH ->    Disconnecting from
>>>>> 10.0.0.1
>>>>> port
>>>>> 22
>>>>> 2011-12-12 18:01:24,159 | INFO  | JSCH ->    Caught an exception,
>>>>> leaving
>>>>> main
>>>>> loop due to socket closed
>>>>>
>>>>> Although the log suggests that the file is written and then route is
>>>>> trying
>>>>> to disconnect as a part of postWriteCheck, the file is not written on
>>>>> the
>>>>> server. Not sure if it is due to unsafe disconnect from the SSH server.
>>>>>
>>>>> Any suggestions what could be wrong?
>>>>>
>>>> I suggest to enable DEBUG/TRACE logging of the JSCH library to see
>>>> more details why it fails, and what the exception is etc.
>>>>
>>>>> Thanks,
>>>>>
>>>>> Kalpak
>>>>
>>>>
>>>>
>>
>>
>



-- 
Claus Ibsen
-----------------
FuseSource
Email: cibsen@fusesource.com
Web: http://fusesource.com
Twitter: davsclaus, fusenews
Blog: http://davsclaus.blogspot.com/
Author of Camel in Action: http://www.manning.com/ibsen/

Re: SFTP endpoint disconnect=true causes problem

Posted by Kalpak Gadre <ka...@gmail.com>.
> On Fri, Dec 16, 2011 at 10:14 AM, Kalpak Gadre<ka...@gmail.com>  wrote:
>> Hi Claus,
>>
>> Thanks for the input.
>>
>> If I am not wrong, the JSCH provides a logging interface to the client
>> application, Camel uses this interface and outputs all the logs starting
>> with "JSCH ->"
>>
>> I looked at the JSCH code to figure where the exception was originating
>> from, but most of the exceptions are simply logged with exception messages
>> and without stack trace in JSCH.
>>
>> I cannot find out stack trace, unless I make changes in JSCH library and
>> recompile to improve loggin. Maybe that is the way to go?
>>
> Maybe JSCH itself has additional logging? I wonder if logs from the
> transport layer is possible?
> Or maybe you can see anything on the other side (eg from the server).
> Maybe there is some error code returned there.
>
> Also you are welcome to double check the camel code, about the
> disconnect option. Maybe there is a slight mistake there? Although
> that may seem a bit odd as invoking disconnect should possible all
> there is needed.

This error is encountered only in the client's environment (As always is 
the case ;). Unfortunately, I do not have access to their SSH server to 
check this. Also, I do not fancy it could be issue with disconnect, as 
the same thing works perfectly fine on my local environment.

A remote possibility I was thinking of was if JSCH is handling 
transportation of data in a separate thread and Camel writes file and 
disconnects, but JSCH is still writing that file in a separate thread on 
the stream. This is just a theory, maybe I can enable thread names in 
logging to ensure that log statements originate from the same thread.

On the other hand, another way to fix the problem of session timeout 
could be redelivery? I think if I could make the route try to redeliver 
in case it encounters an error, I wont need to use disconnect=true. I 
hope it is possible to configure to attempt redelivery on the failure to 
deliver on an initial attempt?

>> Thanks,
>>
>> Kalpak
>>
>>
>>
>>> On Wed, Dec 14, 2011 at 1:44 PM, Kalpak Gadre<ka...@gmail.com>    wrote:
>>>> Hi,
>>>>
>>>> I am working with a route which transfers files over SFTP. The route had
>>>> trouble in case where there was inactivity for more than SSH session
>>>> timeout
>>>> period. Whenever an exchange was initiated after long duration of
>>>> inactivity, it would fail due to "Connection reset by peer" which I
>>>> assume
>>>> is because SSH server dropped the session due to inactivity.
>>>>
>>>> To fix this problem, I added disconnect=true to ensure that every
>>>> transfer
>>>> reconnects to the SSH session. After adding this though, I am seeing
>>>> issues
>>>> transferring files. Here are log snippets,
>>>>
>>>> 2011-12-12 18:01:24,159 | DEBUG | Wrote [/tmp/NSE/FILE_20111212.txt] to
>>>>
>>>> [Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]]
>>>> 2011-12-12 18:01:24,159 | TRACE | postWriteCheck disconnect from:
>>>>
>>>> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
>>>> 2011-12-12 18:01:24,159 | DEBUG | Disconnecting from:
>>>>
>>>> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
>>>> 2011-12-12 18:01:24,159 | INFO  | JSCH ->    Disconnecting from 10.0.0.1
>>>> port
>>>> 22
>>>> 2011-12-12 18:01:24,159 | INFO  | JSCH ->    Caught an exception, leaving
>>>> main
>>>> loop due to socket closed
>>>>
>>>> Although the log suggests that the file is written and then route is
>>>> trying
>>>> to disconnect as a part of postWriteCheck, the file is not written on the
>>>> server. Not sure if it is due to unsafe disconnect from the SSH server.
>>>>
>>>> Any suggestions what could be wrong?
>>>>
>>> I suggest to enable DEBUG/TRACE logging of the JSCH library to see
>>> more details why it fails, and what the exception is etc.
>>>
>>>> Thanks,
>>>>
>>>> Kalpak
>>>
>>>
>
>


Re: SFTP endpoint disconnect=true causes problem

Posted by Claus Ibsen <cl...@gmail.com>.
On Fri, Dec 16, 2011 at 10:14 AM, Kalpak Gadre <ka...@gmail.com> wrote:
> Hi Claus,
>
> Thanks for the input.
>
> If I am not wrong, the JSCH provides a logging interface to the client
> application, Camel uses this interface and outputs all the logs starting
> with "JSCH ->"
>
> I looked at the JSCH code to figure where the exception was originating
> from, but most of the exceptions are simply logged with exception messages
> and without stack trace in JSCH.
>
> I cannot find out stack trace, unless I make changes in JSCH library and
> recompile to improve loggin. Maybe that is the way to go?
>

Maybe JSCH itself has additional logging? I wonder if logs from the
transport layer is possible?
Or maybe you can see anything on the other side (eg from the server).
Maybe there is some error code returned there.

Also you are welcome to double check the camel code, about the
disconnect option. Maybe there is a slight mistake there? Although
that may seem a bit odd as invoking disconnect should possible all
there is needed.


> Thanks,
>
> Kalpak
>
>
>
>> On Wed, Dec 14, 2011 at 1:44 PM, Kalpak Gadre<ka...@gmail.com>  wrote:
>>>
>>> Hi,
>>>
>>> I am working with a route which transfers files over SFTP. The route had
>>> trouble in case where there was inactivity for more than SSH session
>>> timeout
>>> period. Whenever an exchange was initiated after long duration of
>>> inactivity, it would fail due to "Connection reset by peer" which I
>>> assume
>>> is because SSH server dropped the session due to inactivity.
>>>
>>> To fix this problem, I added disconnect=true to ensure that every
>>> transfer
>>> reconnects to the SSH session. After adding this though, I am seeing
>>> issues
>>> transferring files. Here are log snippets,
>>>
>>> 2011-12-12 18:01:24,159 | DEBUG | Wrote [/tmp/NSE/FILE_20111212.txt] to
>>>
>>> [Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]]
>>> 2011-12-12 18:01:24,159 | TRACE | postWriteCheck disconnect from:
>>>
>>> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
>>> 2011-12-12 18:01:24,159 | DEBUG | Disconnecting from:
>>>
>>> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
>>> 2011-12-12 18:01:24,159 | INFO  | JSCH ->  Disconnecting from 10.0.0.1
>>> port
>>> 22
>>> 2011-12-12 18:01:24,159 | INFO  | JSCH ->  Caught an exception, leaving
>>> main
>>> loop due to socket closed
>>>
>>> Although the log suggests that the file is written and then route is
>>> trying
>>> to disconnect as a part of postWriteCheck, the file is not written on the
>>> server. Not sure if it is due to unsafe disconnect from the SSH server.
>>>
>>> Any suggestions what could be wrong?
>>>
>> I suggest to enable DEBUG/TRACE logging of the JSCH library to see
>> more details why it fails, and what the exception is etc.
>>
>>> Thanks,
>>>
>>> Kalpak
>>
>>
>>
>



-- 
Claus Ibsen
-----------------
FuseSource
Email: cibsen@fusesource.com
Web: http://fusesource.com
Twitter: davsclaus, fusenews
Blog: http://davsclaus.blogspot.com/
Author of Camel in Action: http://www.manning.com/ibsen/

Re: SFTP endpoint disconnect=true causes problem

Posted by Kalpak Gadre <ka...@gmail.com>.
Hi Claus,

Thanks for the input.

If I am not wrong, the JSCH provides a logging interface to the client 
application, Camel uses this interface and outputs all the logs starting 
with "JSCH ->"

I looked at the JSCH code to figure where the exception was originating 
from, but most of the exceptions are simply logged with exception 
messages and without stack trace in JSCH.

I cannot find out stack trace, unless I make changes in JSCH library and 
recompile to improve loggin. Maybe that is the way to go?

Thanks,

Kalpak


> On Wed, Dec 14, 2011 at 1:44 PM, Kalpak Gadre<ka...@gmail.com>  wrote:
>> Hi,
>>
>> I am working with a route which transfers files over SFTP. The route had
>> trouble in case where there was inactivity for more than SSH session timeout
>> period. Whenever an exchange was initiated after long duration of
>> inactivity, it would fail due to "Connection reset by peer" which I assume
>> is because SSH server dropped the session due to inactivity.
>>
>> To fix this problem, I added disconnect=true to ensure that every transfer
>> reconnects to the SSH session. After adding this though, I am seeing issues
>> transferring files. Here are log snippets,
>>
>> 2011-12-12 18:01:24,159 | DEBUG | Wrote [/tmp/NSE/FILE_20111212.txt] to
>> [Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]]
>> 2011-12-12 18:01:24,159 | TRACE | postWriteCheck disconnect from:
>> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
>> 2011-12-12 18:01:24,159 | DEBUG | Disconnecting from:
>> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
>> 2011-12-12 18:01:24,159 | INFO  | JSCH ->  Disconnecting from 10.0.0.1 port
>> 22
>> 2011-12-12 18:01:24,159 | INFO  | JSCH ->  Caught an exception, leaving main
>> loop due to socket closed
>>
>> Although the log suggests that the file is written and then route is trying
>> to disconnect as a part of postWriteCheck, the file is not written on the
>> server. Not sure if it is due to unsafe disconnect from the SSH server.
>>
>> Any suggestions what could be wrong?
>>
> I suggest to enable DEBUG/TRACE logging of the JSCH library to see
> more details why it fails, and what the exception is etc.
>
>> Thanks,
>>
>> Kalpak
>
>


Re: SFTP endpoint disconnect=true causes problem

Posted by Claus Ibsen <cl...@gmail.com>.
On Wed, Dec 14, 2011 at 1:44 PM, Kalpak Gadre <ka...@gmail.com> wrote:
> Hi,
>
> I am working with a route which transfers files over SFTP. The route had
> trouble in case where there was inactivity for more than SSH session timeout
> period. Whenever an exchange was initiated after long duration of
> inactivity, it would fail due to "Connection reset by peer" which I assume
> is because SSH server dropped the session due to inactivity.
>
> To fix this problem, I added disconnect=true to ensure that every transfer
> reconnects to the SSH session. After adding this though, I am seeing issues
> transferring files. Here are log snippets,
>
> 2011-12-12 18:01:24,159 | DEBUG | Wrote [/tmp/NSE/FILE_20111212.txt] to
> [Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]]
> 2011-12-12 18:01:24,159 | TRACE | postWriteCheck disconnect from:
> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
> 2011-12-12 18:01:24,159 | DEBUG | Disconnecting from:
> Endpoint[sftp://10.0.0.1//tmp/NSE/?disconnect=true&password=******&username=user]
> 2011-12-12 18:01:24,159 | INFO  | JSCH -> Disconnecting from 10.0.0.1 port
> 22
> 2011-12-12 18:01:24,159 | INFO  | JSCH -> Caught an exception, leaving main
> loop due to socket closed
>
> Although the log suggests that the file is written and then route is trying
> to disconnect as a part of postWriteCheck, the file is not written on the
> server. Not sure if it is due to unsafe disconnect from the SSH server.
>
> Any suggestions what could be wrong?
>

I suggest to enable DEBUG/TRACE logging of the JSCH library to see
more details why it fails, and what the exception is etc.

> Thanks,
>
> Kalpak



-- 
Claus Ibsen
-----------------
FuseSource
Email: cibsen@fusesource.com
Web: http://fusesource.com
Twitter: davsclaus, fusenews
Blog: http://davsclaus.blogspot.com/
Author of Camel in Action: http://www.manning.com/ibsen/