Why are my Syncs failing?

[JanWiesemann]

I've setup two PBS instances. One local and one offside. When I'm trying to sync both instances, the task returns with `TASK ERROR: sync failed with some errors.`. But from what I can see, no error occurred.

Both Instances verified all snapshots without any issues.

Full Log:

2-10-03T22:13:49+02:00: Starting datastore sync job 'Home:main:main:Home:s-e53e482a-5c1d'
2022-10-03T22:13:49+02:00: sync datastore 'main' from 'Home/main'
2022-10-03T22:13:49+02:00: ----
2022-10-03T22:13:49+02:00: Syncing datastore 'main', namespace 'Home' into datastore 'main', namespace 'Home'
2022-10-03T22:13:49+02:00: found 13 groups to sync
2022-10-03T22:13:50+02:00: re-sync snapshot ct/102/2022-10-03T16:00:59Z
2022-10-03T22:13:50+02:00: no data changes
2022-10-03T22:13:50+02:00: re-sync snapshot ct/102/2022-10-03T16:00:59Z done
2022-10-03T22:13:50+02:00: percentage done: 7.69% (1/13 groups)
2022-10-03T22:13:50+02:00: skipped: 47 snapshot(s) (2022-05-29T16:02:44Z .. 2022-10-03T10:00:59Z) older than the newest local snapshot
2022-10-03T22:13:50+02:00: re-sync snapshot ct/104/2022-10-03T16:00:06Z
2022-10-03T22:13:50+02:00: no data changes
2022-10-03T22:13:50+02:00: re-sync snapshot ct/104/2022-10-03T16:00:06Z done
2022-10-03T22:13:50+02:00: percentage done: 15.38% (2/13 groups)
2022-10-03T22:13:50+02:00: skipped: 47 snapshot(s) (2022-05-29T16:09:04Z .. 2022-10-03T10:00:02Z) older than the newest local snapshot
2022-10-03T22:13:50+02:00: re-sync snapshot ct/105/2022-10-03T19:00:09Z
2022-10-03T22:13:50+02:00: no data changes
2022-10-03T22:13:50+02:00: re-sync snapshot ct/105/2022-10-03T19:00:09Z done
2022-10-03T22:13:50+02:00: percentage done: 23.08% (3/13 groups)
2022-10-03T22:13:50+02:00: skipped: 51 snapshot(s) (2022-05-29T19:00:05Z .. 2022-10-03T16:04:28Z) older than the newest local snapshot
2022-10-03T22:13:51+02:00: re-sync snapshot ct/106/2022-10-03T16:00:35Z
2022-10-03T22:13:51+02:00: no data changes
2022-10-03T22:13:51+02:00: re-sync snapshot ct/106/2022-10-03T16:00:35Z done
2022-10-03T22:13:51+02:00: percentage done: 30.77% (4/13 groups)
2022-10-03T22:13:51+02:00: skipped: 47 snapshot(s) (2022-05-29T16:09:27Z .. 2022-10-03T10:00:34Z) older than the newest local snapshot
2022-10-03T22:13:51+02:00: re-sync snapshot ct/107/2022-10-03T16:01:53Z
2022-10-03T22:13:51+02:00: no data changes
2022-10-03T22:13:51+02:00: re-sync snapshot ct/107/2022-10-03T16:01:53Z done
2022-10-03T22:13:51+02:00: percentage done: 38.46% (5/13 groups)
2022-10-03T22:13:51+02:00: skipped: 47 snapshot(s) (2022-05-29T16:10:40Z .. 2022-10-03T10:01:33Z) older than the newest local snapshot
2022-10-03T22:13:51+02:00: re-sync snapshot ct/108/2022-10-03T16:02:18Z
2022-10-03T22:13:51+02:00: no data changes
2022-10-03T22:13:51+02:00: re-sync snapshot ct/108/2022-10-03T16:02:18Z done
2022-10-03T22:13:51+02:00: percentage done: 46.15% (6/13 groups)
2022-10-03T22:13:51+02:00: skipped: 47 snapshot(s) (2022-05-29T16:11:04Z .. 2022-10-03T10:01:56Z) older than the newest local snapshot
2022-10-03T22:13:51+02:00: re-sync snapshot ct/109/2022-10-03T16:02:34Z
2022-10-03T22:13:52+02:00: no data changes
2022-10-03T22:13:52+02:00: re-sync snapshot ct/109/2022-10-03T16:02:34Z done
2022-10-03T22:13:52+02:00: percentage done: 53.85% (7/13 groups)
2022-10-03T22:13:52+02:00: skipped: 47 snapshot(s) (2022-05-29T16:11:25Z .. 2022-10-03T10:02:12Z) older than the newest local snapshot
2022-10-03T22:13:52+02:00: re-sync snapshot ct/112/2022-10-03T16:03:06Z
2022-10-03T22:13:52+02:00: no data changes
2022-10-03T22:13:52+02:00: re-sync snapshot ct/112/2022-10-03T16:03:06Z done
2022-10-03T22:13:52+02:00: percentage done: 61.54% (8/13 groups)
2022-10-03T22:13:52+02:00: skipped: 47 snapshot(s) (2022-05-29T16:12:09Z .. 2022-10-03T10:02:41Z) older than the newest local snapshot
2022-10-03T22:13:53+02:00: re-sync snapshot ct/114/2022-10-03T16:03:28Z
2022-10-03T22:13:53+02:00: no data changes
2022-10-03T22:13:53+02:00: re-sync snapshot ct/114/2022-10-03T16:03:28Z done
2022-10-03T22:13:53+02:00: percentage done: 69.23% (9/13 groups)
2022-10-03T22:13:53+02:00: skipped: 47 snapshot(s) (2022-05-29T16:12:28Z .. 2022-10-03T10:03:02Z) older than the newest local snapshot
2022-10-03T22:13:53+02:00: re-sync snapshot ct/115/2022-10-03T16:03:55Z
2022-10-03T22:13:53+02:00: no data changes
2022-10-03T22:13:53+02:00: re-sync snapshot ct/115/2022-10-03T16:03:55Z done
2022-10-03T22:13:53+02:00: percentage done: 76.92% (10/13 groups)
2022-10-03T22:13:53+02:00: skipped: 47 snapshot(s) (2022-05-29T16:12:52Z .. 2022-10-03T10:03:27Z) older than the newest local snapshot
2022-10-03T22:13:53+02:00: re-sync snapshot vm/101/2022-09-28T16:00:04Z
2022-10-03T22:13:53+02:00: no data changes
2022-10-03T22:13:53+02:00: re-sync snapshot vm/101/2022-09-28T16:00:04Z done
2022-10-03T22:13:53+02:00: percentage done: 82.53% (10/13 groups, 35/48 snapshots in group #11)
2022-10-03T22:13:53+02:00: sync snapshot vm/101/2022-09-29T16:00:07Z
2022-10-03T22:13:53+02:00: sync archive qemu-server.conf.blob
2022-10-03T22:13:54+02:00: sync archive fw.conf.blob
2022-10-03T22:13:54+02:00: sync archive drive-virtio0.img.fidx
2022-10-03T22:13:54+02:00: percentage done: 82.69% (10/13 groups, 36/48 snapshots in group #11)
2022-10-03T22:13:54+02:00: sync group vm/101 failed - blob too small (0 bytes).
2022-10-03T22:13:54+02:00: re-sync snapshot vm/110/2022-10-03T16:02:54Z
2022-10-03T22:13:54+02:00: no data changes
2022-10-03T22:13:54+02:00: re-sync snapshot vm/110/2022-10-03T16:02:54Z done
2022-10-03T22:13:54+02:00: percentage done: 92.31% (12/13 groups)
2022-10-03T22:13:54+02:00: skipped: 10 snapshot(s) (2022-09-29T10:03:26Z .. 2022-10-03T10:02:30Z) older than the newest local snapshot
2022-10-03T22:13:55+02:00: re-sync snapshot vm/111/2022-10-03T16:02:59Z
2022-10-03T22:13:55+02:00: no data changes
2022-10-03T22:13:55+02:00: re-sync snapshot vm/111/2022-10-03T16:02:59Z done
2022-10-03T22:13:55+02:00: percentage done: 100.00% (13/13 groups)
2022-10-03T22:13:55+02:00: skipped: 47 snapshot(s) (2022-05-29T16:11:49Z .. 2022-10-03T10:02:35Z) older than the newest local snapshot
2022-10-03T22:13:55+02:00: Finished syncing namespace Home, current progress: 12 groups, 48 snapshots
2022-10-03T22:13:55+02:00: TASK ERROR: sync failed with some errors.

 

[fabian]

2022-10-03T22:13:54+02:00: sync group vm/101 failed - blob too small (0 bytes).

it seems to me like the next snapshot after 2022-09-29T16:00:07Z (on the source side) might contain a broken file - maybe an empty index.json.blob or qemu-server.conf.blob? could you do stat on all the files contained within?