Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

borg check --repair hangs #4243

Closed
colmode opened this issue Jan 5, 2019 · 48 comments
Closed

borg check --repair hangs #4243

colmode opened this issue Jan 5, 2019 · 48 comments

Comments

@colmode
Copy link

colmode commented Jan 5, 2019

Have you checked borgbackup docs, FAQ, and open Github issues?

Yes

Is this a BUG / ISSUE report or a QUESTION?

bug

System information. For client/server mode post info for both machines.

product: Standard PC (i440FX + PIIX, 1996)
vendor: QEMU
version: pc-i440fx-2.12
width: 64 bits
capabilities: smbios-2.8 dmi-2.8 smp vsyscall32

Your borg version (borg -V).

1.1.8

Operating system (distribution) and version.

Linux vps 4.18.0-2-amd64 #1 SMP Debian 4.18.10-2 (2018-10-07) x86_64 GNU/Linux

Hardware / network configuration, and filesystems used.

ext4/lvm2

How much data is handled by borg?

/dev/mapper/vps-backup 468G 395G 69G 86% /backup

Full borg commandline that lead to the problem (leave away excludes and passwords)

borg -p -v check --repair

Describe the problem you're observing.

check --repair fails to make progress after a certain corrupted segment. On kill/restart it hangs similarly on the next bad segment.

Details:
borg repo was corrupted by power failure on storage cluster where this VM has its vdisks. The hardware/VM are ok now and all filesystems pass forced fsck. All borg operations are usually done in server mode. I see the same hang when running check --repair locally though.

The initial error was:

Remote: Repository index missing or corrupted, trying to recover from:
   File failed integrity check: /backup/borg/index.4578
Data integrity error: Segment entry checksum mismatch [segment 4356, offset 8756312]

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 4434, in main
    exit_code = archiver.run(args)
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 4366, in run
    return set_ec(func(args))
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 139, in wrapper
    kwargs['manifest'], kwargs['key'] = Manifest.load(repository, compatibility)
  File "/usr/lib/python3/dist-packages/borg/helpers.py", line 330, in load
    cdata = repository.get(cls.MANIFEST_ID)
  File "/usr/lib/python3/dist-packages/borg/remote.py", line 924, in get
    for resp in self.get_many([id]):
  File "/usr/lib/python3/dist-packages/borg/remote.py", line 928, in get_many
    for resp in self.call_many('get', [{'id': id} for id in ids], is_preloaded=is_preloaded):
  File "/usr/lib/python3/dist-packages/borg/remote.py", line 773, in call_many
    handle_error(unpacked)
  File "/usr/lib/python3/dist-packages/borg/remote.py", line 735, in handle_error
    raise IntegrityError(args[0].decode())
borg.helpers.IntegrityError: Data integrity error: Segment entry checksum mismatch [segment 4356, offset 8756312]

Platform: Linux wall 4.15.0-42-generic #45-Ubuntu SMP Thu Nov 15 19:32:57 UTC 2018 x86_64
Linux: LinuxMint 19 tara
Borg: 1.1.7  Python: CPython 3.6.7
PID: 521  CWD: /
sys.argv: ['/usr/bin/borg', 'create', '--stats', '--show-rc', '--exclude-caches', '--patterns-from', '/etc/backup.exclude', '::{hostname}-{now}', '/boot/grub', '/data', '/etc', '/home', '/root', '/usr/local', '/var']
SSH_ORIGINAL_COMMAND: None

terminating with error status, rc 2

borg check showed dozens of 'Remote: Data integrity error: Invalid segment magic ...' or 'Remote: Data integrity error: Segment entry checksum mismatch' and ran to completion.

borg check --repair worked its way through most of these, then hung (for 10 days) on 'Remote: Data integrity error: Segment entry checksum mismatch [segment 4403, offset 8319395]'

The borg process was pinning the CPU. I attached to it with strace, it wasn't making any syscalls. ltrace showed that it was memsetting 2 different addresses to 0, with no other intervening libcalls.

I killed/restarted borg check --repair (with -p -v this time). Nothing about segment 4403 this time; instead, hang for hours at:

Remote: Starting repository check
Remote: Data integrity error: Segment entry checksum mismatch [segment 4404, offset 2099200]
Remote: attempting to recover /backup/borg/data/4/4404

Another kill/restart gets us to the same point at segment 4405.

Can you reproduce the problem? If so, describe how. If not, describe troubleshooting steps you took before opening the issue.

See above.

@colmode
Copy link
Author

colmode commented Jan 5, 2019

Here is the traceback on sigint when running check --repair locally:

borg -p -v check --repair
'check --repair' is an experimental feature that might result in data loss.
Type 'YES' if you understand this and want to continue: YES
Starting repository check
Data integrity error: Segment entry checksum mismatch [segment 4405, offset 936892]
attempting to recover /backup/borg/data/4/4405

^CLocal Exception
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 911, in check
    objects = list(self.io.iter_objects(segment))
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 1341, in iter_objects
    read_data=read_data)
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 1428, in _read
    segment, offset))
borg.helpers.IntegrityError: Data integrity error: Segment entry checksum mismatch [segment 4405, offset 936892]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 1373, in recover_segment
    if crc32(data[4:size]) & 0xffffffff != crc:
  File "/usr/lib/python3/dist-packages/borg/helpers.py", line 2239, in handler
    raise exc_cls
KeyboardInterrupt

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 4436, in main
    exit_code = archiver.run(args)
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 4368, in run
    return set_ec(func(args))
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 152, in wrapper
    return method(self, args, repository=repository, **kwargs)
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 313, in do_check
    if not repository.check(repair=args.repair, save_space=args.save_space):
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 916, in check
    self.io.recover_segment(segment, filename)
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 1378, in recover_segment
    data.release()
BufferError: cannot close exported pointers exist

Platform: Linux vps 4.18.0-2-amd64 #1 SMP Debian 4.18.10-2 (2018-10-07) x86_64
Linux: debian buster/sid 
Borg: 1.1.8  Python: CPython 3.7.2
PID: 25460  CWD: /home/bryan
sys.argv: ['/usr/bin/borg', '-p', '-v', 'check', '--repair']
SSH_ORIGINAL_COMMAND: None

@ThomasWaldmann
Copy link
Member

Hmm, maybe the power failure is not the only problem there. borg tries hard to make sure that data is synced to disk before a commit is written (and synced to disk).

So, if the power fail is before the commit, there is just uncomitted data and borg should just discard it, rolling back to a previous consistent state.

If the power fail is after the commit, the state should also be valid as all data is on-disk as it should be.

@ThomasWaldmann
Copy link
Member

@colmode what's your desired goal?

Reporting a potential bug in borg, so we can fix it?

Getting the repo into a valid state so you can access past backups?

@ThomasWaldmann
Copy link
Member

ThomasWaldmann commented Jan 5, 2019

BufferError: cannot close exported pointers exist

Guess the cause of this is you hitting Ctrl-C while it is in the crc32 computation, so it is kind of a cosmetic issue. The memoryview + its release looks like it should be done with a contextmanager.
The traceback looks a bit strange though.

@ThomasWaldmann
Copy link
Member

As a performance note: the code in recover_segment is slow: it advances byte-by-byte, trying to find data with correct CRC. If there is a lot of corrupt data (CRC does not match data), this can take rather long.

@colmode
Copy link
Author

colmode commented Jan 5, 2019

My goal is to get the repo into a valid state, primarily so that I can continue making daily backups without having to re-sync all 300GB of the data, which I would have to if I blow away the repo and start over. At this point I don't care that much about past backups. The current state of the data is ok. It would be nice to preserve past backups though.

@colmode
Copy link
Author

colmode commented Jan 5, 2019

The first hang persisted for 10 days (I was traveling). strace and ltrace showed not much activity, so apparently borg was looping over some internal state.

@colmode
Copy link
Author

colmode commented Jan 5, 2019

It's also curious that borg advances to the next segment on each restart. I haven't studied your internals.

@ThomasWaldmann
Copy link
Member

ThomasWaldmann commented Jan 5, 2019

Doing manual operations on a repo can be dangerous and a risk of total loss of the repo, so usually the advice is to make a copy first.

That said, you maybe could just throw away all corrupt segments (I assume these are only at the end, highest segment files numbers [maybe 4356+?] while all before some specific number might be not corrupted). or rather than throwing away: move to a directory outside the repo

Can you give a ls -l repo/ and also a ls -l repo/data/4000/?

Also: please post your repo/config (you can remove the encrypted key from the post, of course).

@colmode
Copy link
Author

colmode commented Jan 6, 2019

[repository]
version = 1
segments_per_dir = 1000
max_segment_size = 524288000
append_only = 0
storage_quota = 0
additional_free_space = 2G
-rw------- 1 bryan bryan  965 Jan 18  2018 config
drwx------ 7 bryan bryan 4096 Oct 13 00:21 data/
-rw------- 1 bryan bryan 6722 Dec 22 00:18 hints.4578
-rw------- 1 bryan bryan  190 Dec 22 00:18 integrity.4578
drwx------ 2 bryan bryan 4096 Jan  5 16:07 lock.exclusive/
-rw------- 1 bryan bryan   60 Jan  5 16:07 lock.roster
-rw------- 1 bryan bryan   16 Dec 22 00:18 nonce
-rw------- 1 bryan bryan   73 Jan 18  2018 README

data:
drwx------ 2 bryan bryan 20480 Apr 22  2018 0/
drwx------ 2 bryan bryan 12288 Jul 15 01:48 1/
drwx------ 2 bryan bryan 16384 Oct 14 00:50 2/
drwx------ 2 bryan bryan 12288 Dec 16 00:20 3/
drwx------ 2 bryan bryan 12288 Jan  5 14:18 4/

data/4:
total 23766852
-rw------- 1 bryan bryan        17 Oct 13 00:21 4000
-rw------- 1 bryan bryan        17 Oct 13 00:21 4001
-rw------- 1 bryan bryan        17 Oct 13 00:22 4003
-rw------- 1 bryan bryan        17 Oct 13 00:22 4005
-rw------- 1 bryan bryan 245633925 Oct 14 00:47 4006
-rw------- 1 bryan bryan        17 Oct 14 00:47 4007
-rw------- 1 bryan bryan        17 Oct 14 00:47 4009
-rw------- 1 bryan bryan        17 Oct 14 00:48 4011
-rw------- 1 bryan bryan        17 Oct 14 00:48 4013
-rw------- 1 bryan bryan        17 Oct 14 00:49 4015
-rw------- 1 bryan bryan        17 Oct 14 00:49 4017
-rw------- 1 bryan bryan        17 Oct 14 00:49 4019
-rw------- 1 bryan bryan 527153079 Oct 14 00:50 4020
-rw------- 1 bryan bryan        17 Oct 14 00:50 4021
-rw------- 1 bryan bryan 472693106 Oct 14 00:50 4022
-rw------- 1 bryan bryan        17 Oct 14 00:50 4023
-rw------- 1 bryan bryan        17 Oct 15 00:17 4025
-rw------- 1 bryan bryan        17 Oct 15 00:17 4026
-rw------- 1 bryan bryan        17 Oct 15 00:17 4028
-rw------- 1 bryan bryan        17 Oct 15 00:17 4030
-rw------- 1 bryan bryan        17 Oct 16 00:20 4032
-rw------- 1 bryan bryan        17 Oct 16 00:20 4034
-rw------- 1 bryan bryan        17 Oct 16 00:21 4036
-rw------- 1 bryan bryan 196780385 Oct 16 00:21 4037
-rw------- 1 bryan bryan        17 Oct 16 00:21 4038
-rw------- 1 bryan bryan        17 Oct 17 00:23 4040
-rw------- 1 bryan bryan        17 Oct 17 00:23 4041
-rw------- 1 bryan bryan        17 Oct 17 00:24 4043
-rw------- 1 bryan bryan        17 Oct 17 00:24 4045
-rw------- 1 bryan bryan        17 Oct 18 00:18 4047
-rw------- 1 bryan bryan        17 Oct 18 00:18 4049
-rw------- 1 bryan bryan        17 Oct 18 00:18 4051
-rw------- 1 bryan bryan        17 Oct 18 00:18 4053
-rw------- 1 bryan bryan        17 Oct 19 00:16 4055
-rw------- 1 bryan bryan        17 Oct 19 00:16 4056
-rw------- 1 bryan bryan        17 Oct 19 00:16 4058
-rw------- 1 bryan bryan        17 Oct 19 00:16 4060
-rw------- 1 bryan bryan 528977555 Oct 20 00:19 4061
-rw------- 1 bryan bryan 528357719 Oct 20 00:23 4062
-rw------- 1 bryan bryan 524862521 Oct 20 00:27 4063
-rw------- 1 bryan bryan 526161603 Oct 20 00:31 4064
-rw------- 1 bryan bryan        17 Oct 20 00:41 4067
-rw------- 1 bryan bryan        17 Oct 20 00:41 4069
-rw------- 1 bryan bryan        17 Oct 20 00:42 4071
-rw------- 1 bryan bryan        17 Oct 20 00:42 4073
-rw------- 1 bryan bryan 203072619 Oct 21 00:16 4074
-rw------- 1 bryan bryan        17 Oct 21 00:16 4075
-rw------- 1 bryan bryan        17 Oct 21 00:16 4077
-rw------- 1 bryan bryan        17 Oct 22 00:17 4079
-rw------- 1 bryan bryan        17 Oct 22 00:17 4081
-rw------- 1 bryan bryan        17 Oct 22 00:18 4083
-rw------- 1 bryan bryan        17 Oct 22 00:18 4085
-rw------- 1 bryan bryan        17 Oct 23 00:21 4087
-rw------- 1 bryan bryan        17 Oct 23 00:21 4089
-rw------- 1 bryan bryan        17 Oct 23 00:22 4091
-rw------- 1 bryan bryan        17 Oct 23 00:22 4093
-rw------- 1 bryan bryan        17 Oct 24 00:17 4095
-rw------- 1 bryan bryan        17 Oct 24 00:17 4096
-rw------- 1 bryan bryan        17 Oct 24 00:18 4098
-rw------- 1 bryan bryan        17 Oct 24 00:18 4100
-rw------- 1 bryan bryan        17 Oct 25 00:18 4102
-rw------- 1 bryan bryan        17 Oct 25 00:18 4104
-rw------- 1 bryan bryan        17 Oct 25 00:18 4106
-rw------- 1 bryan bryan        17 Oct 25 00:18 4108
-rw------- 1 bryan bryan        17 Oct 26 00:19 4110
-rw------- 1 bryan bryan        17 Oct 26 00:19 4111
-rw------- 1 bryan bryan        17 Oct 26 00:20 4113
-rw------- 1 bryan bryan        17 Oct 26 00:20 4115
-rw------- 1 bryan bryan        17 Oct 27 00:19 4117
-rw------- 1 bryan bryan        17 Oct 27 00:19 4118
-rw------- 1 bryan bryan        17 Oct 27 00:19 4120
-rw------- 1 bryan bryan        17 Oct 27 00:19 4122
-rw------- 1 bryan bryan 213370090 Oct 28 00:17 4123
-rw------- 1 bryan bryan        17 Oct 28 00:17 4124
-rw------- 1 bryan bryan        17 Oct 28 00:17 4126
-rw------- 1 bryan bryan        17 Oct 28 00:18 4128
-rw------- 1 bryan bryan        17 Oct 28 00:18 4130
-rw------- 1 bryan bryan        17 Oct 28 00:18 4132
-rw------- 1 bryan bryan        17 Oct 29 00:20 4134
-rw------- 1 bryan bryan        17 Oct 29 00:20 4136
-rw------- 1 bryan bryan        17 Oct 29 00:21 4138
-rw------- 1 bryan bryan 105942820 Oct 29 00:21 4139
-rw------- 1 bryan bryan        17 Oct 29 00:21 4140
-rw------- 1 bryan bryan        17 Oct 30 00:19 4142
-rw------- 1 bryan bryan        17 Oct 30 00:19 4143
-rw------- 1 bryan bryan        17 Oct 30 00:19 4145
-rw------- 1 bryan bryan        17 Oct 30 00:19 4147
-rw------- 1 bryan bryan 221463939 Oct 31 00:16 4148
-rw------- 1 bryan bryan        17 Oct 31 00:16 4149
-rw------- 1 bryan bryan        17 Oct 31 00:16 4151
-rw------- 1 bryan bryan        17 Oct 31 00:17 4153
-rw------- 1 bryan bryan        17 Oct 31 00:17 4155
-rw------- 1 bryan bryan        17 Nov  1 00:22 4157
-rw------- 1 bryan bryan        17 Nov  1 00:22 4159
-rw------- 1 bryan bryan        17 Nov  1 00:24 4161
-rw------- 1 bryan bryan        17 Nov  1 00:24 4163
-rw------- 1 bryan bryan        17 Nov  2 00:24 4165
-rw------- 1 bryan bryan        17 Nov  2 00:24 4167
-rw------- 1 bryan bryan        17 Nov  2 00:25 4169
-rw------- 1 bryan bryan 142299190 Nov  2 00:25 4170
-rw------- 1 bryan bryan        17 Nov  2 00:25 4171
-rw------- 1 bryan bryan 530447639 Nov  3 00:22 4172
-rw------- 1 bryan bryan 527243839 Nov  3 00:26 4173
-rw------- 1 bryan bryan 525356935 Nov  3 00:31 4174
-rw------- 1 bryan bryan 526897773 Nov  3 00:36 4175
-rw------- 1 bryan bryan 525891738 Nov  3 00:41 4176
-rw------- 1 bryan bryan        17 Nov  3 00:46 4178
-rw------- 1 bryan bryan        17 Nov  3 00:46 4179
-rw------- 1 bryan bryan        17 Nov  3 00:46 4181
-rw------- 1 bryan bryan        17 Nov  3 00:46 4183
-rw------- 1 bryan bryan        17 Nov  3 00:47 4185
-rw------- 1 bryan bryan        17 Nov  3 00:47 4187
-rw------- 1 bryan bryan        17 Nov  3 00:48 4189
-rw------- 1 bryan bryan 524290519 Nov  3 00:48 4190
-rw------- 1 bryan bryan        17 Nov  3 00:48 4191
-rw------- 1 bryan bryan        17 Nov  3 00:48 4193
-rw------- 1 bryan bryan 180700289 Nov  4 00:17 4194
-rw------- 1 bryan bryan        17 Nov  4 00:17 4195
-rw------- 1 bryan bryan        17 Nov  4 00:17 4197
-rw------- 1 bryan bryan        17 Nov  4 00:18 4199
-rw------- 1 bryan bryan 530278323 Nov  4 00:18 4200
-rw------- 1 bryan bryan        17 Nov  4 00:18 4201
-rw------- 1 bryan bryan 430954757 Nov  4 00:19 4202
-rw------- 1 bryan bryan        17 Nov  4 00:19 4203
-rw------- 1 bryan bryan        17 Nov  5 00:17 4205
-rw------- 1 bryan bryan        17 Nov  5 00:17 4206
-rw------- 1 bryan bryan        17 Nov  5 00:18 4208
-rw------- 1 bryan bryan        17 Nov  5 00:18 4210
-rw------- 1 bryan bryan        17 Nov  6 00:19 4212
-rw------- 1 bryan bryan        17 Nov  6 00:19 4214
-rw------- 1 bryan bryan        17 Nov  6 00:20 4216
-rw------- 1 bryan bryan        17 Nov  6 00:20 4218
-rw------- 1 bryan bryan        17 Nov  7 00:15 4220
-rw------- 1 bryan bryan        17 Nov  7 00:15 4222
-rw------- 1 bryan bryan        17 Nov  7 00:15 4224
-rw------- 1 bryan bryan        17 Nov  7 00:15 4226
-rw------- 1 bryan bryan        17 Nov  8 00:21 4228
-rw------- 1 bryan bryan        17 Nov  8 00:21 4230
-rw------- 1 bryan bryan        17 Nov  8 00:22 4232
-rw------- 1 bryan bryan        17 Nov  8 00:22 4234
-rw------- 1 bryan bryan        17 Nov  9 00:23 4237
-rw------- 1 bryan bryan        17 Nov  9 00:23 4238
-rw------- 1 bryan bryan        17 Nov  9 00:23 4240
-rw------- 1 bryan bryan 171493126 Nov  9 00:23 4241
-rw------- 1 bryan bryan        17 Nov  9 00:23 4242
-rw------- 1 bryan bryan        17 Nov 10 00:22 4244
-rw------- 1 bryan bryan        17 Nov 10 00:22 4245
-rw------- 1 bryan bryan        17 Nov 10 00:23 4247
-rw------- 1 bryan bryan        17 Nov 10 00:23 4249
-rw------- 1 bryan bryan 262520187 Nov 11 00:19 4250
-rw------- 1 bryan bryan        17 Nov 11 00:19 4251
-rw------- 1 bryan bryan        17 Nov 11 00:19 4253
-rw------- 1 bryan bryan        17 Nov 11 00:20 4255
-rw------- 1 bryan bryan 142018021 Nov 11 00:20 4256
-rw------- 1 bryan bryan        17 Nov 11 00:20 4257
-rw------- 1 bryan bryan        17 Nov 12 00:20 4259
-rw------- 1 bryan bryan        17 Nov 12 00:20 4260
-rw------- 1 bryan bryan        17 Nov 12 00:21 4262
-rw------- 1 bryan bryan        17 Nov 12 00:21 4264
-rw------- 1 bryan bryan        17 Nov 13 00:19 4266
-rw------- 1 bryan bryan        17 Nov 13 00:19 4268
-rw------- 1 bryan bryan        17 Nov 13 00:20 4270
-rw------- 1 bryan bryan        17 Nov 13 00:20 4272
-rw------- 1 bryan bryan        17 Nov 14 00:19 4274
-rw------- 1 bryan bryan        17 Nov 14 00:19 4276
-rw------- 1 bryan bryan        17 Nov 15 00:18 4278
-rw------- 1 bryan bryan        17 Nov 15 00:18 4280
-rw------- 1 bryan bryan        17 Nov 15 00:19 4282
-rw------- 1 bryan bryan 113320612 Nov 15 00:19 4283
-rw------- 1 bryan bryan        17 Nov 15 00:19 4284
-rw------- 1 bryan bryan        17 Nov 16 00:14 4286
-rw------- 1 bryan bryan        17 Nov 16 00:14 4287
-rw------- 1 bryan bryan        17 Nov 16 00:15 4289
-rw------- 1 bryan bryan 115701382 Nov 16 00:15 4290
-rw------- 1 bryan bryan        17 Nov 16 00:15 4291
-rw------- 1 bryan bryan        17 Nov 17 00:17 4293
-rw------- 1 bryan bryan        17 Nov 17 00:17 4294
-rw------- 1 bryan bryan        17 Nov 17 00:18 4296
-rw------- 1 bryan bryan 306356961 Nov 17 00:18 4297
-rw------- 1 bryan bryan        17 Nov 17 00:18 4298
-rw------- 1 bryan bryan 218500471 Nov 18 00:16 4299
-rw------- 1 bryan bryan        17 Nov 18 00:16 4300
-rw------- 1 bryan bryan        17 Nov 18 00:16 4301
-rw------- 1 bryan bryan        17 Nov 18 00:17 4303
-rw------- 1 bryan bryan        17 Nov 18 00:17 4305
-rw------- 1 bryan bryan        17 Nov 19 00:21 4307
-rw------- 1 bryan bryan        17 Nov 19 00:21 4309
-rw------- 1 bryan bryan        17 Nov 19 00:22 4311
-rw------- 1 bryan bryan        17 Nov 19 00:22 4313
-rw------- 1 bryan bryan        17 Nov 20 00:21 4315
-rw------- 1 bryan bryan        17 Nov 20 00:21 4317
-rw------- 1 bryan bryan        17 Nov 20 00:22 4319
-rw------- 1 bryan bryan        17 Nov 20 00:22 4321
-rw------- 1 bryan bryan 524540699 Nov 21 00:17 4322
-rw------- 1 bryan bryan 524713275 Nov 21 00:21 4323
-rw------- 1 bryan bryan 526700180 Nov 21 00:25 4324
-rw------- 1 bryan bryan 524818632 Nov 21 00:29 4325
-rw------- 1 bryan bryan 524339386 Nov 21 00:33 4326
-rw------- 1 bryan bryan        17 Nov 21 00:39 4329
-rw------- 1 bryan bryan        17 Nov 21 00:39 4331
-rw------- 1 bryan bryan        17 Nov 21 00:40 4333
-rw------- 1 bryan bryan        17 Nov 21 00:40 4335
-rw------- 1 bryan bryan        17 Nov 22 00:15 4337
-rw------- 1 bryan bryan        17 Nov 22 00:15 4339
-rw------- 1 bryan bryan        17 Nov 22 00:16 4341
-rw------- 1 bryan bryan        17 Nov 22 00:16 4343
-rw------- 1 bryan bryan        17 Nov 23 00:18 4345
-rw------- 1 bryan bryan        17 Nov 23 00:18 4346
-rw------- 1 bryan bryan        17 Nov 23 00:19 4348
-rw------- 1 bryan bryan 434670148 Nov 23 00:19 4349
-rw------- 1 bryan bryan        17 Nov 23 00:19 4350
-rw------- 1 bryan bryan        17 Nov 24 00:17 4352
-rw------- 1 bryan bryan        17 Nov 24 00:17 4353
-rw------- 1 bryan bryan        17 Nov 24 00:17 4355
-rw------- 1 bryan bryan 213899070 Dec 24 11:11 4356
-rw------- 1 bryan bryan 214580228 Nov 24 00:18 4356.beforerecover
-rw------- 1 bryan bryan        17 Nov 24 00:18 4357
-rw------- 1 bryan bryan 215718943 Nov 25 00:18 4358
-rw------- 1 bryan bryan         8 Dec 24 11:11 4359
-rw------- 1 bryan bryan        17 Nov 25 00:18 4359.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4360
-rw------- 1 bryan bryan        17 Nov 25 00:18 4360.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4362
-rw------- 1 bryan bryan        17 Nov 25 00:18 4362.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4364
-rw------- 1 bryan bryan        17 Nov 25 00:18 4364.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4366
-rw------- 1 bryan bryan        17 Nov 26 00:21 4366.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4367
-rw------- 1 bryan bryan        17 Nov 26 00:21 4367.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4369
-rw------- 1 bryan bryan        17 Nov 26 00:21 4369.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4371
-rw------- 1 bryan bryan        17 Nov 26 00:21 4371.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4373
-rw------- 1 bryan bryan        17 Nov 27 00:23 4373.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4375
-rw------- 1 bryan bryan        17 Nov 27 00:23 4375.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4377
-rw------- 1 bryan bryan        17 Nov 27 00:24 4377.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4379
-rw------- 1 bryan bryan        17 Nov 27 00:24 4379.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4381
-rw------- 1 bryan bryan        17 Nov 28 00:16 4381.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4383
-rw------- 1 bryan bryan        17 Nov 28 00:16 4383.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4385
-rw------- 1 bryan bryan        17 Nov 28 00:17 4385.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4387
-rw------- 1 bryan bryan        17 Nov 28 00:17 4387.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4389
-rw------- 1 bryan bryan        17 Nov 29 00:18 4389.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4391
-rw------- 1 bryan bryan        17 Nov 29 00:18 4391.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 11:11 4393
-rw------- 1 bryan bryan        17 Nov 29 00:19 4393.beforerecover
-rw------- 1 bryan bryan 176666374 Dec 24 16:27 4394
-rw------- 1 bryan bryan 214851554 Nov 29 00:19 4394.beforerecover
-rw------- 1 bryan bryan         8 Dec 24 16:27 4395
-rw------- 1 bryan bryan        17 Nov 29 00:19 4395.beforerecover
-rw------- 1 bryan bryan  17559680 Dec 24 16:52 4396
-rw------- 1 bryan bryan 313066641 Nov 30 00:24 4396.beforerecover
-rw------- 1 bryan bryan         8 Dec 25 00:12 4397
-rw------- 1 bryan bryan        17 Nov 30 00:24 4397.beforerecover
-rw------- 1 bryan bryan         8 Dec 25 00:12 4398
-rw------- 1 bryan bryan        17 Nov 30 00:24 4398.beforerecover
-rw------- 1 bryan bryan         8 Dec 25 00:12 4400
-rw------- 1 bryan bryan        17 Nov 30 00:25 4400.beforerecover
-rw------- 1 bryan bryan         8 Dec 25 00:12 4402
-rw------- 1 bryan bryan        17 Nov 30 00:25 4402.beforerecover
-rw------- 1 bryan bryan  10598338 Dec 30 08:22 4403
-rw------- 1 bryan bryan 525714896 Dec  1 00:20 4403.beforerecover
-rw------- 1 bryan bryan   2099200 Jan  4 17:58 4404
-rw------- 1 bryan bryan 526897092 Dec  1 00:26 4404.beforerecover
-rw------- 1 bryan bryan    936892 Jan  5 14:18 4405
-rw------- 1 bryan bryan 524582544 Dec  1 00:31 4405.beforerecover
-rw------- 1 bryan bryan 530133294 Dec  1 00:36 4406
-rw------- 1 bryan bryan        17 Dec  1 00:42 4408
-rw------- 1 bryan bryan        17 Dec  1 00:43 4410
-rw------- 1 bryan bryan        17 Dec  1 00:44 4412
-rw------- 1 bryan bryan        17 Dec  1 00:44 4414
-rw------- 1 bryan bryan 251797280 Dec  2 00:20 4415
-rw------- 1 bryan bryan        17 Dec  2 00:20 4416
-rw------- 1 bryan bryan        17 Dec  2 00:20 4418
-rw------- 1 bryan bryan        17 Dec  2 00:21 4420
-rw------- 1 bryan bryan 211725693 Dec  2 00:21 4421
-rw------- 1 bryan bryan        17 Dec  2 00:21 4422
-rw------- 1 bryan bryan        17 Dec  3 00:22 4424
-rw------- 1 bryan bryan        17 Dec  3 00:22 4425
-rw------- 1 bryan bryan        17 Dec  3 00:23 4427
-rw------- 1 bryan bryan        17 Dec  3 00:23 4429
-rw------- 1 bryan bryan        17 Dec  4 00:23 4431
-rw------- 1 bryan bryan        17 Dec  4 00:23 4433
-rw------- 1 bryan bryan        17 Dec  4 00:24 4435
-rw------- 1 bryan bryan        17 Dec  4 00:24 4437
-rw------- 1 bryan bryan        17 Dec  5 00:26 4439
-rw------- 1 bryan bryan        17 Dec  5 00:26 4441
-rw------- 1 bryan bryan        17 Dec  5 00:27 4443
-rw------- 1 bryan bryan 445545031 Dec  5 00:27 4444
-rw------- 1 bryan bryan        17 Dec  5 00:27 4445
-rw------- 1 bryan bryan        17 Dec  6 00:23 4447
-rw------- 1 bryan bryan        17 Dec  6 00:23 4448
-rw------- 1 bryan bryan        17 Dec  6 00:24 4450
-rw------- 1 bryan bryan        17 Dec  6 00:24 4452
-rw------- 1 bryan bryan        17 Dec  7 00:21 4454
-rw------- 1 bryan bryan        17 Dec  7 00:21 4456
-rw------- 1 bryan bryan        17 Dec  7 00:22 4458
-rw------- 1 bryan bryan        17 Dec  7 00:22 4460
-rw------- 1 bryan bryan        17 Dec  8 00:19 4462
-rw------- 1 bryan bryan        17 Dec  8 00:19 4464
-rw------- 1 bryan bryan        17 Dec  8 00:20 4466
-rw------- 1 bryan bryan        17 Dec  8 00:20 4468
-rw------- 1 bryan bryan 203477295 Dec  9 00:22 4469
-rw------- 1 bryan bryan        17 Dec  9 00:22 4470
-rw------- 1 bryan bryan        17 Dec  9 00:22 4472
-rw------- 1 bryan bryan 220186764 Dec 10 00:23 4473
-rw------- 1 bryan bryan        17 Dec 10 00:23 4474
-rw------- 1 bryan bryan        17 Dec 10 00:23 4476
-rw------- 1 bryan bryan        17 Dec 10 00:24 4478
-rw------- 1 bryan bryan 112309737 Dec 10 00:24 4479
-rw------- 1 bryan bryan        17 Dec 10 00:24 4480
-rw------- 1 bryan bryan 187298042 Dec 11 00:23 4481
-rw------- 1 bryan bryan        17 Dec 11 00:23 4482
-rw------- 1 bryan bryan        17 Dec 11 00:23 4483
-rw------- 1 bryan bryan        17 Dec 11 00:24 4485
-rw------- 1 bryan bryan        17 Dec 11 00:24 4487
-rw------- 1 bryan bryan 230288372 Dec 12 00:20 4488
-rw------- 1 bryan bryan        17 Dec 12 00:20 4489
-rw------- 1 bryan bryan        17 Dec 12 00:20 4491
-rw------- 1 bryan bryan        17 Dec 12 00:21 4493
-rw------- 1 bryan bryan        17 Dec 12 00:21 4495
-rw------- 1 bryan bryan 202138864 Dec 13 00:22 4496
-rw------- 1 bryan bryan        17 Dec 13 00:22 4497
-rw------- 1 bryan bryan        17 Dec 13 00:22 4499
-rw------- 1 bryan bryan        17 Dec 13 00:22 4501
-rw------- 1 bryan bryan 106446039 Dec 13 00:22 4502
-rw------- 1 bryan bryan        17 Dec 13 00:22 4503
-rw------- 1 bryan bryan 322172682 Dec 14 00:21 4504
-rw------- 1 bryan bryan        17 Dec 14 00:21 4505
-rw------- 1 bryan bryan        17 Dec 14 00:21 4506
-rw------- 1 bryan bryan 241712279 Dec 15 00:17 4507
-rw------- 1 bryan bryan        17 Dec 15 00:17 4508
-rw------- 1 bryan bryan        17 Dec 15 00:17 4509
-rw------- 1 bryan bryan        17 Dec 15 00:17 4511
-rw------- 1 bryan bryan 282989896 Dec 15 00:17 4512
-rw------- 1 bryan bryan        17 Dec 15 00:17 4513
-rw------- 1 bryan bryan 231525277 Dec 16 00:19 4514
-rw------- 1 bryan bryan        17 Dec 16 00:19 4515
-rw------- 1 bryan bryan        17 Dec 16 00:19 4516
-rw------- 1 bryan bryan        17 Dec 16 00:20 4518
-rw------- 1 bryan bryan 292125097 Dec 16 00:20 4519
-rw------- 1 bryan bryan        17 Dec 16 00:20 4520
-rw------- 1 bryan bryan 251984030 Dec 17 00:18 4521
-rw------- 1 bryan bryan        17 Dec 17 00:18 4522
-rw------- 1 bryan bryan        17 Dec 17 00:18 4523
-rw------- 1 bryan bryan        17 Dec 17 00:19 4525
-rw------- 1 bryan bryan        17 Dec 17 00:19 4527
-rw------- 1 bryan bryan 530404502 Dec 18 00:23 4528
-rw------- 1 bryan bryan 528254313 Dec 18 00:27 4529
-rw------- 1 bryan bryan 527965969 Dec 18 00:31 4530
-rw------- 1 bryan bryan 529527649 Dec 18 00:35 4531
-rw------- 1 bryan bryan 524509331 Dec 18 00:39 4532
-rw------- 1 bryan bryan 525506358 Dec 18 00:43 4533
-rw------- 1 bryan bryan 462014866 Dec 18 00:48 4534
-rw------- 1 bryan bryan        17 Dec 18 00:48 4535
-rw------- 1 bryan bryan        17 Dec 18 00:48 4537
-rw------- 1 bryan bryan        17 Dec 18 00:48 4539
-rw------- 1 bryan bryan        17 Dec 18 00:48 4541
-rw------- 1 bryan bryan        17 Dec 18 00:49 4543
-rw------- 1 bryan bryan        17 Dec 18 00:49 4545
-rw------- 1 bryan bryan        17 Dec 18 00:49 4547
-rw------- 1 bryan bryan 111535808 Dec 18 00:50 4548
-rw------- 1 bryan bryan        17 Dec 18 00:50 4549
-rw------- 1 bryan bryan 232872832 Dec 19 00:20 4550
-rw------- 1 bryan bryan        17 Dec 19 00:20 4551
-rw------- 1 bryan bryan        17 Dec 19 00:20 4552
-rw------- 1 bryan bryan        17 Dec 19 00:21 4554
-rw------- 1 bryan bryan        17 Dec 19 00:21 4556

@colmode
Copy link
Author

colmode commented Jan 6, 2019

The first attempted backup that failed was on Dec 23. There are some files in data/4 that are dated newer than that, including today. There were some attempted backups in the intervening time, but the lockfile was held by the ongoing check --repair each time.

@ThomasWaldmann
Copy link
Member

-rw------- 1 bryan bryan         8 Dec 24 11:11 4371
-rw------- 1 bryan bryan        17 Nov 26 00:21 4371.beforerecover

can you post a hexdump of these 2?

@colmode
Copy link
Author

colmode commented Jan 6, 2019

I have no space to make a repo backup btw.

@colmode
Copy link
Author

colmode commented Jan 6, 2019

hexdump data/4/4371
0000000 4f42 4752 535f 4745
0000008

hexdump data/4/4371.beforerecover
0000000 0000 0000 0000 0000 0000 0000 0000 0000
*
0000011

@ThomasWaldmann
Copy link
Member

The *.beforerecover is what borg check found on disk. Pretty empty (all zeros), but I see from the typical 17 byte file length that there should be a commit tag in there (and also the usual BORG_SEG magic at the start of the file). So data written by borg (and synced) did not really end up on disk...

@ThomasWaldmann
Copy link
Member

ThomasWaldmann commented Jan 6, 2019

So, can you go back, starting from last file, until you find a valid-looking 17byte file?

If there is NNNN and also NNNN.beforerecover, borg detected corruption, so somewhere before that (lower segment file number).

4355 maybe?

@colmode
Copy link
Author

colmode commented Jan 6, 2019

hexdump -C 4355
00000000 42 4f 52 47 5f 53 45 47 40 f4 3c 25 09 00 00 00 |BORG_SEG@.<%....|
00000010 02 |.|
00000011

@colmode
Copy link
Author

colmode commented Jan 6, 2019

The segment files that were under repair when I interrupted have funny sizes:

-rw------- 1 bryan bryan 10598338 Dec 30 08:22 4403
-rw------- 1 bryan bryan 2099200 Jan 4 17:58 4404
-rw------- 1 bryan bryan 936892 Jan 5 14:18 4405

@ThomasWaldmann
Copy link
Member

ThomasWaldmann commented Jan 6, 2019

Seems valid.

OK, maybe try this (no guarantees):

  • make sure no automated borg process is using or going to use the repo soon
  • move all 4356+ numbered files (and also their .beforerecover counterparts) to a directory outside the repo
  • move these from the repo/ toplevel dir to an other dir, too:
-rw------- 1 bryan bryan 6722 Dec 22 00:18 hints.4578
-rw------- 1 bryan bryan  190 Dec 22 00:18 integrity.4578
drwx------ 2 bryan bryan 4096 Jan  5 16:07 lock.exclusive/
-rw------- 1 bryan bryan   60 Jan  5 16:07 lock.roster
there should be also one called index.NNNN - move that too if it is there
  • run borg check --repair --repository-only repo # will take a long time

