rdiff-backup crashes when running backup

Bug #1875163 reported by Walt Mankowski on 2020-04-26
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
rdiff-backup (Ubuntu)
Undecided
Unassigned

Bug Description

Here's the output from last night's cronjob:

Subject: Cron <root@scruffy> if [ -x /backup/scruffy ]; then rdiff-backup --print-statistics --exclude-filelist /usr/local/etc/rdiff_exclude / /backup/scruffy; fi

UpdateError: 'home/waltman/.cache/keybase/keybase.service.log' Updated mirror temp file '/backup/scruffy/home/waltman/.cache/keybase/rdiff-backup.tmp.15973' does not
match source
UpdateError: 'home/waltman/.irssi/db/messages.sqlite' Updated mirror temp file '/backup/scruffy/home/waltman/.irssi/db/rdiff-backup.tmp.56956' does not match source
UpdateError: 'run/rpc_pipefs/gssd/clntXX/info' Updated mirror temp file '/backup/scruffy/run/rpc_pipefs/gssd/clntXX/rdiff-backup.tmp.84241' does not match source
UpdateError: 'run/snapd/ns/discord.mnt' [Errno 22] Invalid argument
UpdateError: 'run/snapd/ns/lxd.mnt' [Errno 22] Invalid argument
Exception 'sequence item 0: expected str instance, bytes found' raised of class '<class 'TypeError'>':
  File "/usr/lib/python3/dist-packages/rdiff_backup/Main.py", line 390, in error_check_Main
    Main(arglist)
  File "/usr/lib/python3/dist-packages/rdiff_backup/Main.py", line 412, in Main
    take_action(rps)
  File "/usr/lib/python3/dist-packages/rdiff_backup/Main.py", line 348, in take_action
    Backup(rps[0], rps[1])
  File "/usr/lib/python3/dist-packages/rdiff_backup/Main.py", line 434, in Backup
    backup.Mirror_and_increment(rpin, rpout, incdir)
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 55, in Mirror_and_increment
    DestS.patch_and_increment(dest_rpath, source_diffiter, inc_rpath)
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 279, in patch_and_increment
    for diff in rorpiter.FillInIter(source_diffiter, dest_rpath):
  File "/usr/lib/python3/dist-packages/rdiff_backup/rorpiter.py", line 202, in FillInIter
    for rp in rpiter:
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 114, in get_diffs
    for dest_sig in dest_sigiter:
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 196, in get_sigs
    for src_rorp, dest_rorp in cls.CCPP:
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 361, in __next__
    source_rorp, dest_rorp = next(self.iter)
  File "/usr/lib/python3/dist-packages/rdiff_backup/rorpiter.py", line 95, in Collate2Iters
    relem1 = next(riter1)
  File "/usr/lib/python3/dist-packages/rdiff_backup/rorpiter.py", line 376, in __next__
    next_elem = next(self.iter)
  File "/usr/lib/python3/dist-packages/rdiff_backup/selection.py", line 138, in Iterate_fast
    rpath, val = next(diryield_stack[-1])
  File "/usr/lib/python3/dist-packages/rdiff_backup/selection.py", line 121, in diryield
    new_rpath = robust.check_common_error(
  File "/usr/lib/python3/dist-packages/rdiff_backup/robust.py", line 44, in check_common_error
    return error_handler(exc, *args)
  File "/usr/lib/python3/dist-packages/rdiff_backup/selection.py", line 108, in error_handler
    log.ErrorLog.write_if_open("ListError", rpath.index + (filename, ),
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 313, in write_if_open
    cls.write(error_type, rp, exc)
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 284, in write
    logstr = cls.get_log_string(error_type, rp, exc)
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 322, in get_log_string
    return "%s: '%s' %s" % (error_type, cls.get_indexpath(rp), exc)
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 302, in get_indexpath
    return "/".join(obj)

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/rdiff_backup/robust.py", line 35, in check_common_error
    return function(*args)
  File "/usr/lib/python3/dist-packages/rdiff_backup/rpath.py", line 1410, in append
    return self.__class__(self.conn, self.base, self.index + ext)
  File "/usr/lib/python3/dist-packages/rdiff_backup/rpath.py", line 1082, in __init__
    self.setdata()
  File "/usr/lib/python3/dist-packages/rdiff_backup/rpath.py", line 1108, in setdata
    self.data = self.conn.rpath.make_file_dict(self.path)
  File "/usr/lib/python3/dist-packages/rdiff_backup/rpath.py", line 386, in make_file_dict
    statblock = os.lstat(filename)
PermissionError: [Errno 13] Permission denied: b'/run/user/1000/doc'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 299, in get_indexpath
    return obj.get_safeindexpath()
AttributeError: 'tuple' object has no attribute 'get_safeindexpath'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/rdiff-backup", line 32, in <module>
    rdiff_backup.Main.error_check_Main(sys.argv[1:])
  File "/usr/lib/python3/dist-packages/rdiff_backup/Main.py", line 390, in error_check_Main
    Main(arglist)
  File "/usr/lib/python3/dist-packages/rdiff_backup/Main.py", line 412, in Main
    take_action(rps)
  File "/usr/lib/python3/dist-packages/rdiff_backup/Main.py", line 348, in take_action
    Backup(rps[0], rps[1])
  File "/usr/lib/python3/dist-packages/rdiff_backup/Main.py", line 434, in Backup
    backup.Mirror_and_increment(rpin, rpout, incdir)
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 55, in Mirror_and_increment
    DestS.patch_and_increment(dest_rpath, source_diffiter, inc_rpath)
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 279, in patch_and_increment
    for diff in rorpiter.FillInIter(source_diffiter, dest_rpath):
  File "/usr/lib/python3/dist-packages/rdiff_backup/rorpiter.py", line 202, in FillInIter
    for rp in rpiter:
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 114, in get_diffs
    for dest_sig in dest_sigiter:
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 196, in get_sigs
    for src_rorp, dest_rorp in cls.CCPP:
  File "/usr/lib/python3/dist-packages/rdiff_backup/backup.py", line 361, in __next__
    source_rorp, dest_rorp = next(self.iter)
  File "/usr/lib/python3/dist-packages/rdiff_backup/rorpiter.py", line 95, in Collate2Iters
    relem1 = next(riter1)
  File "/usr/lib/python3/dist-packages/rdiff_backup/rorpiter.py", line 376, in __next__
    next_elem = next(self.iter)
  File "/usr/lib/python3/dist-packages/rdiff_backup/selection.py", line 138, in Iterate_fast
    rpath, val = next(diryield_stack[-1])
  File "/usr/lib/python3/dist-packages/rdiff_backup/selection.py", line 121, in diryield
    new_rpath = robust.check_common_error(
  File "/usr/lib/python3/dist-packages/rdiff_backup/robust.py", line 44, in check_common_error
    return error_handler(exc, *args)
  File "/usr/lib/python3/dist-packages/rdiff_backup/selection.py", line 108, in error_handler
    log.ErrorLog.write_if_open("ListError", rpath.index + (filename, ),
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 313, in write_if_open
    cls.write(error_type, rp, exc)
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 284, in write
    logstr = cls.get_log_string(error_type, rp, exc)
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 322, in get_log_string
    return "%s: '%s' %s" % (error_type, cls.get_indexpath(rp), exc)
  File "/usr/lib/python3/dist-packages/rdiff_backup/log.py", line 302, in get_indexpath
    return "/".join(obj)
TypeError: sequence item 0: expected str instance, bytes found

ProblemType: Bug
DistroRelease: Ubuntu 20.04
Package: rdiff-backup 2.0.0-1
ProcVersionSignature: Ubuntu 5.4.0-26.30-generic 5.4.30
Uname: Linux 5.4.0-26-generic x86_64
NonfreeKernelModules: nvidia_modeset nvidia
ApportVersion: 2.20.11-0ubuntu27
Architecture: amd64
CasperMD5CheckResult: skip
CurrentDesktop: ubuntu:GNOME
Date: Sun Apr 26 06:08:06 2020
InstallationDate: Installed on 2016-12-27 (1215 days ago)
InstallationMedia: Ubuntu-Server 16.10 "Yakkety Yak" - Release amd64 (20161012.1)
SourcePackage: rdiff-backup
UpgradeStatus: Upgraded to focal on 2020-04-25 (0 days ago)

Walt Mankowski (waltman) wrote :
Otto Kekäläinen (otto) wrote :

Please provide exact steps on how to reproduce this error in a clean Docker image or virtual machine. We cannot debug or fix this if we can't reproduce this.

Walt Mankowski (waltman) wrote :

I'm afraid I don't know nearly enough Docker to be able to do that. But I do know Python. I just took a look at the code and I think I should be able to trap the TypeError exception pretty easily.

I'm currently running `rdiff-backup --check-destination-dir` to undo the failed backup. Once that finishes I'll rerun the backup in the debugger and report back on what I find. Hopefully that will let me set up a simple test case.

Walt Mankowski (waltman) wrote :

I modified get_indexpath() in log.py to catch a TypeError exception and return the string "TypeError" instead of aborting. It printed 4 errors:

ListError: 'TypeError' [Errno 13] Permission denied: b'/run/user/1000/doc'
ListError: 'TypeError' [Errno 13] Permission denied: b'/run/user/1000/gvfs'
ListError: 'TypeError' [Errno 13] Permission denied: b'/run/user/1000/keybase/kbfs'
ListError: 'TypeError' [Errno 13] Permission denied: b'/run/user/141/gvfs'

I'm not really sure what's wrong with the first 3. Maybe they're odd because they're in /run? The final file does really look like it might be corrupted.

At any rate it looks like the easy fix on my end is to exclude /run from my backups.

Eric Hazen (hazen) wrote :

I'm also affected by this bug. It is many months later, but a recent update to some 20.04 package caused this to start happening. Any suggested solutions other than "learn docker, install a new VM etc"?

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers