Host disturbed (IO) by process running inside a CT

LXD
1

Hi there,

I’m facing a strange problem.
Having a process inside a CT that is running into an infinite loop:
[pid 11495] _llseek(29, 7745, [231980609], SEEK_CUR) = 0
[pid 11495] read(29, “”, 8192) = 0
[pid 11495] _llseek(29, 231972864, [231972864], SEEK_SET) = 0
[pid 11495] read(29, “”, 7744) = 0
[pid 11495] _llseek(29, 7744, [231980608], SEEK_CUR) = 0
[pid 11495] read(29, “”, 8192) = 0
[pid 11495] _llseek(29, 231972864, [231972864], SEEK_SET) = 0
[pid 11495] read(29, “”, 7743) = 0
[pid 11495] _llseek(29, 7743, [231980607], SEEK_CUR) = 0
[pid 11495] read(29, “”, 8192) = 0
[pid 11495] _llseek(29, 231972864, [231972864], SEEK_SET) = 0
ect…
It take 100% cpu of 1 core.

The problem is that the host start having IO problems: sshd connection hang ( https://prnt.sc/royrfp ), event a simple ping hang.

As soon as I kill the process, the host goes back to normal.

Any idea ?

2

Looks like this thing is seeking and reading through some large file, this could indeed cause an overwhelming amount of IOps, causing issues if the host and containers are on the same disk, and obviously being significantly worse if that’s on a spinning drive.

Ways to prevent the container from having that much impact could involve limits.disk.priority or the limits.read and limits.write options on the relevant disk devices.

This can be used to slow down I/O and reduce the I/O priority of the container.

3

Ok thank you, will try this.

4

For now I can see this now:
strace of a process running (100% of one core, RT is set) inside a CT:

[pid 1413] read(13, 0xf20fefb0, 8) = -1 EAGAIN (Resource temporarily unavailable)
[pid 1413] poll([{fd=14, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34299299}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34344766}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34397078}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34450017}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34489967}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34532710}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34567072}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34613726}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34661498}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34813403}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34854051}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34895956}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34929759}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=34977601}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35055893}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35102478}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35149271}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35198859}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35239018}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35283158}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35329183}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35389177}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35433666}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35484092}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35529978}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35576772}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35620213}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35665541}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35711217}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35748093}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35794608}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35837421}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=35888056}) = 0
[pid 1413] epoll_wait(5, , 1, 44) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=80151141}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=80258348}) = 0
[pid 1413] read(13, 0xf20fefb0, 8) = -1 EAGAIN (Resource temporarily unavailable)
[pid 1413] poll([{fd=14, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=80407110}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=80471155}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=80521301}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=80568375}) = 0
[pid 1413] clock_gettime(CLOCK_MONOTONIC, {tv_sec=31368, tv_nsec=80603715}) = 0
(ect…)

On the host (kern.log):