borg check will then read all the 4000 segment files, crc-check them and rebuild a new repo index from what it still finds valid.

If possible, start borg from the server and inside a screen, redirect stdout and stderr output to log files.

On the client side, it might be required / advisable to delete the local cache: borg delete --cache-only repo.

After the borg repo check is completed successfully, you could also do borg check --archives-only to do a high-level check. borg needs the key for that, so you might need to run it client-side if you do not want to put the key on the server. this will also take quite long, depending on how many archives / how much data you have.

@ThomasWaldmann
Copy link
Member

Not sure what you mean with "funny sizes"?

@ThomasWaldmann
Copy link
Member

ThomasWaldmann commented Jan 6, 2019

Maybe also talk to the hoster and ask why you see lots of zeros where synced-to-disk data should be.

(before maybe look into some of the bigger NNNN.beforerecover files, whether it is full of zeros or contains longer runs of zeros also)

@colmode
Copy link
Author

colmode commented Jan 6, 2019

Ok; thanks. Will report results.

@colmode
Copy link
Author

colmode commented Jan 6, 2019

borg -p -v check --repair --repository-only

passes:

Starting repository check
Starting repository index check
Completed repository check, no problems found.

However, borg -p -v check --archives-only fails similarly when run either locally or client-side, probably due to another corrupted file:

borg -p -v check --archives-only
Starting archive consistency check...
Analyzing archive wall-2018-01-31T01:45:52 (1/31)
Traceback (most recent call last):

  File "/usr/lib/python3/dist-packages/borg/remote.py", line 248, in serve
    res = f(**args)

  File "/usr/lib/python3/dist-packages/borg/repository.py", line 312, in get_free_nonce
    return int.from_bytes(unhexlify(fd.read()), byteorder='big')

  File "/usr/lib/python3.7/codecs.py", line 322, in decode
    (result, consumed) = self._buffer_decode(data, self.errors, final)

UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbf in position 1: invalid start byte

Borg server: Platform: Linux vps 4.18.0-2-amd64 #1 SMP Debian 4.18.10-2 (2018-10-07) x86_64
Borg server: Linux: debian buster/sid 
Borg server: Borg: 1.1.8  Python: CPython 3.7.2
Borg server: PID: 17896  CWD: /home/bryan
Borg server: sys.argv: ['/usr/bin/borg', 'serve', '--umask=077', '--info']
Borg server: SSH_ORIGINAL_COMMAND: None
Platform: Linux wall 4.15.0-42-generic #45-Ubuntu SMP Thu Nov 15 19:32:57 UTC 2018 x86_64
Linux: LinuxMint 19 tara
Borg: 1.1.8  Python: CPython 3.6.7
PID: 27218  CWD: /root
sys.argv: ['/usr/bin/borg', '-p', '-v', 'check', '--archives-only']
SSH_ORIGINAL_COMMAND: None
borg -p -v check --archives-only
Starting archive consistency check...
Enter passphrase for key /backup/borg: 
Analyzing archive wall-2018-01-31T01:45:52 (1/31)
Local Exception
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 4436, in main
    exit_code = archiver.run(args)
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 4368, in run
    return set_ec(func(args))
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 152, in wrapper
    return method(self, args, repository=repository, **kwargs)
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 320, in do_check
    verify_data=args.verify_data, save_space=args.save_space):
  File "/usr/lib/python3/dist-packages/borg/archive.py", line 1190, in check
    self.rebuild_refcounts(archive=archive, first=first, last=last, sort_by=sort_by, glob=glob)
  File "/usr/lib/python3/dist-packages/borg/archive.py", line 1577, in rebuild_refcounts
    items_buffer.add(item)
  File "/usr/lib/python3/dist-packages/borg/archive.py", line 239, in add
    self.flush()
  File "/usr/lib/python3/dist-packages/borg/archive.py", line 256, in flush
    self.chunks.append(self.write_chunk(chunk))
  File "/usr/lib/python3/dist-packages/borg/archive.py", line 1381, in add_callback
    cdata = self.key.encrypt(chunk)
  File "/usr/lib/python3/dist-packages/borg/crypto/key.py", line 371, in encrypt
    self.nonce_manager.ensure_reservation(num_aes_blocks(len(data)))
  File "/usr/lib/python3/dist-packages/borg/crypto/nonces.py", line 72, in ensure_reservation
    repo_free_nonce = self.get_repo_free_nonce()
  File "/usr/lib/python3/dist-packages/borg/crypto/nonces.py", line 39, in get_repo_free_nonce
    return self.repository.get_free_nonce()
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 312, in get_free_nonce
    return int.from_bytes(unhexlify(fd.read()), byteorder='big')
  File "/usr/lib/python3.7/codecs.py", line 322, in decode
    (result, consumed) = self._buffer_decode(data, self.errors, final)
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbf in position 1: invalid start byte

Platform: Linux vps 4.18.0-2-amd64 #1 SMP Debian 4.18.10-2 (2018-10-07) x86_64
Linux: debian buster/sid 
Borg: 1.1.8  Python: CPython 3.7.2
PID: 17899  CWD: /home/bryan
sys.argv: ['/usr/bin/borg', '-p', '-v', 'check', '--archives-only']
SSH_ORIGINAL_COMMAND: None

@colmode
Copy link
Author

colmode commented Jan 6, 2019

I'll try delete -n on that first archive and see what it says. I'm ok delete --force-in stuff if that might get me back to a clean state.

@colmode
Copy link
Author

colmode commented Jan 6, 2019

borg -p -v delete -n ::wall-2018-01-31T01:45:52
Cache, or information obtained from the security directory is newer than repository - this is either an attack or unsafe (multiple repos with same ID)

I did borg delete --cache-only everywhere, and ~/.cache/borg doesn't contain a directory that matches the id hex string (UUID?) for the current repo. There are some other/older caches though.

@colmode
Copy link
Author

colmode commented Jan 6, 2019

It might have been finding my .cache because I was running undo sudo. After --deleting that, I make some progress:

borg -p -v delete -n ::wall-2018-01-31T01:45:52

Synchronizing chunks cache...
Archives: 31, w/ cached Idx: 0, w/ outdated Idx: 0, w/o cached Idx: 31.
Fetching and building archive index for wall-2018-01-31T01:45:52 ...52
Merging into master chunks index ...
Fetching and building archive index for wall-2018-02-28T01:58:46 ...46
Merging into master chunks index ...
Fetching and building archive index for wall-2018-03-31T01:53:23 ...23
Merging into master chunks index ...
Fetching and building archive index for wall-2018-04-30T01:50:01 ...01
Merging into master chunks index ...
Fetching and building archive index for wall-2018-05-31T02:24:14 ...14
Merging into master chunks index ...
Fetching and building archive index for wall-2018-06-30T01:36:08 ...08
Merging into master chunks index ...
Fetching and building archive index for wall-2018-07-29T01:41:51 ...51
Merging into master chunks index ...
Fetching and building archive index for wall-2018-08-31T00:16:45 ...45
Merging into master chunks index ...
Fetching and building archive index for wall-2018-09-16T00:12:27 ...27
Object with key e39704cad4361fd7e09e99feb805908776de61e21c77f8448caa2de870807824 not found in repository ssh://bryan@vps:7922/backup/borg::wall-2018-01-31T01:45:52.
Traceback (most recent call last):
File "/usr/lib/python3/dist-packages/borg/archiver.py", line 4436, in main
exit_code = archiver.run(args)
File "/usr/lib/python3/dist-packages/borg/archiver.py", line 4368, in run
return set_ec(func(args))
File "/usr/lib/python3/dist-packages/borg/archiver.py", line 152, in wrapper
return method(self, args, repository=repository, **kwargs)
File "/usr/lib/python3/dist-packages/borg/archiver.py", line 1238, in do_delete
return self._delete_archives(args, repository)
File "/usr/lib/python3/dist-packages/borg/archiver.py", line 1282, in delete_archives
with Cache(repository, key, manifest, progress=args.progress, lock_wait=self.lock_wait) as cache:
File "/usr/lib/python3/dist-packages/borg/cache.py", line 379, in new
return local()
File "/usr/lib/python3/dist-packages/borg/cache.py", line 373, in local
lock_wait=lock_wait, cache_mode=cache_mode)
File "/usr/lib/python3/dist-packages/borg/cache.py", line 466, in init
self.sync()
File "/usr/lib/python3/dist-packages/borg/cache.py", line 850, in sync
self.chunks = create_master_idx(self.chunks)
File "/usr/lib/python3/dist-packages/borg/cache.py", line 804, in create_master_idx
fetch_and_build_idx(archive_id, decrypted_repository, archive_chunk_idx)
File "/usr/lib/python3/dist-packages/borg/cache.py", line 703, in fetch_and_build_idx
csize, data = decrypted_repository.get(archive_id)
File "/usr/lib/python3/dist-packages/borg/remote.py", line 1071, in get
return next(self.get_many([key], cache=False))
File "/usr/lib/python3/dist-packages/borg/remote.py", line 1175, in get_many
for key
, data in repository_iterator:
File "/usr/lib/python3/dist-packages/borg/remote.py", line 928, in get_many
for resp in self.call_many('get', [{'id': id} for id in ids], is_preloaded=is_preloaded):
File "/usr/lib/python3/dist-packages/borg/remote.py", line 773, in call_many
handle_error(unpacked)
File "/usr/lib/python3/dist-packages/borg/remote.py", line 750, in handle_error
raise Repository.ObjectNotFound(args[0].decode(), self.location.orig)
borg.repository.Repository.ObjectNotFound: Object with key e39704cad4361fd7e09e99feb805908776de61e21c77f8448caa2de870807824 not found in repository ssh://bryan@vps:7922/backup/borg::wall-2018-01-31T01:45:52.

