FTP inbound adapter throws "Problem occurred while synchronizing remote to local dir"

[konsubuntu]

Hi guys,

I'm new to Spring Integration (and also new to Spring). I'm trying to establish a connection to my server via FTP, to pull some files from there and then maybe process them.
I'm getting an "Problem occurred while synchronizing remote to local directory" error, so I don't understand why.
I'm using using Spring Integration 2.1.0 (with Spring 3.1.0).

Could someone point me in the right direction? Here are some snippets of the code I'm using.

config.xml (excerpt)

	<bean id="ftpSessionFactory"
		class="org.springframework.integration.ftp.session.DefaultFtpSessionFactory">
		<property name="host" value="MY_SERVER" />
		<property name="port" value="21" />
		<property name="username" value="MY_USER" />
		<property name="password" value="MY_PASSWORD" />
		<property name="clientMode" value="0" />
		<property name="fileType" value="2" />
		<property name="bufferSize" value="100000" />
	</bean>
	<int-ftp:inbound-channel-adapter id="ftpInbound"
		channel="ftpChannel" session-factory="ftpSessionFactory" charset="UTF-8"
		auto-create-local-directory="true" delete-remote-files="true"
		filename-pattern="*.txt" remote-directory="/home/spring"
		remote-file-separator="/" local-directory="C:\\Users\\XXX\\Desktop\\TESTFOLDER\\ftp">
		<si:poller fixed-rate="1000" />
	</int-ftp:inbound-channel-adapter>
	<si:channel id="ftpChannel" />
	<bean id="ftpShouter" class="com.xxx.xxx.FtpShouter" />

	<si:service-activator input-channel="ftpChannel"
		output-channel="fileoutput" ref="ftpShouter" method="shout" />

"MY_SERVER" etc are replaced by other values. Just used these to anonymize.



Exerpt from pom.xml for Maven:

<dependency>
   <groupId>org.springframework.integration</groupId>
   <artifactId>spring-integration-core</artifactId>
   <version>2.1.0.RELEASE</version>
</dependency> 
<dependency>
	<groupId>commons-logging</groupId>
	<artifactId>commons-logging</artifactId>
	<version>1.1.1</version>
</dependency>
<dependency>
   <groupId>org.springframework.integration</groupId>
   <artifactId>spring-integration-file</artifactId>
   <version>2.1.0.RELEASE</version>
</dependency> 
<dependency>
   <groupId>org.springframework.integration</groupId>
   <artifactId>spring-integration-ftp</artifactId>
   <version>2.1.0.RELEASE</version>
</dependency>

Stack trace:

Schwerwiegend: org.springframework.integration.MessagingException: Problem occurred while synchronizing remote to local directory
	at org.springframework.integration.file.remote.synchronizer.AbstractInboundFileSynchronizer.synchronizeToLocalDirectory(AbstractInboundFileSynchronizer.java:156)
	at org.springframework.integration.file.remote.synchronizer.AbstractInboundFileSynchronizingMessageSource.receive(AbstractInboundFileSynchronizingMessageSource.java:144)
	at org.springframework.integration.endpoint.SourcePollingChannelAdapter.doPoll(SourcePollingChannelAdapter.java:89)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:146)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:144)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller$1.run(AbstractPollingEndpoint.java:207)
	at org.springframework.integration.util.ErrorHandlingTaskExecutor$1.run(ErrorHandlingTaskExecutor.java:52)
	at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:48)
	at org.springframework.integration.util.ErrorHandlingTaskExecutor.execute(ErrorHandlingTaskExecutor.java:49)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller.run(AbstractPollingEndpoint.java:202)
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:53)
	at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:722)
Caused by: java.net.SocketException: Software caused connection abort: socket write error
	at java.net.SocketOutputStream.socketWrite0(Native Method)
	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
	at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
	at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
	at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
	at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:295)
	at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
	at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
	at java.io.BufferedWriter.flush(BufferedWriter.java:254)
	at org.apache.commons.net.ftp.FTP.__send(FTP.java:496)
	at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:470)
	at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:547)
	at org.apache.commons.net.ftp.FTP.port(FTP.java:872)
	at org.apache.commons.net.ftp.FTPClient._openDataConnection_(FTPClient.java:667)
	at org.apache.commons.net.ftp.FTPClient.initiateListParsing(FTPClient.java:2990)
	at org.apache.commons.net.ftp.FTPClient.initiateListParsing(FTPClient.java:2965)
	at org.apache.commons.net.ftp.FTPClient.listFiles(FTPClient.java:2623)
	at org.springframework.integration.ftp.session.FtpSession.list(FtpSession.java:62)
	at org.springframework.integration.ftp.session.FtpSession.list(FtpSession.java:38)
	at org.springframework.integration.file.remote.session.CachingSessionFactory$CachedSession.list(CachingSessionFactory.java:139)
	at org.springframework.integration.file.remote.synchronizer.AbstractInboundFileSynchronizer.synchronizeToLocalDirectory(AbstractInboundFileSynchronizer.java:145)
	... 19 more

