La Fibre

Télécom => Logiciels et systèmes d'exploitation => Linux Linux (usage serveur) => Discussion démarrée par: vivien le 02 mai 2016 à 22:07:16

Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 02 mai 2016 à 22:07:16
Depuis presque une semaine, la charge du serveur LaFibre.info est passée de 0,4 à 2,4

(https://lafibre.info/images/stats/201605_lafibre_load.png)

J'ai cherché mais l'utilisation du CPU, du disque ou de la carte réseau n'a pas bougé.
J'ai pensé à un process bloqué mais vmstats indique :
r: Nombre de processus en compétition pour le temps CPU. => 1
b: Nombre de processus dormants. => 0
bi: Blocs lus par seconde sur des périphériques orientés bloc. => 3
bo: Blocs écrits par seconde sur des périphériques orientés bloc => 16

Donc la cause du load average semble être lié bo de 16


# vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 1  0  14288 330984 333880 14494236    0    0     3    16    0    0  3  0 97  0  0


Concrètement je n'arrive pas a savoir ce que c'est que ces 16 bloc écrits chaque seconde.

Voici d'autres stats qui elles n'ont pas bougées :

Le disque dur :
(https://lafibre.info/images/stats/201605_lafibre_sda_1.png)(https://lafibre.info/images/stats/201605_lafibre_sda_2.png)(https://lafibre.info/images/stats/201605_lafibre_sda_3.png)

Le CPU :
(https://lafibre.info/images/stats/201605_lafibre_cpu.png)(https://lafibre.info/images/stats/201605_lafibre_cpuspeed.png)

La carte réseau :
(https://lafibre.info/images/stats/201605_lafibre_if.png)

La mémoire :
(https://lafibre.info/images/stats/201605_lafibre_memory.png)

Apache2 :
(https://lafibre.info/images/stats/201605_lafibre_apache_accesses.png)(https://lafibre.info/images/stats/201605_lafibre_apache_volume.png)
Titre: load average du serveur lafibre.info : +2 a cause de I/O inconnues
Posté par: Optix le 02 mai 2016 à 22:48:35
Que donne un :
# swapoff -a

?
Titre: load average du serveur lafibre.info : +2 a cause de I/O inconnues
Posté par: Anonyme le 03 mai 2016 à 00:09:46
Le swap est une piste, mais essaye de regarder tout ce qui en Avg > Cur.
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 03 mai 2016 à 09:14:31
J'ai fais un reboot et...

(https://lafibre.info/images/stats/201605_lafibre_reboot.png)

Il a refusé de redémarer, ce qui explique la coupure de ce matin.

Il répondait toujours au ping : les deux process bloquaient le redémarrage du serveur et comme tous les autres services avaient déja été coupés, Lionel a du faire un reboot hard du serveur...

Merci à lui.

Pour le swap, je monitor la chose, c'est pas la cause de load average élevé :
(https://lafibre.info/images/stats/201605_lafibre_swap.png)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 03 mai 2016 à 09:26:55
Plus de problème de Load average après le reboot :

$ uptime
 09:24:18 up 15 min,  1 user,  load average: 0,27, 0,46, 0,50

# vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 1  0      0 15066712  82056 672004    0    0    95    15   92  236  3  0 94  3  0


bi / bo sont élevés, mais après un reboot, il faut faire pas mal d’accès disque pour toutes les demandes (plus tard elle seront dans le cache vu que le serveur est bien doté en ram)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: Hugues le 03 mai 2016 à 09:30:38
Tu l'as mis à jour sur Ubuntu 16.04 Server au fait ?
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 03 mai 2016 à 09:37:37
Non, car SMF n'est pas compatible PHP 7. (et il aurait été compatible j'aurais un peu attendu)

La charge a brutalement augmenté le lundi 25 avril vers 11h30. Je ne m'étais pas connecté au serveur le jour même ou les jours précédents.

Ma précédente connexion datait du 21 avril pour faire un traceroute : Transit entre Orange et NETPLEX (https://lafibre.info/peering/transit-entre-orange-et-netplex/)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: petrus le 03 mai 2016 à 13:55:18
regarde du coté de perf(1) si tu peux trouver des pistes pour savoir d'où ça vient.

Le blog de Brendan Gregg sur le sujet est très bien : http://www.brendangregg.com/perf.html (http://www.brendangregg.com/perf.html).

Il y a également http://www.brendangregg.com/linuxperf.html (http://www.brendangregg.com/linuxperf.html).

Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 03 mai 2016 à 15:39:56
Merci, si le problème se reproduit, je ferais plus attention...

Le load avrage est repassé à 0,4 :
(https://lafibre.info/images/stats/201605_lafibre_load2.png)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: jack le 03 mai 2016 à 16:18:48
Supprime le swap, ce n'est pas ton ami
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: mirtouf le 03 mai 2016 à 17:22:26
Tout de suite les grands remèdes !  ::)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: Hugues le 03 mai 2016 à 19:46:05
On se raconte que le Swap mange des bébés chatons la nuit et s'autoradicalise.  ::) ::)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 03 mai 2016 à 20:02:08
Le swap n'est clairement pas en cause : j'ai beaucoup de mémoire et très peu de swap utilisé (au bout de plusieurs jours, il va mettre quelques Ko de pages inutilisées)

Le load average :
(https://lafibre.info/images/stats/201605_lafibre_load.png)

L'utilisation du disque dur sur la même période montre bien qu'il n'y a pas eu de modifications :
(https://lafibre.info/images/stats/201605_lafibre_sda_1.png)
(https://lafibre.info/images/stats/201605_lafibre_sda_2.png)

Le swap reste très très faible, regardez les unités :
(https://lafibre.info/images/stats/201605_lafibre_swap.png)

La RAM toujours sur la même période : 14 Mo de swap (le fil rouge tout en haut), 755 Mo de ram utilisée (vert) et 14 000 Mo de ram libre utilisé en cache (le gros du graphe, en bleu-violet)
(https://lafibre.info/images/stats/201605_lafibre_memory.png)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: jack le 03 mai 2016 à 20:14:44
Prochaine fois que ça arrive, fait un htop, trié par la colonne "S" (status), avec les kthreads affichés (maj + k)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: seb le 04 mai 2016 à 00:12:09
J'ai pensé à un process bloqué mais vmstats indique :
r: Nombre de processus en compétition pour le temps CPU. => 1
b: Nombre de processus dormants. => 0
bi: Blocs lus par seconde sur des périphériques orientés bloc. => 3
bo: Blocs écrits par seconde sur des périphériques orientés bloc => 16

Donc la cause du load average semble être lié bo de 16[/size]

# vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 1  0  14288 330984 333880 14494236    0    0     3    16    0    0  3  0 97  0  0


Concrètement je n'arrive pas a savoir ce que c'est que ces 16 bloc écrits chaque seconde.
Probablement l'écriture des logs du serveur, car ce ne sont certainement pas 16 ko/s d'écritures qui vont faire mal à tes disques durs.

Par contre, si ça devait t'arriver de nouveau, sache que lancer un vmstat sans argument va te donner les moyennes depuis le démarrage du système.
Donc si ça faisait plusieurs mois que ton système se tournait les pouces, tu imagines bien que ça ne te donnera aucune indication sur ce qui ne va pas.

La prochaine fois, lancer plutôt un vmstat 1 10, qui va te donner 10 secondes de statistiques toutes fraîches.
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 04 mai 2016 à 08:38:32
Ah vmstat donnaient les infos depuis le démarrage ? Il tournait depuis 3 mois...

Sinon, j'ai trouvé atop qui est pas mal :
(https://lafibre.info/testdebit/ubuntu/201605_atop.png)

(là il est exécuté sur fr.archive.ubuntu.com)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 16 septembre 2016 à 16:52:49
Le phénomène est de retour...

Prochaine fois que ça arrive, fait un htop, trié par la colonne "S" (status), avec les kthreads affichés (maj + k)

Bien joué !

J'ai trouvé mes deux process qui sont bloqué dans l'état D soit disk sleep (uninterruptible)

C'est quoi cet état ?

khubd is a kernel thread and part of the Linux kernel USB core mais je n'ai rien de branché en USB !

(https://lafibre.info/testdebit/ubuntu/201609_htop.png)

J'ai lancé lsusb, il ne répond plus => j'ai maintenant 3 process en disk sleep !
killall lsusb n'arrive pas a killer le 3ème process (lsusb)

Après vérification sur un autre serveur identique, il devrait y avoir un périphérique USB : ID 0624:0248 Avocent Corp. Virtual Hub
Cela semble lié au DRAC de Dell
$ lsusb
Bus 002 Device 003: ID 0424:2514 Standard Microsystems Corp. USB 2.0 Hub
Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 008: ID 0624:0248 Avocent Corp. Virtual Hub
Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 16 septembre 2016 à 20:47:40
Il y a des données dans le dmesg :

[11273834.551052] type=1400 audit(1473524094.532:28): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/sbin/dhclient" pid=22297 comm="apparmor_parser"
[11273834.551236] type=1400 audit(1473524094.532:29): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=22297 comm="apparmor_parser"
[11273834.551388] type=1400 audit(1473524094.532:30): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=22297 comm="apparmor_parser"
[11359185.861753] usb 1-1.1: reset full-speed USB device number 3 using ehci-pci
[11359190.938076] usb 1-1.1: device descriptor read/64, error -32
[11359191.114227] usb 1-1.1: device descriptor read/64, error -32
[11359191.290375] usb 1-1.1: reset full-speed USB device number 3 using ehci-pci
[11359191.362427] usb 1-1.1: device descriptor read/64, error -32
[11359191.538586] usb 1-1.1: device descriptor read/64, error -32
[11359191.714748] usb 1-1.1: reset full-speed USB device number 3 using ehci-pci
[11359192.123084] usb 1-1.1: device not accepting address 3, error -32
[11359192.195140] usb 1-1.1: reset full-speed USB device number 3 using ehci-pci
[11359192.603502] usb 1-1.1: device not accepting address 3, error -32
[11359192.604316] usb 1-1.1: USB disconnect, device number 3
[11359384.590873] INFO: task khubd:71 blocked for more than 120 seconds.
[11359384.591241]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359384.591574] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359384.592047] khubd           D ffff88043fc93180     0    71      2 0x00000000
[11359384.592052]  ffff880428cd7c80 0000000000000046 ffff8804293d6000 ffff880428cd7fd8
[11359384.592057]  0000000000013180 0000000000013180 ffff8804293d6000 ffff880428c290e8
[11359384.592061]  ffff880428c290ec ffff8804293d6000 00000000ffffffff ffff880428c290f0
[11359384.592065] Call Trace:
[11359384.592074]  [<ffffffff81730089>] schedule_preempt_disabled+0x29/0x70
[11359384.592078]  [<ffffffff81731ef5>] __mutex_lock_slowpath+0x135/0x1b0
[11359384.592082]  [<ffffffff81731f8f>] mutex_lock+0x1f/0x2f
[11359384.592088]  [<ffffffff81545c04>] usb_disconnect+0x64/0x200
[11359384.592091]  [<ffffffff815487d3>] hub_port_connect_change+0xd3/0xb20
[11359384.592096]  [<ffffffff8154333d>] ? hub_port_status+0xdd/0x120
[11359384.592099]  [<ffffffff815496f4>] hub_events+0x4d4/0xa20
[11359384.592102]  [<ffffffff81549c75>] hub_thread+0x35/0x160
[11359384.592106]  [<ffffffff810add60>] ? prepare_to_wait_event+0x100/0x100
[11359384.592109]  [<ffffffff81549c40>] ? hub_events+0xa20/0xa20
[11359384.592113]  [<ffffffff8108deb2>] kthread+0xd2/0xf0
[11359384.592117]  [<ffffffff8108dde0>] ? kthread_create_on_node+0x1c0/0x1c0
[11359384.592121]  [<ffffffff8173c2e8>] ret_from_fork+0x58/0x90
[11359384.592125]  [<ffffffff8108dde0>] ? kthread_create_on_node+0x1c0/0x1c0
[11359384.592133] INFO: task kworker/4:2:18579 blocked for more than 120 seconds.
[11359384.592544]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359384.592869] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359384.593321] kworker/4:2     D ffff88043fd13180     0 18579      2 0x00000000
[11359384.593336] Workqueue: events hid_reset [usbhid]
[11359384.593338]  ffff8803f27af850 0000000000000046 ffff8800badb9800 ffff8803f27affd8
[11359384.593341]  0000000000013180 0000000000013180 ffff8800badb9800 ffff8803f27af998
[11359384.593345]  ffff8803f27af9a0 7fffffffffffffff ffff8800badb9800 ffff8800badb9800
[11359384.593348] Call Trace:
[11359384.593352]  [<ffffffff8172fb69>] schedule+0x29/0x70
[11359384.593355]  [<ffffffff8172ed89>] schedule_timeout+0x279/0x320
[11359384.593359]  [<ffffffff810a1988>] ? __enqueue_entity+0x78/0x80
[11359384.593364]  [<ffffffff810a7dbd>] ? enqueue_entity+0x2ad/0xc00
[11359384.593367]  [<ffffffff81730686>] wait_for_completion+0xa6/0x160
[11359384.593372]  [<ffffffff8109d570>] ? wake_up_state+0x20/0x20
[11359384.593377]  [<ffffffff8108748d>] flush_work+0xed/0x1b0
[11359384.593381]  [<ffffffff810836a0>] ? wake_up_worker+0x30/0x30
[11359384.593385]  [<ffffffff81087652>] __cancel_work_timer+0x92/0x1a0
[11359384.593390]  [<ffffffff81076cfb>] ? lock_timer_base.isra.35+0x2b/0x50
[11359384.593394]  [<ffffffff81087770>] cancel_work_sync+0x10/0x20
[11359384.593400]  [<ffffffffa00265dc>] usbhid_close+0xbc/0x100 [usbhid]
[11359384.593407]  [<ffffffffa00771e2>] hidinput_close+0x22/0x30 [hid]
[11359384.593412]  [<ffffffff8159287a>] input_close_device+0x4a/0x70
[11359384.593417]  [<ffffffff815986ff>] evdev_cleanup+0xbf/0xd0
[11359384.593421]  [<ffffffff8159873b>] evdev_disconnect+0x2b/0x60
[11359384.593425]  [<ffffffff81594e85>] __input_unregister_device+0xc5/0x1b0
[11359384.593429]  [<ffffffff8159501d>] input_unregister_device+0x4d/0x80
[11359384.593436]  [<ffffffffa0077386>] hidinput_disconnect+0x96/0xc0 [hid]
[11359384.593442]  [<ffffffffa0073e70>] hid_disconnect+0x60/0x70 [hid]
[11359384.593447]  [<ffffffffa0073f3d>] hid_device_remove+0xbd/0xd0 [hid]
[11359384.593453]  [<ffffffff8149f08f>] __device_release_driver+0x7f/0xf0
[11359384.593457]  [<ffffffff8149f123>] device_release_driver+0x23/0x30
[11359384.593461]  [<ffffffff8149e9a8>] bus_remove_device+0x108/0x180
[11359384.593464]  [<ffffffff8149b439>] device_del+0x129/0x1c0
[11359384.593470]  [<ffffffffa0073fd7>] hid_destroy_device+0x27/0x60 [hid]
[11359384.593475]  [<ffffffffa00245a7>] usbhid_disconnect+0x27/0x50 [usbhid]
[11359384.593480]  [<ffffffff81553814>] usb_unbind_interface+0x64/0x1c0
[11359384.593484]  [<ffffffff8149f08f>] __device_release_driver+0x7f/0xf0
[11359384.593487]  [<ffffffff8149f123>] device_release_driver+0x23/0x30
[11359384.593492]  [<ffffffff815539f8>] usb_driver_release_interface+0x88/0x90
[11359384.593496]  [<ffffffff81553a2e>] usb_forced_unbind_intf+0x2e/0x60
[11359384.593500]  [<ffffffff81553ab9>] unbind_marked_interfaces.isra.9+0x59/0x70
[11359384.593504]  [<ffffffff81553bf9>] usb_unbind_and_rebind_marked_interfaces+0x19/0x30
[11359384.593507]  [<ffffffff81548680>] usb_reset_device+0x140/0x1c0
[11359384.593513]  [<ffffffffa0024bdf>] hid_reset+0x15f/0x1d0 [usbhid]
[11359384.593517]  [<ffffffff81086298>] process_one_work+0x178/0x470
[11359384.593521]  [<ffffffff810870b1>] worker_thread+0x121/0x410
[11359384.593525]  [<ffffffff81086f90>] ? rescuer_thread+0x430/0x430
[11359384.593528]  [<ffffffff8108deb2>] kthread+0xd2/0xf0
[11359384.593532]  [<ffffffff8108dde0>] ? kthread_create_on_node+0x1c0/0x1c0
[11359384.593535]  [<ffffffff8173c2e8>] ret_from_fork+0x58/0x90
[11359384.593539]  [<ffffffff8108dde0>] ? kthread_create_on_node+0x1c0/0x1c0
[11359504.693037] INFO: task khubd:71 blocked for more than 120 seconds.
[11359504.693457]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359504.693849] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359504.694397] khubd           D ffff88043fc93180     0    71      2 0x00000000
[11359504.694402]  ffff880428cd7c80 0000000000000046 ffff8804293d6000 ffff880428cd7fd8
[11359504.694407]  0000000000013180 0000000000013180 ffff8804293d6000 ffff880428c290e8
[11359504.694411]  ffff880428c290ec ffff8804293d6000 00000000ffffffff ffff880428c290f0
[11359504.694415] Call Trace:
[11359504.694424]  [<ffffffff81730089>] schedule_preempt_disabled+0x29/0x70
[11359504.694428]  [<ffffffff81731ef5>] __mutex_lock_slowpath+0x135/0x1b0
[11359504.694432]  [<ffffffff81731f8f>] mutex_lock+0x1f/0x2f
[11359504.694438]  [<ffffffff81545c04>] usb_disconnect+0x64/0x200
[11359504.694441]  [<ffffffff815487d3>] hub_port_connect_change+0xd3/0xb20
[11359504.694446]  [<ffffffff8154333d>] ? hub_port_status+0xdd/0x120
[11359504.694449]  [<ffffffff815496f4>] hub_events+0x4d4/0xa20
[11359504.694452]  [<ffffffff81549c75>] hub_thread+0x35/0x160
[11359504.694456]  [<ffffffff810add60>] ? prepare_to_wait_event+0x100/0x100
[11359504.694459]  [<ffffffff81549c40>] ? hub_events+0xa20/0xa20
[11359504.694463]  [<ffffffff8108deb2>] kthread+0xd2/0xf0
[11359504.694467]  [<ffffffff8108dde0>] ? kthread_create_on_node+0x1c0/0x1c0
[11359504.694471]  [<ffffffff8173c2e8>] ret_from_fork+0x58/0x90
[11359504.694475]  [<ffffffff8108dde0>] ? kthread_create_on_node+0x1c0/0x1c0
[11359504.694484] INFO: task kworker/4:2:18579 blocked for more than 120 seconds.
[11359504.694964]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359504.695349] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359504.712710] kworker/4:2     D ffff88043fd13180     0 18579      2 0x00000000
[11359504.712725] Workqueue: events hid_reset [usbhid]
[11359504.712727]  ffff8803f27af850 0000000000000046 ffff8800badb9800 ffff8803f27affd8
[11359504.712730]  0000000000013180 0000000000013180 ffff8800badb9800 ffff8803f27af998
[11359504.712747]  ffff8803f27af9a0 7fffffffffffffff ffff8800badb9800 ffff8800badb9800
[11359504.712772] Call Trace:
...
[11359624.815201] INFO: task khubd:71 blocked for more than 120 seconds.
[11359624.824377]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359624.833588] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359624.852395] khubd           D ffff88043fc93180     0    71      2 0x00000000
[11359624.852398]  ffff880428cd7c80 0000000000000046 ffff8804293d6000 ffff880428cd7fd8
[11359624.852401]  0000000000013180 0000000000013180 ffff8804293d6000 ffff880428c290e8
[11359624.852402]  ffff880428c290ec ffff8804293d6000 00000000ffffffff ffff880428c290f0
[11359624.852412] Call Trace:
...
[11359624.852460] INFO: task kworker/4:2:18579 blocked for more than 120 seconds.
[11359624.871561]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359624.881830] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359624.902645] kworker/4:2     D ffff88043fd13180     0 18579      2 0x00000000
[11359624.902660] Workqueue: events hid_reset [usbhid]
[11359624.902662]  ffff8803f27af850 0000000000000046 ffff8800badb9800 ffff8803f27affd8
[11359624.902666]  0000000000013180 0000000000013180 ffff8800badb9800 ffff8803f27af998
[11359624.902669]  ffff8803f27af9a0 7fffffffffffffff ffff8800badb9800 ffff8800badb9800
[11359624.902673] Call Trace:
...
[11359745.001438] INFO: task khubd:71 blocked for more than 120 seconds.
[11359745.011708]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359745.021981] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359745.042819] khubd           D ffff88043fc93180     0    71      2 0x00000000
[11359745.042825]  ffff880428cd7c80 0000000000000046 ffff8804293d6000 ffff880428cd7fd8
[11359745.042830]  0000000000013180 0000000000013180 ffff8804293d6000 ffff880428c290e8
[11359745.042834]  ffff880428c290ec ffff8804293d6000 00000000ffffffff ffff880428c290f0
[11359745.042838] Call Trace:
...
[11359745.042947] INFO: task kworker/4:2:18579 blocked for more than 120 seconds.
[11359745.063912]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359745.074247] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359745.095123] kworker/4:2     D ffff88043fd13180     0 18579      2 0x00000000
[11359745.095142] Workqueue: events hid_reset [usbhid]
[11359745.095144]  ffff8803f27af850 0000000000000046 ffff8800badb9800 ffff8803f27affd8
[11359745.095148]  0000000000013180 0000000000013180 ffff8800badb9800 ffff8803f27af998
[11359745.095152]  ffff8803f27af9a0 7fffffffffffffff ffff8800badb9800 ffff8800badb9800
[11359745.095156] Call Trace:
...
[11359865.195680] INFO: task khubd:71 blocked for more than 120 seconds.
[11359865.206289]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359865.216646] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359865.237646] khubd           D ffff88043fc93180     0    71      2 0x00000000
[11359865.237654]  ffff880428cd7c80 0000000000000046 ffff8804293d6000 ffff880428cd7fd8
[11359865.237661]  0000000000013180 0000000000013180 ffff8804293d6000 ffff880428c290e8
[11359865.237669]  ffff880428c290ec ffff8804293d6000 00000000ffffffff ffff880428c290f0
[11359865.237675] Call Trace:
...
[11359865.237749] INFO: task kworker/4:2:18579 blocked for more than 120 seconds.
[11359865.259139]       Not tainted 3.13.0-85-generic #129-Ubuntu
[11359865.269483] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[11359865.290526] kworker/4:2     D ffff88043fd13180     0 18579      2 0x00000000
[11359865.290550] Workqueue: events hid_reset [usbhid]
[11359865.290553]  ffff8803f27af850 0000000000000046 ffff8800badb9800 ffff8803f27affd8
[11359865.290557]  0000000000013180 0000000000013180 ffff8800badb9800 ffff8803f27af998
[11359865.290560]  ffff8803f27af9a0 7fffffffffffffff ffff8800badb9800 ffff8800badb9800
[11359865.290564] Call Trace:
...
[11577633.498136] type=1400 audit(1473827649.048:31): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=1818 comm="apparmor_parser"
[11577635.701857] type=1400 audit(1473827651.248:32): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=1893 comm="apparmor_parser"
[11791266.588265] Peer 0000:0000:0000:0000:0000:ffff:56d2:8af0:52508/443 unexpectedly shrunk window 4050413159:4050463784 (repaired)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: seb le 17 septembre 2016 à 12:14:44
J'ai trouvé mes deux process qui sont bloqué dans l'état D soit disk sleep (uninterruptible)

C'est quoi cet état ?
Juste celui d'un processus qui attend la complétion d'E/S réalisées en mode bloquant (ce qui est le cas par défaut avec les appels système read() et write(), par exemple).

En gros, si tu demandes à lire un fichier, le noyau va figer ton processus le temps qu'il accède à la ressource demandée.
Et par "figer", je veux dire que le processus ne tourne plus du tout (c'est pour ça qu'il n'est pas possible de tuer des processus dans cet état.)
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 17 septembre 2016 à 22:54:14
Donc pas d'autres moyen plus clean de faire un on/off matériel, après avoir fait un halt/reboot qui va arrêter les autres process ?
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: TroniQ89 le 18 septembre 2016 à 02:50:40
Même en SIGKILL (je crois que c'est le nom) ça les tue pas ?

Sinon, le noyau doit avoir un soucis, il faudrait en essayer un autre.
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: thenico le 18 septembre 2016 à 04:32:24
Même en SIGKILL (je crois que c'est le nom) ça les tue pas ?

Tant que l'I/O n'aura pas Timeout, le signal sera en pause.
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 18 septembre 2016 à 07:32:06
Habituellement, il y a un time-out pour les E/S USB ?

Et un bug qui semble correspondre : https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1557172
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: seb le 18 septembre 2016 à 12:03:17
De ce que je crois comprendre de ton problème, c'est le pilote USB lui-même qui est aux fraises.
Et comme c'est justement le pilote qui est censé gérer ces temporisations...

Donc pas d'autres moyen plus clean de faire un on/off matériel, après avoir fait un halt/reboot qui va arrêter les autres process ?
Sans garantie de succès, mais tu peux peut-être essayer de forcer le déchargement du module associé au pilote USB, avant de le recharger.

Avec quelque chose comme ça, peut être:
# lsmod | awk '$1 ~ /usb/ {print "rmmod -f "$1}' | sh
# modprobe usbcore

J'ajouterai qu'après avoir lu les commentaires dans le lien que tu donnes, je me souviens avoir eu des soucis sous Debian testing au printemps.
Mon clavier et ma souris USB ne répondaient subitement plus, et j'étais obligé de redémarrer le système pour reprendre la main dessus.
Je n''avais pas eu le temps de chercher d'où ça venait à l'époque, et le problème avait été résolu suite à une mise à jour de noyau.
Comme un gars dit avoir écrit un correctif pour Debian dans le rapport de bogue, il n'est pas impossible que ce soit lui qui ait résolu mes problèmes.

Tu auras donc peut être tout intérêt à vérifier si ce problème persiste avec un noyau plus récent.
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 18 septembre 2016 à 13:03:32
Je vais effectivement passer sur un noyau plus récent (Ubuntu 14.04 propose maintenant le noyau Linux 4.4 issue d'Ubuntu 16.04).

Je vais demander à Lionel (Adeli/Maxnod) de re-connecter le DRAC (niveau sécurité, je trouvas pas ca top qu'il soit sur une IP publique et si le DRAC se fit hacker, ils ont un accès local au serveur) ce qui va me permettre de faire le hard reboot nécessaire.
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: jack le 18 septembre 2016 à 13:24:09
Même en SIGKILL (je crois que c'est le nom) ça les tue pas ?

Sinon, le noyau doit avoir un soucis, il faudrait en essayer un autre.
Les "threads" noyaux sont insensibles aux signaux

Ce n'est pas nécessaire un bug logiciel, l'aspect défectueux du matériel n'est pas à mettre de côté
Ceci dit, peut-être que des "workarounds" sont disponibles dans une nouvelle version .. :)

Citer
Sans garantie de succès, mais tu peux peut-être essayer de forcer le déchargement du module associé au pilote USB, avant de le recharger.
Il est impossible de décharger un module en cours d'utilisation
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: seb le 18 septembre 2016 à 14:20:55
Il est impossible de décharger un module en cours d'utilisation
L'option -f de la commande rmmod est pourtant censée le permettre:
RMMOD(8)                             rmmod                            RMMOD(8)

NAME
       rmmod - Simple program to remove a module from the Linux Kernel

SYNOPSIS
       rmmod [-f] [-s] [-v] [modulename]

(...)
       -f, --force
           This option can be extremely dangerous: it has no effect unless
           CONFIG_MODULE_FORCE_UNLOAD was set when the kernel was compiled.
           With this option, you can remove modules which are being used, or
           which are not designed to be removed, or have been marked as unsafe
           (see lsmod(8)).

Et l'option CONFIG_MODULE_FORCE_UNLOAD dont il est question est active par défaut sur le noyau Debian :
seb@gaston:~$ grep CONFIG_MODULE_FORCE_UNLOAD /boot/config-$(uname -r)
CONFIG_MODULE_FORCE_UNLOAD=y

S'il n'y a rien d'autre que l'interface RAC du serveur qui utilise la pile USB, ça ne craint pas grand chose d'essayer.

Je vais demander à Lionel (Adeli/Maxnod) de re-connecter le DRAC (niveau sécurité, je trouvas pas ca top qu'il soit sur une IP publique et si le DRAC se fit hacker, ils ont un accès local au serveur) ce qui va me permettre de faire le hard reboot nécessaire.
Tu n'as pas accès à IPMI ?
root@dom0:~# ipmitool power
chassis power Commands: status, on, off, cycle, reset, diag, soft

Après si c'est juste un 'hard reboot' du système que tu cherches à réaliser, pas besoin du RAC :
echo 1 > /proc/sys/kernel/sysrq
echo b > /proc/sysrq-trigger
Évidemment, tu ne lances ça qu'après avoir arrêté les services et démonté les systèmes de fichiers qui peuvent l'être.

Accessoirement, si les processus scotchés en état D influent sur la charge du système, ils ne consomment techniquement aucune ressource.
Titre: load average du serveur lafibre.info : +2 (causes de I/O inconnues)
Posté par: vivien le 24 octobre 2016 à 18:32:34
Lionel (Adeli) a fait un hard reboot du serveur (après avoir déclenché une extinction propre du serveur via le bouton on en face avant)

=> J'ai immédiatement migré sur un Kernel 4.4, j’espère que le bug du dirver USB qui se plante ne se reproduira pas.