Backup Central

Stephen Isard <S.Isard < at > ed.ac.uk>
wrote the following on Tue, 01 Jun 2004 13:36:59 +0100

I think you are right that it is something to do with daylight
savings time. When I sent my original message I was on GMT (same as
UTC, no?).

Yes, I think GMT was too British so they made everyone refer to it
with a French acronym.

So +01:00 would have been incorrect. The UK switched to summer time
on 28 March, so +01:00 should now be right. I have just redone the
same test and got no error messages at all. All the files from both
0.12.3 and 0.12.6 have +01:00 suffixes.

Since you've moved into dst, it may be too late to test this, but I
wonder if you could test this in your version of Python:

laptop:~ $ python
Python 2.3.3 (#1, May 7 2004, 10:31:40)
[GCC 3.3.3 20040412 (Red Hat Linux 3.3.3-7)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
import time
time.daylight
1
time.localtime()
(2004, 6, 6, 12, 12, 32, 6, 158, 1)
time.altzone
25200
time.timezone
28800

Where I am, we are in daylight savings, so we use the alternate
timezone, putting us 25200 seconds (7 hours) before UTC. If you ever
see rdiff-backup giving the wrong date, perhaps you could check these
settings on your version of python.

Yes. The two error_log files from the original test are
error_log.2004-03-06T13:26:34+01:00.data.gz
error_log.2004-03-06T13:28:37+01:00.data.gz

However, the current_mirror file (created by 0.12.6) is
current_mirror.2004-03-06T13:28:37Z.data
and all of the other data and stats files for 13:28:37 have Z as well.

I'm baffled by this error since, looking at the code, rdiff-backup
uses the same time string in both the current_mirror and error_log
files. I can't see how they would every come out differently. Is
this something you can still reproduce?


--
Ben Escoto

David Kempe <dave < at > solutionsfirst.com.au>
wrote the following on Tue, 01 Jun 2004 13:50:48 +1000

I think you have struck in the problem with windows restoring and
comparing Ben. is there a way we can make the time stamp more windows
friendly at the same time? there is a wiki question about it as well

Yes, the windows timestamp isn't very friendly, but the goal was to
make it as unix friendly as possible. But probably any commandline
text program would be a non-starter on Windows; I think you're doing
the only sensible thing and trying to add a slick GUI to it.

About the time stamp question, could I get you to do what I posted in
a recent message:

laptop:~ $ python
Python 2.3.3 (#1, May 7 2004, 10:31:40)
[GCC 3.3.3 20040412 (Red Hat Linux 3.3.3-7)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
import time
time.daylight
1
time.localtime()
(2004, 6, 6, 12, 12, 32, 6, 158, 1)
time.altzone
25200
time.timezone
28800

Perhaps there is a problem with the timezone information with Python
under windows?


--
Ben Escoto

Ben Escoto wrote:

Perhaps there is a problem with the timezone information with Python
under windows?



Woody < at > BDR529 ~
$ python
Python 2.3.3 (#1, Apr 30 2004, 08:54:23)
[GCC 3.3.1 (cygming special)] on cygwin
Type "help", "copyright", "credits" or "license" for more information.

import time
time.daylight

1

time.localtime()

(2004, 6, 7, 10, 54, 21, 0, 159, 0)

time.altzone

-36000

time.timezone

-36000



It's not daylight savings time at the moment, BTW.
-36000 is right for AEST,which is +10hrs

The windows python output:

Python 2.3.2 (#49, Oct 2 2003, 20:02:00) [MSC v.1200 32 bit (Intel)] on
win32
Type "help", "copyright", "credits" or "license" for more information.

import time
time.daylight

1

time.localtime()

(2004, 6, 7, 10, 58, 25, 0, 159, 0)

time.altzone

-39600

time.timezone

-36000




Only differs in the altzone. Our summertime is UTC+11.

Linux python matches the windows python:

sloth:~# python
Python 2.3.2 (#2, Nov 6 2003, 17:16:33)
[GCC 2.95.4 20011002 (Debian prerelease)] on linux2
Type "help", "copyright", "credits" or "license" for more information.

import time
time.daylight

1

time.localtime()

(2004, 6, 7, 11, 1, 14, 0, 159, 0)

time.altzone

-39600

time.timezone

-36000



Woody




-----Original Message-----
From: Dave Kempe [mailto:dave < at > solutionsfirst.com.au]
Sent: Monday, 7 June 2004 9:54 AM
To: Anthony Wood
Subject: [Fwd: Re: [rdiff-backup-users] changed file format?]

David Kempe <dave < at > solutionsfirst.com.au>
wrote the following on Mon, 07 Jun 2004 11:20:27 +1000

Ben Escoto wrote:

Perhaps there is a problem with the timezone information with Python
under windows?

time.altzone
-36000
time.timezone
-36000

Yep, looks like altzone is messed up. This would cause rdiff-backup
to be an hour off during daylight savings time.

I wonder if there is an easy way to tell if this is a global cygwin
problem or something about the python build. Does unix "date" work
under cygwin?


--
Ben Escoto

Since you've moved into dst, it may be too late to test this, but I
wonder if you could test this in your version of Python:
<snip>

I get:

Python 2.2.2 (#1, Feb 24 2003, 19:13:11)
[GCC 3.2.2 20030222 (Red Hat Linux 3.2.2-4)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
import time
time.daylight
1
time.localtime()
(2004, 6, 7, 12, 36, 11, 0, 159, 1)
time.altzone
-3600
time.timezone
0

...
error_log.2004-03-06T13:28:37+01:00.data.gz
..
current_mirror.2004-03-06T13:28:37Z.data
...

I'm baffled by this error since, looking at the code, rdiff-backup
uses the same time string in both the current_mirror and error_log
files. I can't see how they would every come out differently. Is
this something you can still reproduce?

Well, while we are on daylight saving time all the suffixes come out +01:00.
The other arrangement should be reproducible when we go back on GMT.
http://wwp.greenwichmeantime.com/time-zone/rules/eu.htm says that will be
31 Oct this year.

Although there is evidently some problem with the timestamps, I'm still not
clear on what made my original test backup unreadable after I did a second
one. To recap, I did a backup with 0.12.3, producing wrong timestamps, then
another with 0.12.6, producing correct timestamps (apart from the mysterious
error log file) and then I couldn't list the earlier backup anymore. Is the
reason just that I did the two backups too close together, so that the 1 hour
daylight saving error gave the first backup a later time than the second? If
I had left a couple of hours in between would I never have noticed the problem
at all? Here is a listing of the rdiff-backup-data directory for the test:

backup.log
current_mirror.2004-03-06T13:28:37Z.data
error_log.2004-03-06T13:26:34+01:00.data.gz
error_log.2004-03-06T13:28:37+01:00.data.gz
file_statistics.2004-03-06T13:26:34+01:00.data.gz
file_statistics.2004-03-06T13:28:37Z.data.gz
increments
increments.2004-03-06T13:26:34Z.dir
mirror_metadata.2004-03-06T13:26:34+01:00.snapshot.gz
mirror_metadata.2004-03-06T13:28:37Z.snapshot.gz
session_statistics.2004-03-06T13:26:34+01:00.data
session_statistics.2004-03-06T13:28:37Z.data

The "Z" files were made by the second (0.12.6) backup and the "+01:00" ones by
the first (0.12.3) backup.

Stephen Isard

Stephen Isard <S.Isard < at > ed.ac.uk>
wrote the following on Mon, 07 Jun 2004 13:21:34 +0100

I get:

Python 2.2.2 (#1, Feb 24 2003, 19:13:11)
[GCC 3.2.2 20030222 (Red Hat Linux 3.2.2-4)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
import time
time.daylight
1
time.localtime()
(2004, 6, 7, 12, 36, 11, 0, 159, 1)
time.altzone
-3600
time.timezone
0

...
error_log.2004-03-06T13:28:37+01:00.data.gz
..
current_mirror.2004-03-06T13:28:37Z.data
...

Well, while we are on daylight saving time all the suffixes come out +01:00.
The other arrangement should be reproducible when we go back on GMT.
http://wwp.greenwichmeantime.com/time-zone/rules/eu.htm says that will be
31 Oct this year.

Although there is evidently some problem with the timestamps, I'm still not
clear on what made my original test backup unreadable after I did a second
one. To recap, I did a backup with 0.12.3, producing wrong timestamps, then
another with 0.12.6, producing correct timestamps (apart from the mysterious
error log file) and then I couldn't list the earlier backup anymore. Is the
reason just that I did the two backups too close together, so that the 1 hour
daylight saving error gave the first backup a later time than the second? If
I had left a couple of hours in between would I never have noticed the problem
at all? Here is a listing of the rdiff-backup-data directory for the test:

backup.log
current_mirror.2004-03-06T13:28:37Z.data
error_log.2004-03-06T13:26:34+01:00.data.gz
error_log.2004-03-06T13:28:37+01:00.data.gz
file_statistics.2004-03-06T13:26:34+01:00.data.gz
file_statistics.2004-03-06T13:28:37Z.data.gz
increments
increments.2004-03-06T13:26:34Z.dir
mirror_metadata.2004-03-06T13:26:34+01:00.snapshot.gz
mirror_metadata.2004-03-06T13:28:37Z.snapshot.gz
session_statistics.2004-03-06T13:26:34+01:00.data
session_statistics.2004-03-06T13:28:37Z.data

The "Z" files were made by the second (0.12.6) backup and the "+01:00" ones by
the first (0.12.3) backup.

That's a good theory about the first looking as if it were done after
the second, but shouldn't any confusion work in the opposite
direction? 13:26 at +01:00 should be 12:26 GMT. Then if you make
another backup at 13:28 at GMT it should appear an hour and two
minutes later than the first one.

Hmm, actually on second thought I think you're right but have it
backwards. The "Z" files were made by the first (0.12.3) backup
because it had a bug with daylight savings. The "+01:00" files were
made by 0.12.6, and then appeared to be earlier than the previous
backup, causing various problems. (Although rdiff-backup checks for
this; there should have been a "bad time error" or something.)

So anyway it seems that everything might be working now with recent
versions, except when python has the wrong time information, like on
Dave Kempe's cygwin setup.


--
Ben Escoto

Hmm, actually on second thought I think you're right but have it
backwards. The "Z" files were made by the first (0.12.3) backup
because it had a bug with daylight savings. The "+01:00" files were
made by 0.12.6, and then appeared to be earlier than the previous
backup, causing various problems. (Although rdiff-backup checks for
this; there should have been a "bad time error" or something.)

Unfortunately, I don't think that's right because

a) We were on GMT on March 6, so Z is correct and +01:00 is not
b) ls -l says:
Mar 6 13:26 file_statistics.2004-03-06T13:26:34+01:00.data.gz
Mar 6 13:28 file_statistics.2004-03-06T13:28:37Z.data.gz
so the +01:00 one got created first.

As I said, I did get an error message, but it was "Mirror metadata not found"
and didn't refer explicitly to times.

What I'm actually worrying about is whether I'm going to lose access to my
existing backups made with 0.12.3 if I start running 0.12.6 or another more
recent version. Even during summer time

rdiff-backup-0.12.6 --list-at-time 2004-03-06T13:26:34 test

gets me "Mirror metadata not found". Same with either Z or +01:00 tacked on
the end.

Does rdiff-backup consult the filesystem's idea of the file's date? Could
there be a problem because of the inconsistency between the date that's part
of the filename and the real creation time?

Stephen Isard

Stephen Isard <S.Isard < at > ed.ac.uk>
wrote the following on Tue, 08 Jun 2004 14:17:48 +0100

Unfortunately, I don't think that's right because
...
As I said, I did get an error message, but it was "Mirror metadata
not found" and didn't refer explicitly to times.

What I'm actually worrying about is whether I'm going to lose access
to my existing backups made with 0.12.3 if I start running 0.12.6 or
another more recent version. Even during summer time

rdiff-backup-0.12.6 --list-at-time 2004-03-06T13:26:34 test

gets me "Mirror metadata not found". Same with either Z or +01:00
tacked on the end.

Does rdiff-backup consult the filesystem's idea of the file's date?
Could there be a problem because of the inconsistency between the
date that's part of the filename and the real creation time?

Hmm, I don't really understand what is happening, and it seems my
speculation in this thread hasn't been too successful.. Is there some
error you can reproduce now? If you have an old archive that current
rdiff-backup is choking on, perhaps I could download it? (If some of
it confidential, perhaps you could delete all the actual data. It
sounds like the problem occurs right in the beginning, before any
data actually gets moved.)


--
Ben Escoto

Ben Escoto <ben < at > emerose.org>
wrote the following on Fri, 11 Jun 2004 13:36:03 -0700

Hmm, I don't really understand what is happening, and it seems my
speculation in this thread hasn't been too successful.. Is there some
error you can reproduce now? If you have an old archive that current
rdiff-backup is choking on, perhaps I could download it? (If some of
it confidential, perhaps you could delete all the actual data. It
sounds like the problem occurs right in the beginning, before any
data actually gets moved.)

If you do have some data set, you can attach it using the savannah bug
interface at:

https://savannah.nongnu.org/bugs/?group=rdiff-backup

or not, whatever is convenient.


--
Ben Escoto

If you do have some data set, you can attach it using the savannah bug
interface at:

https://savannah.nongnu.org/bugs/?group=rdiff-backup

Thanks, Ben, I've done that. I've attached a tar file of the directory
that I backed up to, first with 0.12.3, then with 0.12.6. I get an error
message from the commands

rdiff-backup-0.12.{3,6} --list-at-time 2004-03-06T13:26:34+01:00 test.old

(and also using all the variants on the time I could think of) on the untarred
directory.

Stephen Isard