Thank you very much!

[ubazan]

I'm having the same problem. I noticed it over a week ago, but it just happened again today. Some network interruption causes the exception and it all goes down hill from there. I have to restart the application to recover.

I'm using integration 2.1.0 and framework 3.1.0, Release. Is there any way to listen for or trap adapter exceptions?

Here's the stack trace:

[2012-02-14 13:43:23,388|ERROR|handler.LoggingHandler|126] org.springframework.integration.MessagingException: Problem occurred while synchronizing remote to local directory
    at org.springframework.integration.file.remote.synchronizer.AbstractInboundFileSynchronizer.synchronizeToLocalDirectory(AbstractInboundFileSynchronizer.java:156)
    at org.springframework.integration.file.remote.synchronizer.AbstractInboundFileSynchronizingMessageSource.receive(AbstractInboundFileSynchronizingMessageSource.java:144)
    at org.springframework.integration.endpoint.SourcePollingChannelAdapter.doPoll(SourcePollingChannelAdapter.java:89)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:146)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:144)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller$1.run(AbstractPollingEndpoint.java:207)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor$1.run(ErrorHandlingTaskExecutor.java:52)
    at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:48)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor.execute(ErrorHandlingTaskExecutor.java:49)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller.run(AbstractPollingEndpoint.java:202)
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:53)
    at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)
Caused by: java.net.SocketException: Connection reset
    at java.net.SocketInputStream.read(SocketInputStream.java:168)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
    at java.io.InputStreamReader.read(InputStreamReader.java:167)
    at java.io.BufferedReader.fill(BufferedReader.java:136)
    at java.io.BufferedReader.read(BufferedReader.java:157)
    at org.apache.commons.net.io.CRLFLineReader.readLine(CRLFLineReader.java:58)
    at org.apache.commons.net.ftp.FTP.__getReply(FTP.java:310)
    at org.apache.commons.net.ftp.FTP.__getReply(FTP.java:290)
    at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:474)
    at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:547)
    at org.apache.commons.net.ftp.FTP.port(FTP.java:872)
    at org.apache.commons.net.ftp.FTPClient._openDataConnection_(FTPClient.java:667)
    at org.apache.commons.net.ftp.FTPClient.initiateListParsing(FTPClient.java:2990)
    at org.apache.commons.net.ftp.FTPClient.initiateListParsing(FTPClient.java:2965)
    at org.apache.commons.net.ftp.FTPClient.listFiles(FTPClient.java:2623)
    at org.springframework.integration.ftp.session.FtpSession.list(FtpSession.java:62)
    at org.springframework.integration.ftp.session.FtpSession.list(FtpSession.java:38)
    at org.springframework.integration.file.remote.session.CachingSessionFactory$CachedSession.list(CachingSessionFactory.java:139)
    at org.springframework.integration.file.remote.synchronizer.AbstractInboundFileSynchronizer.synchronizeToLocalDirectory(AbstractInboundFileSynchronizer.java:145)
    ... 19 more

Thanks.

[ubazan]

I may have posted too soon on this. The following error occurs after the error in the previous post and shows up in the log 8 times over in a minute or so, then no more exceptions, recovery notices or anything. Over an hour later there IS activity and the adapter grabs a file and sends it.

The FTP adapter does appear to resume, but then I have a similar run of hibernate errors due to connection reset. Sorry for the false alarm.

[2012-02-14 13:55:28,249|ERROR|handler.LoggingHandler|126] java.lang.IllegalStateException: failed to create FTPClient
    at org.springframework.integration.ftp.session.AbstractFtpSessionFactory.getSession(AbstractFtpSessionFactory.java:132)
    at org.springframework.integration.file.remote.session.CachingSessionFactory.doGetSession(CachingSessionFactory.java:98)
    at org.springframework.integration.file.remote.session.CachingSessionFactory.doGetSession(CachingSessionFactory.java:95)
    at org.springframework.integration.file.remote.session.CachingSessionFactory.getSession(CachingSessionFactory.java:77)
    at org.springframework.integration.file.remote.synchronizer.AbstractInboundFileSynchronizer.synchronizeToLocalDirectory(AbstractInboundFileSynchronizer.java:143)
    at org.springframework.integration.file.remote.synchronizer.AbstractInboundFileSynchronizingMessageSource.receive(AbstractInboundFileSynchronizingMessageSource.java:144)
    at org.springframework.integration.endpoint.SourcePollingChannelAdapter.doPoll(SourcePollingChannelAdapter.java:89)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:146)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:144)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller$1.run(AbstractPollingEndpoint.java:207)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor$1.run(ErrorHandlingTaskExecutor.java:52)
    at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:48)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor.execute(ErrorHandlingTaskExecutor.java:49)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller.run(AbstractPollingEndpoint.java:202)
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:53)
    at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)
