Skip to content

"FtpSession - failed to disconnect FTPClient" when Removing FtpSession from the pool #3123

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
urajio opened this issue Dec 16, 2019 · 3 comments
Closed

"FtpSession - failed to disconnect FTPClient" when Removing FtpSession from the pool #3123

urajio opened this issue Dec 16, 2019 · 3 comments
Labels
in: ftp type: enhancement
Milestone
5.2.3

Comments

@urajio
Copy link

urajio commented Dec 16, 2019 •
edited by artembilan
Loading

I use Spring Integration 5.2.2.

    @Bean
    public SessionFactory<FTPFile> backendStorageFtpSessionFactory() {
        DefaultFtpSessionFactory ftpSessionFactory = new DefaultFtpSessionFactory();
        ftpSessionFactory.setHost(backendStorageFtpHost);
        ftpSessionFactory.setUsername(backendStorageFtpUser);
        ftpSessionFactory.setPassword(backendStorageFtpPassword);
        ftpSessionFactory.setClientMode(FTPClient.PASSIVE_LOCAL_DATA_CONNECTION_MODE);
        ftpSessionFactory.setFileType(FTP.BINARY_FILE_TYPE);
        return ftpSessionFactory;
    }

    @Bean
    public SessionFactory<FTPFile> backendStorageSessionFactory(SessionFactory<FTPFile> backendStorageFtpSessionFactory) {
        CachingSessionFactory<FTPFile> cachingSessionFactory = new CachingSessionFactory<>(backendStorageFtpSessionFactory);
        return cachingSessionFactory;
    }


    @Bean
    public FtpRemoteFileTemplate getBackendStorageFileTemplate(SessionFactory<FTPFile> backendStorageSessionFactory) {
        FtpRemoteFileTemplate ftpRemoteFileTemplate = new FtpRemoteFileTemplate(backendStorageSessionFactory);
        ftpRemoteFileTemplate.setExistsMode(FtpRemoteFileTemplate.ExistsMode.NLST);
        return ftpRemoteFileTemplate;
    }

    @Bean
    @ServiceActivator(inputChannel = "cloudInboxFiles", adviceChain = "ftpAdvice")
    public MessageHandler backendStorageHandler() {
        final String directoryExpressionString =
                "@backendStorageSettings.getBaseDirectory() + headers['" + FileHeaders.REMOTE_FILE + "'].replaceFirst('[^/]*$', '')";

        FtpMessageHandler handler = new FtpMessageHandler(ftpRemoteFileTemplate, FileExistsMode.FAIL);
        handler.setRemoteDirectoryExpressionString(directoryExpressionString);
        handler.setAutoCreateDirectory(true);
        handler.setFileNameGenerator(ftpFilenameGenerator);
        return handler;
    }

I see a lot of warnings in log:

19:13:37.917 [task-scheduler-1] DEBUG o.s.integration.util.SimplePool - Obtained org.springframework.integration.ftp.session.FtpSession@39516e57 from pool.
19:13:37.929 [task-scheduler-1] DEBUG o.s.integration.util.SimplePool - Obtained org.springframework.integration.ftp.session.FtpSession@687c02b5 from pool.
19:13:37.929 [task-scheduler-1] DEBUG o.s.integration.util.SimplePool - Received a stale item org.springframework.integration.ftp.session.FtpSession@687c02b5, will attempt to get a new one.
19:13:37.929 [task-scheduler-1] DEBUG o.s.integration.util.SimplePool - Removing org.springframework.integration.ftp.session.FtpSession@687c02b5 from the pool
19:13:37.929 [task-scheduler-1] WARN  o.s.i.ftp.session.FtpSession - failed to disconnect FTPClient
java.io.IOException: Connection is not open
	at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:514)
	at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:648)
	at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:622)
	at org.apache.commons.net.ftp.FTP.quit(FTP.java:904)
	at org.apache.commons.net.ftp.FTPClient.logout(FTPClient.java:1148)
	at org.springframework.integration.ftp.session.FtpSession.close(FtpSession.java:157)
	at org.springframework.integration.file.remote.session.CachingSessionFactory$1.removedFromPool(CachingSessionFactory.java:93)
	at org.springframework.integration.file.remote.session.CachingSessionFactory$1.removedFromPool(CachingSessionFactory.java:80)
	at org.springframework.integration.util.SimplePool.doRemoveItem(SimplePool.java:256)
	at org.springframework.integration.util.SimplePool.doGetItem(SimplePool.java:202)
	at org.springframework.integration.util.SimplePool.getItem(SimplePool.java:173)
	at org.springframework.integration.file.remote.session.CachingSessionFactory.getSession(CachingSessionFactory.java:132)
	at org.springframework.integration.file.remote.RemoteFileTemplate.execute(RemoteFileTemplate.java:432)
	at org.springframework.integration.ftp.session.FtpRemoteFileTemplate.doExecuteWithClient(FtpRemoteFileTemplate.java:68)
	at org.springframework.integration.ftp.session.FtpRemoteFileTemplate.exists(FtpRemoteFileTemplate.java:83)
	at org.springframework.integration.file.remote.RemoteFileTemplate.doSend(RemoteFileTemplate.java:574)
	at org.springframework.integration.file.remote.RemoteFileTemplate.sendFileToRemoteDirectory(RemoteFileTemplate.java:557)
	at org.springframework.integration.file.remote.RemoteFileTemplate.doSend(RemoteFileTemplate.java:337)
	at org.springframework.integration.file.remote.RemoteFileTemplate.lambda$send$0(RemoteFileTemplate.java:298)
	at org.springframework.integration.file.remote.RemoteFileTemplate.execute(RemoteFileTemplate.java:437)
	at org.springframework.integration.file.remote.RemoteFileTemplate.send(RemoteFileTemplate.java:298)
	at org.springframework.integration.file.remote.RemoteFileTemplate.send(RemoteFileTemplate.java:286)
	at org.springframework.integration.file.remote.RemoteFileTemplate.send(RemoteFileTemplate.java:278)
	at org.springframework.integration.file.remote.handler.FileTransferringMessageHandler.handleMessageInternal(FileTransferringMessageHandler.java:205)
	at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:170)
	at org.springframework.integration.handler.ReplyProducingMessageHandlerWrapper.handleRequestMessage(ReplyProducingMessageHandlerWrapper.java:49)
	at org.springframework.integration.handler.AbstractReplyProducingMessageHandler$AdvisedRequestHandler.handleRequestMessage(AbstractReplyProducingMessageHandler.java:201)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
	at org.springframework.integration.handler.advice.AbstractRequestHandlerAdvice$CallbackImpl.execute(AbstractRequestHandlerAdvice.java:151)
	at org.springframework.integration.handler.advice.ExpressionEvaluatingRequestHandlerAdvice.doInvoke(ExpressionEvaluatingRequestHandlerAdvice.java:237)
	at org.springframework.integration.handler.advice.AbstractRequestHandlerAdvice.invoke(AbstractRequestHandlerAdvice.java:67)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
	at com.sun.proxy.$Proxy84.handleRequestMessage(Unknown Source)
	at org.springframework.integration.handler.AbstractReplyProducingMessageHandler.doInvokeAdvisedRequestHandler(AbstractReplyProducingMessageHandler.java:146)
	at org.springframework.integration.handler.AbstractReplyProducingMessageHandler.handleMessageInternal(AbstractReplyProducingMessageHandler.java:130)
	at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:170)
	at org.springframework.integration.dispatcher.AbstractDispatcher.tryOptimizedDispatch(AbstractDispatcher.java:115)
	at org.springframework.integration.dispatcher.UnicastingDispatcher.doDispatch(UnicastingDispatcher.java:133)
	at org.springframework.integration.dispatcher.UnicastingDispatcher.dispatch(UnicastingDispatcher.java:106)
	at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:73)
	at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:453)
	at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:403)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:187)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:166)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:47)
	at org.springframework.messaging.core.AbstractMessageSendingTemplate.send(AbstractMessageSendingTemplate.java:109)
	at org.springframework.integration.handler.AbstractMessageProducingHandler.sendOutput(AbstractMessageProducingHandler.java:444)
	at org.springframework.integration.handler.AbstractMessageProducingHandler.doProduceOutput(AbstractMessageProducingHandler.java:318)
	at org.springframework.integration.handler.AbstractMessageProducingHandler.produceOutput(AbstractMessageProducingHandler.java:266)
	at org.springframework.integration.handler.AbstractMessageProducingHandler.sendOutputs(AbstractMessageProducingHandler.java:229)
	at org.springframework.integration.handler.AbstractReplyProducingMessageHandler.handleMessageInternal(AbstractReplyProducingMessageHandler.java:133)
	at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:170)
	at org.springframework.integration.dispatcher.AbstractDispatcher.tryOptimizedDispatch(AbstractDispatcher.java:115)
	at org.springframework.integration.dispatcher.UnicastingDispatcher.doDispatch(UnicastingDispatcher.java:133)
	at org.springframework.integration.dispatcher.UnicastingDispatcher.dispatch(UnicastingDispatcher.java:106)
	at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:73)
	at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:453)
	at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:403)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:187)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:166)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:47)
	at org.springframework.messaging.core.AbstractMessageSendingTemplate.send(AbstractMessageSendingTemplate.java:109)
	at org.springframework.integration.endpoint.SourcePollingChannelAdapter.handleMessage(SourcePollingChannelAdapter.java:234)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint.messageReceived(AbstractPollingEndpoint.java:396)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint.doPoll(AbstractPollingEndpoint.java:380)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint.pollForMessage(AbstractPollingEndpoint.java:328)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint.lambda$null$1(AbstractPollingEndpoint.java:275)
	at org.springframework.integration.util.ErrorHandlingTaskExecutor.lambda$execute$0(ErrorHandlingTaskExecutor.java:57)
	at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50)
	at org.springframework.integration.util.ErrorHandlingTaskExecutor.execute(ErrorHandlingTaskExecutor.java:55)
	at org.springframework.integration.endpoint.AbstractPollingEndpoint.lambda$createPoller$2(AbstractPollingEndpoint.java:272)
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
	at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:93)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
