You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by Ralf Steppacher <ra...@derivativepartners.com> on 2012/08/15 18:07:58 UTC

FTP2 - readlock and lastmodified timestamps

Hello all,

I am having a problem with FTP2 and the lastmodified timestamps it
reports. I download files from an FTP site where an external data
provider places a set of files under the same name every 15 minutes. I
use the "changed" readlock strategy to avoid downloading files that are
currently written.
The log excerpt below shows the download of one of these files. The long
representing the lastmodified timestamp during lock-acquire is
1345019400000 (-> Wed 15 Aug 2012 10:30:00 AM CEST GMT+2). But if you
look at the last line, then Camel reports a lastmodified timestamp of
2012-08-15 10:15:00.
That last line is produced with this XML snippet:

<camel:from ref="ftp1" />
<camel:log message="Processing file ${in.headers.CamelFileName}, last
modified at ${date:file:yyyy-MM-dd HH:mm:ss}" loggingLevel="INFO"
logName="route_morningstar_fileProcessor_1" />

The download starts at 10:30. The file is expected to be replaced at
around that time. The new/latest file should have the timestamp at
10:30, as the readlock output suggests. I know that the lastmodified
timestamp reported by ${date:file:yyyy-MM-dd HH:mm:ss} is wrong because
the content is timestamped data and those timestamps are mostly 14
minutes and 50+ seconds into the future.

I rely on an accurate file modification timestamp in my downstream data
processing. 
This is reproducible with Camel 2.8.4 and 2.9.2.


Ralf