Caused by: java.net.UnknownHostException: ********(masked)
    at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
    at java.net.InetAddress$1.lookupAllHostAddr(InetAddress.java:850)
    at java.net.InetAddress.getAddressFromNameService(InetAddress.java:1201)
    at java.net.InetAddress.getAllByName0(InetAddress.java:1154)
    at java.net.InetAddress.getAllByName(InetAddress.java:1084)
    at java.net.InetAddress.getAllByName(InetAddress.java:1020)
    at java.net.InetAddress.getByName(InetAddress.java:970)
    at org.apache.commons.net.SocketClient.connect(SocketClient.java:189)
    at org.springframework.integration.ftp.session.AbstractFtpSessionFactory.createClient(AbstractFtpSessionFactory.java:145)
    at org.springframework.integration.ftp.session.AbstractFtpSessionFactory.getSession(AbstractFtpSessionFactory.java:129)
    ... 23 more

[konsubuntu]

Hi ubazan,
Thanks for jumping in. Like you said, the problem seems to be a different one. For me, the issue is persistent and the application has never been running with this configuration. It seems like I'm overlooking something to get it work. I expected it to be a file/folder permission problem, though I think that I can rule that out by now. Not sure what else it could be.

[ubazan]

Apologies for the attempted hijacking. Thought I could support the same argument for mutual benefit. After I gave it more time my adapter issue did resolve itself but it never gave notice that it had restored. It was over an hour when a file landed in the remote folder and was picked up. That was my first sign the adapter was actually on-line.

I guess the network problem that caused your adapter to crash does get corrected, and the server and share are still available, etc. I really don't have any idea. I wish there was some way to trap these framework errors.

[konsubuntu]

Hi ubazan,

No need to apologize. It really seemed to be similar in the beginning.

I'm also thinking that I'm slowly getting to the root of my issue. Doesn't seem to be SI related. I suspect that I'm running into a corporate firewall or an ftp server missconfiguration.

The proftpd log tells me, that the established connections only last for the blink of an eye.

Feb 15 14:37:35 MyBox proftpd[12998] MyBox.somewhere.net (myIP): FTP session opened.
Feb 15 14:37:35 MyBox proftpd[12998] MyBox.somewhere.net (myIP): USER spring: Login successful.
Feb 15 14:37:35 MyBox proftpd[12998] MyBox.somewhere.net (myIP): Preparing to chroot to directory '/home/spring'
Feb 15 14:37:35 MyBox proftpd[12998] MyBox.somewhere.net (myIP): FTP session closed.
Feb 15 14:44:48 MyBox proftpd[13020] MyBox.somewhere.net (myIP): FTP session opened.
Feb 15 14:44:48 MyBox proftpd[13020] MyBox.somewhere.net (myIP): USER spring: Login successful.
Feb 15 14:44:48 MyBox proftpd[13020] MyBox.somewhere.net (myIP): Preparing to chroot to directory '/home/spring'
Feb 15 14:44:48 MyBox proftpd[13020] MyBox.somewhere.net (myIP): FTP session closed.
Feb 15 14:45:37 MyBox proftpd[13028] MyBox.somewhere.net (myIP): FTP session opened.
Feb 15 14:45:37 MyBox proftpd[13028] MyBox.somewhere.net (myIP): USER spring: Login successful.
Feb 15 14:45:37 MyBox proftpd[13028] MyBox.somewhere.net (myIP): Preparing to chroot to directory '/home/spring'
Feb 15 14:45:38 MyBox proftpd[13028] MyBox.somewhere.net (myIP): FTP session closed.

I tested to connect to the server via ftp on Firefox. That worked.
Then I tried it via ftp on winSCP and it failed. That was both on a wifi connection

Then I plugged in an ethernet connection and it started to work via winSCP as well. Still failing with SI, though I guess I'm on the right track.

I'll test it at home, to see if it's the local firewall. Otherwise, it's probably a proftpd misconfiguration.
Either way, I'll report if one of that turned out to be case.

[konsubuntu]

OK, the blame really goes to the corporate firewall. (>.<)
Working like a charm from home.
Case closed.