Debian環境でacpidのログをsyslogに出力する

ThinkPadの電源プラグのOn/Offで以前はイベントがlogに残っていたのですが，電源管理デーモンが動いていて電源の状態が取得できる状態でもいつの頃からか記録されなくなりました．停電した時間がわかって便利だったのでログ期記録できないか確認してみました．

acpitool で電源アダプタの状態を取得

$ acpitool | grep AC
AC adapter : online
$ acpitool | grep AC
AC adapter : off-line

ThinkPadのFANを制御する方法を調べて思い出したのでacpidのmanやオプションを確認すると， -l, --logevents オプションを使うとすべてのイベントをログに出力してくれるようです．

$ /sbin/acpid -h 2>&1 | grep '\-l,'
-l, --logevents Log all event activity.
$ man acpid | grep -i logevents -A1
-l, --logevents
This option tells acpid to log information about all events and actions.

/etc/default/acpid ファイルを編集して，acpid の起動オプションに -l を追加します．

diff --git a/default/acpid b/default/acpid
index c651a78..a6a7add 100644
--- a/default/acpid
+++ b/default/acpid
@@ -1,7 +1,7 @@
# Options to pass to acpid
#
# OPTIONS are appended to the acpid command-line
-#OPTIONS=""
+OPTIONS="-l"

# Linux kernel modules to load before starting acpid
#

acpid を再起動してオプションがついているのを確認します．

$ sudo service acpid restart
$ sudo service acpid status
● acpid.service - ACPI event daemon
Loaded: loaded (/lib/systemd/system/acpid.service; disabled; vendor preset: enabled)
Active: active (running) since Sun 2021-07-11 05:57:54 JST; 44s ago
TriggeredBy: ● acpid.socket
● acpid.path
Docs: man:acpid(8)
Main PID: 2830732 (acpid)
Tasks: 1 (limit: 9336)
Memory: 288.0K
CPU: 6ms
CGroup: /system.slice/acpid.service
└─2830732 /usr/sbin/acpid -l

Jul 11 05:57:54 yoga-260 systemd[1]: Started ACPI event daemon.
Jul 11 05:57:54 yoga-260 acpid[2830732]: starting up with netlink and the input layer
Jul 11 05:57:54 yoga-260 acpid[2830732]: 1 rule loaded
Jul 11 05:57:54 yoga-260 acpid[2830732]: waiting for events: event logging is on
$ ps aux | grep [/]sbin/acpid
root 2830732 0.0 0.0 2352 684 ? Ss 05:57 0:00 /usr/sbin/acpid -l

acpid に -l オプションのついている状態でsyslogをtailしながら電源を抜き差ししてみると少し可読性が悪いですがログが出力されるのがわかりました．

$ sudo tail -f /var/log/syslog | grep acpid:
Jul 11 05:59:22 yoga-260 acpid: received netlink event "battery PNP0C0A:00 00000080 00000001"
Jul 11 05:59:22 yoga-260 acpid: 0 total rules matched
Jul 11 05:59:22 yoga-260 acpid: completed netlink event "battery PNP0C0A:00 00000080 00000001"
Jul 11 05:59:23 yoga-260 acpid: received netlink event "ac_adapter ACPI0003:00 00000080 00000000"
Jul 11 05:59:23 yoga-260 acpid: 0 total rules matched
Jul 11 05:59:23 yoga-260 acpid: completed netlink event "ac_adapter ACPI0003:00 00000080 00000000"
Jul 11 05:59:23 yoga-260 acpid: received netlink event "ibm/hotkey LEN0068:00 00000080 00006030"
Jul 11 05:59:23 yoga-260 acpid: 0 total rules matched
Jul 11 05:59:23 yoga-260 acpid: completed netlink event "ibm/hotkey LEN0068:00 00000080 00006030"
Jul 11 05:59:23 yoga-260 acpid: received netlink event "thermal_zone LNXTHERM:00 00000081 00000000"
Jul 11 05:59:23 yoga-260 acpid: 0 total rules matched
Jul 11 05:59:23 yoga-260 acpid: completed netlink event "thermal_zone LNXTHERM:00 00000081 00000000"
Jul 11 05:59:26 yoga-260 acpid: received netlink event "battery PNP0C0A:00 00000080 00000001"
Jul 11 05:59:26 yoga-260 acpid: 0 total rules matched
Jul 11 05:59:26 yoga-260 acpid: completed netlink event "battery PNP0C0A:00 00000080 00000001"
Jul 11 05:59:26 yoga-260 acpid: received netlink event "ac_adapter ACPI0003:00 00000080 00000001"
Jul 11 05:59:26 yoga-260 acpid: 0 total rules matched
Jul 11 05:59:26 yoga-260 acpid: completed netlink event "ac_adapter ACPI0003:00 00000080 00000001"
Jul 11 05:59:26 yoga-260 acpid: received netlink event "ibm/hotkey LEN0068:00 00000080 00006030"
Jul 11 05:59:26 yoga-260 acpid: 0 total rules matched
Jul 11 05:59:26 yoga-260 acpid: completed netlink event "ibm/hotkey LEN0068:00 00000080 00006030"
Jul 11 05:59:26 yoga-260 acpid: received netlink event "thermal_zone LNXTHERM:00 00000081 00000000"
Jul 11 05:59:26 yoga-260 acpid: 0 total rules matched
Jul 11 05:59:26 yoga-260 acpid: completed netlink event "thermal_zone LNXTHERM:00 00000081 00000000"

