Rotate hook does not work on Fedora (SELinux?!)

[martin-ueding]

Ever since I switched to Fedora, the rotate hook does not work any more. Now I finally have the time to fix this.

The event is the following, the first one is close, the second one to open:

# acpi_listen
video/tabletmode TBLT 0000008A 00000001
video/tabletmode TBLT 0000008A 00000000

The event does match:

event=video/tabletmode TBLT 0000008A 0000000[01].*

Then I ran journalctl -f and this is what I got:

Mär 27 17:39:50 martin-friese.fritz.box thinkpad-rotate-hook[28661]: video/tabletmode TBLT 0000008A 00000001
Mär 27 17:39:50 martin-friese.fritz.box audit[28666]: AVC avc:  denied  { setgid } for  pid=28666 comm="sudo" capability=6  scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:apmd_t:s0 tclass=capability permissive=0
Mär 27 17:39:50 martin-friese.fritz.box python3[28663]: detected unhandled Python exception in '/usr/bin/thinkpad-rotate-hook'
Mär 27 17:39:51 martin-friese.fritz.box abrt-server[28668]: Package 'thinkpad-scripts' isn't signed with proper key
Mär 27 17:39:51 martin-friese.fritz.box abrt-server[28668]: 'post-create' on '/var/spool/abrt/Python3-2016-03-27-17:39:50-28663' exited with 1
Mär 27 17:39:51 martin-friese.fritz.box abrt-server[28668]: Deleting problem directory '/var/spool/abrt/Python3-2016-03-27-17:39:50-28663'
Mär 27 17:39:52 martin-friese.fritz.box thinkpad-rotate-hook[28671]: video/tabletmode TBLT 0000008A 00000000
Mär 27 17:39:52 martin-friese.fritz.box audit[28676]: AVC avc:  denied  { setgid } for  pid=28676 comm="sudo" capability=6  scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:apmd_t:s0 tclass=capability permissive=0
Mär 27 17:39:52 martin-friese.fritz.box python3[28673]: detected unhandled Python exception in '/usr/bin/thinkpad-rotate-hook'
Mär 27 17:39:52 martin-friese.fritz.box abrt-server[28678]: Not saving repeating crash in '/usr/bin/thinkpad-rotate-hook'

From my limited knowledge of SELinux, the _r and _t sound very much like that. Now I have to read up on SELinux in order to find out to enable an exception for this.

[martin-ueding]

I haved asked this as a question on Unix Stack Exchange.

[Aruee]

I thought I might try and see if I can find a solution, but it seems that I'm not even getting to where you are right now... This is my journalctl -f output:

Jul 13 11:13:18 computername python3[11561]: detected unhandled Python exception in '/usr/bin/thinkpad-rotate-hook'
Jul 13 11:13:18 computername abrt-server[11563]: Deleting problem directory Python3-2016-07-13-11:13:18-11561 (dup of Python3-2016-07-13-01:29:24-31291)
Jul 13 11:13:18 computername abrt-server[11563]: No actions are found for event 'notify-dup'
Jul 13 11:13:20 computername audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fprintd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 13 11:13:22 computername python3[11571]: detected unhandled Python exception in '/usr/bin/thinkpad-rotate-hook'
Jul 13 11:13:22 computername abrt-server[11573]: Not saving repeating crash in '/usr/bin/thinkpad-rotate-hook'

However, if I check the referenced abrt problem directory, the backtrace looks like this:

[root@cpsnb02 Python3-2016-07-13-01:29:24-31291] # cat ./backtrace 
__init__.py:839:resolve:pkg_resources.DistributionNotFound: The 'thinkpad-scripts==4.7.3' distribution was not found and is required by the application

Traceback (most recent call last):
  File "/usr/bin/thinkpad-rotate-hook", line 5, in <module>
    from pkg_resources import load_entry_point
  File "/usr/lib/python3.4/site-packages/pkg_resources/__init__.py", line 3084, in <module>
    @_call_aside
  File "/usr/lib/python3.4/site-packages/pkg_resources/__init__.py", line 3070, in _call_aside
    f(*args, **kwargs)
  File "/usr/lib/python3.4/site-packages/pkg_resources/__init__.py", line 3097, in _initialize_master_working_set
    working_set = WorkingSet._build_master()
  File "/usr/lib/python3.4/site-packages/pkg_resources/__init__.py", line 651, in _build_master
    ws.require(__requires__)
  File "/usr/lib/python3.4/site-packages/pkg_resources/__init__.py", line 952, in require
    needed = self.resolve(parse_requirements(requirements))
  File "/usr/lib/python3.4/site-packages/pkg_resources/__init__.py", line 839, in resolve
    raise DistributionNotFound(req, requirers)
