borgbackup / borg

Deduplicating archiver with compression and authenticated encryption.
https://www.borgbackup.org/
Other
11.19k stars 742 forks source link

TypeError: 'int' object is not iterable #2939

Closed mathiasslawik closed 7 years ago

mathiasslawik commented 7 years ago

Hello,

unfortunately, I had a "corrupted chunks index" due to filesystem corruption (that I myself caused - but that's another story). To fix it, I invoked borg delete --cache-only that removed the local cache. However, I now get the following error when trying to run the backup:

Aug 15 14:02:19 darkroom borgmatic[7640]: Synchronizing chunks cache...
Aug 15 14:02:19 darkroom borgmatic[7640]: Archives: 99, w/ cached Idx: 99, w/ outdated Idx: 1, w/o cached Idx: 1.
Aug 15 14:02:19 darkroom borgmatic[7640]: Reading cached archive chunk index for darkroom-2017-07-30T05:00:00.804255 ...
Aug 15 14:02:19 darkroom borgmatic[7640]: Merging into master chunks index ...
Aug 15 14:02:19 darkroom borgmatic[7640]: Reading cached archive chunk index for switchy-2017-08-09T21:32:04.884748 ...
Aug 15 14:02:19 darkroom borgmatic[7640]: Merging into master chunks index ...
Aug 15 14:02:19 darkroom borgmatic[7640]: Reading cached archive chunk index for darkroom-2017-07-31T01:00:00.800344 ...
... snip ...
Aug 15 14:02:42 darkroom borgmatic[7640]: Reading cached archive chunk index for darkroom-2017-07-31T05:00:00.814492 ...
Aug 15 14:02:42 darkroom borgmatic[7640]: Merging into master chunks index ...
Aug 15 14:02:42 darkroom borgmatic[7640]: Reading cached archive chunk index for switchy-2017-02-28T23:30:21.442136 ...
Aug 15 14:02:42 darkroom borgmatic[7640]: Merging into master chunks index ...
Aug 15 14:02:42 darkroom borgmatic[7640]: Done.
Aug 15 14:02:43 darkroom borgmatic[7640]: Local Exception.
Aug 15 14:02:43 darkroom borgmatic[7640]: Traceback (most recent call last):
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archiver.py", line 2168, in main
Aug 15 14:02:43 darkroom borgmatic[7640]:     exit_code = archiver.run(args)
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archiver.py", line 2104, in run
Aug 15 14:02:43 darkroom borgmatic[7640]:     return set_ec(func(args))
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archiver.py", line 107, in wrapper
Aug 15 14:02:43 darkroom borgmatic[7640]:     return method(self, args, repository=repository, **kwargs)
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archiver.py", line 331, in do_create
Aug 15 14:02:43 darkroom borgmatic[7640]:     create_inner(archive, cache)
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archiver.py", line 304, in create_inner
Aug 15 14:02:43 darkroom borgmatic[7640]:     read_special=args.read_special, dry_run=dry_run)
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archiver.py", line 380, in _process
Aug 15 14:02:43 darkroom borgmatic[7640]:     read_special=read_special, dry_run=dry_run)
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archiver.py", line 380, in _process
Aug 15 14:02:43 darkroom borgmatic[7640]:     read_special=read_special, dry_run=dry_run)
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archiver.py", line 361, in _process
Aug 15 14:02:43 darkroom borgmatic[7640]:     status = archive.process_file(path, st, cache, self.ignore_inode)
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/archive.py", line 679, in process_file
Aug 15 14:02:43 darkroom borgmatic[7640]:     ids = cache.file_known_and_unchanged(path_hash, st, ignore_inode)
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/cache.py", line 489, in file_known_and_unchanged
Aug 15 14:02:43 darkroom borgmatic[7640]:     self._read_files()
Aug 15 14:02:43 darkroom borgmatic[7640]:   File "/usr/lib/python3.6/site-packages/borg/cache.py", line 211, in _read_files
Aug 15 14:02:43 darkroom borgmatic[7640]:     for path_hash, item in u:
Aug 15 14:02:43 darkroom borgmatic[7640]: TypeError: 'int' object is not iterable
Aug 15 14:02:43 darkroom borgmatic[7640]: Platform: Linux darkroom 4.12.4-1-ARCH #1 SMP PREEMPT Fri Jul 28 18:54:18 UTC 2017 x86_64
Aug 15 14:02:43 darkroom borgmatic[7640]: Linux: arch
Aug 15 14:02:43 darkroom borgmatic[7640]: Borg: 1.0.11  Python: CPython 3.6.2
Aug 15 14:02:43 darkroom borgmatic[7640]: PID: 7645  CWD: /
Aug 15 14:02:43 darkroom borgmatic[7640]: sys.argv: ['/usr/sbin/borg', 'create', '/volume1/Backup/borg-systems::darkroom-2017-08-15T14:02:18.282818', '/', '--exclude-from', '/etc/borgmatic/rootfs.excludes', '--compression', 'lz4', '--one-file-system', '--info', '--stats']
Aug 15 14:02:43 darkroom borgmatic[7640]: SSH_ORIGINAL_COMMAND: None
Aug 15 14:02:43 darkroom borgmatic[7640]: Command '('borg', 'create', '/volume1/Backup/borg-systems::darkroom-2017-08-15T14:02:18.282818', '/', '--exclude-from', '/etc/borgmatic/rootfs.excludes', '--compression', 'lz4', '--one-file-system', '--info', '--stats')' returned non-zero exit status 2.
Aug 15 14:02:43 darkroom systemd[1]: borgmatic.service: Main process exited, code=exited, status=1/FAILURE
Aug 15 14:02:43 darkroom systemd[1]: Failed to start borgmatic backup.
Aug 15 14:02:43 darkroom systemd[1]: borgmatic.service: Unit entered failed state.
Aug 15 14:02:43 darkroom systemd[1]: borgmatic.service: Triggering OnFailure= dependencies.
Aug 15 14:02:43 darkroom systemd[1]: borgmatic.service: Failed with result 'exit-code'.

I really don't know if it's a very stupid simple error that I'm causing or if there is something else going on here. As a background: I'm doing a backup of my root partition to a directory on a large RAID5 array which I later sync to another server. Until the corruption happened, the backup ran without a problem for at least half a year. You see two machines ("darkroom" and "switchy") as I backup also a portable device to the same repo to use deduplication as both use Archlinux. I run borg through borgmatic as a systemd timer job.

If there's anything else you need, please let me know. Thanks in advance for looking into this issue.

Best regards, Mathias

ThomasWaldmann commented 7 years ago

That looks like a corrupted "files" cache. Maybe check if the cache was really removed (permissions?).

ThomasWaldmann commented 7 years ago

The borg delete --cache-only repo code should have killed the whole cache directory (in a rm -rf way), so it is strange that there seems to be an invalid files cache file left.

ThomasWaldmann commented 7 years ago

The cache is in $HOME/.cache/borg/<repoid>/ assuming you did not point it somewhere else via env vars.

ThomasWaldmann commented 7 years ago

As a side note: borg 1.1 will protect important files by checksums/hashes, so any corrupt file will be recognized.

ThomasWaldmann commented 7 years ago

Maybe we could have a simple fix for 1.0, just starting a new files cache from scratch in case of unpack errors.

ThomasWaldmann commented 7 years ago

@mathiasslawik see #2941 - I tested it by manually corrupting the files cache (got the same TypeError as you) and it can deal with it now.