すべてのイベントが出力されるので，ボリュームや，輝度の調整でもこのように書き出されます．

Jul 11 06:01:12 t430s acpid: received input layer event "button/volumeup VOLUP 00000080 00000000 K"
Jul 11 06:01:12 t430s acpid: rule from 1840013[0:0] matched
Jul 11 06:01:12 t430s acpid: notifying client 1840013[0:0]
Jul 11 06:01:12 t430s acpid: 1 total rule matched
Jul 11 06:01:12 t430s acpid: completed input layer event "button/volumeup VOLUP 00000080 00000000 K"
Jul 11 06:01:13 t430s acpid: received input layer event "button/volumedown VOLDN 00000080 00000000 K"
Jul 11 06:01:13 t430s acpid: rule from 1840013[0:0] matched
Jul 11 06:01:13 t430s acpid: notifying client 1840013[0:0]
Jul 11 06:01:13 t430s acpid: 1 total rule matched
Jul 11 06:01:13 t430s acpid: completed input layer event "button/volumedown VOLDN 00000080 00000000 K"
Jul 11 06:01:16 t430s acpid: received input layer event "video/brightnessdown BRTDN 00000087 00000000 K"
Jul 11 06:01:16 t430s acpid: rule from 1840013[0:0] matched
Jul 11 06:01:16 t430s acpid: notifying client 1840013[0:0]
Jul 11 06:01:16 t430s acpid: 1 total rule matched
Jul 11 06:01:16 t430s acpid: completed input layer event "video/brightnessdown BRTDN 00000087 00000000 K"
Jul 11 06:01:16 t430s acpid: received input layer event "video/brightnessup BRTUP 00000086 00000000 K"
Jul 11 06:01:16 t430s acpid: rule from 1840013[0:0] matched
Jul 11 06:01:16 t430s acpid: notifying client 1840013[0:0]
Jul 11 06:01:16 t430s acpid: 1 total rule matched
Jul 11 06:01:16 t430s acpid: completed input layer event "video/brightnessup BRTUP 00000086 00000000 K"

以前よりログが冗長で可読性が悪いですがとりあえず動作しました．これで停電が発生したときに停電発生時間や，短い停電であれば停電間隔が確認できます．

環境1(実際はsid)

$ dpkg-query -W acpid rsyslog systemd
acpid 1:2.0.32-1
rsyslog 8.2102.0-2
systemd 247.3-5
$ lsb_release -dr
Description: Debian GNU/Linux 11 (bullseye)
Release: 11
$ arch
x86_64
$ sudo lshw | grep -E '^\ \ \ \ product:|^\ \ \ \ version:'
product: 23533KJ (LENOVO_MT_2353)
version: ThinkPad T430s

環境2

$ dpkg-query -W acpid rsyslog systemd
acpid 1:2.0.32-1
rsyslog 8.2102.0-2
systemd 247.3-5
$ lsb_release -dr
Description: Debian GNU/Linux 11 (bullseye)
Release: 11
$ arch
x86_64
$ sudo lshw | grep -E '^\ \ \ \ product:|^\ \ \ \ version:'
product: 20FEA02WJP (LENOVO_MT_20FE_BU_Think_FM_ThinkPad Yoga 260)
version: ThinkPad Yoga 260