Garbage collect task failing due to timeout when using s3 (minio) in LAN

A

awe_cz

New Member
Jan 8, 2025
5
0
1
Code: 
2025-08-27T00:00:00+02:00: starting garbage collection on store s3-eu
2025-08-27T00:00:00+02:00: task triggered by schedule 'daily'
2025-08-27T00:00:01+02:00: Access time update check successful, proceeding with GC.
2025-08-27T00:00:01+02:00: Using access time cutoff 1d 5m, minimum access time is 2025-08-25T21:55:00Z
2025-08-27T00:00:01+02:00: Start GC phase1 (mark used chunks)
2025-08-27T00:00:02+02:00: marked 1% (2 of 114 index files)
(...)
2025-08-27T00:00:21+02:00: marked 100% (114 of 114 index files)
2025-08-27T00:00:21+02:00: Start GC phase2 (sweep unused chunks)
2025-08-27T00:15:29+02:00: Not found, mark for deletion: s3-eu/.chunks/18d8/18d871c9524c0c92992d26070bb0ad3772dec0e724de2ea78ed350270a4f0a11
(..)
2025-08-27T00:18:28+02:00: Not found, mark for deletion: s3-eu/.chunks/1cec/1cec90eaf83f4ab1729524b8599c2ff30792877702e6328d323f0bb33056b563
2025-08-27T00:19:31+02:00: queued notification (id=e22ada68-da20-4c6c-b29c-3bc50829b14c)
2025-08-27T00:19:31+02:00: TASK ERROR: request timeout: deadline has elapsed

It looks like some hardcoded timeout, could we extend it somehow?

Thanks,
Martin
 
Hi,
this version is much better, it failed after three hours somewhere in the middle of the garbage collection process when s3 returned 504 - I fixed that by increasing timeout on nginx proxy in between pbs and minio.

But this also uncovered another problem, looks like something in pbs dies and it does not respond to http/s request and shows in proximox as not available.

I intentionally left it in this state, is there a page describing what should be investigated in this case?

Thanks.
 
Last edited:
Yes, from the description on bugzilla this really looks like this case. It backed up almost the whole cluster (~2TB) and it died at the end of it. The only problem here is that this happened with 4.0.15-1 which was supposed to be fixed, right?
 
Last edited:
Yes, however as reported, the fix seems to be incomplete or the issue not related to the fixed bug.

awe_cz said:
It backed up almost the whole cluster (~2TB) and it died at the end of it
Click to expand...
Please provide the vm config for the vm at which the backup job failed, by identifying the VMID from the backup job and running qm config <VMID> --current
 
This is the VM the backup failed on;

Code: 
~# qm config 146 --current
agent: 1
balloon: 0
bios: seabios
boot: 
cores: 2
cpu: host
ide0: local:iso/virtio-win-0.1.266.iso,media=cdrom,size=707456K
machine: pc-i440fx-9.0
memory: 6144
meta: creation-qemu=9.0.2,ctime=1736540719
name: VPN5
net0: e1000=BC:24:11:9E:63:A1,bridge=vmbr0
numa: 0
onboot: 1
ostype: win10
sata0: local-lvm-nvme:vm-146-disk-0,cache=writethrough,discard=on,size=50G,ssd=1
scsihw: lsi
smbios1: uuid=564da9e3-fc6b-111e-ae46-fc0cd1e014f9
sockets: 2
tpmstate0: local-lvm-nvme:vm-146-disk-1,size=4M,version=v2.0
vmgenid: 888fe674-4177-4c9a-94cc-7f02ebea3514

