OVH Cloud OVH Cloud

INFO: task blocked for more than 120 seconds

14 réponses
Avatar
steve
Bonjour à tous,

Depuis que j'ai changé de machine, j'ai des problèmes de freeze
intempestifs. Mais tout n'est pas gelé. Un 'ls' gèle alors que d'autres
processus fonctionne normalement. La souris n'est pas touchée ni le
clavier. Dans les logs, j'ai ça:

1 box kernel: [ 3988.692306] INFO: task md1_raid1:406 blocked for more than 120 seconds.
1 box kernel: [ 3988.692314] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.692316] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.692320] md1_raid1 D 0 406 2 0x80000000
1 box kernel: [ 3988.692324] Call Trace:
1 box kernel: [ 3988.692337] ? __schedule+0x3f5/0x880
1 box kernel: [ 3988.692342] schedule+0x32/0x80
1 box kernel: [ 3988.692356] md_super_wait+0x6e/0xa0 [md_mod]
1 box kernel: [ 3988.692365] ? remove_wait_queue+0x60/0x60
1 box kernel: [ 3988.692373] md_update_sb.part.61+0x4af/0x910 [md_mod]
1 box kernel: [ 3988.692381] md_check_recovery+0x312/0x530 [md_mod]
1 box kernel: [ 3988.692388] raid1d+0x60/0x8c0 [raid1]
1 box kernel: [ 3988.692394] ? schedule+0x32/0x80
1 box kernel: [ 3988.692398] ? schedule_timeout+0x1e5/0x350
1 box kernel: [ 3988.692405] ? md_thread+0x125/0x170 [md_mod]
1 box kernel: [ 3988.692411] md_thread+0x125/0x170 [md_mod]
1 box kernel: [ 3988.692416] ? remove_wait_queue+0x60/0x60
1 box kernel: [ 3988.692420] kthread+0xf8/0x130
1 box kernel: [ 3988.692427] ? md_rdev_init+0xc0/0xc0 [md_mod]
1 box kernel: [ 3988.692430] ? kthread_create_worker_on_cpu+0x70/0x70
1 box kernel: [ 3988.692433] ret_from_fork+0x35/0x40
1 box kernel: [ 3988.692438] INFO: task md0_raid1:411 blocked for more than 120 seconds.
1 box kernel: [ 3988.692441] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.692443] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.692446] md0_raid1 D 0 411 2 0x80000000
[...]
1 box kernel: [ 3988.692539] INFO: task jbd2/md0-8:985 blocked for more than 120 seconds.
1 box kernel: [ 3988.692542] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.692544] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.692546] jbd2/md0-8 D 0 985 2 0x80000000
1 box kernel: [ 3988.692549] Call Trace:
[...]
1 box kernel: [ 3988.692730] INFO: task jbd2/md1-8:994 blocked for more than 120 seconds.
1 box kernel: [ 3988.692733] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.692735] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.692737] jbd2/md1-8 D 0 994 2 0x80000000
[...]
1 box kernel: [ 3988.692896] INFO: task uptimed:1161 blocked for more than 120 seconds.
1 box kernel: [ 3988.692899] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.692901] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.692904] uptimed D 0 1161 1 0x00000080
1 box kernel: [ 3988.692906] Call Trace:
[...]
1 box kernel: [ 3988.693069] RIP: 0033:0x7fdf53aaa6f0
1 box kernel: [ 3988.693076] Code: Bad RIP value.
1 box kernel: [ 3988.693078] RSP: 002b:00007ffece358a28 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
1 box kernel: [ 3988.693082] RAX: ffffffffffffffda RBX: 0000564ce8e167b0 RCX: 00007fdf53aaa6f0
1 box kernel: [ 3988.693083] RDX: 00000000000001b6 RSI: 0000000000000241 RDI: 00007fdf53d702b0
1 box kernel: [ 3988.693085] RBP: 0000000000000004 R08: 0000000000000004 R09: 0000000000000001
1 box kernel: [ 3988.693087] R10: 0000000000000240 R11: 0000000000000246 R12: 00007fdf53d7042d
1 box kernel: [ 3988.693088] R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000000
1 box kernel: [ 3988.693119] INFO: task fetchmail:3244 blocked for more than 120 seconds.
1 box kernel: [ 3988.693122] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.693124] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.693127] fetchmail D 0 3244 1 0x00000080
1 box kernel: [ 3988.693129] Call Trace:
1 box kernel: [ 3988.693331] RIP: 0033:0x7ff77cd21970
[...]
1 box kernel: [ 3988.693335] Code: Bad RIP value.
1 box kernel: [ 3988.693336] RSP: 002b:00007ffd2b5b26f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
1 box kernel: [ 3988.693339] RAX: ffffffffffffffda RBX: 0000000000000050 RCX: 00007ff77cd21970
1 box kernel: [ 3988.693341] RDX: 0000000000000050 RSI: 000055b1c5456900 RDI: 0000000000000001
1 box kernel: [ 3988.693343] RBP: 000055b1c5456900 R08: 00007ff77cfe1760 R09: 00007ff77e682740
1 box kernel: [ 3988.693344] R10: 0000000000000073 R11: 0000000000000246 R12: 0000000000000050
1 box kernel: [ 3988.693346] R13: 0000000000000001 R14: 00007ff77cfe0600 R15: 0000000000000050
1 box kernel: [ 3988.693362] INFO: task kworker/u56:0:7704 blocked for more than 120 seconds.
1 box kernel: [ 3988.693365] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.693367] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.693370] kworker/u56:0 D 0 7704 2 0x80000080
1 box kernel: [ 3988.693378] Workqueue: writeback wb_workfn (flush-9:0)
[...]
1 box kernel: [ 3988.693635] INFO: task kworker/u56:2:10260 blocked for more than 120 seconds.
1 box kernel: [ 3988.693639] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.693640] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.693643] kworker/u56:2 D 0 10260 2 0x80000080
1 box kernel: [ 3988.693650] Workqueue: writeback wb_workfn (flush-9:1)
1 box kernel: [ 3988.693804] INFO: task lpqd:10309 blocked for more than 120 seconds.
[...]
1 box kernel: [ 3988.693806] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 3988.693808] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 3988.693811] lpqd D 0 10309 2682 0x00000080
1 box kernel: [ 3988.693813] Call Trace:
[...]
1 box kernel: [ 3988.693949] RIP: 0033:0x7f98a07789e7
1 box kernel: [ 3988.693953] Code: Bad RIP value.
1 box kernel: [ 3988.693954] RSP: 002b:00007ffcce9c2e58 EFLAGS: 00000202 ORIG_RAX: 0000000000000031
1 box kernel: [ 3988.693957] RAX: ffffffffffffffda RBX: 0000564564def780 RCX: 00007f98a07789e7
1 box kernel: [ 3988.693959] RDX: 000000000000006e RSI: 00007ffcce9c2f40 RDI: 0000000000000007
1 box kernel: [ 3988.693960] RBP: 0000564564e17360 R08: 00007f98a0a28f78 R09: 0000000000000410
1 box kernel: [ 3988.693962] R10: 00000000000002f0 R11: 0000000000000202 R12: 0000000000000007
1 box kernel: [ 3988.693963] R13: 00007ffcce9c2f40 R14: 0000564564e177f8 R15: 0000564564e188b0
1 box kernel: [ 4109.529828] INFO: task systemd:1 blocked for more than 120 seconds.
1 box kernel: [ 4109.529836] Tainted: P OE 4.19.0-0.bpo.2-amd64 #1 Debian 4.19.16-1~bpo9+1
1 box kernel: [ 4109.529838] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
1 box kernel: [ 4109.529841] systemd D 0 1 0 0x00000000
1 box kernel: [ 4109.529846] Call Trace:
[...]
1 box kernel: [ 4109.530016] RIP: 0033:0x7fca74ec2687
1 box kernel: [ 4109.530023] Code: Bad RIP value.
1 box kernel: [ 4109.530025] RSP: 002b:00007ffc280fb378 EFLAGS: 00000246 ORIG_RAX: 0000000000000053
1 box kernel: [ 4109.530029] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fca74ec2687
1 box kernel: [ 4109.530030] RDX: 00000000000002ee RSI: 00000000000001c0 RDI: 000055d88ed7d220
1 box kernel: [ 4109.530032] RBP: 000000000003a2f8 R08: 0000000000000000 R09: 0000000000000070
1 box kernel: [ 4109.530034] R10: 0000000000000000 R11: 0000000000000246 R12: 000055d88ed7d272
1 box kernel: [ 4109.530036] R13: 8421084210842109 R14: 00000000000000c2 R15: 00007fca74f50540

