The rsync-3.1.3 package from focal installs OK (with a bit of --ignore-depends=rsync
); but unfortunately gives the same error.
Using strace to watch the lxd process and its descendants on the old (sending) system, I can see that it is exec’ing the rsync
binary, but also lxc netcat
:
[pid 1831] stat("/usr/local/sbin/rsync", <unfinished ...>
[pid 1831] stat("/usr/local/bin/rsync", 0xc820358378) = -1 ENOENT (No such file or directory)
[pid 1831] stat("/usr/sbin/rsync", <unfinished ...>
[pid 1831] stat("/usr/bin/rsync", <unfinished ...>
[pid 24799] execve("/usr/bin/rsync", ["rsync", "-arvP", "--devices", "--numeric-ids", "--partial", "--sparse", "/var/lib/lxd/containers/ix-dc1/", "localhost:/tmp/foo", "-e", "sh -c \"/usr/bin/lxd netcat @lxd/2e66ee13-aeb6-4bd1-87f0-6b017a910730 ix-dc1\""], [/* 5 vars */] <unfinished ...>
[pid 24800] execve("/usr/local/sbin/sh", ["sh", "-c", "/usr/bin/lxd netcat @lxd/2e66ee13-aeb6-4bd1-87f0-6b017a910730 ix-dc1", "localhost", "rsync", "--server", "-vlogDtprSe.iLsfxC", "--partial", "--numeric-ids", ".", "/tmp/foo"], [/* 5 vars */] <unfinished ...>
[pid 24800] execve("/usr/local/bin/sh", ["sh", "-c", "/usr/bin/lxd netcat @lxd/2e66ee13-aeb6-4bd1-87f0-6b017a910730 ix-dc1", "localhost", "rsync", "--server", "-vlogDtprSe.iLsfxC", "--partial", "--numeric-ids", ".", "/tmp/foo"], [/* 5 vars */] <unfinished ...>
[pid 24800] execve("/usr/sbin/sh", ["sh", "-c", "/usr/bin/lxd netcat @lxd/2e66ee13-aeb6-4bd1-87f0-6b017a910730 ix-dc1", "localhost", "rsync", "--server", "-vlogDtprSe.iLsfxC", "--partial", "--numeric-ids", ".", "/tmp/foo"], [/* 5 vars */]) = -1 ENOENT (No such file or directory)
[pid 24800] execve("/usr/bin/sh", ["sh", "-c", "/usr/bin/lxd netcat @lxd/2e66ee13-aeb6-4bd1-87f0-6b017a910730 ix-dc1", "localhost", "rsync", "--server", "-vlogDtprSe.iLsfxC", "--partial", "--numeric-ids", ".", "/tmp/foo"], [/* 5 vars */]) = -1 ENOENT (No such file or directory)
[pid 24800] execve("/sbin/sh", ["sh", "-c", "/usr/bin/lxd netcat @lxd/2e66ee13-aeb6-4bd1-87f0-6b017a910730 ix-dc1", "localhost", "rsync", "--server", "-vlogDtprSe.iLsfxC", "--partial", "--numeric-ids", ".", "/tmp/foo"], [/* 5 vars */]) = -1 ENOENT (No such file or directory)
[pid 24800] execve("/bin/sh", ["sh", "-c", "/usr/bin/lxd netcat @lxd/2e66ee13-aeb6-4bd1-87f0-6b017a910730 ix-dc1", "localhost", "rsync", "--server", "-vlogDtprSe.iLsfxC", "--partial", "--numeric-ids", ".", "/tmp/foo"], [/* 5 vars */]) = 0
[pid 5610] write(18, "0\0\0\nERROR: buffer overflow in recv_rules [Receiver]\n]\0\0\nrsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]\n\4\0\0]\26\0\0\0", 157 <unfinished ...>
[pid 24804] <... read resumed> "0\0\0\nERROR: buffer overflow in recv_rules [Receiver]\n]\0\0\nrsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]\n\4\0\0]\26\0\0\0", 32768) = 157
[pid 24804] write(1, "0\0\0\nERROR: buffer overflow in recv_rules [Receiver]\n]\0\0\nrsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]\n\4\0\0]\26\0\0\0", 157 <unfinished ...>
[pid 24799] lstat("rootfs/etc/default/rsync", {st_mode=S_IFREG|0644, st_size=1768, ...}) = 0
[pid 24799] lstat("rootfs/etc/init.d/rsync", {st_mode=S_IFREG|0755, st_size=4355, ...}) = 0
[pid 24799] read(5, "0\0\0\nERROR: buffer overflow in recv_rules [Receiver]\n]\0\0\nrsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]\n\4\0\0]\26\0\0\0", 32768) = 157
[pid 24799] write(2, "rsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]", 92 <unfinished ...>
[pid 1831] <... read resumed> "\nrsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]\n", 1489) = 94
[pid 1831] write(5, "lvl=eror msg=\"Rsync send failed: /var/lib/lxd/containers/ix-dc1/: exit status 22: ERROR: buffer overflow in recv_rules [Receiver]\\nrsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]\\n\" t=2022-09-14T16:36:09+0100\n", 254 <unfinished ...>
[pid 1831] write(2, "lvl=eror msg=\"Rsync send failed: /var/lib/lxd/containers/ix-dc1/: exit status 22: ERROR: buffer overflow in recv_rules [Receiver]\\nrsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]\\n\" t=2022-09-14T16:36:09+0100\n", 254 <unfinished ...>
I’m not sure what’s going on with /tmp/foo
, I guess that’s just a dummy placeholder?
The above was just grepped to ‘rsync’. Looking at the full strace up to the point where the error occurs, it seems to be walking the container until it recurses to rootfs/bin
:
[pid 24799] lstat("rootfs/lib64", <unfinished ...>
[pid 5610] epoll_wait(8, <unfinished ...>
[pid 24799] <... lstat resumed> {st_mode=S_IFDIR|0755, st_size=40, ...}) = 0
[pid 5610] <... epoll_wait resumed> [], 128, 0) = 0
[pid 24799] lstat("rootfs/media", <unfinished ...>
[pid 5610] epoll_wait(8, <unfinished ...>
[pid 24799] <... lstat resumed> {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 1810] <... futex resumed> ) = 1
[pid 24799] lstat("rootfs/mnt", <unfinished ...>
[pid 1809] read(18, <unfinished ...>
[pid 24799] <... lstat resumed> {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 1810] write(14, "\27\3\3\0u\0\0\0\0\0\0\0\3]\377\274\337\357\330\311\36n\207%\206\245Q\353\317\\\301v~\251\245\216N\n\4\0068X\245J\231\222y6%\v\342\251\375{r6\6\346\21\"J\207\207\362\20673\10\1Oz$\
206r\264\373\10\356%\277\341\262\317\311BP\n(\264\241i8d.\234\32\f\311<\256\316\221\204\222\240!\344w\"\264\335)\324\321\220\267{|&\236\223\242", 122 <unfinished ...>
[pid 24799] lstat("rootfs/opt", <unfinished ...>
[pid 1809] <... read resumed> 0xc820630000, 131072) = -1 EAGAIN (Resource temporarily unavailable)
[pid 24799] <... lstat resumed> {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 1810] <... write resumed> ) = 122
[pid 24799] lstat("rootfs/proc", <unfinished ...>
[pid 1810] futex(0xc8202d2d08, FUTEX_WAIT, 0, NULL <unfinished ...>
[pid 24799] <... lstat resumed> {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 1809] futex(0xc8202e2508, FUTEX_WAIT, 0, NULL <unfinished ...>
[pid 24799] lstat("rootfs/root", <unfinished ...>
[pid 1704] <... select resumed> ) = 0 (Timeout)
[pid 24799] <... lstat resumed> {st_mode=S_IFDIR|0700, st_size=468, ...}) = 0
[pid 1704] futex(0x115f630, FUTEX_WAIT, 0, {60, 0} <unfinished ...>
[pid 24799] lstat("rootfs/run", {st_mode=S_IFDIR|0755, st_size=14, ...}) = 0
[pid 24799] lstat("rootfs/sbin", {st_mode=S_IFDIR|0755, st_size=3626, ...}) = 0
[pid 24799] lstat("rootfs/srv", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 24799] lstat("rootfs/sys", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 24799] lstat("rootfs/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=126, ...}) = 0
[pid 24799] lstat("rootfs/usr", {st_mode=S_IFDIR|0755, st_size=70, ...}) = 0
[pid 24799] lstat("rootfs/var", <unfinished ...>
[pid 5610] <... epoll_wait resumed> [{EPOLLIN|EPOLLOUT, {u32=973834744, u64=140450699381240}}], 128, -1) = 1
[pid 24799] <... lstat resumed> {st_mode=S_IFDIR|0755, st_size=100, ...}) = 0
[pid 5610] futex(0x115f630, FUTEX_WAKE, 1 <unfinished ...>
[pid 24799] getdents(3, <unfinished ...>
[pid 5610] <... futex resumed> ) = 1
[pid 24799] <... getdents resumed> /* 0 entries */, 32768) = 0
[pid 5610] read(14, <unfinished ...>
[pid 24799] close(3 <unfinished ...>
[pid 5610] <... read resumed> "\27\3\3\0\275\0\0\0\0\0\0\0\5\263\343\35`\242\325\313\206D\23\340\312\300);T\4\247I\37\343\275\247S\247~\\\376\331\215\16$\300/\227\16\374<3\274\234\vJp\0\345\274\10\316\2
47\273Jt9U\r\221xK}\356\212a>\357\217}\223\356\227P\335P4\205t%\314\3\275\31\342\205\233\275\26\211X\"V\305\360\226\360\372\224@\252\356_\331\"\243[\315\201\272@\213T\311\376\326\177\267\np`\353\374\321\
264\317\350T\\r\212?\361?\227UR\263\360N\236}\363O\305\250\233KR\205\256\211\vk\253\316\231e\340|-o\16\271\316\372*!\213\373Z\205\205\251\323\\q~7\275*\226\304\333", 1024) = 194
[pid 24799] <... close resumed> ) = 0
[pid 1704] <... futex resumed> ) = 0
[pid 24799] open("rootfs/bin", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC <unfinished ...>
[pid 5610] write(18, "0\0\0\nERROR: buffer overflow in recv_rules [Receiver]\n]\0\0\nrsync error: error allocating core memory buffers (code 22) at util2.c(111) [Receiver=3.1.3]\n\4\0\0]\26\0\0\0", 157
<unfinished ...>
I’m a bit stumped now.
Just to confirm the obvious, I think there should be plenty of RAM available for this operation: there is 4GB real RAM plus 4GB swap.
root@ix-dns1:~# free
total used free shared buff/cache available
Mem: 4028756 452608 1126744 26432 2449404 3193620
Swap: 3906556 120548 3786008