Backup Central

Hi,
I am getting a crash from backing up an smbfs mounted filesystem to an
ext3 system. Here is the trace:

Processing changed file
raid5/Mohammed/cop/build/output/gen-src/au/com/ucw/cop/interfaces/ProductControllerEJBLocal.java
Traceback (most recent call last):
File "/usr/bin/rdiff-backup", line 23, in ?
rdiff_backup.Main.Main(sys.argv[1:])
File "/usr/lib/python2.4/site-packages/rdiff_backup/Main.py", line
283, in Main
take_action(rps)
File "/usr/lib/python2.4/site-packages/rdiff_backup/Main.py", line
253, in take_action
elif action == "backup": Backup(rps[0], rps[1])
File "/usr/lib/python2.4/site-packages/rdiff_backup/Main.py", line
306, in Backup
backup.Mirror(rpin, rpout)
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
38, in Mirror
DestS.patch(dest_rpath, source_diffiter)
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
216, in patch
for diff in rorpiter.FillInIter(source_diffiter, dest_rpath):
File "/usr/lib/python2.4/site-packages/rdiff_backup/rorpiter.py",
line 181, in FillInIter
for rp in rpiter:
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
103, in get_diffs
for dest_sig in dest_sigiter:
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
167, in get_sigs
for src_rorp, dest_rorp in cls.CCPP:
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
301, in next
source_rorp, dest_rorp = self.iter.next()
File "/usr/lib/python2.4/site-packages/rdiff_backup/rorpiter.py",
line 92, in Collate2Iters
try: relem1 = riter1.next()
File "/usr/lib/python2.4/site-packages/rdiff_backup/rorpiter.py",
line 352, in next
del self.cache_dict[self.cache_indicies[0]]
KeyError: ('raid5', 'Mohammed', 'cop', 'build', 'output', 'ejb', 'au',
'com', 'ucw', 'cop', 'interfaces', 'CatalogueRequestControllerEJB.class')
Exception exceptions.TypeError: "'NoneType' object is not callable" in
<bound method GzipFile.__del__ of <gzip open file
'/backup/ucwserver/e-rdiff/rdiff-backup-data/file_statistics.2005-11-22T17:34:00+11:00.data.gz',
mode 'wb' at 0xbf265f50 -0x40d873b4>> ignored
Exception exceptions.TypeError: "'NoneType' object is not callable" in
<bound method GzipFile.__del__ of <gzip open file
'/backup/ucwserver/e-rdiff/rdiff-backup-data/error_log.2005-11-22T17:34:00+11:00.data.gz',
mode 'wb' at 0xbf551f98 -0x40d7a2b4>> ignored
Exception exceptions.TypeError: "'NoneType' object is not callable" in
<bound method GzipFile.__del__ of <gzip open file
'/backup/ucwserver/e-rdiff/rdiff-backup-data/mirror_metadata.2005-11-22T17:34:00+11:00.snapshot.gz',
mode 'wb' at 0xbf265f98 -0x40d87334>> ignored

Any ideas on how I can work around the problem?
I am using rdiff-backup 1.0.1 on Redhat Fedora Core 1 with python2.4.

any hints appreciated.

thanks

dave

David Kempe wrote:
Hi,
I am getting a crash from backing up an smbfs mounted filesystem to an
ext3 system. Here is the trace:


I just rsynced the source to the destination, rmed the rdiff-backup-data
directory and ran it again with --force and get the same crash on the
same file. Any hints on how to get rdiff-backup to give more info would
be great - the metadata for this particular file is never written, the
filesystem permissions on it seem entirely normal.

dave

David Kempe <dave < at > solutionsfirst.com.au>
wrote the following on Wed, 23 Nov 2005 06:50:51 +1100

I just rsynced the source to the destination, rmed the
rdiff-backup-data directory and ran it again with --force and get
the same crash on the same file. Any hints on how to get
rdiff-backup to give more info would be great - the metadata for
this particular file is never written, the filesystem permissions on
it seem entirely normal.

Interesting, I've never been able to reproduce that bug (I haven't
seen it for years, but it gets reported occasionally on the list).
How much data is involved? Small enough that could you tar it up and
have me download it?


--
Ben Escoto

Ben Escoto wrote:
Interesting, I've never been able to reproduce that bug (I haven't
seen it for years, but it gets reported occasionally on the list).
How much data is involved? Small enough that could you tar it up and
have me download it?



I deleted the old file that was causing problems and it crashed again
on another file. Its so small I tarred it up and attached it. the file
is part of an internet explorer cache on an smbfs mounted drive. The
file is not important, so I don't mind not backing it up, but
rdiff-backup crashing is bad.
Here is the trace for this particular file:

Processing changed file raid5/Support/temp/lisa/Local Settings/Temporary
Internet Files/Content.IE5/PFRJ9PO2/transparent[1].gif
Traceback (most recent call last):
File "/usr/bin/rdiff-backup", line 23, in ?
rdiff_backup.Main.Main(sys.argv[1:])
File "/usr/lib/python2.4/site-packages/rdiff_backup/Main.py", line
283, in Main
take_action(rps)
File "/usr/lib/python2.4/site-packages/rdiff_backup/Main.py", line
253, in take_action
elif action == "backup": Backup(rps[0], rps[1])
File "/usr/lib/python2.4/site-packages/rdiff_backup/Main.py", line
306, in Backup
backup.Mirror(rpin, rpout)
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
38, in Mirror
DestS.patch(dest_rpath, source_diffiter)
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
216, in patch
for diff in rorpiter.FillInIter(source_diffiter, dest_rpath):
File "/usr/lib/python2.4/site-packages/rdiff_backup/rorpiter.py",
line 181, in FillInIter
for rp in rpiter:
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
103, in get_diffs
for dest_sig in dest_sigiter:
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
167, in get_sigs
for src_rorp, dest_rorp in cls.CCPP:
File "/usr/lib/python2.4/site-packages/rdiff_backup/backup.py", line
301, in next
source_rorp, dest_rorp = self.iter.next()
File "/usr/lib/python2.4/site-packages/rdiff_backup/rorpiter.py",
line 92, in Collate2Iters
try: relem1 = riter1.next()
File "/usr/lib/python2.4/site-packages/rdiff_backup/rorpiter.py",
line 352, in next
del self.cache_dict[self.cache_indicies[0]]
KeyError: ('raid5', 'Support', 'temp', 'lisa', 'Local Settings',
'Temporary Internet Files', 'Content.IE5', 'IVUDKFUP',
'MumsDay_105x85[1].gif')
Exception exceptions.TypeError: "'NoneType' object is not callable" in
<bound method GzipFile.__del__ of <gzip open file
'/backup/ucwserver/e-rdiff/rdiff-backup-data/file_statistics.2005-11-23T10:40:50+11:00.data.gz',
mode 'wb' at 0xbf23cf50 -0x40db0394>> ignored
Exception exceptions.TypeError: "'NoneType' object is not callable" in
<bound method GzipFile.__del__ of <gzip open file
'/backup/ucwserver/e-rdiff/rdiff-backup-data/error_log.2005-11-23T10:40:50+11:00.data.gz',
mode 'wb' at 0xbf528f98 -0x40da3294>> ignored
Exception exceptions.TypeError: "'NoneType' object is not callable" in
<bound method GzipFile.__del__ of <gzip open file
'/backup/ucwserver/e-rdiff/rdiff-backup-data/mirror_metadata.2005-11-23T10:40:50+11:00.snapshot.gz',
mode 'wb' at 0xbf23cf98 -0x40db0314>> ignored

Dave Kempe <dave < at > solutionsfirst.com.au>
wrote the following on Wed, 23 Nov 2005 13:16:25 +1100
Ben Escoto wrote:
Interesting, I've never been able to reproduce that bug (I haven't
seen it for years, but it gets reported occasionally on the list).
How much data is involved? Small enough that could you tar it up and
have me download it?

I deleted the old file that was causing problems and it crashed again
on another file. Its so small I tarred it up and attached it. the file
is part of an internet explorer cache on an smbfs mounted drive. The
file is not important, so I don't mind not backing it up, but
rdiff-backup crashing is bad.
Here is the trace for this particular file:

After looking at this more closely it's not the possible bug I was
thinking of. I don't think it's caused by any particular file.

This may be a silly question, but is possible there are two files in
your directory that have exactly the same name (I've seen it before
but think it's some kind of directory bug)? As in, maybe

cd raid5/Support/temp/lisa/Local Settings/Temporary Internet
Files/Content.IE5/IVUDKFUP
ls

shows MumsDay_105x85[1].gif twice?

If not, this patch may give a bit more feedback to see what the
problem is:

--- rorpiter.py 24 Oct 2005 17:16:05 -0000 1.28
+++ rorpiter.py 24 Nov 2005 03:23:29 -0000
< at > < at > -345,7 +345,9 < at > < at >
self.cache_indicies.append(next_index)

if len(self.cache_indicies) > self.cache_size:
- del self.cache_dict[self.cache_indicies[0]]
+ cur_index = self.cache_indicies[0]
+ log.Log("Deleting %s from cache" % (cur_index,), 2)
+ del self.cache_dict[cur_index]
del self.cache_indicies[0]

return next_elem

--
Ben Escoto

Ben Escoto wrote:
This may be a silly question, but is possible there are two files in
your directory that have exactly the same name (I've seen it before
but think it's some kind of directory bug)? As in, maybe

cd raid5/Support/temp/lisa/Local Settings/Temporary Internet
Files/Content.IE5/IVUDKFUP
ls

shows MumsDay_105x85[1].gif twice?


you know what, there is!
a whole bunch of them:

msn_logo_small[1].gif
msn_logo_small[1].gif
MumsDay_105x85[1].gif
MumsDay_105x85[1].gif
music15[1].gif
music15[1].gif
music_icon[1].gif
music_icon[1].gif
music_lovers_nh[1].jpg
music_lovers_nh[1].jpg
nav01r[1].gif

I don't know how to count them, but there would be hundreds of files
with exactly the same name in this directory.

After doing some more troubleshooting, it must be an smbfs bug - when I
mount it with cifs on a 2.6 kernel system, it works fine. Damn smbfs. I
am going to have to upgrade this kernel now.
Or you could fix it so that if for some bizarre reason if rdiff-backup
encounters two identical files in the one directory, it doesn't crash,
and only backs up one of them
its going to hard for me to upgrade this kernel, but I can do it.

thanks

dave