pkg_resources.DistributionNotFound: The 'thinkpad-scripts==4.7.3' distribution was not found and is required by the application

Local variables in innermost frame:
replace_conflicting: False
installer: None
req: Requirement.parse('thinkpad-scripts==4.7.3')
requirements: []
self: <pkg_resources.WorkingSet object at 0x7fd0cd0dc2e8>
dist: None
requirers: None
ws: <pkg_resources.WorkingSet object at 0x7fd0cd0dc2e8>
required_by: defaultdict(<class 'set'>, {})
processed: {}
to_activate: []
best: {'thinkpad-scripts': None}
env: <pkg_resources.Environment object at 0x7fd0cd0dc2b0>

Any idea why thinkpad-scripts supposedly isn't installed or said to be the wrong version? I have installed the current version from source (this repo, master branch) via

make
sudo make install
sudo setup.py install

Am I missing anything?

[martin-ueding]

The current master is 4.7.4 since I have incorporated your fix some 9 hours ago. I would guess that there is something left over from 4.7.3 somewhere on your system and that causes the conflict.

Did you restart the system between the upgrade and trying to reproduce the bug?

[martin-ueding]

I got my hands into SELinux yesterday when I worked on pam_mount on Fedora 24 which required me to generate some new policies.

Yesterday I have upgraded my machine to Fedora 24. The rotate hook does not work, so I would say that this problem is exactly as before.

Using my new knowledge, I have ran

ausearch -c sudo --raw | audit2allow -M thinkpad-rotate-hook

From that I got a policy snippet (.te file):

allow apmd_t self:capability setgid;

Using semodule -i thinkpad-rotate-hook.pp I have installed this snippet. Then the rotate hook would not be denied by SELinux directly. However, I got a Python exception where the pieces are lined up in /var/spool/abrt/Python3-2016-07-21-18:12:46-21478. The backtrace is:

subprocess.py:584:check_call:subprocess.CalledProcessError: Command '['sudo', '-u', 'mu', '-i', 'env', 'DISPLAY=:0.0', '/usr/bin/thinkpad-rotate', '', '--via-hook']' returned non-zero exit status 1

Traceback (most recent call last):
  File "/usr/bin/thinkpad-rotate-hook", line 9, in <module>
    load_entry_point('thinkpad-scripts==4.7.4', 'console_scripts', 'thinkpad-rotate-hook')()
  File "/usr/lib/python3.5/site-packages/tps/hooks.py", line 126, in main_rotate_hook
    ], logger)
  File "/usr/lib/python3.5/site-packages/tps/__init__.py", line 139, in wrapper
    return function(command, *args, **kwargs)
  File "/usr/lib64/python3.5/subprocess.py", line 584, in check_call
    raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['sudo', '-u', 'mu', '-i', 'env', 'DISPLAY=:0.0', '/usr/bin/thinkpad-rotate', '', '--via-hook']' returned non-zero exit status 1

Local variables in innermost frame:
kwargs: {}
popenargs: (['sudo', '-u', 'mu', '-i', 'env', 'DISPLAY=:0.0', '/usr/bin/thinkpad-rotate', '', '--via-hook'],)
retcode: 1
cmd: ['sudo', '-u', 'mu', '-i', 'env', 'DISPLAY=:0.0', '/usr/bin/thinkpad-rotate', '', '--via-hook']

I am not to sure what to make out of this. The sudo invocation still fails. It could also be that thinkpad-rotate fails and that makes sudo to fail. All in all I get the impression that the implementation using this ACPI hook and sudo is a kludge. We should probably run some daemon in the context of the user account and then listen to the signal. I have to think about this a bit more.

[jturner314]

I don't really know anything about SELinux, but here are a few (hopefully helpful) thoughts:

• It would be useful to know if the sudo ... thinkpad-rotate call is failing because of sudo or thinkpad-rotate. Do sudo or thinkpad-rotate produce any useful logs? If not, you could use strace to watch what sudo and thinkpad-rotate are doing. By the way, does thinkpad-dock-hook have the same issue?
• It might not be a good idea to add all of the necessary SELinux permissions to the system apmd_t type. It may be better to transition the process to a different SELinux context. This page looks helpful for learning more about transitions between SELinux contexts.
• If you're looking into switching to a daemon running in the context of the user, you may be interested in systemd's user units, but of course that's systemd-only.

[martin-ueding]

I have just tried to use setenforce 0, the hardware rotation hook works just fine then. I got the following output.

Closing the lid:

audit[26807]: AVC avc:  denied  { setgid } for  pid=26807 comm="sudo" capability=6  scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:apmd_t:s0 tclass=capability permissive=1
audit[26807]: AVC avc:  denied  { setrlimit } for  pid=26807 comm="sudo" scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:apmd_t:s0 tclass=process permissive=1
sudo[26807]:     root : TTY=unknown ; PWD=/ ; USER=mu ; COMMAND=/usr/bin/fish -c env DISPLAY=:0.0 /usr/bin/thinkpad-rotate  --via-hook
audit[26807]: USER_CMD pid=26807 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='cwd="/" cmd=2D66697368202D6320656E7620444953504C41595C3D5C3A305C2E30205C2F7573725C2F62696E5C2F7468696E6B7061642D726F7461746520202D2D7669612D686F6F6B terminal=? res=success'
audit[26807]: CRED_REFR pid=26807 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="mu" exe="/usr/bin/sudo" hostname=? addr=? terminal=? res=success'
audit[26807]: AVC avc:  denied  { setsched } for  pid=26807 comm="sudo" scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:apmd_t:s0 tclass=process permissive=1
audit[1]: USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='avc:  received setenforce notice (enforcing=0) exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
audit[26807]: AVC avc:  denied  { sys_ptrace } for  pid=26807 comm="sudo" capability=19  scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:apmd_t:s0 tclass=capability permissive=1
audit[26807]: USER_START pid=26807 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='op=PAM:session_open grantors=pam_keyinit,pam_keyinit,pam_limits,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="mu" exe="/usr/bin/sudo" hostname=? addr=? terminal=? res=success'
audit[26808]: AVC avc:  denied  { setrlimit } for  pid=26808 comm="sudo" scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:apmd_t:s0 tclass=process permissive=1
audit[26809]: AVC avc:  denied  { read } for  pid=26809 comm="thinkpad-rotate" name="site-packages" dev="dm-3" ino=14946999 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:gconf_home_t:s0 tclass=dir permissive=1
audit[26809]: AVC avc:  denied  { read } for  pid=26809 comm="thinkpad-rotate" name="easy-install.pth" dev="dm-3" ino=14947049 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:gconf_home_t:s0 tclass=file permissive=1
audit[26809]: AVC avc:  denied  { open } for  pid=26809 comm="thinkpad-rotate" path="/home/mu/.local/lib/python3.5/site-packages/easy-install.pth" dev="dm-3" ino=14947049 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:gconf_home_t:s0 tclass=file permissive=1
audit[26809]: AVC avc:  denied  { ioctl } for  pid=26809 comm="thinkpad-rotate" path="/home/mu/.local/lib/python3.5/site-packages/easy-install.pth" dev="dm-3" ino=14947049 ioctlcmd=0x5401 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:gconf_home_t:s0 tclass=file permissive=1
audit[26809]: AVC avc:  denied  { read } for  pid=26809 comm="thinkpad-rotate" name="comic_rss-2.0-py3.5.egg" dev="dm-3" ino=14947048 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
audit[26809]: AVC avc:  denied  { open } for  pid=26809 comm="thinkpad-rotate" path="/home/mu/.local/lib/python3.5/site-packages/comic_rss-2.0-py3.5.egg" dev="dm-3" ino=14947048 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
audit[26809]: AVC avc:  denied  { ioctl } for  pid=26809 comm="thinkpad-rotate" path="/home/mu/.local/lib/python3.5/site-packages/comic_rss-2.0-py3.5.egg" dev="dm-3" ino=14947048 ioctlcmd=0x5451 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
audit[26809]: AVC avc:  denied  { open } for  pid=26809 comm="thinkpad-rotate" path="/home/mu/.local/lib/python3.5/site-packages/termcolor-1.1.0-py3.5.egg" dev="dm-3" ino=14947050 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:user_tmp_t:s0 tclass=file permissive=1
audit[26809]: AVC avc:  denied  { ioctl } for  pid=26809 comm="thinkpad-rotate" path="/home/mu/.config/thinkpad-scripts/config.ini" dev="dm-3" ino=7865238 ioctlcmd=0x5401 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:config_home_t:s0 tclass=file permissive=1
audit[26810]: AVC avc:  denied  { connectto } for  pid=26810 comm="xrandr" path=002F746D702F2E5831312D756E69782F5830 scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:xserver_t:s0-s0:c0.c1023 tclass=unix_stream_socket permissive=1
audit[26810]: AVC avc:  denied  { read } for  pid=26810 comm="xrandr" name=".Xauthority" dev="dm-3" ino=5512132 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:xauth_home_t:s0 tclass=file permissive=1
audit[26810]: AVC avc:  denied  { open } for  pid=26810 comm="xrandr" path="/home/mu/.Xauthority" dev="dm-3" ino=5512132 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:xauth_home_t:s0 tclass=file permissive=1
audit[26809]: AVC avc:  denied  { execute } for  pid=26809 comm="thinkpad-rotate" name="prerotate" dev="dm-3" ino=7865814 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:config_home_t:s0 tclass=file permissive=1
audit[26811]: AVC avc:  denied  { execute_no_trans } for  pid=26811 comm="thinkpad-rotate" path="/home/mu/.config/thinkpad-scripts/hooks/prerotate" dev="dm-3" ino=7865814 scontext=system_u:system_r:apmd_t:s0 tcontext=unconfined_u:object_r:config_home_t:s0 tclass=file permissive=1
audit[26835]: AVC avc:  denied  { connectto } for  pid=26835 comm="xinput" path=002F746D702F2E5831312D756E69782F5830 scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:xserver_t:s0-s0:c0.c1023 tclass=unix_stream_socket permissive=1
audit[26807]: USER_END pid=26807 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='op=PAM:session_close grantors=pam_keyinit,pam_keyinit,pam_limits,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="mu" exe="/usr/bin/sudo" hostname=? addr=? terminal=? res=success'
audit[26807]: CRED_DISP pid=26807 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="mu" exe="/usr/bin/sudo" hostname=? addr=? terminal=? res=success'

