Bug#994125: rsync: rsync hangs (?) after upgrade to bullseye

0 views
Skip to first unread message

Samuel Henrique

unread,
Sep 12, 2021, 1:10:04 PMSep 12
to
Hello Janusz,

Thank you for your bug report,

We will have to try to get a more verbose output to investigate this.

Could you provide what exactly your script is doing? Like which
options of rsync it is using.
And could you try to do the same operation but with the verbose
parameters "-vvv" set and provide the log?
It's possible that you're gonna have to save the output to some file,
if it becomes too big.

Regards,

--
Samuel Henrique <samueloph>

Janusz S. Bień

unread,
Sep 13, 2021, 3:50:03 AMSep 13
to

Hi!

Yesterday rsync finished after 3 hours. I had a lot of new large files
(virtual machines) and I have added numerous small files (so taking
longer than usual should be expected), and the reported speed was 1.94M
bytes/sec:

--8<---------------cut here---------------start------------->8---
2021/09/12 15:53:10 [8103] Number of files: 347,684 (reg: 306,343, dir: 24,017, link: 17,324)
2021/09/12 15:53:10 [8103] Number of created files: 82,443 (reg: 58,416, dir: 9,455, link: 14,572)
2021/09/12 15:53:10 [8103] Number of regular files transferred: 58,441
2021/09/12 15:53:10 [8103] Total file size: 466.40G bytes
2021/09/12 15:53:10 [8103] Total transferred file size: 237.44G bytes
2021/09/12 15:53:10 [8103] Literal data: 21.31G bytes
2021/09/12 15:53:10 [8103] Matched data: 216.13G bytes
2021/09/12 15:53:10 [8103] File list size: 4.39M
2021/09/12 15:53:10 [8103] File list generation time: 0.002 seconds
2021/09/12 15:53:10 [8103] File list transfer time: 0.000 seconds
2021/09/12 15:53:10 [8103] Total bytes sent: 21.33G
2021/09/12 15:53:10 [8103] Total bytes received: 16.11M
2021/09/12 15:53:10 [8103] sent 21.33G bytes received 16.11M bytes 1.94M bytes/sec
2021/09/12 15:53:10 [8103] total size is 466.40G speedup is 21.84
--8<---------------cut here---------------end--------------->8---


Unfortunately I deleted incidentally almost all earlier logs, but I'm
pretty sure the speed was usually much higher. In the logs left I see,
to my surprise, that sometimes the speed was even lower, e.g.

2021/06/02 12:58:26 [14079] sent 3.39M bytes received 137.16K bytes 190.76K bytes/sec

but sometimes it was also quite high, e.g.

2021/06/03 15:31:14 [16281] sent 57.63G bytes received 149.27K bytes 50.98M bytes/sec

The computer, the router and the QNAP NAS are in the same room. Some
time ago I tested the speed of computer-NAS connection. Unfortunately I
forgot what programs I used, I don't remember also the exact value but
it was satisfactory (100M bytes/sec?).

On Sun, Sep 12 2021 at 17:59 +01, Samuel Henrique wrote:

[...]

> Could you provide what exactly your script is doing? Like which
> options of rsync it is using.

This is a one-liner split here by Emacs:
--8<---------------cut here---------------start------------->8---
time nice rsync --verbose --archive --delete
--exclude-from=/home/jsbien/backups/home-exclude.txt --human-readable
--stats --log-file=desktophome2NAS.log /home/jsbien/
jsbien@zjbnas:/share/CACHEDEV1_DATA/homes/jsbien/backup
--8<---------------cut here---------------end--------------->8---


> And could you try to do the same operation but with the verbose
> parameters "-vvv" set and provide the log?

I've got (no substantial changes on the disk in the meantime):

--8<---------------cut here---------------start------------->8---
2021/09/13 08:24:33 [9967] Number of files: 347,906 (reg: 306,534, dir: 24,048, link: 17,324)
2021/09/13 08:24:33 [9967] Number of created files: 226 (reg: 195, dir: 31)
2021/09/13 08:24:33 [9967] Number of regular files transferred: 318
2021/09/13 08:24:33 [9967] Total file size: 467.00G bytes
2021/09/13 08:24:33 [9967] Total transferred file size: 617.83M bytes
2021/09/13 08:24:33 [9967] Literal data: 593.33M bytes
2021/09/13 08:24:33 [9967] Matched data: 24.96M bytes
2021/09/13 08:24:33 [9967] File list size: 2.36M
2021/09/13 08:24:33 [9967] File list generation time: 0.005 seconds
2021/09/13 08:24:33 [9967] File list transfer time: 0.000 seconds
2021/09/13 08:24:33 [9967] Total bytes sent: 605.35M
2021/09/13 08:24:33 [9967] Total bytes received: 142.04M
2021/09/13 08:24:33 [9967] sent 605.35M bytes received 142.04M bytes 3.80M bytes/sec
2021/09/13 08:24:33 [9967] total size is 467.00G speedup is 624.83
2021/09/13 08:24:33 [9967] [sender] _exit_cleanup(code=0, file=main.c, line=1330): about to call exit(0)
--8<---------------cut here---------------end--------------->8---

