labunix's blog

labunixのラボUnix

大量にsyslogに出る「Operation not permitted」に対処する。

■大量にsyslogに出る「Operation not permitted」に対処する。
 以下でアップデートしてからの事象。

 jessie を stretch にアップグレードしてみた。(簡易版)
 http://labunix.hateblo.jp/entry/20170717/1500228179

$ lsb_release -a
No LSB modules are available.
Distributor ID:	Debian
Description:	Debian GNU/Linux 9.0 (stretch)
Release:	9.0
Codename:	stretch

■stretchにアップデートしてからの症状。
 バグらしいので以下を参考に。

 "Operation not permitted" entry swells the messages file
 https://ask.fedoraproject.org/en/question/101480/operation-not-permitted-entry-swells-the-messages-file/

■状況確認。秒間約14ものログを吐きつづけてた様子。

$ sudo ls -l /dev/input/event9 
crw-rw---- 1 root input 13, 73  719 23:15 /dev/input/event9

$ sudo awk -F: '/Operation not permitted/{a[$NF]+=1}END{for(n in a){print a[n],n}}' /var/log/syslog
1633  Operation not permitted

$ sudo awk -F: '/Operation not permitted/{a[$NF]+=1}END{for(n in a){print a[n],n}}' /var/log/syslog.1
123346  Operation not permitted

$ sudo zcat /var/log/syslog.2.gz | awk -F: '/Operation not permitted/{a[$NF]+=1}END{for(n in a){print a[n],n}}'
123307  Operation not permitted
1  failed to set IOPL for I/O (Operation not permitted)
1  Operation not permitted (1)

$ echo "123346" | awk '{print $1/360/24}'
14.2716

$ udevadm info --export-db | grep ACCEL
E: ID_INPUT_ACCELEROMETER=1
E: ID_INPUT_ACCELEROMETER=1
E: ID_INPUT_ACCELEROMETER=1

$ udevadm info /dev/input/event9
P: /devices/virtual/input/input12/event9
N: input/event9
E: DEVNAME=/dev/input/event9
E: DEVPATH=/devices/virtual/input/input12/event9
E: ID_INPUT=1
E: ID_INPUT_ACCELEROMETER=1
E: IIO_SENSOR_PROXY_TYPE=input-accel
E: LIBINPUT_DEVICE_GROUP=19/0/0/0:wmi
E: MAJOR=13
E: MINOR=73
E: SUBSYSTEM=input
E: SYSTEMD_WANTS=iio-sensor-proxy.service
E: TAGS=:systemd:
E: USEC_INITIALIZED=12694078

■「Acer BMA150 accelerometer」のbug。
 「acer_wmi kernel module」の修正、4.11 以降で修正されているらしい。

 platform/x86: acer-wmi: setup accelerometer when machine has appropriate notify event
 https://github.com/torvalds/linux/commit/98d610c3739ac354319a6590b915f4624d9151e6

$ uname -r
4.9.0-3-amd64

$ uname -a
Linux vmx-rdebian 4.9.0-3-amd64 #1 SMP Debian 4.9.30-2+deb9u2 (2017-06-26) x86_64 GNU/Linux

$ sudo awk '/acer_wmi:/' /var/log/dmesg
[    5.807755] acer_wmi: Acer Laptop ACPI-WMI Extras
[    5.807767] acer_wmi: Function bitmap for Communication Button: 0x801
[    5.807855] acer_wmi: Brightness must be controlled by generic video driver
[    5.840324] acer_wmi: Enabling Launch Manager failed: 0xe2 - 0x0
[    5.841117] acer_wmi: Get 0x1 Device Status failed: 0xe2 - 0x0
[    5.841983] acer_wmi: Get 0x800 Device Status failed: 0xe2 - 0x0
[    5.842634] acer_wmi: Get Current Device Status failed: 0xe2 - 0x0

$ sudo systemctl list-dependencies --reverse iio-sensor-proxy.service 
iio-sensor-proxy.service
● ├─sys-devices-virtual-input-input12-event9.device
● ├─sys-devices-virtual-input-input12-js0.device
● └─sys-devices-virtual-input-input12.device

$ cat /sys/devices/virtual/input/input12/name 
Acer BMA150 accelerometer

■対処

$ sudo systemctl stop iio-sensor-proxy.service
$ sudo systemctl mask iio-sensor-proxy.service

■対処確認。
 対処後以降「iio-sensor-proxy.service」のエラーが出ていないことを確認。

$ sudo awk '/IIO Sensor Proxy/' /var/log/daemon.log
Jul 17 02:42:49 vmx-rdebian systemd[1]: Starting IIO Sensor Proxy service...
Jul 17 02:42:49 vmx-rdebian systemd[1]: Started IIO Sensor Proxy service.
Jul 19 23:15:01 vmx-rdebian systemd[1]: Stopping IIO Sensor Proxy service...
Jul 19 23:15:44 vmx-rdebian systemd[1]: Starting IIO Sensor Proxy service...
Jul 19 23:15:48 vmx-rdebian systemd[1]: Started IIO Sensor Proxy service.
Jul 21 00:28:51 vmx-rdebian systemd[1]: Stopping IIO Sensor Proxy service...
Jul 21 00:28:51 vmx-rdebian systemd[1]: Stopped IIO Sensor Proxy service.

$ sudo  awk '/iio\-sensor/{a=$1" "$2" "$3;count+=1}END{print a,count}' /var/log/syslog
Jul 21 00:28:50 1633