Opening the lid:

audit[26845]: USER_CMD pid=26845 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='cwd="/" cmd=2D66697368202D6320656E7620444953504C41595C3D5C3A305C2E30205C2F7573725C2F62696E5C2F7468696E6B7061642D726F74617465206E6F726D616C202D2D7669612D686F6F6B terminal=? res=success'
sudo[26845]:     root : TTY=unknown ; PWD=/ ; USER=mu ; COMMAND=/usr/bin/fish -c env DISPLAY=:0.0 /usr/bin/thinkpad-rotate normal --via-hook
audit[26845]: CRED_REFR pid=26845 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="mu" exe="/usr/bin/sudo" hostname=? addr=? terminal=? res=success'
audit[26845]: AVC avc:  denied  { setsched } for  pid=26845 comm="sudo" scontext=system_u:system_r:apmd_t:s0 tcontext=system_u:system_r:apmd_t:s0 tclass=process permissive=1
audit[26845]: USER_START pid=26845 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='op=PAM:session_open grantors=pam_keyinit,pam_keyinit,pam_limits,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="mu" exe="/usr/bin/sudo" hostname=? addr=? terminal=? res=success'
audit[26845]: USER_END pid=26845 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='op=PAM:session_close grantors=pam_keyinit,pam_keyinit,pam_limits,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="mu" exe="/usr/bin/sudo" hostname=? addr=? terminal=? res=success'
audit[26845]: CRED_DISP pid=26845 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:apmd_t:s0 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="mu" exe="/usr/bin/sudo" hostname=? addr=? terminal=? res=success'

In principle one should be able to go through this now and extract all the needed permissions to get this running again. Our scripts seem to work, it really is SELinux what blocks it on Fedora.

Whether it is a good idea to open up SELinux without understanding what it really does and what the additional rules imply, is a different story.