Kernel hung_task_timeout: Läuft hier eine Software Amok oder liegts am Host-System?

fuerni · Jun 10th 2019

Hallo,

mein RS 1000 SAS G7SE läuft seit fast 2 Jahren problemlos. Seit Anfang Juni meldet mir mein Monitoring allerdings alle paar Tage ein HTTPS-Timeouts auf eine PHP-Website mit lokaler Datenbankanbindung.

Im Kernel-Log finde ich zu diesem Zeitpunkt folgendes:

Code

Jun 10 14:13:37 kaiser kernel: [306917.576563] INFO: task jbd2/sda4-8:701 blocked for more than 120 seconds.
Jun 10 14:13:37 kaiser kernel: [306917.576775]       Not tainted 4.9.0-9-amd64 #1 Debian 4.9.168-1+deb9u2
Jun 10 14:13:37 kaiser kernel: [306917.576925] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jun 10 14:13:37 kaiser kernel: [306917.577056] jbd2/sda4-8     D    0   701      2 0x00000000
Jun 10 14:13:37 kaiser kernel: [306917.577061]  ffff9847340e9c00 0000000000000000 ffff9847334cf000 ffff98473fd18980
Jun 10 14:13:37 kaiser kernel: [306917.577063]  ffff984599846040 ffffaec4410e7a70 ffffffff99c15aa9 0000000000000000
Jun 10 14:13:37 kaiser kernel: [306917.577066]  00ffaec4410e7ab8 ffff98473fd18980 0000000000000046 ffff9847334cf000
Jun 10 14:13:37 kaiser kernel: [306917.577068] Call Trace:
Jun 10 14:13:41 kaiser kernel: [306917.577114]  [<ffffffff99c15aa9>] ? __schedule+0x239/0x6f0
Jun 10 14:13:41 kaiser kernel: [306917.577116]  [<ffffffff99c16760>] ? bit_wait+0x50/0x50
Jun 10 14:13:41 kaiser kernel: [306917.577118]  [<ffffffff99c15f92>] ? schedule+0x32/0x80
Jun 10 14:13:41 kaiser kernel: [306917.577119]  [<ffffffff99c1932d>] ? schedule_timeout+0x1dd/0x380
Jun 10 14:13:41 kaiser kernel: [306917.593358]  [<ffffffff9965af3a>] ? kvm_clock_get_cycles+0x1a/0x20
Jun 10 14:13:41 kaiser kernel: [306917.593425]  [<ffffffff99c16760>] ? bit_wait+0x50/0x50
Jun 10 14:13:41 kaiser kernel: [306917.593432]  [<ffffffff99c1580d>] ? io_schedule_timeout+0x9d/0x100
Jun 10 14:13:42 kaiser kernel: [306917.593456]  [<ffffffff996bd377>] ? prepare_to_wait+0x57/0x80
Jun 10 14:13:42 kaiser kernel: [306917.593466]  [<ffffffff99c16777>] ? bit_wait_io+0x17/0x60
Jun 10 14:13:42 kaiser kernel: [306917.593469]  [<ffffffff99c16335>] ? __wait_on_bit+0x55/0x80
Jun 10 14:13:42 kaiser kernel: [306917.593486]  [<ffffffff99782ea8>] ? find_get_pages_tag+0x158/0x2e0
Jun 10 14:13:42 kaiser kernel: [306917.593495]  [<ffffffff9978210f>] ? wait_on_page_bit+0x7f/0xa0
Jun 10 14:13:42 kaiser kernel: [306917.593497]  [<ffffffff996bd7e0>] ? wake_atomic_t_function+0x60/0x60
Jun 10 14:13:42 kaiser kernel: [306917.593500]  [<ffffffff99782210>] ? __filemap_fdatawait_range+0xe0/0x140
Jun 10 14:13:42 kaiser kernel: [306917.593519]  [<ffffffff99907d96>] ? submit_bio+0x76/0x140
Jun 10 14:13:42 kaiser kernel: [306917.593522]  [<ffffffff9978227f>] ? filemap_fdatawait_range+0xf/0x30
Jun 10 14:13:42 kaiser kernel: [306917.593564]  [<ffffffffc03bf7c5>] ? jbd2_journal_commit_transaction+0x735/0x17c0 [jbd2]
Jun 10 14:13:42 kaiser kernel: [306917.593568]  [<ffffffff99c1a9a4>] ? __switch_to_asm+0x34/0x70
Jun 10 14:13:42 kaiser kernel: [306917.593570]  [<ffffffff99c1a9a4>] ? __switch_to_asm+0x34/0x70
Jun 10 14:13:42 kaiser kernel: [306917.593572]  [<ffffffff99c1a9b0>] ? __switch_to_asm+0x40/0x70
Jun 10 14:13:42 kaiser kernel: [306917.593580]  [<ffffffff996a1d21>] ? finish_task_switch+0x71/0x210
Jun 10 14:13:42 kaiser kernel: [306917.593585]  [<ffffffffc03c4c72>] ? kjournald2+0xc2/0x260 [jbd2]
Jun 10 14:13:42 kaiser kernel: [306917.593587]  [<ffffffff996bd740>] ? prepare_to_wait_event+0xf0/0xf0
Jun 10 14:13:42 kaiser kernel: [306917.593591]  [<ffffffffc03c4bb0>] ? commit_timeout+0x10/0x10 [jbd2]
Jun 10 14:13:42 kaiser kernel: [306917.593599]  [<ffffffff9969a969>] ? kthread+0xd9/0xf0
Jun 10 14:13:42 kaiser kernel: [306917.593601]  [<ffffffff99c1a9a4>] ? __switch_to_asm+0x34/0x70
Jun 10 14:13:42 kaiser kernel: [306917.593603]  [<ffffffff9969a890>] ? kthread_park+0x60/0x60
Jun 10 14:13:42 kaiser kernel: [306917.593605]  [<ffffffff99c1aa37>] ? ret_from_fork+0x57/0x70
Jun 10 14:13:42 kaiser kernel: [306917.594216] rs:main Q:Reg   D    0   867      1 0x00000000
Jun 10 14:13:42 kaiser kernel: [306917.594222]  ffff984737530000 ffff984733d2e800 ffff984733ba6040 ffff98473fd18980
Jun 10 14:13:42 kaiser kernel: [306917.594225]  ffff9847334bc040 ffffaec44101fa20 ffffffff99c15aa9 0000000000000000
Jun 10 14:13:42 kaiser kernel: [306917.594228]  0000000000000000 ffff98473fd18980 0000000000000000 ffff984733ba6040
Jun 10 14:13:42 kaiser kernel: [306917.594231] Call Trace:
Jun 10 14:13:42 kaiser kernel: [306917.594236]  [<ffffffff99c15aa9>] ? __schedule+0x239/0x6f0
Jun 10 14:13:42 kaiser kernel: [306917.594238]  [<ffffffff99c16760>] ? bit_wait+0x50/0x50
Jun 10 14:13:42 kaiser kernel: [306917.594241]  [<ffffffff99c15f92>] ? schedule+0x32/0x80
Jun 10 14:13:42 kaiser kernel: [306917.594243]  [<ffffffff99c1932d>] ? schedule_timeout+0x1dd/0x380
Jun 10 14:13:42 kaiser kernel: [306917.594265]  [<ffffffff996f14fe>] ? ktime_get+0x3e/0xb0
Jun 10 14:13:42 kaiser kernel: [306917.594268]  [<ffffffff99c16760>] ? bit_wait+0x50/0x50
Jun 10 14:13:42 kaiser kernel: [306917.594271]  [<ffffffff99c1580d>] ? io_schedule_timeout+0x9d/0x100
Jun 10 14:13:42 kaiser kernel: [306917.594273]  [<ffffffff996bd377>] ? prepare_to_wait+0x57/0x80
Jun 10 14:13:42 kaiser kernel: [306917.594275]  [<ffffffff99c16777>] ? bit_wait_io+0x17/0x60
Jun 10 14:13:42 kaiser kernel: [306917.594277]  [<ffffffff99c16335>] ? __wait_on_bit+0x55/0x80
Jun 10 14:13:42 kaiser kernel: [306917.594279]  [<ffffffff99c1a9a4>] ? __switch_to_asm+0x34/0x70
Jun 10 14:13:42 kaiser kernel: [306917.594280]  [<ffffffff99c16760>] ? bit_wait+0x50/0x50
Jun 10 14:13:42 kaiser kernel: [306917.594282]  [<ffffffff99c1649e>] ? out_of_line_wait_on_bit+0x7e/0xa0
Jun 10 14:13:42 kaiser kernel: [306917.594284]  [<ffffffff996bd7e0>] ? wake_atomic_t_function+0x60/0x60
Jun 10 14:13:42 kaiser kernel: [306917.594289]  [<ffffffffc03bdbe1>] ? do_get_write_access+0x1f1/0x450 [jbd2]
Jun 10 14:13:42 kaiser kernel: [306917.594294]  [<ffffffffc03bde8c>] ? jbd2_journal_get_write_access+0x4c/0x60 [jbd2]
Jun 10 14:13:42 kaiser kernel: [306917.594405]  [<ffffffffc0415a36>] ? __ext4_journal_get_write_access+0x36/0x70 [ext4]
Jun 10 14:13:42 kaiser kernel: [306917.594425]  [<ffffffffc03e35f0>] ? ext4_reserve_inode_write+0x70/0x90 [ext4]
Jun 10 14:13:42 kaiser kernel: [306917.594437]  [<ffffffffc03e8373>] ? ext4_dirty_inode+0x43/0x60 [ext4]
Jun 10 14:13:42 kaiser kernel: [306917.594448]  [<ffffffffc03e365f>] ? ext4_mark_inode_dirty+0x4f/0x200 [ext4]
Jun 10 14:13:42 kaiser kernel: [306917.594458]  [<ffffffffc03e8373>] ? ext4_dirty_inode+0x43/0x60 [ext4]
Jun 10 14:13:42 kaiser kernel: [306917.594482]  [<ffffffff9983b02b>] ? __mark_inode_dirty+0x16b/0x360
Jun 10 14:13:42 kaiser kernel: [306917.594485]  [<ffffffff998284d9>] ? generic_update_time+0x79/0xd0
Jun 10 14:13:42 kaiser kernel: [306917.594487]  [<ffffffff998286e6>] ? current_time+0x36/0x70
Jun 10 14:13:42 kaiser kernel: [306917.594488]  [<ffffffff998287df>] ? file_update_time+0xbf/0x110
Jun 10 14:13:42 kaiser kernel: [306917.594495]  [<ffffffff996fb4a4>] ? futex_wake+0x94/0x170
Jun 10 14:13:42 kaiser kernel: [306917.594498]  [<ffffffff99784ef9>] ? __generic_file_write_iter+0x99/0x1b0
Jun 10 14:13:42 kaiser kernel: [306917.594510]  [<ffffffffc03da200>] ? ext4_file_write_iter+0x90/0x380 [ext4]
Jun 10 14:13:42 kaiser kernel: [306917.594518]  [<ffffffff9984f81e>] ? fsnotify+0x3ae/0x500
Jun 10 14:13:42 kaiser kernel: [306917.594526]  [<ffffffff9980b450>] ? new_sync_write+0xe0/0x130
Jun 10 14:13:42 kaiser kernel: [306917.594528]  [<ffffffff9980bc40>] ? vfs_write+0xb0/0x190
Jun 10 14:13:42 kaiser kernel: [306917.594531]  [<ffffffff9980d082>] ? SyS_write+0x52/0xc0
Jun 10 14:13:42 kaiser kernel: [306917.594558]  [<ffffffff99603b7d>] ? do_syscall_64+0x8d/0x100
Jun 10 14:13:42 kaiser kernel: [306917.594561]  [<ffffffff99c1a88e>] ? entry_SYSCALL_64_after_swapgs+0x58/0xc6
Jun 10 14:13:42 kaiser kernel: [306920.558700] sd 2:0:0:0: [sda] tag#0 abort
Jun 10 14:13:42 kaiser kernel: [306920.558856] sd 2:0:0:0: [sda] tag#2 abort
Jun 10 14:13:42 kaiser kernel: [306920.559012] sd 2:0:0:0: [sda] tag#3 abort

Display More

Und bei den Statistiken im SCP habe ich einen Peak in allen Diagrammen (CPU, Festplatte IOPS [Read], Netzwerk PPS [RX+TX], Netzwerk Bytes [TX]).

Liegt das an meinem System (dreht da eine Software durch), ist das ein Angriff oder gibt es da ein Problem an meinem Host?

Ich hoffe, jemand kann mir hier einen Tipp geben - danke schonmal.

vmk · Jun 10th 2019

Wenn fsck nichts zu Tage befördert, dann hast du ein Storage-Problem. Eventuell kann der Support dich auf einen anderen Bode verschieben.

fuerni · Jun 10th 2019

Danke für die schnelle Hilfe vmk.

fsck sagt "clean". Dann werd ichs mal beim Support versuchen.