Does it look reasonable? Do you want to see the whole log? There is
nothing confidential in it but I don't like to make it public.

However I noticed a new problem

--8<---------------cut here---------------start------------->8---
2021/09/13 09:18:48 [10490] [generator] make_file(git/Parkosz-robocze/indeksy/snippets/.@__thumb/s800snippet_ParkoszJBC_page0012x1188y0467.png,*,2)
2021/09/13 09:18:48 [10490] delete_item(git/Parkosz-robocze/indeksy/snippets/.@__thumb/s800snippet_ParkoszJBC_page0014x0713y1780.png) mode=100666 flags=4
2021/09/13 09:18:48 [10490] rsync: delete_file: unlink(git/Parkosz-robocze/indeksy/snippets/.@__thumb/s800snippet_ParkoszJBC_page0014x0713y1780.png) failed: Permission denied (13)
--8<---------------cut here---------------end--------------->8---

I'm totally confused by it. rsync logs to NAS as an administrator.

All I want is just a usable backup :-) I will appreciate very much your
help.

Best regards

Janusz

--
,
Janusz S. Bien
emeryt (emeritus)
https://sites.google.com/view/jsbien

Samuel Henrique

unread,
Sep 24, 2021, 3:50:03 PMSep 24
to
Hello Janusz,

> --8<---------------cut here---------------end--------------->8---
>
> Does it look reasonable? Do you want to see the whole log? There is
> nothing confidential in it but I don't like to make it public.
>
> However I noticed a new problem
>
> --8<---------------cut here---------------start------------->8---
> 2021/09/13 09:18:48 [10490] [generator] make_file(git/Parkosz-robocze/indeksy/snippets/.@__thumb/s800snippet_ParkoszJBC_page0012x1188y0467.png,*,2)
> 2021/09/13 09:18:48 [10490] delete_item(git/Parkosz-robocze/indeksy/snippets/.@__thumb/s800snippet_ParkoszJBC_page0014x0713y1780.png) mode=100666 flags=4
> 2021/09/13 09:18:48 [10490] rsync: delete_file: unlink(git/Parkosz-robocze/indeksy/snippets/.@__thumb/s800snippet_ParkoszJBC_page0014x0713y1780.png) failed: Permission denied (13)
> --8<---------------cut here---------------end--------------->8---

The logs are good enough I guess, but it's looking like the issue is
still too broad, and not related to the packaging of rsync, for me to
be able to help properly [1]. Rsync is known to have its performance
affected by the compression parameters, which I see you're using, for
example, you could try to perform some experiments with compression
disabled to see if you get better speeds.

I would suggest you try to contact the rsync user lists, the rsync
website has some references on where to get help[0]. By following this
route your messages will reach out to a much broader audience and it's
very likely someone will be able to help you.
Alternatively, you could also contact the debian user mailing list.

Thank you,

[0] https://rsync.samba.org/lists.html
[1] If the issue is not related to the packaging, this also means the
fix is best done if coming directly from upstream (in the cases where
there's a bug).

--
Samuel Henrique <samueloph>

Janusz S. Bień

unread,
Sep 25, 2021, 1:40:02 AMSep 25
to
On Fri, Sep 24 2021 at 20:40 +01, Samuel Henrique wrote:

[...]

> The logs are good enough I guess, but it's looking like the issue is
> still too broad, and not related to the packaging of rsync, for me to
> be able to help properly [1]. Rsync is known to have its performance
> affected by the compression parameters, which I see you're using, for
> example, you could try to perform some experiments with compression
> disabled to see if you get better speeds.

There is also a third option that the NAS is the culprit.

>
> I would suggest you try to contact the rsync user lists, the rsync
> website has some references on where to get help[0]. By following this
> route your messages will reach out to a much broader audience and it's
> very likely someone will be able to help you.
> Alternatively, you could also contact the debian user mailing list.

OK, please close the issue.

JSB
Reply all
Reply to author
Forward
0 new messages