Hi Claus,
Thank you for your help. I can't change anything on the other party's handling
and we don't have write access to the FTP server. I can certainly try to use
something like readLock=changed, readLockMinAge=300s to ensure a delay before
the route attempts to download the file. But surely this doesn't explain how
file content can be overwritten by other files?
Kind regards
Carsten Bülow
-----Oprindelig meddelelse-----
Fra: Claus Ibsen <claus.ib...@gmail.com>
Sendt: 5. juli 2021 12:20
Til: users@camel.apache.org
Emne: Re: Camel FTP bug? Filename used for another file
Hi
Okay if you attempt to download files while the other party uploads the files,
then you need to configure a read-locking strategy to avoid downloading files.
that are "being written".
There are several strategies for that, such as the other party write the files
using a temporary name, another folder, and then do a rename when the upload is
complete.
Or that they write a 2nd "done file" to mark the upload complete.
Otherwise you need to configure your ftp endpoint with a read locking (and for
FTP you dont have any 100% bulletproof strategy if so) and then you may need to
use the changed read lock which delays the download process as you need to
monitor the file for changes (and FTP servers may only have hour and minutes
for file stamp precision, and not include seconds, or that seconds are 00).
On Mon, Jul 5, 2021 at 11:53 AM Carsten Bulow
<carsten.bu...@process-factory.dk> wrote:
>
> Hi Claus,
>
> Thank you for your reply. Yes, there's only the one application with the
> route running, though there are separate test and production servers. Their
> configuration points to separate external FTP servers, matching the
> environment.
>
> I've changed the route to only start polling the FTP server in the morning
> (as the error seems to occur in the night when the supplier uploads the
> files) and we haven't experienced any issues since. Though this really only
> circumvents the problem.
>
> As far as I can see in any logs we haven't experienced it on the test server,
> save once. I've upgraded to Camel 3.11.0 and Spring Boot 2.5.2 and deployed
> it on test, though from what I can see of changelogs I don't really expect
> the FTP component to be changed between these releases.
>
>
> Kind regards
>
> Carsten Bülow
>
> -----Oprindelig meddelelse-----
> Fra: Claus Ibsen <claus.ib...@gmail.com>
> Sendt: 2. juli 2021 16:10
> Til: users@camel.apache.org
> Emne: Re: Camel FTP bug? Filename used for another file
>
> Hi
>
> This would be the first time I hear about this.
> Do you have only one active Camel application (node) that runs this route
> with the FTP consumer?
>
> If you can reproduce this on a test environment, then you are also welcome to
> try with Camel 3.11.0 release.
>
>
> On Thu, Jul 1, 2021 at 5:12 PM Carsten Bulow
> <carsten.bu...@process-factory.dk> wrote:
> >
> > Hi Camel team,
> >
> > I'm currently looking into a production issue we're having that has led to
> > data loss. I've tried searching for solutions but to no avail. In short,
> > what we're experiencing is that a Camel route downloads several files from
> > a FTPS server and saves them to a local file path. Some files are fine,
> > some files have had their content replaced by the content of another file.
> >
> > As an example, 3 files: Test1.xml, Test2.xml, Test3.xml. The content of
> > file Test3.xml has been replaced by the content of file Test1.xml.
> > Test1.xml and Test2.xml are unaffected. In my world this is a "should never
> > be able to happen"-error.
> >
> > The issue doesn't happen every day and I can see in our logs that the
> > retrieve file operations have failed on days with error in files. We're
> > getting read time out and cannot retrieve file exceptions, possible because
> > the supplier is currently writing to the file or having a file lock, I
> > don't know. My assumption is that the route will re-try to fetch the file
> > and somehow the active context filename of one filename is transferred into
> > another context (not sure of the inner workings) of another file leading to
> > using an incorrect filename. I don't have any idea how this can happen.
> >
> > We didn't use the fileExist option when writing the files because we know
> > the file supplier uses unique filenames but I made an immediate hotfix
> > adding fileExist=Move to the route so we'll at least have a backup.
> >
> > Any help with this issue will be appreciated.
> >
> >
> > Further details:
> > New application that has been running for two weeks before first issue.
> > We've had the issue on 4 separate occasions. We've been using older Camel
> > versions for almost a decade that has a similar route with no issues.
> > Camel 3.8.0
> > Spring Boot 2.4.2
> > Windows Server 2016, Java 8 (AdoptOpenJDK jdk-8.0.282.8)
> >
> >
> > The route, using Java DSL:
> > Sort the files on the FTPS server, download each file, save file in an
> > archive folder by date and then in a different folder for further handling.
> >
> > from(uri)
> > .routeId("consume-ftp")
> > .setHeader("direction", simple("inbound"))
> > .log(LoggingLevel.DEBUG, "route.ftp-download", "Retrieving file
> > from FTP: ${file:name}")
> > .toD(file:// + configuration.getArchiveInbound() +
> > "/${date:now:yyyy-MM-dd}?flatten=true")
> > .to(file:// + configuration.getInbound() + "?flatten=true")
> > .log(LoggingLevel.INFO, "route.ftp-download", "Inbound file
> > archived and sent to handling: ${file:name}");
> >
> > where,
> > String uri = "ftps://example.com:1234/download?username=user&password=pw" +
> > "&ftpClient.keyStore.file=filepath" +
> > "&ftpClient.keyStore.password=pw" +
> > "&ftpClient.keyStore.keyPassword=pw" +
> > "&delete=true" +
> > "&include=.*\\.xml\\Z" +
> > "&passiveMode=true" +
> > "&binary=true" +
> > "&stepwise=false" +
> > "&autoCreate=false" +
> > "&disconnect=true" +
> > "&maxMessagesPerPoll=100" +
> > "&maximumReconnectAttempts=3" +
> > "&reconnectDelay=600000" +
> > "&scheduler=quartz" +
> > "&scheduler.cron=0 0/30 * * * ?" +
> > "&localWorkDirectory=localpath" +
> > "&preSort=true" +
> > "&sorter=#fileSorter";
> >
> > I don't know why maximumReconnectAttempts and reconnectDelay were added and
> > they might be related to the issue since they could keep a filename in
> > memory. I have now removed those two and added fileExist and moveExisting
> > to the two producers to avoid losing data.
> >
> >
> > Logs:
> > The handling of the below logs has led to:
> > The content of Test11.xml has been replaced by Test6.xml The content
> > of Test13.xml has been replaced by Test11.xml The content of
> > Test14.xml has been replaced by Test12.xml
> >
> > I did a bit of cleanup to avoid too much repetition:
> >
> > 2021-06-17 01:30:00,015 [DEBUG]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.RemoteFileConsumer.connectIf
> > Ne
> > cessary]: Exception checking connection status: File operation failed:
> > null Connection is not open. Code: 221
> > 2021-06-17 01:30:00,015 [DEBUG]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.RemoteFileConsumer.connectIf
> > Ne
> > cessary]: Not connected/logged in, connecting to:
> > ftps://u...@example.com:1234
> > 2021-06-17 01:30:09,312 [DEBUG]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.RemoteFileConsumer.connectIf
> > Ne
> > cessary]: Connected and logged in to: ftps://u...@example.com:1234
> > 2021-06-17 01:30:09,577 [WARN ] (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error processing
> > file RemoteFile[Test1.xml] due to File operation failed: 150 File status
> > okay; about to open data connection.
> > Couldn't kickstart handshaking. Code: 150. Caused by:
> > [org.apache.camel.component.file.GenericFileOperationFailedException - File
> > operation failed: 150 File status okay; about to open data connection.
> > Couldn't kickstart handshaking. Code: 150]
> > org.apache.camel.component.file.GenericFileOperationFailedException: File
> > operation failed: 150 File status okay; about to open data connection.
> > Couldn't kickstart handshaking. Code: 150
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFileToFileInLocalWorkDirectory(FtpOperations.java:629)
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFile(FtpOperations.java:416)
> > at
> > org.apache.camel.component.file.GenericFileConsumer.processExchange(GenericFileConsumer.java:435)
> > at
> > org.apache.camel.component.file.remote.RemoteFileConsumer.processExchange(RemoteFileConsumer.java:147)
> > at
> > org.apache.camel.component.file.GenericFileConsumer.processBatch(GenericFileConsumer.java:240)
> > at
> > org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:201)
> > at
> > org.apache.camel.support.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:190)
> > at
> > org.apache.camel.support.ScheduledPollConsumer.run(ScheduledPollConsumer.java:107)
> > at
> > org.apache.camel.pollconsumer.quartz.QuartzScheduledPollConsumerJob.execute(QuartzScheduledPollConsumerJob.java:61)
> > at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.
> > ja
> > va:573) Caused by: javax.net.ssl.SSLException: Couldn't kickstart
> > handshaking
> > at sun.security.ssl.Alert.createSSLException(Alert.java:127)
> > at
> > sun.security.ssl.TransportContext.fatal(TransportContext.java:324)
> > at
> > sun.security.ssl.TransportContext.fatal(TransportContext.java:267)
> > at
> > sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:397)
> > at
> > org.apache.commons.net.ftp.FTPSClient._openDataConnection_(FTPSClient.java:641)
> > at
> > org.apache.commons.net.ftp.FTPClient._retrieveFile(FTPClient.java:1896)
> > at
> > org.apache.commons.net.ftp.FTPClient.retrieveFile(FTPClient.java:1882)
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFileToFileInLocalWorkDirectory(FtpOperations.java:602)
> > ... 10 common frames omitted
> > Suppressed: java.net.SocketException: Connection reset by peer:
> > socket write error
> > at java.net.SocketOutputStream.socketWrite0(Native Method)
> > at
> > java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
> > at
> > java.net.SocketOutputStream.write(SocketOutputStream.java:155)
> > at
> > sun.security.ssl.SSLSocketOutputRecord.encodeAlert(SSLSocketOutputRecord.java:81)
> > at
> > sun.security.ssl.TransportContext.fatal(TransportContext.java:355)
> > ... 16 common frames omitted Caused by:
> > java.net.SocketException: Connection reset by peer: socket write error
> > at java.net.SocketOutputStream.socketWrite0(Native Method)
> > at
> > java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
> > at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
> > at
> > sun.security.ssl.SSLSocketOutputRecord.flush(SSLSocketOutputRecord.java:251)
> > at
> > sun.security.ssl.HandshakeOutStream.flush(HandshakeOutStream.java:89)
> > at
> > sun.security.ssl.ClientHello$ClientHelloKickstartProducer.produce(ClientHello.java:580)
> > at sun.security.ssl.SSLHandshake.kickstart(SSLHandshake.java:500)
> > at
> > sun.security.ssl.ClientHandshakeContext.kickstart(ClientHandshakeContext.java:107)
> > at
> > sun.security.ssl.TransportContext.kickstart(TransportContext.java:231)
> > at
> > sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:387)
> > ... 14 common frames omitted
> > 2021-06-17 01:35:09,577 [WARN ] (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error processing
> > file RemoteFile[Test2.xml] due to File operation failed: Read timed out.
> > Code: 150.
> > org.apache.camel.component.file.GenericFileOperationFailedException: File
> > operation failed: Read timed out. Code: 150
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFileToFileInLocalWorkDirectory(FtpOperations.java:629)
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFile(FtpOperations.java:416)
> > at
> > org.apache.camel.component.file.GenericFileConsumer.processExchange(GenericFileConsumer.java:435)
> > at
> > org.apache.camel.component.file.remote.RemoteFileConsumer.processExchange(RemoteFileConsumer.java:147)
> > at
> > org.apache.camel.component.file.GenericFileConsumer.processBatch(GenericFileConsumer.java:240)
> > at
> > org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:201)
> > at
> > org.apache.camel.support.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:190)
> > at
> > org.apache.camel.support.ScheduledPollConsumer.run(ScheduledPollConsumer.java:107)
> > at
> > org.apache.camel.pollconsumer.quartz.QuartzScheduledPollConsumerJob.execute(QuartzScheduledPollConsumerJob.java:61)
> > at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.
> > ja
> > va:573) Caused by: java.net.SocketTimeoutException: Read timed out
> > at java.net.SocketInputStream.socketRead0(Native Method)
> > at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
> > at java.net.SocketInputStream.read(SocketInputStream.java:171)
> > at java.net.SocketInputStream.read(SocketInputStream.java:141)
> > at
> > sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:457)
> > at
> > sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68)
> > at
> > sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1095)
> > at sun.security.ssl.SSLSocketImpl.access$200(SSLSocketImpl.java:72)
> > at
> > sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:815)
> > at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
> > at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
> > at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
> > at java.io.InputStreamReader.read(InputStreamReader.java:184)
> > at java.io.BufferedReader.fill(BufferedReader.java:161)
> > at java.io.BufferedReader.readLine(BufferedReader.java:324)
> > at java.io.BufferedReader.readLine(BufferedReader.java:389)
> > at org.apache.commons.net.ftp.FTP.__getReply(ftp://FTP.java:320)
> > at org.apache.commons.net.ftp.FTP.__getReply(ftp://FTP.java:299)
> > at org.apache.commons.net.ftp.FTP.sendCommand(ftp://FTP.java:522)
> > at
> > org.apache.commons.net.ftp.FTPSClient.sendCommand(FTPSClient.java:563)
> > at org.apache.commons.net.ftp.FTP.sendCommand(ftp://FTP.java:644)
> > at org.apache.commons.net.ftp.FTP.sendCommand(ftp://FTP.java:618)
> > at org.apache.commons.net.ftp.FTP.pasv(ftp://FTP.java:1041)
> > at
> > org.apache.commons.net.ftp.FTPClient._openDataConnection_(FTPClient.java:896)
> > at
> > org.apache.commons.net.ftp.FTPSClient._openDataConnection_(FTPSClient.java:622)
> > at
> > org.apache.commons.net.ftp.FTPClient._retrieveFile(FTPClient.java:1896)
> > at
> > org.apache.commons.net.ftp.FTPClient.retrieveFile(FTPClient.java:1882)
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFileToFileInLocalWorkDirectory(FtpOperations.java:602)
> > ... 10 common frames omitted
> > 2021-06-17 01:40:09,577 [WARN ] (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error processing
> > file RemoteFile[Test3.xml] due to File operation failed: Read timed out.
> > Code: 150.
> > org.apache.camel.component.file.GenericFileOperationFailedException: File
> > operation failed: Read timed out. Code: 150
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFileToFileInLocalWorkDirectory(FtpOperations.java:629)
> > ...
> > 2021-06-17 01:40:09,671 [WARN ]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error
> > processing file RemoteFile[Test4.xml] due to Cannot retrieve file
> > org.apache.camel.component.file.GenericFileOperationFailedException: Cannot
> > retrieve file: RemoteFile[Test4.xml] from: ftps://example.com:1234...
> > at
> > org.apache.camel.component.file.GenericFileConsumer.processExchange(GenericFileConsumer.java:457)
> > at
> > org.apache.camel.component.file.remote.RemoteFileConsumer.processExchange(RemoteFileConsumer.java:147)
> > at
> > org.apache.camel.component.file.GenericFileConsumer.processBatch(GenericFileConsumer.java:240)
> > at
> > org.apache.camel.component.file.GenericFileConsumer.poll(GenericFileConsumer.java:201)
> > at
> > org.apache.camel.support.ScheduledPollConsumer.doRun(ScheduledPollConsumer.java:190)
> > at
> > org.apache.camel.support.ScheduledPollConsumer.run(ScheduledPollConsumer.java:107)
> > at
> > org.apache.camel.pollconsumer.quartz.QuartzScheduledPollConsumerJob.execute(QuartzScheduledPollConsumerJob.java:61)
> > at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> > at
> > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.
> > ja
> > va:573)
> > 2021-06-17 01:40:12,718 [WARN ]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error
> > processing file RemoteFile[Test5.xml] due to Cannot retrieve file
> > org.apache.camel.component.file.GenericFileOperationFailedException: Cannot
> > retrieve file: RemoteFile[Test5.xml] from: ftps://example.com:1234...
> > ...
> > 2021-06-17 01:40:12,718 [WARN ]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error
> > processing file RemoteFile[Test6.xml] due to Cannot retrieve file
> > org.apache.camel.component.file.GenericFileOperationFailedException: Cannot
> > retrieve file: RemoteFile[Test6.xml] from: ftps://example.com:1234...
> > ...
> > 2021-06-17 01:40:12,734 [WARN ]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error
> > processing file RemoteFile[Test7.xml] due to Cannot retrieve file
> > org.apache.camel.component.file.GenericFileOperationFailedException: Cannot
> > retrieve file: RemoteFile[Test7.xml] from: ftps://example.com:1234...
> > ...
> > 2021-06-17 01:45:12,749 [WARN ] (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error processing
> > file RemoteFile[Test8.xml] due to File operation failed: Read timed out.
> > Code: 150.
> > org.apache.camel.component.file.GenericFileOperationFailedException: File
> > operation failed: Read timed out. Code: 150
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFileToFileInLocalWorkDirectory(FtpOperations.java:629)
> > ...
> > 2021-06-17 01:50:12,749 [WARN ] (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error processing
> > file RemoteFile[Test9.xml] due to File operation failed: Read timed out.
> > Code: 150.
> > org.apache.camel.component.file.GenericFileOperationFailedException: File
> > operation failed: Read timed out. Code: 150
> > at
> > org.apache.camel.component.file.remote.FtpOperations.retrieveFileToFileInLocalWorkDirectory(FtpOperations.java:629)
> > ...
> > 2021-06-17 01:50:12,827 [WARN ]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error
> > processing file RemoteFile[Test10.xml] due to Cannot retrieve file
> > org.apache.camel.component.file.GenericFileOperationFailedException: Cannot
> > retrieve file: RemoteFile[Test10.xml] from: ftps://example.com:1234...
> > at
> > org.apache.camel.component.file.GenericFileConsumer.processExchange(GenericFileConsumer.java:457)
> > ...
> > 2021-06-17 01:50:22,030 [DEBUG]
> > (DefaultQuartzScheduler-camel-1_Worker-1) [route.ftp-download]:
> > Retrieving file from FTP: Test11.xml
> > 2021-06-17 01:50:22,046 [INFO ]
> > (DefaultQuartzScheduler-camel-1_Worker-1) [route.ftp-download]:
> > Inbound file archived and sent to handling: Test11.xml
> > 2021-06-17 01:50:22,187 [WARN ]
> > (DefaultQuartzScheduler-camel-1_Worker-1)
> > [org.apache.camel.component.file.remote.FtpConsumer.log]: Error
> > processing file RemoteFile[Test12.xml] due to Cannot retrieve file
> > org.apache.camel.component.file.GenericFileOperationFailedException: Cannot
> > retrieve file: RemoteFile[Test12.xml] from: ftps://example.com:1234...
> > at
> > org.apache.camel.component.file.GenericFileConsumer.processExchange(GenericFileConsumer.java:457)
> > ...
> > 2021-06-17 01:50:22,359 [DEBUG]
> > (DefaultQuartzScheduler-camel-1_Worker-1) [route.ftp-download]:
> > Retrieving file from FTP: Test13.xml.xml
> > 2021-06-17 01:50:22,359 [INFO ]
> > (DefaultQuartzScheduler-camel-1_Worker-1) [route.ftp-download]:
> > Inbound file archived and sent to handling: Test13.xml.xml
> > 2021-06-17 01:50:22,531 [DEBUG]
> > (DefaultQuartzScheduler-camel-1_Worker-1) [route.ftp-download]:
> > Retrieving file from FTP: Test14.xml
> > 2021-06-17 01:50:22,531 [INFO ]
> > (DefaultQuartzScheduler-camel-1_Worker-1) [route.ftp-download]:
> > Inbound file archived and sent to handling: Test14.xml
> >
> >
> >
> > Kind regards
> >
> > Carsten Bülow
>
>
>
> --
> Claus Ibsen
> -----------------
> http://davsclaus.com @davsclaus
> Camel in Action 2: https://www.manning.com/ibsen2
--
Claus Ibsen
-----------------
http://davsclaus.com @davsclaus
Camel in Action 2: https://www.manning.com/ibsen2