J'ai supprimé les détails des call trace ([...]) afin de ne pas faire trop long.

On voit que plusieurs processus bloquent (md1_raid1, md0_raid1, uptimed,
fetchmail, kworker, lpqd et systemd). Je pensais à un disque défectueux
dans une grappe RAID 1, alors je l'ai enlevé, ce qui a eu pour effet de
d'augmenter la durée entre deux freeze. J'ai également essayé avec des
versions de noyaux inférieurs, mais même résultat. J'ai lu quelque part
sur Internet que cela pouvait être dû à une machine lente, mais c'est
loin d'être mon cas.

Je suis complètement à court d'idée.

Et vous ?

Merci d'avance,
Steve

4 réponses

1 2
Avatar
steve
Le 16-04-2019, à 21:09:29 +0200, Étienne Mollier a écrit :
Au début, j'ai compris « Oui ça vaudrait le coup d'essayer! »
Mais peut-être qu'il s'agit plutôt de « Oui, le problème se
reproduit avec un noyau non teinté! »

Voilà, j'ai essayé avec le driver « nouveau ». Impossible de charger
xorg, faut dire que j'ai une carte assez récente (GeForce GTX 1080 Ti).
Je suis donc repassé sur le driver proprio nvidia…
En éteignant la machine, j'ai observé un truc étrange:
Failed unmounting /var
et /var est monté sur /dev/md0.
Je ne sais pas si ça peut corrompre ce système de fichiers si la machine
s'éteint avant que cette partition ne soit démontée. Une piste ?
Avatar
=c3
Bonjour,
Je crois que je commence à sécher. Ça vaudrait le coup d'ouvrir
un rapport à propos du noyau via reportbug. Si ce comportement
est connu d'un mainteneur, alors peut-être qu'il aura une
solution, sinon ce sera toujours bien d'en avoir une trace.
Steve, au 2019-04-17 :
Le 16-04-2019, à 21:09:29 +0200, Étienne Mollier a écrit :
Toutefois, je ne sais pas si vous vous êtes retrouvé dans la
situation décrite par le changelog, ni si corruption il y a ;
je crois qu'il y aurait aussi des erreurs relatives à votre
système de fichier dans `dmesg` dans ce cas.

