Hi And does it work when you have stream download off also ?
On Sun, Sep 29, 2019 at 4:00 PM Peter Nowak <[email protected]> wrote: > > Hi guys, > > i think i found a bug in the "GenericFileRenameProcessStrategy" when > using the ftp component with the options "streamDownload=true" and > "move=testfolder". > > After successfully retrieving the stream, the rename command (and the > directory checks) is executed before the > "FTPClient.completePendingCommand()". The "PWD" command therefor > returns the line "226 Successfully transferred /demo/demofile.txt" but > expects the replycode "257" (complete response "257 "/" is current > directory") and now the following commands and their responses are all > mixed up and the renaming fails. I think it is a bug and the method > "FTPOperations.releaseRetrievedFileResources()" (which calls > "FTPClient.completePendingCommand()") should be called at the > beginning of "GenericFileRenameProcessStrategy.commit()" (like in the > "GenericFileDeleteProcessStrategy" line 64) instead of the end. > > WIthout the "streamDownload=true" option everything works fine, as the > "FTPClient._retrieveFile()" method calls the > "completePendingCommand()" directly after it finished downloading the > file. > > Tested version: 2.23.1 (and 2.24.2) > FTP Server: Filezilla 0.96.0 > Demoroute: > ************************************ > > from("ftp://demo@localhost/demo?password=demo&delay=120000" > + "&move=archive" > + "&antExclude=archive/**" > + "&disconnect=true" > + "&streamDownload=true") > .log("Consuming file") > .process(exchange -> { > System.out.println(exchange.getIn().getBody(String.class)); > }) > .end(); > > ***************************** > Log output: > **************************** > ... > 2019-09-29 15:36:10.739 INFO 13852 --- [ main] > o.a.camel.spring.SpringCamelContext : Route: route1 started and > consuming from: > ftp://demo@localhost/demo?antExclude=archive%2F**&delay=120000&disconnect=true&move=archive&password=xxxxxx&streamDownload=true > 2019-09-29 15:36:10.741 INFO 13852 --- [ main] > o.a.camel.spring.SpringCamelContext : Total 1 routes, of which 1 > are started > 2019-09-29 15:36:10.744 INFO 13852 --- [ main] > o.a.camel.spring.SpringCamelContext : Apache Camel 2.24.2 > (CamelContext: camel-1) started in 0.427 seconds > 2019-09-29 15:36:10.749 INFO 13852 --- [ main] > c.e.c.CamelFtpDemoApplication : Started > CamelFtpDemoApplication in 4.023 seconds (JVM running for 4.651) > 2019-09-29 15:36:11.774 INFO 13852 --- [@localhost/demo] route1 > : Consuming file > Hi, i am a demo file!!!! > 2019-09-29 15:36:11.789 WARN 13852 --- [@localhost/demo] > o.a.c.c.file.GenericFileOnCompletion : Error during commit. > Exchange[ID-peter-1569764169435-0-1]. Caused by: > [org.apache.camel.component.file.GenericFileOperationFailedException - > Cannot rename file: RemoteFile[demofile.txt] to: > RemoteFile[archive/demofile.txt]] > > org.apache.camel.component.file.GenericFileOperationFailedException: > Cannot rename file: RemoteFile[demofile.txt] to: > RemoteFile[archive/demofile.txt] > at > org.apache.camel.component.file.strategy.GenericFileProcessStrategySupport.renameFile(GenericFileProcessStrategySupport.java:130) > ~[camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.component.file.strategy.GenericFileRenameProcessStrategy.commit(GenericFileRenameProcessStrategy.java:111) > ~[camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.component.file.GenericFileOnCompletion.processStrategyCommit(GenericFileOnCompletion.java:127) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.component.file.GenericFileOnCompletion.onCompletion(GenericFileOnCompletion.java:83) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.component.file.GenericFileOnCompletion.onComplete(GenericFileOnCompletion.java:59) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.util.UnitOfWorkHelper.doneSynchronizations(UnitOfWorkHelper.java:104) > [camel-core-2.24.2.jar:2.24.2] > at org.apache.camel.impl.DefaultUnitOfWork.done(DefaultUnitOfWork.java:243) > [camel-core-2.24.2.jar:2.24.2] > at org.apache.camel.util.UnitOfWorkHelper.doneUow(UnitOfWorkHelper.java:65) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.processor.CamelInternalProcessor$UnitOfWorkProcessorAdvice.after(CamelInternalProcessor.java:685) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.processor.CamelInternalProcessor$UnitOfWorkProcessorAdvice.after(CamelInternalProcessor.java:634) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.processor.CamelInternalProcessor$InternalCallback.done(CamelInternalProcessor.java:251) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:183) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.component.file.GenericFileConsumer.processExchange(GenericFileConsumer.java:454) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.component.file.remote.RemoteFileConsumer.processExchange(RemoteFileConsumer.java:133) > [camel-ftp-2.24.2.jar:2.24.2] > at > org.apache.camel.component.file.GenericFileConsumer.processBatch(GenericFileConsumer.java:223) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:187) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.impl.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:174) > [camel-core-2.24.2.jar:2.24.2] > at > org.apache.camel.impl.ScheduledPollConsumer.run(ScheduledPollConsumer.java:101) > [camel-core-2.24.2.jar:2.24.2] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) > [na:1.8.0_202] > at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) > [na:1.8.0_202] > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) > [na:1.8.0_202] > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) > [na:1.8.0_202] > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) > [na:1.8.0_202] > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) > [na:1.8.0_202] > at java.lang.Thread.run(Thread.java:748) [na:1.8.0_202] > ... > *********************** > > Filezilla Server output: > ********************************** > (000010)29.09.2019 15:36:10 - (not logged in) (127.0.0.1)> Connected > on port 21, sending welcome message... > (000010)29.09.2019 15:36:10 - (not logged in) (127.0.0.1)> > 220-FileZilla Server 0.9.60 beta > (000010)29.09.2019 15:36:10 - (not logged in) (127.0.0.1)> 220-written > by Tim Kosse ([email protected]) > (000010)29.09.2019 15:36:10 - (not logged in) (127.0.0.1)> 220 Please > visit https://filezilla-project.org/ > (000010)29.09.2019 15:36:10 - (not logged in) (127.0.0.1)> USER demo > (000010)29.09.2019 15:36:10 - (not logged in) (127.0.0.1)> 331 > Password required for demo > (000010)29.09.2019 15:36:10 - (not logged in) (127.0.0.1)> PASS **** > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> 230 Logged on > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> TYPE A > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> 200 Type set to A > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> PWD > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> 257 "/" is current directory. > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> CWD demo > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> 250 CWD successful. > "/demo" is current directory. > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> CWD / > (000010)29.09.2019 15:36:10 - demo (127.0.0.1)> 250 CWD successful. > "/" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> NOOP > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 200 OK > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> PWD > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 257 "/" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> CWD demo > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 250 CWD successful. > "/demo" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> SYST > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 215 UNIX emulated by FileZilla > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> PORT 127,0,0,1,201,185 > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 200 Port command successful > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> LIST > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 150 Opening data > channel for directory listing of "/demo" > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 226 Successfully > transferred "/demo" > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> CWD / > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 250 CWD successful. > "/" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> PWD > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 257 "/" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> CWD demo > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 250 CWD successful. > "/demo" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> PORT 127,0,0,1,201,186 > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 200 Port command successful > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> RETR demofile.txt > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 150 Opening data > channel for file download from server of "/demo/demofile.txt" > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 226 Successfully > transferred "/demo/demofile.txt" > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> CWD / > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 250 CWD successful. > "/" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> PWD > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 257 "/" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> CWD demo > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 250 CWD successful. > "/demo" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> CWD archive > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 250 CWD successful. > "/demo/archive" is current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> DELE demofile.txt > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 550 File not found > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> PWD > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 257 "/demo/archive" is > current directory. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> CWD demo/archive > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 550 CWD failed. > "/demo/archive/demo/archive": directory not found. > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> RNFR demo/demofile.txt > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 550 file/directory not found > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> QUIT > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> 221 Goodbye > (000010)29.09.2019 15:36:11 - demo (127.0.0.1)> disconnected. > ********************************** > > Best regards, > Peter > -- > > Peter Nowak > Developer > > ecosio GmbH > Lange Gasse 30, 1080 Vienna, Austria/Europe > Mail: [email protected] > T: +43 1 996 2106-0, F: +43 1 996 2106-99 > UID: ATU68241501, FBNR: FN 405017 p, Handelsgericht Wien > Geschäftsführer: Christoph Ebm, Philipp Liegl, Marco Zapletal > Web: https://ecosio.com, Blog: https://ecosio.com/blog, Newsletter -- Claus Ibsen ----------------- http://davsclaus.com @davsclaus Camel in Action 2: https://www.manning.com/ibsen2