[30209.986667] INFO: task kworker/6:0:2388 blocked for more than 120 seconds.
[30209.987429] Tainted: P OE 4.19.0-8-amd64 #1 Debian 4.19.98-1
[30209.988031] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[30209.988620] kworker/6:0 D 0 2388 2 0x80000000
[30209.989214] Workqueue: events slab_caches_to_rcu_destroy_workfn
[30209.989802] Call Trace:
[30209.990395] ? __schedule+0x2a2/0x870
[30209.990980] ? __queue_work+0x103/0x3e0
[30209.991527] schedule+0x28/0x80
[30209.992079] schedule_timeout+0x26d/0x390
[30209.992627] ? __kmem_cache_shutdown+0x264/0x280
[30209.993168] ? pcpu_free_area+0x27a/0x2f0
[30209.993784] wait_for_completion+0x11f/0x190
[30209.994387] ? wake_up_q+0x70/0x70
[30209.994996] _rcu_barrier+0x120/0x180
[30209.995543] slab_caches_to_rcu_destroy_workfn+0x8f/0xe0
[30209.996100] process_one_work+0x1a7/0x3a0
[30209.996582] worker_thread+0x30/0x390
[30209.997068] ? create_worker+0x1a0/0x1a0
[30209.997561] kthread+0x112/0x130
[30209.998061] ? kthread_bind+0x30/0x30
[30209.998581] ret_from_fork+0x22/0x40
[30330.817842] INFO: task kworker/6:0:2388 blocked for more than 120 seconds.
[30330.818557] Tainted: P OE 4.19.0-8-amd64 #1 Debian 4.19.98-1
[30330.819151] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[30330.819708] kworker/6:0 D 0 2388 2 0x80000000
[30330.820245] Workqueue: events slab_caches_to_rcu_destroy_workfn
[30330.820808] Call Trace:
[30330.821363] ? __schedule+0x2a2/0x870
[30330.821907] ? __queue_work+0x103/0x3e0
[30330.822446] schedule+0x28/0x80
[30330.822998] schedule_timeout+0x26d/0x390
[30330.823543] ? __kmem_cache_shutdown+0x264/0x280
[30330.824079] ? pcpu_free_area+0x27a/0x2f0
[30330.824598] wait_for_completion+0x11f/0x190
[30330.825102] ? wake_up_q+0x70/0x70
[30330.825591] _rcu_barrier+0x120/0x180
[30330.826064] slab_caches_to_rcu_destroy_workfn+0x8f/0xe0
[30330.826539] process_one_work+0x1a7/0x3a0
[30330.827021] worker_thread+0x30/0x390
[30330.827461] ? create_worker+0x1a0/0x1a0
[30330.827895] kthread+0x112/0x130
[30330.828321] ? kthread_bind+0x30/0x30
[30330.828750] ret_from_fork+0x22/0x40
[30451.648926] INFO: task kworker/6:0:2388 blocked for more than 120 seconds.
[30451.649546] Tainted: P OE 4.19.0-8-amd64 #1 Debian 4.19.98-1
[30451.650007] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[30451.650443] kworker/6:0 D 0 2388 2 0x80000000
[30451.650874] Workqueue: events slab_caches_to_rcu_destroy_workfn
[30451.651297] Call Trace:
[30451.651713] ? __schedule+0x2a2/0x870
[30451.652142] ? __queue_work+0x103/0x3e0
[30451.652518] schedule+0x28/0x80
[30451.652913] schedule_timeout+0x26d/0x390
[30451.653316] ? __kmem_cache_shutdown+0x264/0x280
[30451.653714] ? pcpu_free_area+0x27a/0x2f0
[30451.654089] wait_for_completion+0x11f/0x190
[30451.654461] ? wake_up_q+0x70/0x70
[30451.654830] _rcu_barrier+0x120/0x180
[30451.655199] slab_caches_to_rcu_destroy_workfn+0x8f/0xe0
[30451.655578] process_one_work+0x1a7/0x3a0
[30451.655989] worker_thread+0x30/0x390
[30451.656390] ? create_worker+0x1a0/0x1a0
[30451.656731] kthread+0x112/0x130
[30451.657070] ? kthread_bind+0x30/0x30
[30451.657402] ret_from_fork+0x22/0x40
[30572.480073] INFO: task kworker/6:0:2388 blocked for more than 120 seconds.
[30572.480690] Tainted: P OE 4.19.0-8-amd64 #1 Debian 4.19.98-1
[30572.481112] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[30572.481521] kworker/6:0 D 0 2388 2 0x80000000
[30572.481904] Workqueue: events slab_caches_to_rcu_destroy_workfn
[30572.482316] Call Trace:
[30572.482693] ? __schedule+0x2a2/0x870
[30572.483086] ? __queue_work+0x103/0x3e0
[30572.483460] schedule+0x28/0x80
[30572.483854] schedule_timeout+0x26d/0x390
[30572.484294] ? __kmem_cache_shutdown+0x264/0x280
[30572.484714] ? pcpu_free_area+0x27a/0x2f0
[30572.485117] wait_for_completion+0x11f/0x190
[30572.485542] ? wake_up_q+0x70/0x70
[30572.485943] _rcu_barrier+0x120/0x180
[30572.486363] slab_caches_to_rcu_destroy_workfn+0x8f/0xe0
[30572.486774] process_one_work+0x1a7/0x3a0
[30572.487163] worker_thread+0x30/0x390
[30572.487572] ? create_worker+0x1a0/0x1a0
[30572.487991] kthread+0x112/0x130
[30572.488403] ? kthread_bind+0x30/0x30
[30572.488804] ret_from_fork+0x22/0x40
[30693.311278] INFO: task kworker/6:0:2388 blocked for more than 120 seconds.
[30693.311903] Tainted: P OE 4.19.0-8-amd64 #1 Debian 4.19.98-1
[30693.312414] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[30693.312898] kworker/6:0 D 0 2388 2 0x80000000
[30693.313373] Workqueue: events slab_caches_to_rcu_destroy_workfn
[30693.313845] Call Trace:
[30693.314324] ? __schedule+0x2a2/0x870
[30693.314771] ? __queue_work+0x103/0x3e0
[30693.315204] schedule+0x28/0x80
[30693.315641] schedule_timeout+0x26d/0x390
[30693.316045] ? __kmem_cache_shutdown+0x264/0x280
[30693.316468] ? pcpu_free_area+0x27a/0x2f0
[30693.316915] wait_for_completion+0x11f/0x190
[30693.317320] ? wake_up_q+0x70/0x70
[30693.317715] _rcu_barrier+0x120/0x180
[30693.318117] slab_caches_to_rcu_destroy_workfn+0x8f/0xe0
[30693.318555] process_one_work+0x1a7/0x3a0
[30693.318991] worker_thread+0x30/0x390
[30693.319447] ? create_worker+0x1a0/0x1a0
[30693.319906] kthread+0x112/0x130
[30693.320341] ? kthread_bind+0x30/0x30
[30693.320726] ret_from_fork+0x22/0x40
[30814.142431] INFO: task kworker/6:0:2388 blocked for more than 120 seconds.
[30814.143034] Tainted: P OE 4.19.0-8-amd64 #1 Debian 4.19.98-1
[30814.143455] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[30814.143831] kworker/6:0 D 0 2388 2 0x80000000
[30814.144228] Workqueue: events slab_caches_to_rcu_destroy_workfn
[30814.144628] Call Trace:
[30814.145125] ? __schedule+0x2a2/0x870
[30814.145596] ? __queue_work+0x103/0x3e0
[30814.146070] schedule+0x28/0x80
[30814.146511] schedule_timeout+0x26d/0x390
[30814.146930] ? __kmem_cache_shutdown+0x264/0x280
[30814.147340] ? pcpu_free_area+0x27a/0x2f0
[30814.147721] wait_for_completion+0x11f/0x190
[30814.148168] ? wake_up_q+0x70/0x70
[30814.148557] _rcu_barrier+0x120/0x180
[30814.148942] slab_caches_to_rcu_destroy_workfn+0x8f/0xe0
[30814.149349] process_one_work+0x1a7/0x3a0
[30814.149749] worker_thread+0x30/0x390
[30814.150153] ? create_worker+0x1a0/0x1a0
[30814.150520] kthread+0x112/0x130
[30814.150928] ? kthread_bind+0x30/0x30
[30814.151341] ret_from_fork+0x22/0x40
[30816.674512] clocksource: timekeeping watchdog on CPU1: Marking clocksource ‘tsc’ as unstable because the skew is too large:
[30816.675202] clocksource: ‘hpet’ wd_now: bb3f183c wd_last: 8f77d872 mask: ffffffff
[30816.675680] clocksource: ‘tsc’ cs_now: 6d9274b00c26 cs_last: 68149cc2efdc mask: ffffffffffffffff
[30816.676154] tsc: Marking TSC unstable due to clocksource watchdog
[30816.682907] TSC found unstable after boot, most likely due to broken BIOS. Use ‘tsc=unstable’.
[30816.683654] sched_clock: Marking unstable (30816433629526, 263632034)<-(30816690043660, -7139703)
[30816.707702] clocksource: Switched to clocksource hpet

I had this same kernel log on the previous case.

How can I prevent the process inside a CT to disturb the host like this ?
Is that a kernel bug or something ?

uname -a

Linux cpu-5240 4.19.0-8-amd64 #1 SMP Debian 4.19.98-1 (2020-01-26) x86_64 GNU/Linux