Log - explication/origine du message "....service: Consumed ...s CPU time"

Support Debian
Tags: #<Tag:0x00007f63f2bbd2c8>
#1

Sous Debian 12,
je viens de redémarrer les services apache2 et ssh et je joins les 2 extractions de mes logs

journalctl -u apache2 --since 2023-10-01
oct. 03 18:45:48 f2 systemd[1]: apache2.service: Consumed 29.990s CPU time.
– Boot 6edbf711c24e4e06928315c28c280523 –
oct. 22 09:09:34 f2 systemd[1]: apache2.service: Consumed 1min 56.245s CPU time.
– Boot c71d9814cb68405791cf29688d7f9c5c –
oct. 27 12:44:31 f2 systemd[1]: apache2.service: Consumed 37.508s CPU time.
– Boot a3fece4054cd493d8f31b9b8c73c95af –
oct. 29 18:59:41 f2 systemd[1]: apache2.service: Consumed 9.791s CPU time.

journalctl -u ssh --since 2023-10-01
oct. 03 18:45:34 f2 systemd[1]: ssh.service: Consumed 1.025s CPU time.
– Boot 6edbf711c24e4e06928315c28c280523 –
oct. 17 07:53:21 f2 systemd[1]: ssh.service: Consumed 2.637s CPU time.
oct. 22 09:09:24 f2 systemd[1]: ssh.service: Consumed 1.040s CPU time.
– Boot f95e1300229140ea9f8f36359e043865 –
nov. 24 16:12:27 f2 systemd[1]: ssh.service: Consumed 42min 38.087s CPU time.

Je ne comprends pas l’origine et la signification des ces messages?
Ni, pourquoi le redémarrage de ssh semble avoir généré le dernier message mais pas celui d’apache2?
A noter, que j’ai redémarré ensuite ssh, ce qui n’a pas généré d’autre log.

Merci d’avance pour toute explication.

Updatedb (plocate) et logs
#2

Ajoute l’option -x et tu auras l’explication de chaque ligne de log, esemple:

░░ L'unité (unit) ssh.service a terminé son arrêt.
nov. 06 07:49:34 rpi systemd[1]: ssh.service: Consumed 1.990s CPU time.
░░ Subject: Ressources consommées durant l'éxécution de l'unité (unit)
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░

Cela devrait effectivement apparaître juste après l’arrêt du service. J’ignore pourquoi ce n’est pas systématique.

1 J'aime
#3

Merci pour le -x

C’est donc le problème principal à expliquer.

A priori (post précédent avec plocate), cela fonctionnait systématiquement sous Debian 11.

#4

En principe c’est géré par la directive CPUAccounting qui est activée par défaut.

Ce que j’observe c’est que cette ligne est absente si le service n’a pas consommé de temps processeur (ou très peu ?). C’est le cas si on s’amuse à redémarrer plusieurs fois de suite un service. En creusant dans la doc sur systemd et les cgroup il y a sûrement une explication (que je n’irai pas chercher :wink: )

1 J'aime
#5

Hello @anon70622873

Je ne te comprends pas, selon moi le CPUAccounting fonctionne bien, y compris en redémarrant plusieurs fois le service. Il suffit de regarder le status après chaque restart.

Ceci dit je n’ai toujours pas d’autre idée/piste, à suivre …

#6

L’explication finale est simple, merci à @Aki du forum

https://forums.debian.net

The message appears in the log because the service consumed more that 1 second of CPU time.

#7

C’est ce que je disais précédemment :

#8

Oui et maintenant on a l’explication.