[SOLVED] Restore from backup never ends

[muekno]

did a manualy backup from a VM before updating application.
tried to restore as update fails.
restore log:

progress 78% (read 26801602560 bytes, zeroes = 46% (12385779712 bytes), duration 360 sec)
progress 79% (read 27145535488 bytes, zeroes = 46% (12549357568 bytes), duration 365 sec)
progress 80% (read 27489468416 bytes, zeroes = 46% (12658409472 bytes), duration 370 sec)
progress 81% (read 27833401344 bytes, zeroes = 46% (12998148096 bytes), duration 370 sec)
progress 82% (read 28177334272 bytes, zeroes = 47% (13342081024 bytes), duration 370 sec)
progress 83% (read 28521267200 bytes, zeroes = 47% (13686013952 bytes), duration 370 sec)
progress 84% (read 28865200128 bytes, zeroes = 48% (14029946880 bytes), duration 370 sec)
progress 85% (read 29209133056 bytes, zeroes = 48% (14277410816 bytes), duration 373 sec)
progress 86% (read 29553065984 bytes, zeroes = 48% (14382268416 bytes), duration 382 sec)
progress 87% (read 29896998912 bytes, zeroes = 48% (14508097536 bytes), duration 389 sec)
progress 88% (read 30236737536 bytes, zeroes = 49% (14835253248 bytes), duration 390 sec)
progress 89% (read 30580670464 bytes, zeroes = 49% (15179186176 bytes), duration 390 sec)
progress 90% (read 30924603392 bytes, zeroes = 50% (15523119104 bytes), duration 390 sec)
progress 91% (read 31268536320 bytes, zeroes = 50% (15846080512 bytes), duration 390 sec)
progress 92% (read 31612469248 bytes, zeroes = 50% (15850274816 bytes), duration 399 sec)
progress 93% (read 31956402176 bytes, zeroes = 49% (15850274816 bytes), duration 408 sec)
progress 94% (read 32300335104 bytes, zeroes = 49% (16026435584 bytes), duration 412 sec)
progress 95% (read 32644268032 bytes, zeroes = 49% (16261316608 bytes), duration 414 sec)
progress 96% (read 32988200960 bytes, zeroes = 50% (16605249536 bytes), duration 414 sec)
progress 97% (read 33332133888 bytes, zeroes = 50% (16944988160 bytes), duration 414 sec)
progress 98% (read 33676066816 bytes, zeroes = 51% (17288921088 bytes), duration 414 sec)
progress 99% (read 34019999744 bytes, zeroes = 51% (17628659712 bytes), duration 414 sec)
progress 100% (read 34359738368 bytes, zeroes = 52% (17964204032 bytes), duration 415 sec)
restore image complete (bytes=34359738368, duration=415.02s, speed=78.96MB/s)

but never get OK
tried again with the automatic weekly backup, log above the same thing.

I had successfull restores some time before

What i did , selceted the stop VM, selected backup, click restore, accepted defaults and ok
I have no problem with the older automatic backup, as VM ist quite static, and I have still a backup one week older, but one must finish
What is wrong?

 

[muekno]

Now quit a long time I got an OK, why is teh a logn time sind restore complete and the final OK?

 

[Darkk]

Yes, it does take a very long time to restore as PBS have to reassemble all the chucks. Plus at the end it does final clean up before the job ends.

 

[gfngfn256]

Now quit a long time

How long? Your posts are 2 minutes apart. (Don't know how long you waited till you posted the first post).
You don't provide HW, Storage & NW details, so all of them could be factors.

N.B. I think you need to change the thread title.

 

[muekno]

i waited about 20 minutes, but if it is normal that there is some time it is ok

 

[UdoB]

i waited about 20 minutes,

Yeah, that's long.

Not PVE but possibly for the same reason: I do copy .iso files to classic USB sticks from time to time, to produce a bootable medium to install some random Operating System. I have a lot of not-so-new (read: slow) sticks for this. The classic "dd"-command will read a -let's say- 5 GB large file from the source disk with several 100 MBytes per second and the "status=progress" tells me it wrote nearly all the data. Then it stops outputting status information after reaching 99%. The actual end of that command will need another 10 or 20 minutes for me.

This is (write-) buffer bloat. The command used (your restore process) will read the data, give the data to "the operating system" in an asyncronous manner to write it to the destination, and only at the very end it will run a "flush now" command and... wait for the "actually finished!" state - longer than the user expected.

What I wanted to say: your destination disks are slow. Possibly a cheap consumer SSD or perhaps rotating rust.

 

[muekno]

Ok, my systems are not the fasted, the harddisks too but I use ZFS and have a lot of memory (64 GB). I am IT supporter and for my home and partly test network the performance for daily work is absolut fast enough. For more test I have a second similar PROXMOX server.
I do restiores nearly never,only if some updates OS or application fails. So if, as I learned now the restore may take some while till the OK , thats OK for me. Former restores had a delay between restore complete and the final OK too, but normal less 1 to 3 minutes.

Regards
Rainer

 

[gfngfn256]

20 minutes is pretty long - seeing that the total disk size (written) is roughly 15.3gb (48% of 32gb). Possibly you have a lot of other writing activity (at the time) to that disk.

 

[UdoB]

This is (write-) buffer bloat.

I would like to extend my statement - the described effect is not what ZFS in itself gives us.

For writing data ZFS itself has the concept of "Transaction Groups" (TXG) constituting the ZIL (ZFS Intent Log). The written data is buffered there. This works like a "write cache" for asynchronous written data. (SYNC data is also stored here, but it will be "flushed" immediately.) Data is gathered here and usually the transmission to disk is delayed. But only for up to five seconds! After five seconds this TXG changes its state and is being written to disk. As this take some time a second TXG is used to accept new data arriving. (Actually there can be a third one, but usually only for microseconds during the "switch" - but no more.)

This means: under normal circumstances data is being written to disk after five seconds.

If there are buffers ("write caches") placed in front of that TXG-mechanism then my statement in my previous post is valid. Then flushing that non-ZFS(!) buffers may take a longer than five seconds, depending on the volume and the actual performance of the hardware disks.

It is a clever mechanism, but the actual behavior may be surprising...