10865 Wrong modified times on FTP

[chrisjj]

My syncs to an IPOWER FTP server are messed-up by the failure of copied files to show the same timestamp despite '[X] Preserve timestamps on upload' e.g.

http://img40.imageshack.us/img40/892/picdj.th.png (http://img40.imageshack.us/img40/892/picdj.png)

Any fix?

[Aaron]

Hello Chris,

Timestamp setting is ultimately controlled by the FTP server. If it does not support the feature, or your user does not have access, then we cannot preserve the timestamp.

Can you manually Touch the files after the transfer? Or does that also fail?

We also include the option "Touch local files after upload" to workaround any potential server issues:
http://www.scootersoftware.com/support.php?zz=kb_ftpdifferent.php

[Craig]

Post a log showing the the connection and an attempt to upload a file. What's shown in your screenshot does include the MFMT command, so BC should be able to set the timestamps.

[chrisjj]

> Timestamp setting is ultimately controlled by the FTP server. If it does not
> support the feature, or your user does not have access, then we cannot
> preserve the timestamp.

BC3 is setting the timestamp. Just that it is then displaying a value different to the original.

> Can you manually Touch the files after the transfer?

Yes.

> Or does that also fail?

No - the shows the requested time.

> We also include the option "Touch local files after upload"
> to workaround any potential server issues:

Thanks, but that's a) unavailable when the source files are on read-only media b) unacceptable because e.g. it messes-up sync to a second server.

[chrisjj]

> Post a log showing the the connection and an attempt to upload a file.

See circumvention of forum limit, following.

> What's shown in your screenshot does include the MFMT
> command, so BC should be able to set the timestamps.

Thanks. BC is setting the timestamps, and maybe to the the right correct. Just the values it is displaying (and sync is working by) are not correct.

[chrisjj]

Part 1 of 2:

2009-11-03 19:55:55 Username: OWNER-ZBB5FTV33\Chris
2009-11-03 19:55:56 Stat> Connected.
2009-11-03 19:55:56 Recv> 220-
2009-11-03 19:55:56 Recv> 220 IPOWER FTP Server ready
2009-11-03 19:55:56 Sent> USER djcjj
2009-11-03 19:55:56 Recv> 331 Password required for djcjj
2009-11-03 19:55:56 Sent> PASS ********
2009-11-03 19:55:56 Recv> 230 User djcjj logged in
2009-11-03 19:55:56 Sent> FEAT
2009-11-03 19:55:56 Recv> 211-Features:
2009-11-03 19:55:56 MDTM
2009-11-03 19:55:56 MFMT
2009-11-03 19:55:56 MFF modify;UNIX.group;UNIX.mode;
2009-11-03 19:55:56 MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX .mode*;UNIX.owner*;
2009-11-03 19:55:56 REST STREAM
2009-11-03 19:55:56 SIZE
2009-11-03 19:55:57 Recv> 211 End
2009-11-03 19:55:57 Sent> TYPE I
2009-11-03 19:55:57 Recv> 200 Type set to I
2009-11-03 19:55:57 Sent> SYST
2009-11-03 19:55:57 Recv> 215 UNIX Type: L8
2009-11-03 19:55:57 Sent> PWD
2009-11-03 19:55:57 Recv> 257 "/" is the current directory
2009-11-03 19:55:57 Sent> REST 1
2009-11-03 19:55:57 Recv> 350 Restarting at 1. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:55:57 Sent> REST 0
2009-11-03 19:55:57 Recv> 350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:55:57 Sent> CWD /FromC
2009-11-03 19:55:58 Recv> 250 CWD command successful
2009-11-03 19:55:58 Sent> TYPE A
2009-11-03 19:55:58 Recv> 200 Type set to A
2009-11-03 19:55:58 Sent> PASV
2009-11-03 19:55:58 Recv> 227 Entering Passive Mode (66,96,131,6,140,68)
2009-11-03 19:55:58 Sent> LIST
2009-11-03 19:55:58 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:55:59 Recv> 226 Transfer complete
2009-11-03 19:55:59 Load comparison: S:\TLIB <-> ftp://djcjj@tangodc.com/FromC
2009-11-03 19:55:59 Sent> CWD /FromC/00008637211721
2009-11-03 19:55:59 Stat> Connected.
2009-11-03 19:55:59 Stat> Connected.
2009-11-03 19:55:59 Stat> Connected.
2009-11-03 19:55:59 Recv> 250 CWD command successful
2009-11-03 19:55:59 Sent> PASV
2009-11-03 19:55:59 Stat> Connected.
2009-11-03 19:55:59 Recv> 220-
2009-11-03 19:55:59 Recv> 220-
2009-11-03 19:55:59 Recv> 220-
2009-11-03 19:55:59 Recv> 220-
2009-11-03 19:55:59 Recv> 227 Entering Passive Mode (66,96,131,6,169,84)
2009-11-03 19:56:00 Sent> LIST
2009-11-03 19:56:00 Recv> 220 IPOWER FTP Server ready
2009-11-03 19:56:00 Recv> 220 IPOWER FTP Server ready
2009-11-03 19:56:00 Sent> USER djcjj
2009-11-03 19:56:00 Sent> USER djcjj
2009-11-03 19:56:00 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:00 Recv> 220 IPOWER FTP Server ready
2009-11-03 19:56:00 Sent> USER djcjj
2009-11-03 19:56:00 Recv> 220 IPOWER FTP Server ready
2009-11-03 19:56:00 Sent> USER djcjj
2009-11-03 19:56:00 Recv> 331 Password required for djcjj
2009-11-03 19:56:00 Recv> 331 Password required for djcjj
2009-11-03 19:56:00 Sent> PASS ********
2009-11-03 19:56:00 Sent> PASS ********
2009-11-03 19:56:00 Recv> 331 Password required for djcjj
2009-11-03 19:56:00 Sent> PASS ********
2009-11-03 19:56:00 Recv> 331 Password required for djcjj
2009-11-03 19:56:00 Sent> PASS ********
2009-11-03 19:56:00 Recv> 230 User djcjj logged in
2009-11-03 19:56:00 Sent> FEAT
2009-11-03 19:56:00 Recv> 230 User djcjj logged in
2009-11-03 19:56:00 Sent> FEAT
2009-11-03 19:56:00 Recv> 211-Features:
2009-11-03 19:56:00 MDTM
2009-11-03 19:56:00 MFMT
2009-11-03 19:56:00 MFF modify;UNIX.group;UNIX.mode;
2009-11-03 19:56:00 MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX .mode*;UNIX.owner*;
2009-11-03 19:56:00 REST STREAM
2009-11-03 19:56:00 SIZE
2009-11-03 19:56:00 Recv> 226 Transfer complete
2009-11-03 19:56:00 Sent> CWD /FromC/02480001076026
2009-11-03 19:56:00 Recv> 230 User djcjj logged in
2009-11-03 19:56:00 Sent> FEAT
2009-11-03 19:56:00 Recv> 211-Features:
2009-11-03 19:56:00 MDTM
2009-11-03 19:56:00 MFMT
2009-11-03 19:56:00 MFF modify;UNIX.group;UNIX.mode;
2009-11-03 19:56:00 MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX .mode*;UNIX.owner*;
2009-11-03 19:56:00 REST STREAM
2009-11-03 19:56:00 SIZE
2009-11-03 19:56:00 Recv> 230 User djcjj logged in
2009-11-03 19:56:00 Sent> FEAT
2009-11-03 19:56:00 Recv> 250 CWD command successful
2009-11-03 19:56:00 Sent> PASV
2009-11-03 19:56:00 Recv> 211-Features:
2009-11-03 19:56:00 MDTM
2009-11-03 19:56:00 MFMT
2009-11-03 19:56:00 MFF modify;UNIX.group;UNIX.mode;
2009-11-03 19:56:00 MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX .mode*;UNIX.owner*;
2009-11-03 19:56:00 REST STREAM
2009-11-03 19:56:00 SIZE
2009-11-03 19:56:00 Recv> 211-Features:
2009-11-03 19:56:00 MDTM
2009-11-03 19:56:00 MFMT
2009-11-03 19:56:00 MFF modify;UNIX.group;UNIX.mode;
2009-11-03 19:56:00 MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX .mode*;UNIX.owner*;
2009-11-03 19:56:00 REST STREAM
2009-11-03 19:56:00 SIZE
2009-11-03 19:56:00 Recv> 211 End
2009-11-03 19:56:00 Recv> 211 End
2009-11-03 19:56:00 Sent> TYPE I
2009-11-03 19:56:00 Sent> TYPE I
2009-11-03 19:56:00 Recv> 211 End
2009-11-03 19:56:00 Recv> 211 End
2009-11-03 19:56:00 Sent> TYPE I
2009-11-03 19:56:00 Sent> TYPE I
2009-11-03 19:56:00 Recv> 227 Entering Passive Mode (66,96,131,6,207,72)
2009-11-03 19:56:00 Recv> 200 Type set to I
2009-11-03 19:56:00 Sent> SYST
2009-11-03 19:56:00 Recv> 200 Type set to I
2009-11-03 19:56:00 Sent> SYST