Code: 
INFO: Starting Backup of VM 146 (qemu)
INFO: Backup started at 2025-09-18 05:23:31
INFO: status = running
INFO: VM Name: VPN5
INFO: include disk 'sata0' 'local-lvm-nvme:vm-146-disk-0' 50G
INFO: include disk 'tpmstate0' 'local-lvm-nvme:vm-146-disk-1' 4M
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/146/2025-09-18T03:23:31Z'
INFO: attaching TPM drive to QEMU for backup
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'd3f523ce-abb7-45a1-9dd7-d01c81f6892b'
INFO: resuming VM again
INFO: sata0: dirty-bitmap status: OK (20.7 GiB of 50.0 GiB dirty)
INFO: tpmstate0-backup: dirty-bitmap status: created new
INFO: using fast incremental mode (dirty-bitmap), 20.7 GiB dirty of 50.0 GiB total
INFO:   1% (272.0 MiB of 20.7 GiB) in 3s, read: 90.7 MiB/s, write: 89.3 MiB/s
INFO:   2% (484.0 MiB of 20.7 GiB) in 6s, read: 70.7 MiB/s, write: 70.7 MiB/s
INFO:   3% (716.0 MiB of 20.7 GiB) in 9s, read: 77.3 MiB/s, write: 77.3 MiB/s
INFO:   4% (992.0 MiB of 20.7 GiB) in 12s, read: 92.0 MiB/s, write: 92.0 MiB/s
INFO:   5% (1.1 GiB of 20.7 GiB) in 16s, read: 36.0 MiB/s, write: 35.0 MiB/s
INFO:   6% (1.3 GiB of 20.7 GiB) in 19s, read: 61.3 MiB/s, write: 61.3 MiB/s
INFO:   7% (1.5 GiB of 20.7 GiB) in 22s, read: 64.0 MiB/s, write: 64.0 MiB/s
INFO:   8% (1.7 GiB of 20.7 GiB) in 27s, read: 39.2 MiB/s, write: 37.6 MiB/s
INFO:   9% (1.9 GiB of 20.7 GiB) in 31s, read: 64.0 MiB/s, write: 64.0 MiB/s
INFO:  10% (2.2 GiB of 20.7 GiB) in 34s, read: 80.0 MiB/s, write: 78.7 MiB/s
INFO:  11% (2.3 GiB of 20.7 GiB) in 37s, read: 66.7 MiB/s, write: 61.3 MiB/s
INFO:  12% (2.6 GiB of 20.7 GiB) in 40s, read: 88.0 MiB/s, write: 88.0 MiB/s
INFO:  13% (2.7 GiB of 20.7 GiB) in 43s, read: 41.3 MiB/s, write: 41.3 MiB/s
INFO:  14% (2.9 GiB of 20.7 GiB) in 46s, read: 72.0 MiB/s, write: 69.3 MiB/s
INFO:  15% (3.2 GiB of 20.7 GiB) in 50s, read: 64.0 MiB/s, write: 60.0 MiB/s
INFO:  16% (3.5 GiB of 20.7 GiB) in 53s, read: 90.7 MiB/s, write: 86.7 MiB/s
INFO:  17% (3.6 GiB of 20.7 GiB) in 56s, read: 56.0 MiB/s, write: 54.7 MiB/s
INFO:  18% (3.8 GiB of 20.7 GiB) in 59s, read: 78.7 MiB/s, write: 70.7 MiB/s
INFO:  19% (4.0 GiB of 20.7 GiB) in 1m 2s, read: 64.0 MiB/s, write: 53.3 MiB/s
INFO:  20% (4.2 GiB of 20.7 GiB) in 1m 5s, read: 62.7 MiB/s, write: 60.0 MiB/s
INFO:  21% (4.5 GiB of 20.7 GiB) in 1m 8s, read: 82.7 MiB/s, write: 78.7 MiB/s
INFO:  22% (4.6 GiB of 20.7 GiB) in 1m 11s, read: 30.7 MiB/s, write: 29.3 MiB/s
INFO:  23% (4.8 GiB of 20.7 GiB) in 1m 17s, read: 40.7 MiB/s, write: 38.7 MiB/s
INFO:  24% (5.0 GiB of 20.7 GiB) in 1m 20s, read: 68.0 MiB/s, write: 62.7 MiB/s
INFO:  25% (5.2 GiB of 20.7 GiB) in 1m 25s, read: 43.2 MiB/s, write: 32.0 MiB/s
INFO:  26% (5.4 GiB of 20.7 GiB) in 1m 28s, read: 78.7 MiB/s, write: 70.7 MiB/s
INFO:  27% (5.6 GiB of 20.7 GiB) in 1m 34s, read: 36.7 MiB/s, write: 35.3 MiB/s
INFO:  28% (5.9 GiB of 20.7 GiB) in 1m 37s, read: 77.3 MiB/s, write: 72.0 MiB/s
INFO:  29% (6.1 GiB of 20.7 GiB) in 1m 41s, read: 54.0 MiB/s, write: 52.0 MiB/s
INFO:  30% (6.3 GiB of 20.7 GiB) in 1m 44s, read: 86.7 MiB/s, write: 82.7 MiB/s
INFO:  31% (6.5 GiB of 20.7 GiB) in 1m 48s, read: 30.0 MiB/s, write: 24.0 MiB/s
INFO:  32% (6.7 GiB of 20.7 GiB) in 1m 51s, read: 86.7 MiB/s, write: 80.0 MiB/s
INFO:  33% (6.9 GiB of 20.7 GiB) in 1m 54s, read: 49.3 MiB/s, write: 37.3 MiB/s
INFO:  34% (7.1 GiB of 20.7 GiB) in 1m 57s, read: 82.7 MiB/s, write: 81.3 MiB/s
INFO:  35% (7.3 GiB of 20.7 GiB) in 2m 2s, read: 40.8 MiB/s, write: 38.4 MiB/s
INFO:  36% (7.6 GiB of 20.7 GiB) in 2m 5s, read: 97.3 MiB/s, write: 81.3 MiB/s
INFO:  37% (7.7 GiB of 20.7 GiB) in 2m 8s, read: 25.3 MiB/s, write: 21.3 MiB/s
INFO:  38% (7.9 GiB of 20.7 GiB) in 2m 13s, read: 56.8 MiB/s, write: 36.8 MiB/s
INFO:  39% (8.2 GiB of 20.7 GiB) in 2m 16s, read: 100.0 MiB/s, write: 73.3 MiB/s
INFO:  40% (8.4 GiB of 20.7 GiB) in 2m 19s, read: 77.3 MiB/s, write: 69.3 MiB/s
INFO:  42% (8.7 GiB of 20.7 GiB) in 2m 22s, read: 82.7 MiB/s, write: 77.3 MiB/s
INFO:  43% (8.9 GiB of 20.7 GiB) in 2m 25s, read: 68.0 MiB/s, write: 64.0 MiB/s
INFO:  44% (9.1 GiB of 20.7 GiB) in 2m 28s, read: 84.0 MiB/s, write: 80.0 MiB/s
INFO:  45% (9.4 GiB of 20.7 GiB) in 2m 34s, read: 36.7 MiB/s, write: 36.7 MiB/s
INFO:  46% (9.6 GiB of 20.7 GiB) in 2m 37s, read: 73.3 MiB/s, write: 69.3 MiB/s
INFO:  47% (9.7 GiB of 20.7 GiB) in 2m 42s, read: 31.2 MiB/s, write: 31.2 MiB/s
INFO:  48% (10.0 GiB of 20.7 GiB) in 2m 45s, read: 85.3 MiB/s, write: 82.7 MiB/s
INFO:  49% (10.2 GiB of 20.7 GiB) in 2m 48s, read: 69.3 MiB/s, write: 68.0 MiB/s
INFO:  50% (10.4 GiB of 20.7 GiB) in 2m 51s, read: 72.0 MiB/s, write: 72.0 MiB/s
INFO:  51% (10.6 GiB of 20.7 GiB) in 2m 54s, read: 65.3 MiB/s, write: 64.0 MiB/s
INFO:  52% (10.8 GiB of 20.7 GiB) in 2m 58s, read: 53.0 MiB/s, write: 52.0 MiB/s
INFO:  53% (11.0 GiB of 20.7 GiB) in 3m 4s, read: 40.7 MiB/s, write: 40.0 MiB/s
INFO:  54% (11.2 GiB of 20.7 GiB) in 3m 8s, read: 54.0 MiB/s, write: 51.0 MiB/s
INFO:  55% (11.4 GiB of 20.7 GiB) in 3m 13s, read: 33.6 MiB/s, write: 31.2 MiB/s
INFO:  56% (11.6 GiB of 20.7 GiB) in 3m 17s, read: 60.0 MiB/s, write: 58.0 MiB/s
INFO:  57% (11.9 GiB of 20.7 GiB) in 3m 20s, read: 97.3 MiB/s, write: 92.0 MiB/s
INFO:  58% (12.1 GiB of 20.7 GiB) in 3m 23s, read: 50.7 MiB/s, write: 46.7 MiB/s
INFO:  59% (12.3 GiB of 20.7 GiB) in 3m 26s, read: 81.3 MiB/s, write: 73.3 MiB/s
INFO:  60% (12.5 GiB of 20.7 GiB) in 3m 29s, read: 72.0 MiB/s, write: 69.3 MiB/s
INFO:  61% (12.8 GiB of 20.7 GiB) in 3m 32s, read: 88.0 MiB/s, write: 81.3 MiB/s
INFO:  62% (12.9 GiB of 20.7 GiB) in 3m 35s, read: 56.0 MiB/s, write: 52.0 MiB/s
INFO:  63% (13.2 GiB of 20.7 GiB) in 3m 38s, read: 88.0 MiB/s, write: 86.7 MiB/s
INFO:  64% (13.3 GiB of 20.7 GiB) in 3m 41s, read: 42.7 MiB/s, write: 41.3 MiB/s
INFO:  65% (13.5 GiB of 20.7 GiB) in 3m 44s, read: 77.3 MiB/s, write: 74.7 MiB/s
INFO:  66% (13.7 GiB of 20.7 GiB) in 3m 47s, read: 38.7 MiB/s, write: 37.3 MiB/s
INFO:  67% (13.9 GiB of 20.7 GiB) in 3m 51s, read: 55.0 MiB/s, write: 52.0 MiB/s
INFO:  68% (14.1 GiB of 20.7 GiB) in 3m 55s, read: 58.0 MiB/s, write: 55.0 MiB/s
INFO:  69% (14.4 GiB of 20.7 GiB) in 4m 2s, read: 40.6 MiB/s, write: 38.9 MiB/s
INFO:  70% (14.5 GiB of 20.7 GiB) in 4m 5s, read: 49.3 MiB/s, write: 48.0 MiB/s
INFO:  71% (14.8 GiB of 20.7 GiB) in 4m 8s, read: 84.0 MiB/s, write: 77.3 MiB/s
INFO:  72% (15.0 GiB of 20.7 GiB) in 4m 11s, read: 85.3 MiB/s, write: 82.7 MiB/s
INFO:  73% (15.2 GiB of 20.7 GiB) in 4m 14s, read: 58.7 MiB/s, write: 56.0 MiB/s
INFO:  74% (15.4 GiB of 20.7 GiB) in 4m 17s, read: 82.7 MiB/s, write: 81.3 MiB/s
INFO:  75% (15.7 GiB of 20.7 GiB) in 4m 20s, read: 78.7 MiB/s, write: 78.7 MiB/s
INFO:  76% (15.9 GiB of 20.7 GiB) in 4m 23s, read: 66.7 MiB/s, write: 66.7 MiB/s
INFO:  77% (16.1 GiB of 20.7 GiB) in 4m 26s, read: 74.7 MiB/s, write: 57.3 MiB/s
INFO:  78% (16.2 GiB of 20.7 GiB) in 4m 30s, read: 38.0 MiB/s, write: 25.0 MiB/s
INFO:  79% (16.5 GiB of 20.7 GiB) in 4m 33s, read: 85.3 MiB/s, write: 84.0 MiB/s
INFO:  80% (16.6 GiB of 20.7 GiB) in 4m 36s, read: 37.3 MiB/s, write: 37.3 MiB/s
INFO:  81% (16.9 GiB of 20.7 GiB) in 4m 39s, read: 109.3 MiB/s, write: 108.0 MiB/s
INFO:  83% (17.2 GiB of 20.7 GiB) in 4m 42s, read: 108.0 MiB/s, write: 104.0 MiB/s
INFO:  84% (17.4 GiB of 20.7 GiB) in 4m 46s, read: 44.0 MiB/s, write: 41.0 MiB/s
INFO:  85% (17.7 GiB of 20.7 GiB) in 4m 49s, read: 94.7 MiB/s, write: 94.7 MiB/s
INFO:  86% (17.8 GiB of 20.7 GiB) in 4m 52s, read: 57.3 MiB/s, write: 56.0 MiB/s
INFO:  87% (18.1 GiB of 20.7 GiB) in 4m 55s, read: 74.7 MiB/s, write: 61.3 MiB/s
INFO:  88% (18.3 GiB of 20.7 GiB) in 4m 58s, read: 80.0 MiB/s, write: 70.7 MiB/s
INFO:  89% (18.4 GiB of 20.7 GiB) in 5m 1s, read: 53.3 MiB/s, write: 46.7 MiB/s
INFO:  90% (18.7 GiB of 20.7 GiB) in 5m 4s, read: 92.0 MiB/s, write: 92.0 MiB/s
INFO:  91% (18.9 GiB of 20.7 GiB) in 5m 7s, read: 48.0 MiB/s, write: 48.0 MiB/s
INFO:  92% (19.1 GiB of 20.7 GiB) in 5m 10s, read: 89.3 MiB/s, write: 68.0 MiB/s
INFO:  93% (19.2 GiB of 20.7 GiB) in 5m 13s, read: 38.7 MiB/s, write: 38.7 MiB/s
INFO:  94% (19.5 GiB of 20.7 GiB) in 5m 16s, read: 86.7 MiB/s, write: 84.0 MiB/s
INFO:  95% (19.7 GiB of 20.7 GiB) in 5m 19s, read: 82.7 MiB/s, write: 60.0 MiB/s
INFO:  96% (20.0 GiB of 20.7 GiB) in 5m 22s, read: 102.7 MiB/s, write: 60.0 MiB/s
INFO:  98% (20.3 GiB of 20.7 GiB) in 5m 25s, read: 104.0 MiB/s, write: 92.0 MiB/s
INFO:  99% (20.5 GiB of 20.7 GiB) in 5m 28s, read: 53.3 MiB/s, write: 38.7 MiB/s
INFO: 100% (20.7 GiB of 20.7 GiB) in 5m 31s, read: 64.0 MiB/s, write: 60.0 MiB/s
ERROR: backup close image failed: command error: stream closed because of a broken pipe
INFO: aborting backup job
INFO: resuming VM again
ERROR: Backup of VM 146 failed - backup close image failed: command error: stream closed because of a broken pipe
INFO: Failed at 2025-09-18 12:47:18
 
You must log in or register to reply here.
Top Bottom