[Bug]: Very slow backup without any change (regression from v1.1.3 against v1.0.6)

[flibustenet]

Describe the bug

v1.1.3
and
plakar/v1.2.0-devel.26ac123046f19593d66e44329ccf33c5925d5784

On a new S3 repository, the first shot is very fast, 2:01.
The second and others are very slow 20:21 even when there is no change on the source data.

$ time plakar at @scw backup ~/projects/
[02:01] 673fd0f7 completed                                                       13 GiB
********************************************************************************** 100%
        import: nodes=37500/37500, objects=204891/204891
         store: read=0 B, write=8.5 GiB

real	2m2,814s
user	6m41,849s
sys	1m28,069s

$ time plakar at @scw backup ~/projects/
[20:21] 01a03c90 completed                                                       13 GiB
********************************************************************************** 100%
        import: nodes=37500/37500, objects=204891/204891
         store: read=56 MiB, write=568 KiB

real	20m41,662s
user	3m53,357s
sys	0m47,574s

It was discussed on Discord, I put here to track.

[jeromebagattin]

Same problem here, my home backup time has gone from 30 seconds to 20 minutes.

I've tried:

• cleaning the caches
• rebuilding the store

[poolpOrg]

@mathieu-plak has spotted a possible cause last week and issued a fix, we'll release a bug fix version tomorrow.

[mathieu-plak]

Should be fixed in v1.1.4 that just went out.

[jeromebagattin]

Normal time is back, thanks

[flibustenet]

For me it doesn't change. I'll try with v1.0.6 on the same bucket to be sure it's not an issue with the bucket.

[TobyGiacometti]

@flibustenet Have you tried backup -cache no to see if the regression is caused by the switch to in-memory VFS caching in version 1.1.3 and the resulting increase of requests to the store?

[flibustenet]

Yes, it's with the in-memory VFS

With 1.0.6 it's very fast.
With 1.1.4 it's very slow
With 1.1.4 and -cache no it's very fast

Same bucket, cleaned.

plakar 1.0.6

rm -r .cache/plakar
plakar backup 12GiB
1/ 
real	2m23,992s
user	0m6,546s
sys	0m12,348s

2/
real	0m45,697s
user	0m5,269s
sys	0m10,913s

3/
real	0m44,464s
user	0m5,580s
sys	0m10,314s

plakar 1.1.4

rm -r .cache/plakar
1/
[01:52] 57589559 completed                                                                             13 GiB
******************************************************************************************************** 100%
        import: nodes=37510/37510, objects=205494/205494
         store: read=0 B, write=8.6 GiB

real	1m53,468s
user	5m34,282s
sys	1m6,037s

3/ time plakar at @scw114 backup ~/projets/
[14:43] 4e158dc4 completed                                                                             13 GiB
******************************************************************************************************** 100%
        import: nodes=37510/37510, objects=205494/205494
         store: read=60 MiB, write=16 MiB

real	14m44,288s
user	3m9,140s
sys	0m43,950s

3/ time plakar at @scw114 backup -cache no ~/projets/
[00:58] ae1f3628 completed                                                                             13 GiB
******************************************************************************************************** 100%
        import: nodes=37510/37510, objects=205494/205494
         store: read=0 B, write=17 MiB

real	0m59,108s
user	3m31,087s
sys	0m46,876s

[mathieu-plak]

Hello! Sorry to be obtuse but can you confirm the version string from plakar? The issued fix should really fix this, and it was confirmed by multiple people.

If it's not the case I'd be interested in a full trace run of the slow backup to identify the bottleneck. (I know it's the VFS but I need a more precise view :D). If you are not confortable sharing the trace here feel free to ping us in private on discord.

[flibustenet]

It's v1.1.4, i send the trace on discord.