Proxmox Backup Server deduplication value drops

[WindowLock]

Hello, Proxmox community!

I have a query that I've been unable to resolve for the past weeks. My deduplication ratio on Proxmox Backup Server (PBS) has significantly decreased. Previously, I know (though I can't access older logs to confirm) that the deduplication factor was above 12, but within the last month (before even upgrading PBS to the latest version 3.1-5), it's plummeted to just 5.93, I even upgraded to the latest version (love to be on the latest) this does not recover.

Disk space keeps on increasing, despite a pruning job that retains: 2 daily, 2 weekly, 12 monthly, and 10 yearly backups.

The most recent garbage collection showed:

2024-04-12T08:20:16+02:00: starting garbage collection on store Backup-Server
2024-04-12T08:20:16+02:00: Start GC phase1 (mark used chunks)
2024-04-12T08:20:17+02:00: marked 1% (3 of 232 index files)
2024-04-12T08:20:17+02:00: marked 2% (5 of 232 index files)
2024-04-12T08:20:17+02:00: marked 3% (7 of 232 index files)
2024-04-12T08:20:18+02:00: marked 4% (10 of 232 index files)
2024-04-12T08:20:18+02:00: marked 5% (12 of 232 index files)
2024-04-12T08:20:18+02:00: marked 6% (14 of 232 index files)
2024-04-12T08:20:18+02:00: marked 7% (17 of 232 index files)
2024-04-12T08:20:18+02:00: marked 8% (19 of 232 index files)
2024-04-12T08:20:18+02:00: marked 9% (21 of 232 index files)
2024-04-12T08:20:18+02:00: marked 10% (24 of 232 index files)
2024-04-12T08:20:19+02:00: marked 11% (26 of 232 index files)
2024-04-12T08:20:19+02:00: marked 12% (28 of 232 index files)
2024-04-12T08:20:19+02:00: marked 13% (31 of 232 index files)
2024-04-12T08:20:19+02:00: marked 14% (33 of 232 index files)
2024-04-12T08:20:20+02:00: marked 15% (35 of 232 index files)
2024-04-12T08:20:20+02:00: marked 16% (38 of 232 index files)
2024-04-12T08:20:20+02:00: marked 17% (40 of 232 index files)
2024-04-12T08:20:21+02:00: marked 18% (42 of 232 index files)
2024-04-12T08:20:21+02:00: marked 19% (45 of 232 index files)
2024-04-12T08:20:22+02:00: marked 20% (47 of 232 index files)
2024-04-12T08:20:22+02:00: marked 21% (49 of 232 index files)
2024-04-12T08:20:22+02:00: marked 22% (52 of 232 index files)
2024-04-12T08:20:23+02:00: marked 23% (54 of 232 index files)
2024-04-12T08:20:23+02:00: marked 24% (56 of 232 index files)
2024-04-12T08:20:23+02:00: marked 25% (58 of 232 index files)
2024-04-12T08:20:25+02:00: marked 26% (61 of 232 index files)
2024-04-12T08:20:27+02:00: marked 27% (63 of 232 index files)
2024-04-12T08:20:28+02:00: marked 28% (65 of 232 index files)
2024-04-12T08:20:29+02:00: marked 29% (68 of 232 index files)
2024-04-12T08:20:29+02:00: marked 30% (70 of 232 index files)
2024-04-12T08:20:30+02:00: marked 31% (72 of 232 index files)
2024-04-12T08:20:31+02:00: marked 32% (75 of 232 index files)
2024-04-12T08:20:31+02:00: marked 33% (77 of 232 index files)
2024-04-12T08:20:32+02:00: marked 34% (79 of 232 index files)
2024-04-12T08:20:32+02:00: marked 35% (82 of 232 index files)
2024-04-12T08:20:32+02:00: marked 36% (84 of 232 index files)
2024-04-12T08:20:33+02:00: marked 37% (86 of 232 index files)
2024-04-12T08:20:50+02:00: marked 38% (89 of 232 index files)
2024-04-12T08:21:51+02:00: marked 39% (91 of 232 index files)
2024-04-12T08:22:05+02:00: marked 40% (93 of 232 index files)
2024-04-12T08:22:14+02:00: marked 41% (96 of 232 index files)
2024-04-12T08:22:56+02:00: marked 42% (98 of 232 index files)
2024-04-12T08:23:37+02:00: marked 43% (100 of 232 index files)
2024-04-12T08:24:38+02:00: marked 44% (103 of 232 index files)
2024-04-12T08:25:17+02:00: marked 45% (105 of 232 index files)
2024-04-12T08:26:16+02:00: marked 46% (107 of 232 index files)
2024-04-12T08:26:44+02:00: marked 47% (110 of 232 index files)
2024-04-12T08:26:44+02:00: marked 48% (112 of 232 index files)
2024-04-12T08:26:45+02:00: marked 49% (114 of 232 index files)
2024-04-12T08:26:46+02:00: marked 50% (116 of 232 index files)
2024-04-12T08:26:47+02:00: marked 51% (119 of 232 index files)
2024-04-12T08:26:47+02:00: marked 52% (121 of 232 index files)
2024-04-12T08:26:48+02:00: marked 53% (123 of 232 index files)
2024-04-12T08:26:50+02:00: marked 54% (126 of 232 index files)
2024-04-12T08:26:50+02:00: marked 55% (128 of 232 index files)
2024-04-12T08:26:51+02:00: marked 56% (130 of 232 index files)
2024-04-12T08:26:52+02:00: marked 57% (133 of 232 index files)
2024-04-12T08:26:53+02:00: marked 58% (135 of 232 index files)
2024-04-12T08:26:53+02:00: marked 59% (137 of 232 index files)
2024-04-12T08:26:54+02:00: marked 60% (140 of 232 index files)
2024-04-12T08:26:56+02:00: marked 61% (142 of 232 index files)
2024-04-12T08:26:56+02:00: marked 62% (144 of 232 index files)
2024-04-12T08:26:57+02:00: marked 63% (147 of 232 index files)
2024-04-12T08:26:58+02:00: marked 64% (149 of 232 index files)
2024-04-12T08:26:59+02:00: marked 65% (151 of 232 index files)
2024-04-12T08:27:01+02:00: marked 66% (154 of 232 index files)
2024-04-12T08:27:02+02:00: marked 67% (156 of 232 index files)
2024-04-12T08:27:03+02:00: marked 68% (158 of 232 index files)
2024-04-12T08:27:03+02:00: marked 69% (161 of 232 index files)
2024-04-12T08:27:04+02:00: marked 70% (163 of 232 index files)
2024-04-12T08:27:05+02:00: marked 71% (165 of 232 index files)
2024-04-12T08:27:06+02:00: marked 72% (168 of 232 index files)
2024-04-12T08:27:06+02:00: marked 73% (170 of 232 index files)
2024-04-12T08:27:07+02:00: marked 74% (172 of 232 index files)
2024-04-12T08:27:07+02:00: marked 75% (174 of 232 index files)
2024-04-12T08:27:08+02:00: marked 76% (177 of 232 index files)
2024-04-12T08:27:08+02:00: marked 77% (179 of 232 index files)
2024-04-12T08:27:08+02:00: marked 78% (181 of 232 index files)
2024-04-12T08:27:08+02:00: marked 79% (184 of 232 index files)
2024-04-12T08:27:08+02:00: marked 80% (186 of 232 index files)
2024-04-12T08:27:08+02:00: marked 81% (188 of 232 index files)
2024-04-12T08:27:08+02:00: marked 82% (191 of 232 index files)
2024-04-12T08:27:08+02:00: marked 83% (193 of 232 index files)
2024-04-12T08:27:08+02:00: marked 84% (195 of 232 index files)
2024-04-12T08:27:08+02:00: marked 85% (198 of 232 index files)
2024-04-12T08:27:09+02:00: marked 86% (200 of 232 index files)
2024-04-12T08:27:10+02:00: marked 87% (202 of 232 index files)
2024-04-12T08:27:11+02:00: marked 88% (205 of 232 index files)
2024-04-12T08:27:59+02:00: marked 89% (207 of 232 index files)
2024-04-12T08:28:00+02:00: marked 90% (209 of 232 index files)
2024-04-12T08:28:01+02:00: marked 91% (212 of 232 index files)
2024-04-12T08:28:02+02:00: marked 92% (214 of 232 index files)
2024-04-12T08:28:07+02:00: marked 93% (216 of 232 index files)
2024-04-12T08:28:11+02:00: marked 94% (219 of 232 index files)
2024-04-12T08:28:12+02:00: marked 95% (221 of 232 index files)
2024-04-12T08:28:13+02:00: marked 96% (223 of 232 index files)
2024-04-12T08:28:17+02:00: marked 97% (226 of 232 index files)
2024-04-12T08:28:47+02:00: marked 98% (228 of 232 index files)
2024-04-12T08:28:48+02:00: marked 99% (230 of 232 index files)
2024-04-12T08:28:48+02:00: marked 100% (232 of 232 index files)
2024-04-12T08:28:48+02:00: Start GC phase2 (sweep unused chunks)
2024-04-12T08:28:48+02:00: processed 1% (56017 chunks)
2024-04-12T08:28:48+02:00: processed 2% (111680 chunks)
2024-04-12T08:28:48+02:00: processed 3% (167632 chunks)
2024-04-12T08:28:49+02:00: processed 4% (223484 chunks)
2024-04-12T08:28:49+02:00: processed 5% (279311 chunks)
2024-04-12T08:28:49+02:00: processed 6% (335388 chunks)
2024-04-12T08:28:49+02:00: processed 7% (391119 chunks)
2024-04-12T08:28:49+02:00: processed 8% (446695 chunks)
2024-04-12T08:28:49+02:00: processed 9% (502771 chunks)
2024-04-12T08:28:50+02:00: processed 10% (558474 chunks)
2024-04-12T08:28:50+02:00: processed 11% (614249 chunks)
2024-04-12T08:28:50+02:00: processed 12% (670078 chunks)
2024-04-12T08:28:50+02:00: processed 13% (725881 chunks)
2024-04-12T08:28:50+02:00: processed 14% (782111 chunks)
2024-04-12T08:28:50+02:00: processed 15% (838163 chunks)
2024-04-12T08:28:51+02:00: processed 16% (893567 chunks)
2024-04-12T08:28:51+02:00: processed 17% (949312 chunks)
2024-04-12T08:28:51+02:00: processed 18% (1005301 chunks)
2024-04-12T08:28:51+02:00: processed 19% (1061250 chunks)
2024-04-12T08:28:51+02:00: processed 20% (1117238 chunks)
2024-04-12T08:28:51+02:00: processed 21% (1172970 chunks)
2024-04-12T08:28:52+02:00: processed 22% (1228548 chunks)
2024-04-12T08:28:52+02:00: processed 23% (1284493 chunks)
2024-04-12T08:28:52+02:00: processed 24% (1340426 chunks)
2024-04-12T08:28:52+02:00: processed 25% (1395844 chunks)
2024-04-12T08:28:52+02:00: processed 26% (1452074 chunks)
2024-04-12T08:28:52+02:00: processed 27% (1507714 chunks)
2024-04-12T08:28:53+02:00: processed 28% (1563983 chunks)
2024-04-12T08:28:53+02:00: processed 29% (1619859 chunks)
2024-04-12T08:28:53+02:00: processed 30% (1675842 chunks)
2024-04-12T08:28:53+02:00: processed 31% (1731593 chunks)
2024-04-12T08:28:53+02:00: processed 32% (1787826 chunks)
2024-04-12T08:28:53+02:00: processed 33% (1843501 chunks)
2024-04-12T08:28:54+02:00: processed 34% (1899109 chunks)
2024-04-12T08:28:54+02:00: processed 35% (1954791 chunks)
2024-04-12T08:28:54+02:00: processed 36% (2010797 chunks)
2024-04-12T08:28:54+02:00: processed 37% (2066646 chunks)
2024-04-12T08:28:54+02:00: processed 38% (2122447 chunks)
2024-04-12T08:28:54+02:00: processed 39% (2178073 chunks)
2024-04-12T08:28:54+02:00: processed 40% (2233515 chunks)
2024-04-12T08:28:55+02:00: processed 41% (2289133 chunks)
2024-04-12T08:28:55+02:00: processed 42% (2344949 chunks)
2024-04-12T08:28:55+02:00: processed 43% (2401023 chunks)
2024-04-12T08:28:55+02:00: processed 44% (2456786 chunks)
2024-04-12T08:28:55+02:00: processed 45% (2512575 chunks)
2024-04-12T08:28:55+02:00: processed 46% (2568032 chunks)
2024-04-12T08:28:56+02:00: processed 47% (2624156 chunks)
2024-04-12T08:28:56+02:00: processed 48% (2680277 chunks)
2024-04-12T08:28:56+02:00: processed 49% (2736092 chunks)
2024-04-12T08:28:56+02:00: processed 50% (2792119 chunks)
2024-04-12T08:28:56+02:00: processed 51% (2848295 chunks)
2024-04-12T08:28:56+02:00: processed 52% (2904088 chunks)
2024-04-12T08:28:57+02:00: processed 53% (2959979 chunks)
2024-04-12T08:28:57+02:00: processed 54% (3015755 chunks)
2024-04-12T08:28:57+02:00: processed 55% (3071331 chunks)
2024-04-12T08:28:57+02:00: processed 56% (3127090 chunks)
2024-04-12T08:28:57+02:00: processed 57% (3182642 chunks)
2024-04-12T08:28:57+02:00: processed 58% (3238555 chunks)
2024-04-12T08:28:58+02:00: processed 59% (3294646 chunks)
2024-04-12T08:28:58+02:00: processed 60% (3350376 chunks)
2024-04-12T08:28:58+02:00: processed 61% (3406344 chunks)
2024-04-12T08:28:58+02:00: processed 62% (3462422 chunks)
2024-04-12T08:28:58+02:00: processed 63% (3518308 chunks)
2024-04-12T08:28:58+02:00: processed 64% (3574354 chunks)
2024-04-12T08:28:59+02:00: processed 65% (3630306 chunks)
2024-04-12T08:28:59+02:00: processed 66% (3686548 chunks)
2024-04-12T08:28:59+02:00: processed 67% (3742624 chunks)
2024-04-12T08:28:59+02:00: processed 68% (3798339 chunks)
2024-04-12T08:28:59+02:00: processed 69% (3853803 chunks)
2024-04-12T08:28:59+02:00: processed 70% (3909789 chunks)
2024-04-12T08:29:00+02:00: processed 71% (3965515 chunks)
2024-04-12T08:29:00+02:00: processed 72% (4021262 chunks)
2024-04-12T08:29:00+02:00: processed 73% (4077145 chunks)
2024-04-12T08:29:00+02:00: processed 74% (4133085 chunks)
2024-04-12T08:29:00+02:00: processed 75% (4188851 chunks)
2024-04-12T08:29:00+02:00: processed 76% (4244541 chunks)
2024-04-12T08:29:01+02:00: processed 77% (4300168 chunks)
2024-04-12T08:29:01+02:00: processed 78% (4356179 chunks)
2024-04-12T08:29:01+02:00: processed 79% (4411865 chunks)
2024-04-12T08:29:01+02:00: processed 80% (4467942 chunks)
2024-04-12T08:29:01+02:00: processed 81% (4524149 chunks)
2024-04-12T08:29:01+02:00: processed 82% (4579765 chunks)
2024-04-12T08:29:02+02:00: processed 83% (4635745 chunks)
2024-04-12T08:29:02+02:00: processed 84% (4691380 chunks)
2024-04-12T08:29:02+02:00: processed 85% (4747329 chunks)
2024-04-12T08:29:02+02:00: processed 86% (4803017 chunks)
2024-04-12T08:29:02+02:00: processed 87% (4858746 chunks)
2024-04-12T08:29:02+02:00: processed 88% (4914723 chunks)
2024-04-12T08:29:03+02:00: processed 89% (4970709 chunks)
2024-04-12T08:29:03+02:00: processed 90% (5026448 chunks)
2024-04-12T08:29:03+02:00: processed 91% (5082114 chunks)
2024-04-12T08:29:03+02:00: processed 92% (5137787 chunks)
2024-04-12T08:29:03+02:00: processed 93% (5193686 chunks)
2024-04-12T08:29:03+02:00: processed 94% (5249356 chunks)
2024-04-12T08:29:04+02:00: processed 95% (5305067 chunks)
2024-04-12T08:29:04+02:00: processed 96% (5360764 chunks)
2024-04-12T08:29:04+02:00: processed 97% (5416168 chunks)
2024-04-12T08:29:04+02:00: processed 98% (5472154 chunks)
2024-04-12T08:29:04+02:00: processed 99% (5528037 chunks)
2024-04-12T08:29:04+02:00: Removed garbage: 0 B
2024-04-12T08:29:04+02:00: Removed chunks: 0
2024-04-12T08:29:04+02:00: Pending removals: 664.095 GiB (in 341452 chunks)
2024-04-12T08:29:04+02:00: Original data usage: 81.015 TiB
2024-04-12T08:29:04+02:00: On-Disk usage: 13.67 TiB (16.87%)
2024-04-12T08:29:04+02:00: On-Disk chunks: 5242257
2024-04-12T08:29:04+02:00: Deduplication factor: 5.93
2024-04-12T08:29:04+02:00: Average chunk size: 2.734 MiB
2024-04-12T08:29:04+02:00: TASK OK

I'm only backing up 11 servers, with our file server being the largest at 4TiB (with 1.5 TiB actually used but thinly provisioned). I suspect a configuration error might have been made by the person who initially set up Proxmox, but I can't pinpoint the cause of the continuous drop in the deduplication ratio. Our file server, for instance, contains 98% identical data in each backup, much of it being default Windows server files, which I'd assume should be highly deduplicable.

What should I investigate to understand what's happening? A few months ago, it seemed like our backup capacity was virtually unlimited, according to PBS's time-to-full calculation. Now, it's counting down by days.

The filesystem in use is XFS, with a PERC H700 controller. Could this be the root of the issue? I'm considering migrating to a new PBS setup using ZFS and an HBA controller instead of PERC, but that's not feasible for the next few months and would want to make the current situation hold up a bit longer. Expanding the storage is not easy, because it's XFS with 8x 2TiB disks and cannot be easily replaced with 4TiB disks I guess (or at least I don't dare to change them)

Thanks in advance for taking my post in consideration and your potential answers.

 

[Chris]

2024-04-12T08:29:04+02:00: Removed garbage: 0 B 2024-04-12T08:29:04+02:00: Removed chunks: 0 2024-04-12T08:29:04+02:00: Pending removals: 664.095 GiB (in 341452 chunks)

Hi,
according to the garbage collection task log you showed, there are pending removals, but no garbage chunks were removed? So either there were non marked from the previous run, or they have been touched since. Please post also the task log of the previous garbage collection task. Is there an active writer still operating on that datastore? Are there other processes interacting with the datastore which might update the atime of the chunks?

 

[WindowLock]

Hi,
according to the garbage collection task log you showed, there are pending removals, but no garbage chunks were removed? So either there were non marked from the previous run, or they have been touched since. Please post also the task log of the previous garbage collection task. Is there an active writer still operating on that datastore? Are there other processes interacting with the datastore which might update the atime of the chunks?

Yes, you're correct about the pending removals amounting to approximately 700GiB. However, even with the scheduled removal on April 13th around 9:20 AM, I don't anticipate a significant increase in the deduplication factor based on my understanding of how it's currently calculated.

Here's the log from the previous task for reference:

2024-04-03T21:15:00+02:00: starting garbage collection on store Backup-Server
2024-04-03T21:15:00+02:00: task triggered by schedule 'daily'
2024-04-03T21:15:00+02:00: Start GC phase1 (mark used chunks)
2024-04-03T21:15:04+02:00: marked 1% (4 of 303 index files)
2024-04-03T21:15:04+02:00: marked 2% (7 of 303 index files)
2024-04-03T21:52:01+02:00: marked 99% (300 of 303 index files)
2024-04-03T21:52:02+02:00: marked 100% (303 of 303 index files)
2024-04-03T21:52:02+02:00: Start GC phase2 (sweep unused chunks)
2024-04-03T21:52:05+02:00: processed 1% (57070 chunks)
2024-04-03T21:57:01+02:00: processed 99% (5634880 chunks)
2024-04-03T21:57:02+02:00: Removed garbage: 478.635 GiB
2024-04-03T21:57:02+02:00: Removed chunks: 395742
2024-04-03T21:57:02+02:00: Original data usage: 104.651 TiB
2024-04-03T21:57:02+02:00: On-Disk usage: 13.869 TiB (13.25%)
2024-04-03T21:57:02+02:00: On-Disk chunks: 5295770
2024-04-03T21:57:02+02:00: Deduplication factor: 7.55
2024-04-03T21:57:02+02:00: Average chunk size: 2.746 MiB
2024-04-03T21:57:02+02:00: TASK OK

The scheduling misstep meant the Garbage Collection ran at an inopportune time, with the last significant deletion happening on April 3rd. As of now, there aren't any ongoing writes or operations affecting the datastore. Does this mean I've misunderstood how the deduplication factor is presented? Will there be an improvement in the deduplication factor following tomorrow's removal and subsequent Garbage Collection?

Notably, the deduplication factor was at 7.55 on April 3rd, according to the log. The day before it was at 8.46 here's a log for reference:

2024-04-01T00:00:00+02:00: starting garbage collection on store Backup-Server
2024-04-01T00:00:00+02:00: task triggered by schedule 'daily'
2024-04-01T00:00:00+02:00: Start GC phase1 (mark used chunks)
2024-04-01T00:06:07+02:00: marked 1% (4 of 348 index files)
2024-04-01T00:08:07+02:00: marked 2% (7 of 348 index files)
2024-04-02T01:14:25+02:00: marked 99% (345 of 348 index files)
2024-04-02T01:14:25+02:00: marked 100% (348 of 348 index files)
2024-04-02T01:14:25+02:00: Start GC phase2 (sweep unused chunks)
2024-04-02T01:19:21+02:00: processed 1% (57223 chunks)
2024-04-02T10:52:12+02:00: processed 99% (5648531 chunks)
2024-04-02T10:57:23+02:00: Removed garbage: 25.864 GiB
2024-04-02T10:57:23+02:00: Removed chunks: 17020
2024-04-02T10:57:23+02:00: Pending removals: 22.373 GiB (in 15874 chunks)
2024-04-02T10:57:23+02:00: Original data usage: 120.979 TiB
2024-04-02T10:57:23+02:00: On-Disk usage: 14.293 TiB (11.81%)
2024-04-02T10:57:23+02:00: On-Disk chunks: 5672373
2024-04-02T10:57:23+02:00: Deduplication factor: 8.46
2024-04-02T10:57:23+02:00: Average chunk size: 2.642 MiB
2024-04-02T10:57:23+02:00: TASK OK

Nevertheless, just a week later, the deduplication factor has declined to 5.5 as you can review in the first post log I shared, despite the number of VMs remaining the same and minimal changes to the data. This trend highlights a consistent decrease, which raises concerns.

What would be the best approach to diagnose the root cause of this issue? Or is everything actually in order, and I'm possibly overcomplicating the situation?

 

[Chris]

The deduplication factor is calculated by taking the ratio of the indexed data chunks for all snapshots on the datastore to the actual on disk data size, both shown as original data usage and on-disk usage. So since the original data usage fluctuates a lot (81 - 120.9 TiB) , while the on disk usage stays (roughly) the same (13.6 - 14.2 TiB) as seen from you logs, the deduplication factor will change accordingly.

But from what you showed, the garbage collection does free up unused chunks and the used on-disk storage space should not be increasing, it rather seems to decrease. How did you conclude that there is an increase? Is this maybe a ZFS dataset, sharing is space with others on a ZFS pool?