[chrisjj]

Part 2 of 2:


2009-11-03 19:56:01 Sent> LIST
2009-11-03 19:56:01 Recv> 200 Type set to I
2009-11-03 19:56:01 Recv> 215 UNIX Type: L8
2009-11-03 19:56:01 Sent> PWD
2009-11-03 19:56:01 Recv> 200 Type set to I
2009-11-03 19:56:01 Recv> 215 UNIX Type: L8
2009-11-03 19:56:01 Sent> SYST
2009-11-03 19:56:01 Sent> PWD
2009-11-03 19:56:01 Sent> SYST
2009-11-03 19:56:01 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:01 Recv> 215 UNIX Type: L8
2009-11-03 19:56:01 Recv> 257 "/" is the current directory
2009-11-03 19:56:01 Sent> REST 1
2009-11-03 19:56:01 Recv> 215 UNIX Type: L8
2009-11-03 19:56:01 Recv> 257 "/" is the current directory
2009-11-03 19:56:01 Sent> PWD
2009-11-03 19:56:01 Sent> REST 1
2009-11-03 19:56:01 Sent> PWD
2009-11-03 19:56:01 Recv> 350 Restarting at 1. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:56:01 Sent> REST 0
2009-11-03 19:56:01 Recv> 350 Restarting at 1. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:56:01 Recv> 257 "/" is the current directory
2009-11-03 19:56:01 Sent> REST 0
2009-11-03 19:56:01 Sent> REST 1
2009-11-03 19:56:01 Recv> 257 "/" is the current directory
2009-11-03 19:56:01 Sent> REST 1
2009-11-03 19:56:01 Recv> 350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:56:01 Sent> CWD /FromC/00828768502525
2009-11-03 19:56:01 Recv> 226 Transfer complete
2009-11-03 19:56:01 Sent> CWD /FromC/00008637211721/1
2009-11-03 19:56:01 Recv> 350 Restarting at 1. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:56:01 Sent> REST 0
2009-11-03 19:56:01 Recv> 350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:56:01 Sent> CWD /FromC/00828766032628
2009-11-03 19:56:01 Recv> 350 Restarting at 1. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:56:01 Sent> REST 0
2009-11-03 19:56:01 Recv> 250 CWD command successful
2009-11-03 19:56:01 Sent> TYPE A
2009-11-03 19:56:01 Recv> 350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:56:01 Recv> 250 CWD command successful
2009-11-03 19:56:01 Sent> CWD /FromC/02480001070727
2009-11-03 19:56:01 Sent> TYPE A
2009-11-03 19:56:01 Recv> 350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer
2009-11-03 19:56:01 Recv> 250 CWD command successful
2009-11-03 19:56:01 Sent> PASV
2009-11-03 19:56:01 Sent> CWD /FromC/02480001070529
2009-11-03 19:56:01 Recv> 200 Type set to A
2009-11-03 19:56:01 Sent> PASV
2009-11-03 19:56:01 Recv> 200 Type set to A
2009-11-03 19:56:01 Recv> 250 CWD command successful
2009-11-03 19:56:01 Sent> PASV
2009-11-03 19:56:01 Sent> TYPE A
2009-11-03 19:56:01 Recv> 250 CWD command successful
2009-11-03 19:56:01 Sent> TYPE A
2009-11-03 19:56:01 Recv> 200 Type set to A
2009-11-03 19:56:01 Sent> PASV
2009-11-03 19:56:01 Recv> 200 Type set to A
2009-11-03 19:56:01 Sent> PASV
2009-11-03 19:56:01 Recv> 227 Entering Passive Mode (66,96,131,6,127,208)
2009-11-03 19:56:02 Sent> LIST
2009-11-03 19:56:02 Recv> 227 Entering Passive Mode (66,96,131,6,211,32)
2009-11-03 19:56:02 Recv> 227 Entering Passive Mode (66,96,131,6,128,176)
2009-11-03 19:56:02 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:02 Sent> LIST
2009-11-03 19:56:02 Sent> LIST
2009-11-03 19:56:02 Recv> 227 Entering Passive Mode (66,96,131,6,129,68)
2009-11-03 19:56:02 Recv> 227 Entering Passive Mode (66,96,131,6,129,64)
2009-11-03 19:56:02 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:02 Sent> LIST
2009-11-03 19:56:02 Sent> LIST
2009-11-03 19:56:02 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:02 Recv> 226 Transfer complete
2009-11-03 19:56:02 Sent> CWD /FromC/02480001076026/1
2009-11-03 19:56:02 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:02 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:02 Recv> 250 CWD command successful
2009-11-03 19:56:02 Sent> PASV
2009-11-03 19:56:02 Recv> 226 Transfer complete
2009-11-03 19:56:02 Recv> 226 Transfer complete
2009-11-03 19:56:02 Sent> CWD /FromC/02480001076125
2009-11-03 19:56:02 Sent> CWD /FromC/00828766032628/1
2009-11-03 19:56:02 Recv> 226 Transfer complete
2009-11-03 19:56:02 Recv> 226 Transfer complete
2009-11-03 19:56:02 Sent> CWD /FromC/00828768502525/1
2009-11-03 19:56:02 Sent> CWD /FromC/02480001070727/1
2009-11-03 19:56:02 Recv> 250 CWD command successful
2009-11-03 19:56:02 Recv> 250 CWD command successful
2009-11-03 19:56:02 Sent> PASV
2009-11-03 19:56:02 Sent> PASV
2009-11-03 19:56:02 Recv> 250 CWD command successful
2009-11-03 19:56:02 Sent> PASV
2009-11-03 19:56:02 Recv> 250 CWD command successful
2009-11-03 19:56:02 Sent> PASV
2009-11-03 19:56:02 Recv> 227 Entering Passive Mode (66,96,131,6,204,4)
2009-11-03 19:56:03 Sent> LIST
2009-11-03 19:56:03 Recv> 227 Entering Passive Mode (66,96,131,6,135,168)
2009-11-03 19:56:03 Recv> 227 Entering Passive Mode (66,96,131,6,135,164)
2009-11-03 19:56:03 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:03 Sent> LIST
2009-11-03 19:56:03 Sent> LIST
2009-11-03 19:56:03 Recv> 227 Entering Passive Mode (66,96,131,6,221,164)
2009-11-03 19:56:03 Recv> 227 Entering Passive Mode (66,96,131,6,137,56)
2009-11-03 19:56:03 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:03 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:03 Sent> LIST
2009-11-03 19:56:03 Sent> LIST
2009-11-03 19:56:03 Recv> 226 Transfer complete
2009-11-03 19:56:03 Sent> CWD /FromC/02480001070529/1
2009-11-03 19:56:03 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:03 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:03 Recv> 226 Transfer complete
2009-11-03 19:56:03 Recv> 226 Transfer complete
2009-11-03 19:56:03 Sent> CWD /FromC/02480001076125/1
2009-11-03 19:56:03 Recv> 250 CWD command successful
2009-11-03 19:56:03 Sent> PASV
2009-11-03 19:56:03 Recv> 250 CWD command successful
2009-11-03 19:56:03 Sent> PASV
2009-11-03 19:56:03 Recv> 226 Transfer complete
2009-11-03 19:56:03 Recv> 226 Transfer complete
2009-11-03 19:56:04 Recv> 227 Entering Passive Mode (66,96,131,6,140,200)
2009-11-03 19:56:04 Recv> 227 Entering Passive Mode (66,96,131,6,141,64)
2009-11-03 19:56:04 Sent> LIST
2009-11-03 19:56:04 Sent> LIST
2009-11-03 19:56:04 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:04 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 19:56:04 Recv> 226 Transfer complete
2009-11-03 19:56:04 Recv> 226 Transfer complete
2009-11-03 19:58:58 Sent> TYPE I
2009-11-03 19:58:58 Recv> 200 Type set to I
2009-11-03 19:58:58 Sent> CWD /FromC/00008637211721/1
2009-11-03 19:58:58 Recv> 250 CWD command successful
2009-11-03 19:58:58 Sent> PASV
2009-11-03 19:58:59 Recv> 227 Entering Passive Mode (66,96,131,6,132,200)
2009-11-03 19:58:59 Sent> STOR 1.wma
2009-11-03 19:58:59 Recv> 150 Opening BINARY mode data connection for 1.wma
2009-11-03 20:02:12 Recv> 226 Transfer complete
2009-11-03 20:02:12 Sent> MFMT 20091004233222 1.wma
2009-11-03 20:02:12 Recv> 213 Modify=20091004233222; 1.wma
2009-11-03 20:02:12 Sent> TYPE A
2009-11-03 20:02:13 Recv> 200 Type set to A
2009-11-03 20:02:13 Sent> PASV
2009-11-03 20:02:13 Recv> 227 Entering Passive Mode (66,96,131,6,239,244)
2009-11-03 20:02:13 Sent> LIST
2009-11-03 20:02:13 Recv> 150 Opening ASCII mode data connection for file list
2009-11-03 20:02:14 Recv> 226 Transfer complete
2009-11-03 20:02:14 Successfully copied 1 items. Completed in 3 minutes, 17 seconds.

[Craig]

Looks like the timezone setting is off. BC is probably expecting timestamps in your local timezone, and the server is probably setting them to UTC. In your FTP profile change the timezone setting to the second item "(UTC) Coordinated Universal Time". I'm fuzzy on which settings take effect immediately, so you might need to restart BC to kick it.

[chrisjj]

Looks like the timezone setting is off. BC is probably expecting timestamps in your local timezoneGiven the BC Profile says "Time zone: Automatically Detect / Use Server Time", are you suggesting this is failing? Does the log reveal this?

[chrisjj]

> In your FTP profile change the timezone setting to the second item "(UTC) Coordinated Universal Time".

That works - thanks... but I guess only so long as the server is actually on that setting, so am reluctant to keep it. I'd rather have the autodetect working.

[Craig]

Actually auto-detecting the server timezone relies on the FTP server supporting the "SITE ZONE" command. If that isn't supported then it falls back to assuming the local timezone.

An FTP server that returns UTC times is very unlikely to ever change that. Setting it to that in your profile is is unlikely to cause problems unless your ISP changes to a completely different FTP server. In any case, auto-detection can't always work, which is why we have the timezone option in the first place.

[chrisjj]

> Actually auto-detecting the server timezone relies on the FTP
> server supporting the "SITE ZONE" command.