Platform: Linux wall 4.15.0-42-generic #45-Ubuntu SMP Thu Nov 15 19:32:57 UTC 2018 x86_64
Linux: LinuxMint 19 tara
Borg: 1.1.8 Python: CPython 3.6.7
PID: 29407 CWD: /home/bryan
sys.argv: ['/usr/bin/borg', '-p', '-v', 'delete', '-n', '::wall-2018-01-31T01:45:52']
SSH_ORIGINAL_COMMAND: None

@colmode
Copy link
Author

colmode commented Jan 6, 2019

And sitll:

borg -p -v check --archives-only

Analyzing archive wall-2018-01-31T01:45:52 (1/31)
Traceback (most recent call last):

File "/usr/lib/python3/dist-packages/borg/remote.py", line 248, in serve
res = f(**args)

File "/usr/lib/python3/dist-packages/borg/repository.py", line 312, in get_free_nonce
return int.from_bytes(unhexlify(fd.read()), byteorder='big')

File "/usr/lib/python3.7/codecs.py", line 322, in decode
(result, consumed) = self._buffer_decode(data, self.errors, final)

UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbf in position 1: invalid start byte

@ThomasWaldmann
Copy link
Member

Check if the contents of the repo/nonce file look reasonable.
Maybe you also have corruption in that file (like all-binary-zeros, like seen above).

@ThomasWaldmann
Copy link
Member

ThomasWaldmann commented Jan 6, 2019

borg remembers some security related stuff locally in ~/.config/borg/security.
You may need to remove some stuff there due to the deletion of repo contents.

Also, there seems to be some object in the repo really missing (ObjectNotFound), so it would be good to have that borg check --repair --archives-only succeeding (which might kill some more corrupted stuff, but at least get the repo into a valid state).

@colmode
Copy link
Author

colmode commented Jan 6, 2019

nonce looks plausible: 73 bytes non-0.

Ok, you hadn't mentioned --archives-only with --repair previously. Will try that.

All the files in .config/borg/security seems to have been generated today.

@colmode
Copy link
Author

colmode commented Jan 6, 2019

Does it make sense to delete --force the broken archives if check --repair --archives-only doesn't work?

@colmode
Copy link
Author

colmode commented Jan 6, 2019

borg -p -v check --repair --archives-only has the same crash:

Analyzing archive wall-2018-01-31T01:45:52 (1/31)
...
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbf in position 1: invalid start byte

@colmode
Copy link
Author

colmode commented Jan 6, 2019

Shouldn't the nonce be ok since I can borg mount and access the earlier archives?

@ThomasWaldmann
Copy link
Member

ThomasWaldmann commented Jan 6, 2019

This is where it reads / decodes the repo/nonce file.

The contents of that should be pure ascii (a long hex number).

@ThomasWaldmann
Copy link
Member

Btw, if you post tracebacks or stuff you entered as a command, use github markdown to mark it as "code" (triple backticks on a line above and below it).

@colmode
Copy link
Author

colmode commented Jan 6, 2019

Sorry, it's 16 bytes; was looking at the wrong file. It's not ascii hex, just 16 non-0 bytes.

@ThomasWaldmann
Copy link
Member

ThomasWaldmann commented Jan 6, 2019

write 80000000000000001 into it (16 bytes total).

That will forward it to a likely safe value, you'll lose about half the nonce-space, but usually that is no issue.

@colmode
Copy link
Author

colmode commented Jan 6, 2019

Is 0x80 the first byte (byte 0) of the file there, or is 0x01 the first byte?

@colmode
Copy link
Author

colmode commented Jan 6, 2019

Oic, maybe. You are calling unhexlify(), so the file is supposed to be ascii hex.

@colmode
Copy link
Author

colmode commented Jan 6, 2019

Your string 80000000000000001 has 17 chars. One fewer zeros then, to make 16?

@ThomasWaldmann
Copy link
Member

Oops. Yeah, should be 16. Also, I got it slightly wrong, should be 8000000000000080.
The idea is to have the MSB 1, no matter how the byte order is.

@colmode
Copy link
Author

colmode commented Jan 7, 2019

8000000000000001 seems to have worked ok. borg -p -v check --repair --archives-only passed with lots of zero replacements and then a new backup ran normally.

Do the zero chunks get replaced properly in the new archive if the file mtime is old? I'm not concerned with older archives that now have bad chunks, but I'd like to ensure that the latest backup is good.

@colmode
Copy link
Author

colmode commented Jan 7, 2019

When I borg mount and try to cat files that had zero-replacement chunks, I get an i/o error.

@colmode
Copy link
Author

colmode commented Jan 7, 2019

ls shows the correct file size, but borg list shows size 0:

-rw-r--r-- 1 root root 30506115 Sep 11 01:11 dlocatedb
drwxr-xr-x root   root          0 Tue, 2018-09-11 01:11:11 data/local/backup/remote-backups/nin/var/lib/dlocate

@ThomasWaldmann
Copy link
Member

borg mount --help

@colmode
Copy link
Author

colmode commented Jan 7, 2019

Oic, that is actually helpful behavior.

I delete two of the compromised archives to make sure pruning would work.

Thanks for helping me recover!

@colmode colmode closed this as completed Jan 7, 2019
ThomasWaldmann added a commit to ThomasWaldmann/borg that referenced this issue Jan 8, 2019
ThomasWaldmann added a commit to ThomasWaldmann/borg that referenced this issue Jan 25, 2019
ThomasWaldmann added a commit to ThomasWaldmann/borg that referenced this issue Jan 25, 2019
ThomasWaldmann added a commit to ThomasWaldmann/borg that referenced this issue Jan 29, 2019
keep "data" as is, use "d" for slices

so that the data.release() call is on the original memoryview and
also we can delete the last reference to a slice of it first.
ThomasWaldmann added a commit that referenced this issue Jan 29, 2019
@ghost ghost mentioned this issue Aug 26, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants