Hi!
This weekend we had a crash of a long-running Timescale DB, and it seemed it ended up in an infinite recovery loop. This is on a sensitive system, and we need the database to be up most of the time, or at least be able to recover within some minutes if it crashes.
After both Googling and searching the forum, I can’t seem to find any good answers to what has happened, why it happened, and how to avoid it. Therefore I turn to this forum!
We are running on Timescale 2.4.0,
which is running inside a Docker container (with a restart mechanism).
Timescale has more or less standard settings. Autovacuum is on.
We have high definition audio recordings that are writing binary data every ~2 seconds. We have a python script that drops chunks on a regular basis (10-15 minutes), not using the automatic retention because of the time-coordinate we are using.
It seems that the DB, during autovacuum, tried to access a file that didn’t exist anymore for some reason. Then a segfault, restart of the Docker container or PSQL process, and a failed recovery. From the system logs there it seems that part of the problem could be internal docker networking (we are using Docker containers for data recording and for analysis that are connecting with the Timescale server through a Docker network).
- Why did the database corruption happen in the first place? The DB has been running for over half a year continuosly. No specific command/operation was issued on the day of the crash as far as I know.
- Why did the auto-recovery not work?
- How to avoid something like this in the future?
Feel free to ask more questions if there is anything you need to help me in this pickle.
PSQL logs:
Summary
At 2023-06-11 12:17:00 the auto “drop_chunks” completed successfully
This is from the first DB log line that was unexpected.
2023-06-11 12:19:29.980 UTC [82417] ERROR: could not access status of transaction 3089445826
2023-06-11 12:19:29.980 UTC [82417] DETAIL: Could not open file "pg_xact/0B82": No such file or directory.
2023-06-11 12:19:29.980 UTC [82417] CONTEXT: while scanning block 9780 of relation "_timescaledb_internal._hyper_1075_4606_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_1075_4606_chunk"
2023-06-11 12:19:30.261 UTC [82417] ERROR: MultiXactId 3557121635 does no longer exist -- apparent wraparound
2023-06-11 12:19:30.261 UTC [82417] CONTEXT: while scanning block 527 of relation "_timescaledb_internal._hyper_1143_4607_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_1143_4607_chunk"
2023-06-11 12:19:37.117 UTC [82430] ERROR: could not access status of transaction 3089445826
2023-06-11 12:19:37.117 UTC [82430] DETAIL: Could not open file "pg_xact/0B82": No such file or directory.
2023-06-11 12:19:37.117 UTC [82430] CONTEXT: while scanning block 9780 of relation "_timescaledb_internal._hyper_1075_4606_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_1075_4606_chunk"
2023-06-11 12:19:37.152 UTC [82430] ERROR: MultiXactId 3557121635 does no longer exist -- apparent wraparound
2023-06-11 12:19:37.152 UTC [82430] CONTEXT: while scanning block 527 of relation "_timescaledb_internal._hyper_1143_4607_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_1143_4607_chunk"
2023-06-11 12:19:37.873 UTC [82417] ERROR: invalid page in block 1932 of relation base/16964/39187372
2023-06-11 12:19:37.873 UTC [82417] CONTEXT: while vacuuming index "4605_4606_ts_7a6ca8bd_cddd_438a_941d_87a1309c0d9c_time_key" of relation "_timescaledb_internal._hyper_503_4605_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_503_4605_chunk"
2023-06-11 12:19:46.474 UTC [82417] ERROR: invalid page in block 9156 of relation base/16964/39187380
2023-06-11 12:19:46.474 UTC [82417] CONTEXT: while scanning block 9156 of relation "_timescaledb_internal._hyper_1076_4609_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_1076_4609_chunk"
...
2023-06-11 12:21:04.962 UTC [45] LOG: server process (PID 82780) was terminated by signal 11: Segmentation fault
2023-06-11 12:21:04.962 UTC [45] DETAIL: Failed process was running: autovacuum: VACUUM _timescaledb_internal._hyper_1077_4620_chunk (to prevent wraparound)
2023-06-11 12:21:04.962 UTC [45] LOG: terminating any other active server processes
2023-06-11 12:21:04.962 UTC [82831] xal@results_database WARNING: terminating connection because of crash of another server process
2023-06-11 12:21:04.962 UTC [82831] xal@results_database DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2023-06-11 12:21:04.962 UTC [82831] xal@results_database HINT: In a moment you should be able to reconnect to the database and repeat your command.
2023-06-11 12:21:04.962 UTC [82825] xal@results_database WARNING: terminating connection because of crash of another server process
2023-06-11 12:21:04.962 UTC [82825] xal@results_database DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
...
2023-06-11 12:21:05.064 UTC [45] LOG: all server processes terminated; reinitializing
2023-06-11 12:21:05.297 UTC [82832] LOG: database system was interrupted; last known up at 2023-06-11 12:20:52 UTC
2023-06-11 12:21:06.749 UTC [82833] xal@raw_database FATAL: the database system is in recovery mode
2023-06-11 12:21:06.751 UTC [82834] xal@raw_database FATAL: the database system is in recovery mode
...
2023-06-11 12:21:09.778 UTC [82832] LOG: database system was not properly shut down; automatic recovery in progress
2023-06-11 12:21:09.811 UTC [82832] LOG: redo starts at 1368/D7060280
2023-06-11 12:21:11.600 UTC [82832] LOG: redo done at 1368/FA92CC80
2023-06-11 12:21:14.446 UTC [82882] xal@raw_database FATAL: the database system is in recovery mode
...
2023-06-11 12:21:14.576 UTC [45] LOG: database system is ready to accept connections
2023-06-11 12:21:14.585 UTC [82888] LOG: TimescaleDB background worker launcher connected to shared catalogs
2023-06-11 12:21:14.639 UTC [82895] ERROR: MultiXactId 3557121635 does no longer exist -- apparent wraparound
2023-06-11 12:21:14.639 UTC [82895] CONTEXT: while scanning block 527 of relation "_timescaledb_internal._hyper_1143_4607_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_1143_4607_chunk"
2023-06-11 12:21:14.642 UTC [82894] ERROR: could not access status of transaction 3089445826
2023-06-11 12:21:14.642 UTC [82894] DETAIL: Could not open file "pg_xact/0B82": No such file or directory.
2023-06-11 12:21:14.642 UTC [82894] CONTEXT: while scanning block 9780 of relation "_timescaledb_internal._hyper_1075_4606_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_1075_4606_chunk"
2023-06-11 12:21:14.642 UTC [82894] ERROR: MultiXactId 3557121635 does no longer exist -- apparent wraparound
2023-06-11 12:21:14.642 UTC [82894] CONTEXT: while scanning block 527 of relation "_timescaledb_internal._hyper_1143_4607_chunk"
automatic vacuum of table "results_database._timescaledb_internal._hyper_1143_4607_chunk"
System logs:
Summary
Jun 11 12:17:01 vegusdal CRON[1204388]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Jun 11 12:21:01 vegusdal CRON[1263258]: (xal) CMD (/usr/local/sbin/start_autossh.sh)
Jun 11 12:21:04 vegusdal kernel: [44500994.981567] show_signal_msg: 10 callbacks suppressed
Jun 11 12:21:04 vegusdal kernel: [44500994.981574] postgres[1254355]: segfault at 7f660031241e ip 000055851e827a98 sp 00007ffffd418cb8 error 4 in postgres[55851e76a000+4c0000]
Jun 11 12:21:04 vegusdal kernel: [44500994.981588] Code: 28 01 48 83 c4 18 5b 41 5c 41 5d 41 5e 41 5f 5d c3 90 f3 0f 1e fa 4c 63 46 04 4c 8d 4e 08 31 f6 49 39 f0 76 5e 0f 1f 44 00 00 <0f> b7 17 0f b7
47 02 c1 e2 10 09 c2 4a 8d 04 06 48 89 c1 48 83 e0
Jun 11 12:21:06 vegusdal containerd[1201]: time="2023-06-11T12:21:06.051467763Z" level=info msg="shim disconnected" id=61a0f92a32e79314c9cc0b09c100d62297d8535d2e5a62c15cf968175c61193d
Jun 11 12:21:06 vegusdal containerd[1201]: time="2023-06-11T12:21:06.051598520Z" level=error msg="copy shim log" error="read /proc/self/fd/124: file already closed"
Jun 11 12:21:06 vegusdal dockerd[1239]: time="2023-06-11T12:21:06.052208311Z" level=info msg="ignoring event" container=61a0f92a32e79314c9cc0b09c100d62297d8535d2e5a62c15cf968175c61193d module=libconta
inerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:06 vegusdal kernel: [44500996.737928] vethda0e83f: renamed from eth0
Jun 11 12:21:06 vegusdal systemd-networkd[761484]: vethfe05733: Lost carrier
Jun 11 12:21:06 vegusdal kernel: [44500996.887874] internal_networ: port 28(vethfe05733) entered disabled state
Jun 11 12:21:06 vegusdal systemd-udevd[1264546]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:06 vegusdal networkd-dispatcher[2402745]: WARNING:Unknown index 633 seen, reloading interface list
Jun 11 12:21:06 vegusdal systemd-udevd[1264546]: Using default interface naming scheme 'v245'.
Jun 11 12:21:06 vegusdal kernel: [44500997.188010] internal_networ: port 28(vethfe05733) entered disabled state
Jun 11 12:21:06 vegusdal dockerd[1239]: time="2023-06-11T12:21:06.822543555Z" level=info msg="ignoring event" container=e6a3b49363629c0e82c9493a707d69dabe1c45a312e0201bece63d24870a2dfc module=libconta
inerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:06 vegusdal containerd[1201]: time="2023-06-11T12:21:06.822995219Z" level=info msg="shim disconnected" id=e6a3b49363629c0e82c9493a707d69dabe1c45a312e0201bece63d24870a2dfc
Jun 11 12:21:06 vegusdal containerd[1201]: time="2023-06-11T12:21:06.823095350Z" level=error msg="copy shim log" error="read /proc/self/fd/100: file already closed"
Jun 11 12:21:06 vegusdal kernel: [44500997.348653] device vethfe05733 left promiscuous mode
Jun 11 12:21:06 vegusdal kernel: [44500997.348662] internal_networ: port 28(vethfe05733) entered disabled state
Jun 11 12:21:07 vegusdal systemd-networkd[761484]: vethfe05733: Link DOWN
Jun 11 12:21:07 vegusdal systemd-udevd[1264546]: vethda0e83f: Failed to get link config: No such device
Jun 11 12:21:07 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '634' we don't know about, ignoring.
Jun 11 12:21:07 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '634' we don't know about, ignoring.
Jun 11 12:21:07 vegusdal systemd-networkd[761484]: vethda0e83f: Failed to wait for the interface to be initialized: No such device
Jun 11 12:21:07 vegusdal kernel: [44500997.698018] veth05de12e: renamed from eth0
Jun 11 12:21:07 vegusdal systemd-networkd[761484]: veth48de467: Lost carrier
Jun 11 12:21:07 vegusdal kernel: [44500997.867745] internal_networ: port 22(veth48de467) entered disabled state
Jun 11 12:21:07 vegusdal systemd-udevd[1264546]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:07 vegusdal systemd-udevd[1264546]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:07 vegusdal networkd-dispatcher[2402745]: WARNING:Unknown index 557 seen, reloading interface list
Jun 11 12:21:07 vegusdal systemd[1843]: run-docker-netns-0268045b7e82.mount: Succeeded.
Jun 11 12:21:07 vegusdal systemd[1]: run-docker-netns-0268045b7e82.mount: Succeeded.
Jun 11 12:21:07 vegusdal systemd-networkd[761484]: veth48de467: Link DOWN
Jun 11 12:21:07 vegusdal kernel: [44500998.258000] internal_networ: port 22(veth48de467) entered disabled state
Jun 11 12:21:07 vegusdal systemd[1]: var-lib-docker-overlay2-bb8772b6277aafd8927541e358e30c7203386e2d4a5046f98205909836ce575c-merged.mount: Succeeded.
Jun 11 12:21:07 vegusdal systemd[1843]: var-lib-docker-overlay2-bb8772b6277aafd8927541e358e30c7203386e2d4a5046f98205909836ce575c-merged.mount: Succeeded.
Jun 11 12:21:07 vegusdal kernel: [44500998.438556] device veth48de467 left promiscuous mode
Jun 11 12:21:07 vegusdal kernel: [44500998.438572] internal_networ: port 22(veth48de467) entered disabled state
Jun 11 12:21:07 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '558' we don't know about, ignoring.
Jun 11 12:21:07 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '558' we don't know about, ignoring.
Jun 11 12:21:08 vegusdal systemd[1843]: run-docker-netns-685de377422c.mount: Succeeded.
Jun 11 12:21:08 vegusdal systemd[1]: run-docker-netns-685de377422c.mount: Succeeded.
Jun 11 12:21:08 vegusdal systemd[1843]: var-lib-docker-overlay2-58c9cde0c58427508ff0cc05a07ea7651fa021eca07445bc06673769875453e2-merged.mount: Succeeded.
Jun 11 12:21:08 vegusdal systemd[1]: var-lib-docker-overlay2-58c9cde0c58427508ff0cc05a07ea7651fa021eca07445bc06673769875453e2-merged.mount: Succeeded.
Jun 11 12:21:12 vegusdal containerd[1201]: time="2023-06-11T12:21:12.000791842Z" level=info msg="shim disconnected" id=bedbcb01919e3943e45f4764d07ab8b4a397567086ce8fa0280d813e618d80a9
Jun 11 12:21:12 vegusdal containerd[1201]: time="2023-06-11T12:21:12.000907171Z" level=error msg="copy shim log" error="read /proc/self/fd/128: file already closed"
Jun 11 12:21:12 vegusdal dockerd[1239]: time="2023-06-11T12:21:12.001059300Z" level=info msg="ignoring event" container=bedbcb01919e3943e45f4764d07ab8b4a397567086ce8fa0280d813e618d80a9 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:12 vegusdal systemd-networkd[761484]: vethecb0253: Lost carrier
Jun 11 12:21:12 vegusdal kernel: [44501002.667957] internal_networ: port 29(vethecb0253) entered disabled state
Jun 11 12:21:12 vegusdal kernel: [44501002.668416] veth95a9c8d: renamed from eth0
Jun 11 12:21:12 vegusdal systemd-udevd[1265562]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:12 vegusdal systemd-udevd[1265562]: Using default interface naming scheme 'v245'.
Jun 11 12:21:12 vegusdal networkd-dispatcher[2402745]: WARNING:Unknown index 669 seen, reloading interface list
Jun 11 12:21:12 vegusdal systemd-udevd[1265562]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:12 vegusdal systemd-networkd[761484]: vethecb0253: Link DOWN
Jun 11 12:21:12 vegusdal kernel: [44501003.248056] internal_networ: port 29(vethecb0253) entered disabled state
Jun 11 12:21:12 vegusdal kernel: [44501003.440018] device vethecb0253 left promiscuous mode
Jun 11 12:21:12 vegusdal kernel: [44501003.440031] internal_networ: port 29(vethecb0253) entered disabled state
Jun 11 12:21:13 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '670' we don't know about, ignoring.
Jun 11 12:21:13 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '670' we don't know about, ignoring.
Jun 11 12:21:13 vegusdal systemd[1]: run-docker-netns-00a7182e409b.mount: Succeeded.
Jun 11 12:21:13 vegusdal systemd[1843]: run-docker-netns-00a7182e409b.mount: Succeeded.
Jun 11 12:21:13 vegusdal systemd[1843]: var-lib-docker-overlay2-26f2cbe81028d130e680b36da37cb766b7d6ca66d300ba008af619b9fa1835ed-merged.mount: Succeeded.
Jun 11 12:21:13 vegusdal systemd[1]: var-lib-docker-overlay2-26f2cbe81028d130e680b36da37cb766b7d6ca66d300ba008af619b9fa1835ed-merged.mount: Succeeded.
Jun 11 12:21:15 vegusdal kernel: [44501006.334187] postgres[1265941]: segfault at 7f65e8fe041e ip 000055851e827a98 sp 00007ffffd418cb8 error 4 in postgres[55851e76a000+4c0000]
Jun 11 12:21:15 vegusdal kernel: [44501006.334205] Code: 28 01 48 83 c4 18 5b 41 5c 41 5d 41 5e 41 5f 5d c3 90 f3 0f 1e fa 4c 63 46 04 4c 8d 4e 08 31 f6 49 39 f0 76 5e 0f 1f 44 00 00 <0f> b7 17 0f b7
47 02 c1 e2 10 09 c2 4a 8d 04 06 48 89 c1 48 83 e0
Jun 11 12:21:17 vegusdal containerd[1201]: time="2023-06-11T12:21:17.968124224Z" level=info msg="shim disconnected" id=8767c60cb019e186fceac3658c1ebf459080dd87af751a6e26623fce5584adcb
Jun 11 12:21:17 vegusdal containerd[1201]: time="2023-06-11T12:21:17.968242008Z" level=error msg="copy shim log" error="read /proc/self/fd/116: file already closed"
Jun 11 12:21:17 vegusdal dockerd[1239]: time="2023-06-11T12:21:17.968121717Z" level=info msg="ignoring event" container=8767c60cb019e186fceac3658c1ebf459080dd87af751a6e26623fce5584adcb module=libconta
inerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:18 vegusdal systemd-networkd[761484]: veth5d205bd: Lost carrier
Jun 11 12:21:18 vegusdal kernel: [44501008.648011] internal_networ: port 26(veth5d205bd) entered disabled state
Jun 11 12:21:18 vegusdal kernel: [44501008.648194] veth87b213c: renamed from eth0
Jun 11 12:21:18 vegusdal systemd-udevd[1266727]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:18 vegusdal systemd-udevd[1266727]: Using default interface naming scheme 'v245'.
Jun 11 12:21:18 vegusdal networkd-dispatcher[2402745]: WARNING:Unknown index 611 seen, reloading interface list
Jun 11 12:21:18 vegusdal kernel: [44501009.068353] internal_networ: port 26(veth5d205bd) entered disabled state
Jun 11 12:21:18 vegusdal kernel: [44501009.258615] device veth5d205bd left promiscuous mode
Jun 11 12:21:18 vegusdal kernel: [44501009.258625] internal_networ: port 26(veth5d205bd) entered disabled state
Jun 11 12:21:18 vegusdal systemd-udevd[1266727]: veth87b213c: Failed to get link config: No such device
Jun 11 12:21:18 vegusdal systemd-networkd[761484]: veth5d205bd: Link DOWN
Jun 11 12:21:18 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '612' we don't know about, ignoring.
Jun 11 12:21:18 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '612' we don't know about, ignoring.
Jun 11 12:21:18 vegusdal systemd-networkd[761484]: veth87b213c: Failed to wait for the interface to be initialized: No such device
Jun 11 12:21:19 vegusdal systemd[1843]: run-docker-netns-59b3d2dada36.mount: Succeeded.
Jun 11 12:21:19 vegusdal systemd[1]: run-docker-netns-59b3d2dada36.mount: Succeeded.
Jun 11 12:21:19 vegusdal systemd[1]: var-lib-docker-overlay2-da9c08573447b5a7579444d611f56bdfdc8d4c5d75f47acc1d887eb161b7d944-merged.mount: Succeeded.
Jun 11 12:21:19 vegusdal systemd[1843]: var-lib-docker-overlay2-da9c08573447b5a7579444d611f56bdfdc8d4c5d75f47acc1d887eb161b7d944-merged.mount: Succeeded.
Jun 11 12:21:22 vegusdal kernel: [44501012.793535] postgres[1266997]: segfault at 7f65e648441e ip 000055851e827a98 sp 00007ffffd418cb8 error 4 in postgres[55851e76a000+4c0000]
Jun 11 12:21:22 vegusdal kernel: [44501012.793553] Code: 28 01 48 83 c4 18 5b 41 5c 41 5d 41 5e 41 5f 5d c3 90 f3 0f 1e fa 4c 63 46 04 4c 8d 4e 08 31 f6 49 39 f0 76 5e 0f 1f 44 00 00 <0f> b7 17 0f b7
47 02 c1 e2 10 09 c2 4a 8d 04 06 48 89 c1 48 83 e0
Jun 11 12:21:27 vegusdal kernel: [44501018.238075] postgres[1268122]: segfault at 7f65e5e7e41e ip 000055851e827a98 sp 00007ffffd418cb8 error 4 in postgres[55851e76a000+4c0000]
Jun 11 12:21:27 vegusdal kernel: [44501018.238093] Code: 28 01 48 83 c4 18 5b 41 5c 41 5d 41 5e 41 5f 5d c3 90 f3 0f 1e fa 4c 63 46 04 4c 8d 4e 08 31 f6 49 39 f0 76 5e 0f 1f 44 00 00 <0f> b7 17 0f b7
47 02 c1 e2 10 09 c2 4a 8d 04 06 48 89 c1 48 83 e0
Jun 11 12:21:33 vegusdal kernel: [44501023.833935] postgres[1269218]: segfault at 7f65e5f9841e ip 000055851e827a98 sp 00007ffffd418cb8 error 4 in postgres[55851e76a000+4c0000]
Jun 11 12:21:33 vegusdal kernel: [44501023.833984] Code: 28 01 48 83 c4 18 5b 41 5c 41 5d 41 5e 41 5f 5d c3 90 f3 0f 1e fa 4c 63 46 04 4c 8d 4e 08 31 f6 49 39 f0 76 5e 0f 1f 44 00 00 <0f> b7 17 0f b7 47 02 c1 e2 10 09 c2 4a 8d 04 06 48 89 c1 48 83 e0
Jun 11 12:21:38 vegusdal kernel: [44501029.459611] postgres[1270409]: segfault at 7f65e616441e ip 000055851e827a98 sp 00007ffffd418cb8 error 4 in postgres[55851e76a000+4c0000]
Jun 11 12:21:38 vegusdal kernel: [44501029.459629] Code: 28 01 48 83 c4 18 5b 41 5c 41 5d 41 5e 41 5f 5d c3 90 f3 0f 1e fa 4c 63 46 04 4c 8d 4e 08 31 f6 49 39 f0 76 5e 0f 1f 44 00 00 <0f> b7 17 0f b7 47 02 c1 e2 10 09 c2 4a 8d 04 06 48 89 c1 48 83 e0
Jun 11 12:21:43 vegusdal dockerd[1239]: time="2023-06-11T12:21:43.160473081Z" level=info msg="ignoring event" container=10556765a79324981461417a6706c89aa17b225417bb661cc5f044752b8ea582 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:43 vegusdal containerd[1201]: time="2023-06-11T12:21:43.160862454Z" level=info msg="shim disconnected" id=10556765a79324981461417a6706c89aa17b225417bb661cc5f044752b8ea582
Jun 11 12:21:43 vegusdal containerd[1201]: time="2023-06-11T12:21:43.160971183Z" level=error msg="copy shim log" error="read /proc/self/fd/32: file already closed"
Jun 11 12:21:43 vegusdal containerd[1201]: time="2023-06-11T12:21:43.182043271Z" level=info msg="shim disconnected" id=f5b1b8d844c3cd276c427b8f27b1df4d751a5811206c0d33645c00d0bc63d861
Jun 11 12:21:43 vegusdal containerd[1201]: time="2023-06-11T12:21:43.182156412Z" level=error msg="copy shim log" error="read /proc/self/fd/28: file already closed"
Jun 11 12:21:43 vegusdal dockerd[1239]: time="2023-06-11T12:21:43.182081660Z" level=info msg="ignoring event" container=f5b1b8d844c3cd276c427b8f27b1df4d751a5811206c0d33645c00d0bc63d861 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:43 vegusdal kernel: [44501033.778650] veth4e39b61: renamed from eth0
Jun 11 12:21:43 vegusdal systemd-networkd[761484]: veth191ace2: Lost carrier
Jun 11 12:21:43 vegusdal kernel: [44501033.928237] internal_networ: port 5(veth191ace2) entered disabled state
Jun 11 12:21:43 vegusdal containerd[1201]: time="2023-06-11T12:21:43.483324820Z" level=info msg="shim disconnected" id=333c864ba09f35d707da429eaa72badbef8ab70cf1c5f189bed21f3c3264c4d3
Jun 11 12:21:43 vegusdal containerd[1201]: time="2023-06-11T12:21:43.483423636Z" level=error msg="copy shim log" error="read /proc/self/fd/104: file already closed"
Jun 11 12:21:43 vegusdal dockerd[1239]: time="2023-06-11T12:21:43.485461406Z" level=info msg="ignoring event" container=333c864ba09f35d707da429eaa72badbef8ab70cf1c5f189bed21f3c3264c4d3 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:43 vegusdal kernel: [44501034.408306] internal_networ: port 4(vethb77b56e) entered disabled state
Jun 11 12:21:43 vegusdal kernel: [44501034.408489] veth261f9fa: renamed from eth0
Jun 11 12:21:43 vegusdal networkd-dispatcher[2402745]: WARNING:Unknown index 545 seen, reloading interface list
Jun 11 12:21:43 vegusdal systemd-networkd[761484]: vethb77b56e: Lost carrier
Jun 11 12:21:44 vegusdal kernel: [44501034.838285] veth9add8fe: renamed from eth0
Jun 11 12:21:44 vegusdal kernel: [44501034.958301] internal_networ: port 23(veth3e1dc9e) entered disabled state
Jun 11 12:21:44 vegusdal dockerd[1239]: time="2023-06-11T12:21:44.467493963Z" level=info msg="ignoring event" container=b848531be58ffb6bcf0e7622659669546c885a7f1cd036d0d10ad76c8fdd992e module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:44 vegusdal containerd[1201]: time="2023-06-11T12:21:44.467828363Z" level=info msg="shim disconnected" id=b848531be58ffb6bcf0e7622659669546c885a7f1cd036d0d10ad76c8fdd992e
Jun 11 12:21:44 vegusdal containerd[1201]: time="2023-06-11T12:21:44.467923648Z" level=error msg="copy shim log" error="read /proc/self/fd/92: file already closed"
Jun 11 12:21:44 vegusdal kernel: [44501035.028531] internal_networ: port 5(veth191ace2) entered disabled state
Jun 11 12:21:44 vegusdal kernel: [44501035.219056] device veth191ace2 left promiscuous mode
Jun 11 12:21:44 vegusdal kernel: [44501035.219064] internal_networ: port 5(veth191ace2) entered disabled state
Jun 11 12:21:44 vegusdal dockerd[1239]: time="2023-06-11T12:21:44.705102511Z" level=info msg="ignoring event" container=a47d42b35751762e10e237b3be551cdf786ffb405b815808150dba4fd0000012 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:44 vegusdal containerd[1201]: time="2023-06-11T12:21:44.705710587Z" level=info msg="shim disconnected" id=a47d42b35751762e10e237b3be551cdf786ffb405b815808150dba4fd0000012
Jun 11 12:21:44 vegusdal containerd[1201]: time="2023-06-11T12:21:44.706019914Z" level=error msg="copy shim log" error="read /proc/self/fd/56: file already closed"
Jun 11 12:21:45 vegusdal systemd-udevd[1271704]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:45 vegusdal systemd-networkd[761484]: veth3e1dc9e: Lost carrier
Jun 11 12:21:45 vegusdal systemd-networkd[761484]: veth191ace2: Link DOWN
Jun 11 12:21:45 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '546' we don't know about, ignoring.
Jun 11 12:21:45 vegusdal systemd-networkd[761484]: rtnl: received neighbor for link '546' we don't know about, ignoring.
Jun 11 12:21:45 vegusdal systemd-udevd[1271704]: ethtool: could not get ethtool features for veth4e39b61
Jun 11 12:21:45 vegusdal systemd-udevd[1271704]: Could not set offload features of veth4e39b61: No such device
Jun 11 12:21:45 vegusdal dockerd[1239]: time="2023-06-11T12:21:45.484894692Z" level=info msg="ignoring event" container=a1237efb7ad16aa0a987277619d509f84695f43b97f13631c35695043d87ce1d module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:45 vegusdal containerd[1201]: time="2023-06-11T12:21:45.485080331Z" level=info msg="shim disconnected" id=a1237efb7ad16aa0a987277619d509f84695f43b97f13631c35695043d87ce1d
Jun 11 12:21:45 vegusdal containerd[1201]: time="2023-06-11T12:21:45.485208393Z" level=error msg="copy shim log" error="read /proc/self/fd/60: file already closed"
Jun 11 12:21:45 vegusdal systemd-udevd[1271708]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:45 vegusdal kernel: [44501036.019492] vethd128e3b: renamed from eth0
Jun 11 12:21:45 vegusdal systemd[1843]: run-docker-netns-51b42b4e26d5.mount: Succeeded.
Jun 11 12:21:45 vegusdal systemd[1]: run-docker-netns-51b42b4e26d5.mount: Succeeded.
Jun 11 12:21:45 vegusdal systemd[1843]: var-lib-docker-overlay2-1231c03f23c9b8631bc384af8088cdf14ccf7f6cb580a9cfe0f21c854651e7e1-merged.mount: Succeeded.
Jun 11 12:21:45 vegusdal systemd[1]: var-lib-docker-overlay2-1231c03f23c9b8631bc384af8088cdf14ccf7f6cb580a9cfe0f21c854651e7e1-merged.mount: Succeeded.
Jun 11 12:21:45 vegusdal dockerd[1239]: time="2023-06-11T12:21:45.627852506Z" level=info msg="ignoring event" container=006a974001aa9e074dbddf449dd32f00bda531455a783c2d5a654f34986aba71 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:45 vegusdal containerd[1201]: time="2023-06-11T12:21:45.628660656Z" level=info msg="shim disconnected" id=006a974001aa9e074dbddf449dd32f00bda531455a783c2d5a654f34986aba71
Jun 11 12:21:45 vegusdal containerd[1201]: time="2023-06-11T12:21:45.628763991Z" level=error msg="copy shim log" error="read /proc/self/fd/64: file already closed"
Jun 11 12:21:45 vegusdal systemd-networkd[761484]: vethcd7ca5a: Lost carrier
Jun 11 12:21:45 vegusdal kernel: [44501036.158307] internal_networ: port 20(vethcd7ca5a) entered disabled state
Jun 11 12:21:45 vegusdal systemd-networkd[761484]: vethe2fe2dc: Lost carrier
Jun 11 12:21:45 vegusdal kernel: [44501036.228580] internal_networ: port 11(vethe2fe2dc) entered disabled state
Jun 11 12:21:45 vegusdal kernel: [44501036.228834] veth8db62ee: renamed from eth0
Jun 11 12:21:45 vegusdal systemd-udevd[1271704]: veth4e39b61: Failed to get link config: No such device
Jun 11 12:21:45 vegusdal systemd-udevd[1271732]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:45 vegusdal dockerd[1239]: time="2023-06-11T12:21:45.792946955Z" level=info msg="ignoring event" container=94381971d471ec334d030d7e9b61c0690122765a1c2001a56ab275f79d05f895 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:45 vegusdal containerd[1201]: time="2023-06-11T12:21:45.793006010Z" level=info msg="shim disconnected" id=94381971d471ec334d030d7e9b61c0690122765a1c2001a56ab275f79d05f895
Jun 11 12:21:45 vegusdal containerd[1201]: time="2023-06-11T12:21:45.793160188Z" level=error msg="copy shim log" error="read /proc/self/fd/52: file already closed"
Jun 11 12:21:45 vegusdal containerd[1201]: time="2023-06-11T12:21:45.846529772Z" level=info msg="shim disconnected" id=c1295ec924ca928a2c9b7f512b9e92773d41f273a7c4b8a21fcaac76b4a2aa03
Jun 11 12:21:45 vegusdal containerd[1201]: time="2023-06-11T12:21:45.846634408Z" level=error msg="copy shim log" error="read /proc/self/fd/72: file already closed"
Jun 11 12:21:45 vegusdal dockerd[1239]: time="2023-06-11T12:21:45.846692466Z" level=info msg="ignoring event" container=c1295ec924ca928a2c9b7f512b9e92773d41f273a7c4b8a21fcaac76b4a2aa03 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun 11 12:21:46 vegusdal kernel: [44501036.878432] internal_networ: port 4(vethb77b56e) entered disabled state
Jun 11 12:21:46 vegusdal kernel: [44501037.068757] device vethb77b56e left promiscuous mode
Jun 11 12:21:46 vegusdal kernel: [44501037.068763] internal_networ: port 4(vethb77b56e) entered disabled state
Jun 11 12:21:46 vegusdal systemd-udevd[1271708]: ethtool: could not set ethtool features for veth261f9fa
Jun 11 12:21:46 vegusdal systemd-udevd[1271708]: Could not set offload features of veth261f9fa: Operation not permitted
Jun 11 12:21:46 vegusdal kernel: [44501037.448623] veth83a66e9: renamed from eth0
Jun 11 12:21:47 vegusdal kernel: [44501037.638263] internal_networ: port 12(vethb6d2832) entered disabled state
Jun 11 12:21:47 vegusdal kernel: [44501037.688273] internal_networ: port 13(vethbb896d7) entered disabled state
Jun 11 12:21:47 vegusdal systemd-udevd[1271732]: Using default interface naming scheme 'v245'.
Jun 11 12:21:47 vegusdal kernel: [44501037.828725] veth8021e50: renamed from eth0
Jun 11 12:21:47 vegusdal systemd-udevd[1271704]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:47 vegusdal kernel: [44501038.458265] veth31619f0: renamed from eth0
Jun 11 12:21:48 vegusdal kernel: [44501038.598356] internal_networ: port 15(vethae3846b) entered disabled state
Jun 11 12:21:48 vegusdal kernel: [44501038.648311] internal_networ: port 10(vethbcaae55) entered disabled state
Jun 11 12:21:48 vegusdal kernel: [44501038.648483] veth64f003b: renamed from eth0
Jun 11 12:21:48 vegusdal systemd-udevd[1271708]: veth261f9fa: Failed to get link config: No such device
Jun 11 12:21:48 vegusdal systemd-udevd[1271731]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun 11 12:21:48 vegusdal systemd-networkd[761484]: vethb77b56e: Link DOWN
Jun 11 12:21:48 vegusdal systemd[1843]: run-docker-netns-7cb5afc988be.mount: Succeeded.
Jun 11 12:21:48 vegusdal systemd[1]: run-docker-netns-7cb5afc988be.mount: Succeeded.
Jun 11 12:21:48 vegusdal systemd[1843]: var-lib-docker-overlay2-f02a874aaec6c244c23514282897926b0e44d556541b4721525373eb31836c89-merged.mount: Succeeded.
Jun 11 12:21:48 vegusdal systemd[1]: var-lib-docker-overlay2-f02a874aaec6c244c23514282897926b0e44d556541b4721525373eb31836c89-merged.mount: Succeeded.
...