2012-08-15 10:30:09,326 TRACE
org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous last modified: -9223372036854775808, new last modified: 1345019400000
2012-08-15 10:30:09,326 TRACE
org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous length: -9223372036854775808, new length: 11182
2012-08-15 10:30:09,326 TRACE
org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Exclusive read lock not granted. Sleeping for 5000 millis.
2012-08-15 10:30:14,607 TRACE
org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous last modified: 1345019400000, new last modified: 1345019400000
2012-08-15 10:30:14,607 TRACE
org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous length: 11182, new length: 11182
2012-08-15 10:30:14,607 TRACE
org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Read lock acquired.
2012-08-15 10:30:14,607 TRACE
org.apache.camel.component.file.remote.FtpConsumer - Retrieving file:
DP_EUROPE-15082012.csv from:
Endpoint[ftp://user@ip/?binary=true&delay=3600000&disconnect=true&filter=%23tenforeFTPFilter3&idempotent=false&localWorkDirectory=c%3A%2Ftmp%2Fampa%2Fftp_tmp&password=******&readLock=changed&readLockTimeout=120000]
[-- snip --]
2012-08-15 10:30:14,982 TRACE
org.apache.camel.component.file.remote.FtpConsumer - Retrieved file:
DP_EUROPE-15082012.csv from: 
[-- snip --]
2012-08-15 10:30:14,982 INFO  route_morningstar_fileProcessor_3 -
Processing file DP_EUROPE-15082012.csv, last modified at 2012-08-15
10:15:00


Re: FTP2 - readlock and lastmodified timestamps

Posted by Ralf Steppacher <ra...@derivativepartners.com>.
Thank you very much for both the improvement ticket (and its resolution)
and the hint about the read lock interval. I shall try that.


-----Original Message-----
From: Claus Ibsen <cl...@gmail.com>
Reply-to: users@camel.apache.org
To: users@camel.apache.org
Subject: Re: FTP2 - readlock and lastmodified timestamps
Date: Thu, 16 Aug 2012 09:54:53 +0200

Hi

I dont think the timestamp and file size is absolutely accurate when
using the FTP client. I have seen in the past clients return seconds
always as 00.

The API in the FTP clients that Camel uses have been improved, and now
offers a specific getModificationTime method, we may try to alter the
Camel code to use that instead of the current logic which is doing a
LS again.

I logged a ticket about that
https://issues.apache.org/jira/browse/CAMEL-5512

You may try to increase the read lock interval option (readLockCheckInterval)
http://camel.apache.org/file2.html




On Wed, Aug 15, 2012 at 6:07 PM, Ralf Steppacher
<ra...@derivativepartners.com> wrote:
> Hello all,
>
> I am having a problem with FTP2 and the lastmodified timestamps it
> reports. I download files from an FTP site where an external data
> provider places a set of files under the same name every 15 minutes. I
> use the "changed" readlock strategy to avoid downloading files that are
> currently written.
> The log excerpt below shows the download of one of these files. The long
> representing the lastmodified timestamp during lock-acquire is
> 1345019400000 (-> Wed 15 Aug 2012 10:30:00 AM CEST GMT+2). But if you
> look at the last line, then Camel reports a lastmodified timestamp of
> 2012-08-15 10:15:00.
> That last line is produced with this XML snippet:
>
> <camel:from ref="ftp1" />
> <camel:log message="Processing file ${in.headers.CamelFileName}, last
> modified at ${date:file:yyyy-MM-dd HH:mm:ss}" loggingLevel="INFO"
> logName="route_morningstar_fileProcessor_1" />
>
> The download starts at 10:30. The file is expected to be replaced at
> around that time. The new/latest file should have the timestamp at
> 10:30, as the readlock output suggests. I know that the lastmodified
> timestamp reported by ${date:file:yyyy-MM-dd HH:mm:ss} is wrong because
> the content is timestamped data and those timestamps are mostly 14
> minutes and 50+ seconds into the future.
>
> I rely on an accurate file modification timestamp in my downstream data
> processing.
> This is reproducible with Camel 2.8.4 and 2.9.2.
>
>
> Ralf
>
>
> 2012-08-15 10:30:09,326 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous last modified: -9223372036854775808, new last modified: 1345019400000
> 2012-08-15 10:30:09,326 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous length: -9223372036854775808, new length: 11182
> 2012-08-15 10:30:09,326 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Exclusive read lock not granted. Sleeping for 5000 millis.
> 2012-08-15 10:30:14,607 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous last modified: 1345019400000, new last modified: 1345019400000
> 2012-08-15 10:30:14,607 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous length: 11182, new length: 11182
> 2012-08-15 10:30:14,607 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Read lock acquired.
> 2012-08-15 10:30:14,607 TRACE
> org.apache.camel.component.file.remote.FtpConsumer - Retrieving file:
> DP_EUROPE-15082012.csv from:
> Endpoint[ftp://user@ip/?binary=true&delay=3600000&disconnect=true&filter=%23tenforeFTPFilter3&idempotent=false&localWorkDirectory=c%3A%2Ftmp%2Fampa%2Fftp_tmp&password=******&readLock=changed&readLockTimeout=120000]
> [-- snip --]
> 2012-08-15 10:30:14,982 TRACE
> org.apache.camel.component.file.remote.FtpConsumer - Retrieved file:
> DP_EUROPE-15082012.csv from:
> [-- snip --]
> 2012-08-15 10:30:14,982 INFO  route_morningstar_fileProcessor_3 -
> Processing file DP_EUROPE-15082012.csv, last modified at 2012-08-15
> 10:15:00
>




Re: FTP2 - readlock and lastmodified timestamps

Posted by Claus Ibsen <cl...@gmail.com>.
Hi

I dont think the timestamp and file size is absolutely accurate when
using the FTP client. I have seen in the past clients return seconds
always as 00.

The API in the FTP clients that Camel uses have been improved, and now
offers a specific getModificationTime method, we may try to alter the
Camel code to use that instead of the current logic which is doing a
LS again.

I logged a ticket about that
https://issues.apache.org/jira/browse/CAMEL-5512

You may try to increase the read lock interval option (readLockCheckInterval)
http://camel.apache.org/file2.html




On Wed, Aug 15, 2012 at 6:07 PM, Ralf Steppacher
<ra...@derivativepartners.com> wrote:
> Hello all,
>
> I am having a problem with FTP2 and the lastmodified timestamps it
> reports. I download files from an FTP site where an external data
> provider places a set of files under the same name every 15 minutes. I
> use the "changed" readlock strategy to avoid downloading files that are
> currently written.
> The log excerpt below shows the download of one of these files. The long
> representing the lastmodified timestamp during lock-acquire is
> 1345019400000 (-> Wed 15 Aug 2012 10:30:00 AM CEST GMT+2). But if you
> look at the last line, then Camel reports a lastmodified timestamp of
> 2012-08-15 10:15:00.
> That last line is produced with this XML snippet:
>
> <camel:from ref="ftp1" />
> <camel:log message="Processing file ${in.headers.CamelFileName}, last
> modified at ${date:file:yyyy-MM-dd HH:mm:ss}" loggingLevel="INFO"
> logName="route_morningstar_fileProcessor_1" />
>
> The download starts at 10:30. The file is expected to be replaced at
> around that time. The new/latest file should have the timestamp at
> 10:30, as the readlock output suggests. I know that the lastmodified
> timestamp reported by ${date:file:yyyy-MM-dd HH:mm:ss} is wrong because
> the content is timestamped data and those timestamps are mostly 14
> minutes and 50+ seconds into the future.
>
> I rely on an accurate file modification timestamp in my downstream data
> processing.
> This is reproducible with Camel 2.8.4 and 2.9.2.
>
>
> Ralf
>
>
> 2012-08-15 10:30:09,326 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous last modified: -9223372036854775808, new last modified: 1345019400000
> 2012-08-15 10:30:09,326 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous length: -9223372036854775808, new length: 11182
> 2012-08-15 10:30:09,326 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Exclusive read lock not granted. Sleeping for 5000 millis.
> 2012-08-15 10:30:14,607 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous last modified: 1345019400000, new last modified: 1345019400000
> 2012-08-15 10:30:14,607 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Previous length: 11182, new length: 11182
> 2012-08-15 10:30:14,607 TRACE
> org.apache.camel.component.file.remote.strategy.FtpChangedExclusiveReadLockStrategy - Read lock acquired.
> 2012-08-15 10:30:14,607 TRACE
> org.apache.camel.component.file.remote.FtpConsumer - Retrieving file:
> DP_EUROPE-15082012.csv from:
> Endpoint[ftp://user@ip/?binary=true&delay=3600000&disconnect=true&filter=%23tenforeFTPFilter3&idempotent=false&localWorkDirectory=c%3A%2Ftmp%2Fampa%2Fftp_tmp&password=******&readLock=changed&readLockTimeout=120000]
> [-- snip --]
> 2012-08-15 10:30:14,982 TRACE
> org.apache.camel.component.file.remote.FtpConsumer - Retrieved file:
> DP_EUROPE-15082012.csv from:
> [-- snip --]
> 2012-08-15 10:30:14,982 INFO  route_morningstar_fileProcessor_3 -
> Processing file DP_EUROPE-15082012.csv, last modified at 2012-08-15
> 10:15:00
>



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