Worth documenting, I suggest.

> If that isn't supported then it falls back to assuming the local timezone.

I have to say it really poor that the failure of "Automatically Detect / Use Server Time" is not reported to the user. Had it been, BC would not have wasted so much of my time on this.

> Setting it to that in your profile is is unlikely to cause problems unless
> your ISP changes to a completely different FTP server.

Slightly different is more than enough.

> In any case, auto-detection can't always work

You're saying SITE ZONE is not necessarily sufficient??

[Craig]

> I have to say it really poor that the failure of "Automatically Detect / Use
> Server Time" is not reported to the user. Had it been, BC would not have
> wasted so much of my time on this.

Why not blame the FTP server for failing to support "SITE ZONE", or the FTP protocol for failing to specify timezone handling in the first place? BC's auto detection is a heuristic, it's doesn't have a simple pass/fail check.

> Slightly different is more than enough.

I can't think of any good reason why a modern server would switch from UTC to a local timezone. Even if it were to do so, the failure is obvious, since all of the timestamps will suddenly be off by several hours.

Regardless, the behavior is what it is, and I can't wish it into working better. The FTP RFCs don't specific timezone handling, and SITE ZONE isn't supported by every server. BC does as good as possible given the limitations of the protocol. If that's not good enough use a network share or SFTP.

> You're saying SITE ZONE is not necessarily sufficient??

No, I'm saying that many FTP servers don't support SITE ZONE. If your server supported it it would work.

[chrisjj]

> Why not blame the FTP server for failing to support , or the
> FTP protocol for failing to specify timezone handling in the first place?

In a BC support forum??

> BC's auto detection is a heuristic, it's doesn't have a simple pass/fail check.

Would you please document what features BC requires from the server in order that "Automatically Detect / Use Server Time" works.

> I can't think of any good reason why a modern server would switch
> from UTC to a local timezone.

Sorry, but that's insufficient consolation in the event it does.

> Regardless, the behavior is what it is, and I can't wish it into working
> better. ... BC does as good as possible given the limitations of the
> protocol.

Not alerting the autodetect failure or even recording it in the log AFAICS isn't "as good as possible".