@artembilan
Copy link
Member

Hi, @urajio !

What is your concern here, please?

java.io.IOException: Connection is not open
	at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:514)
	at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:648)
	at org.apache.commons.net.ftp.FTP.sendCommand(FTP.java:622)
	at org.apache.commons.net.ftp.FTP.quit(FTP.java:904)
	at org.apache.commons.net.ftp.FTPClient.logout(FTPClient.java:1148)
	at org.springframework.integration.ftp.session.FtpSession.close(FtpSession.java:157)

So, it is an expected behavior when you try to logout from not connected FTP Client.
Our logic is like this:

	public void close() {
		try {
			if (this.readingRaw.get() && !finalizeRaw() && LOGGER.isWarnEnabled()) {
				LOGGER.warn("Finalize on readRaw() returned false for " + this);
			}
			this.client.logout();
			this.client.disconnect();
		}
		catch (Exception e) {
			LOGGER.warn("failed to disconnect FTPClient", e);
		}
	}

You can turn off that WARN using an appropriate logging system config.
you need this category to adjust logging level for FtpSession: org.springframework.integration.ftp.session.

So, from my perspective what you show us here is really an expected and correct behavior.

Thanks

@artembilan artembilan added the status: waiting-for-reporter Needs a feedback from the reporter label Dec 16, 2019
@urajio
Copy link
Author

urajio commented Dec 17, 2019

Yes, I can ignore all ftp session warning. But maybe you can not call logout() on a disconnected connection, and avoid this warning?

@artembilan
Copy link
Member

Yeah, good idea!
Feel free to contribute such a fix!
I’ll review and merge in the morning then.

@artembilan artembilan added in: ftp type: enhancement and removed status: waiting-for-reporter Needs a feedback from the reporter labels Dec 17, 2019
@artembilan artembilan added this to the 5.2.3 milestone Dec 17, 2019
@urajio urajio mentioned this issue Dec 17, 2019
Closed
@jonforums jonforums mentioned this issue Feb 5, 2020
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
in: ftp type: enhancement
Projects
None yet
Milestone
5.2.3
Development

No branches or pull requests
2 participants
@artembilan @urajio