J'ai bien peur que non. J'aimerais bien avoir plus d'information dans
les différents fichiers journaux mais je ne sais pas trop comment et
quoi activer.

Les message relatif au noyau et ses sous-systèmes apparaissent
en sortie de la commande `dmesg`. En dehors, je ne vois pas, à
part des copies dans les différents agrégateurs de journaux.
Il est éventuellement possible d'augmenter la verbosité de
certains modules noyau, via des options du type module.debug=1,
mais pas certain que ça aide dans votre cas. Je n'exclue pas
d'avoir loupé quelque chose moi-même.
Dans le doute, la force brute est aussi une solution valide pour
chercher une aiguille dans une botte de foin:
# rgrep -i 'ext4|raid|md[0-2]' /var/
uname -a
Linux box.maison.mrs 4.19.0-0.bpo.4-amd64 #1 SMP Debian 4.19.28-2~bpo9+1 (2019-03-27) x86_64 GNU/Linux

4.19.28-2~bpo9+1, ça devrait être bon. :)
Dans le doute, j'ajouterais un incrément dans les backups avant
reconstruction, au cas où...
Voilà, j'ai essayé avec le driver « nouveau ». Impossible de charger
xorg, faut dire que j'ai une carte assez récente (GeForce GTX 1080 Ti).

Ça vient probablement du fichier /etc/X11/xorg.conf, produit par
nvidia-xconfig ou nvidia-settings, lors de l'installation et la
configuration du pilote respectivement. Avec un peu de chance,
le serveur X démarrera si ce fichier n'existe plus, par exemple
en le renommant /etc/X11/xorg.conf.nvidia-bck.
Si vraiment c'est « nouveau » qui coince, alors il est toujours
possible de le replacer en liste noire, le pilote nvidiafb
pourra éventuellement prendre le relai ; ceci étant j'ai déjà vu
ce pilote coincer méchamment sur carte Quadro, avec la console
coincée sur une fonte blanche à fond vert… L'écran vert de la
mort ?
En éteignant la machine, j'ai observé un truc étrange:
Failed unmounting /var
et /var est monté sur /dev/md0.
Je ne sais pas si ça peut corrompre ce système de fichiers si la machine
s'éteint avant que cette partition ne soit démontée. Une piste ?

À première vue, ça aurait pu expliquer les erreurs corrigées par
fsck, que vous avez mentionné un peu plus tôt dans le file de
discussion. Toutefois, si le système de fichier ne s'était pas
correctement démonté à l'arrêt de la machine, je crois que le
fsck aurait dû se déclencher au démarrage suivant.
Les erreurs BIOS, et bien, sont des erreurs BIOS (mis à jour très
récemment, ce qui a diminué leur nombre).

L'essentiel est effectivement du bruit, mais c'est bien pensé,
le coup de mettre à jour le Bios.
Amicalement,
--
Étienne Mollier
Avatar
steve
Le 17-04-2019, à 22:47:29 +0200, Étienne Mollier a écrit :
Bonjour,
Je crois que je commence à sécher. Ça vaudrait le coup d'ouvrir

Et bien moi je crois que je suis sur une piste :)
J'ai trouvé trace de fautes de segmentation de mon agent de transport
mail, dma. Je l'ai donc remplacé par exim4, juste pour voir, et pour le
moment, plus de gel. Je croise les doigts.
[...]
Les message relatif au noyau et ses sous-systèmes apparaissent
en sortie de la commande `dmesg`.

Ou pour ceux qui aime de journalctl… :)
uname -a
Linux box.maison.mrs 4.19.0-0.bpo.4-amd64 #1 SMP Debian 4.19.28-2~bpo9+1 (2019-03-27) x86_64 GNU/Linux

4.19.28-2~bpo9+1, ça devrait être bon. :)
Dans le doute, j'ajouterais un incrément dans les backups avant
reconstruction, au cas où...

C'est à dire ?
Voilà, j'ai essayé avec le driver « nouveau ». Impossible de charger
xorg, faut dire que j'ai une carte assez récente (GeForce GTX 1080 Ti).

Ça vient probablement du fichier /etc/X11/xorg.conf, produit par
nvidia-xconfig ou nvidia-settings, lors de l'installation et la
configuration du pilote respectivement. Avec un peu de chance,
le serveur X démarrera si ce fichier n'existe plus, par exemple
en le renommant /etc/X11/xorg.conf.nvidia-bck.

C'est vrai que j'ai oublié la possibilité de supprimer ce fichier. En
faisant le test, j'ai simplement remplacé nvidia par nouveau pour le
driver.
Mais honnêtement ces histoires de pilotes de cartes graphiques me
gavent, c'est pour cela que j'utilise le pilote proprio nvidia qui,
jusqu'à présent, remplissait majoritairement mes besoins. Bien sûr, s'il
devient évident qu'il est la cause de mes soucis, j'envisagerais de
passer des heures à essayer de faire fonctionner le pilote libre. Mais
là j'ai vraiment autre chose à faire.
Si vraiment c'est « nouveau » qui coince, alors il est toujours
possible de le replacer en liste noire, le pilote nvidiafb
pourra éventuellement prendre le relai ; ceci étant j'ai déjà vu
ce pilote coincer méchamment sur carte Quadro, avec la console
coincée sur une fonte blanche à fond vert… L'écran vert de la
mort ?

:)
En éteignant la machine, j'ai observé un truc étrange:
Failed unmounting /var
et /var est monté sur /dev/md0.
Je ne sais pas si ça peut corrompre ce système de fichiers si la machine
s'éteint avant que cette partition ne soit démontée. Une piste ?

À première vue, ça aurait pu expliquer les erreurs corrigées par
fsck, que vous avez mentionné un peu plus tôt dans le file de
discussion. Toutefois, si le système de fichier ne s'était pas
correctement démonté à l'arrêt de la machine, je crois que le
fsck aurait dû se déclencher au démarrage suivant.

Ce qu'il ne fait pas me semble-t-il. Quand je l'ai lancé manuellement
sur un système live, il m'a indiqué que ça faisait des semaines qu'il
n'avait pas été lancé. Ce qui me semble bizarre et qui est une autre
ligne dans mon TODO informatique.
Dans la même veine, j'ai ça:
var.mount: Directory /var to mount over is not empty, mounting anyway.
Pareil pour tmp (qui n'est pas en RAID1). Je n'arrive pas à comprendre
la raison.
Steve
Avatar
=c3
Steve, au 2019-04-18 :
Le 17-04-2019, à 22:47:29 +0200, Étienne Mollier a écrit :
Je crois que je commence à sécher. Ça vaudrait le coup d'ouvrir

Et bien moi je crois que je suis sur une piste :)
J'ai trouvé trace de fautes de segmentation de mon agent de transport
mail, dma. Je l'ai donc remplacé par exim4, juste pour voir, et pour le
moment, plus de gel. Je croise les doigts.

Ça c'est une très bonne nouvelle! :)
Dans le doute, j'ajouterais un incrément dans les backups avant
reconstruction, au cas où...

C'est à dire ?

Faites une sauvegarde avant la manipulation, des fois que…
var.mount: Directory /var to mount over is not empty, mounting
anyway.

C'est peut-être du bruit lié à un démarrage sans montage du /var
une fois. Et comme les fichiers ne sont pas effacés mais
seulement inaccessibles, le message se reproduit à chaque
démarrage.
Ça pourrait aussi être lié à ce bug si le problème se reproduit
après ménage dans le /var de votre partition / (utilisez `mount
--bind / /mnt/rescue` pour voir ce qu'il se passe sous les
points de montages) :
https://github.com/systemd/systemd/issues/4494
Corrigé dans systemd 233, mais je ne suis pas allé vérifier si
ça été corrigé dans Stretch ou non.
Ou alors un de vos services démarre trop vite et aurait grand
besoin de dépendre de var.mount et tmp.mount avant de commencer
à tourner ?
Amicalement,
--
Étienne Mollier
1 2