1298597 – at jobs fails: atd: Not allowed to set exec context to unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 for user : No such file or directory

Bug 1298597 - at jobs fails: atd: Not allowed to set exec context to unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 for user : No such file or directory

Summary: at jobs fails: atd: Not allowed to set exec context to unconfined_u:unconfine...

Keywords:
Status:	CLOSED DUPLICATE of bug 1298192
Alias:	None
Product:	Fedora
Classification:	Fedora
Component:	selinux-policy
Sub Component:
Version:	23
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	---
Assignee:	Miroslav Grepl
QA Contact:	Fedora Extras Quality Assurance
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2016-01-14 14:10 UTC by Petr Pisar
Modified:	2016-01-18 10:20 UTC (History)
CC List:	6 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2016-01-18 10:20:38 UTC
Type:	Bug
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Description Petr Pisar 2016-01-14 14:10:05 UTC

Scheduled at jobs fail in Fedora 23. If I schedule a job as "test" user:

$ printf 'touch ~/test' | at 'now + 1 minutes'
warning: commands will be executed using /bin/sh
job 5 at Thu Jan 14 15:02:00 2016

then atd daemon gets AVC denial when executing the job. This is complete log from the event (search for "SELinux Failed to set context"):

led 14 15:02:00 fedora-23 audit[848]: USER_ACCT pid=848 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:accounting grantors=pam_access,pam_unix acct="test" exe="/usr/sbin/atd" hostname=? addr=? terminal=atd res=success'
led 14 15:02:00 fedora-23 kernel: audit: type=1101 audit(1452780120.079:103): pid=848 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:accounting grantors=pam_access,pam_unix acct="test" exe="/usr/sbin/atd" hostname=? addr=? terminal=atd res=success'
led 14 15:02:00 fedora-23 kernel: audit: type=1006 audit(1452780120.088:104): pid=848 uid=0 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 old-auid=4294967295 auid=500 old-ses=4294967295 ses=2 res=1
led 14 15:02:00 fedora-23 audit[1]: USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='Unknown permission start for class system exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
led 14 15:02:00 fedora-23 kernel: audit: type=1107 audit(1452780120.101:105): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='Unknown permission start for class system exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
led 14 15:02:00 fedora-23 audit[1]: USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='Unknown permission start for class system exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
led 14 15:02:00 fedora-23 kernel: audit: type=1107 audit(1452780120.109:106): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='Unknown permission start for class system exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
led 14 15:02:00 fedora-23 systemd[1]: Created slice user-500.slice.
led 14 15:02:00 fedora-23 systemd[1]: Starting user-500.slice.
led 14 15:02:00 fedora-23 systemd[1]: Starting User Manager for UID 500...
led 14 15:02:00 fedora-23 audit[1]: USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='Unknown permission start for class system exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
led 14 15:02:00 fedora-23 kernel: audit: type=1107 audit(1452780120.124:107): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='Unknown permission start for class system exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
led 14 15:02:00 fedora-23 systemd-logind[483]: New session 2 of user test.
led 14 15:02:00 fedora-23 systemd[1]: Started Session 2 of user test.
led 14 15:02:00 fedora-23 systemd[1]: Starting Session 2 of user test.
led 14 15:02:00 fedora-23 audit[850]: USER_ACCT pid=850 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:accounting grantors=pam_unix acct="test" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
led 14 15:02:00 fedora-23 kernel: audit: type=1101 audit(1452780120.154:108): pid=850 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:accounting grantors=pam_unix acct="test" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
led 14 15:02:00 fedora-23 systemd[850]: pam_unix(systemd-user:session): session opened for user test by (uid=0)
led 14 15:02:00 fedora-23 audit[850]: USER_START pid=850 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix acct="test" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
led 14 15:02:00 fedora-23 kernel: audit: type=1105 audit(1452780120.165:109): pid=850 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_systemd,pam_unix acct="test" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
led 14 15:02:00 fedora-23 systemd[850]: Reached target Timers.
led 14 15:02:00 fedora-23 systemd[850]: Starting Timers.
led 14 15:02:00 fedora-23 systemd[850]: Reached target Sockets.
led 14 15:02:00 fedora-23 systemd[850]: Starting Sockets.
led 14 15:02:00 fedora-23 systemd[850]: Reached target Paths.
led 14 15:02:00 fedora-23 systemd[850]: Starting Paths.
led 14 15:02:00 fedora-23 systemd[850]: Reached target Basic System.
led 14 15:02:00 fedora-23 systemd[850]: Starting Basic System.
led 14 15:02:00 fedora-23 systemd[850]: Reached target Default.
led 14 15:02:00 fedora-23 systemd[850]: Startup finished in 87ms.
led 14 15:02:00 fedora-23 systemd[1]: Started User Manager for UID 500.
led 14 15:02:00 fedora-23 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=user@500 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
led 14 15:02:00 fedora-23 systemd[850]: Starting Default.
led 14 15:02:00 fedora-23 kernel: audit: type=1130 audit(1452780120.267:110): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=user@500 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
led 14 15:02:00 fedora-23 atd[848]: pam_unix(atd:session): session opened for user test by (uid=0)
led 14 15:02:00 fedora-23 audit[848]: USER_START pid=848 uid=0 auid=500 ses=2 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:session_open grantors=pam_loginuid,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="test" exe="/usr/sbin/atd" hostname=? addr=? terminal=atd res=success'
led 14 15:02:00 fedora-23 audit[848]: CRED_ACQ pid=848 uid=0 auid=500 ses=2 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_env,pam_env,pam_unix acct="test" exe="/usr/sbin/atd" hostname=? addr=? terminal=atd res=success'
led 14 15:02:00 fedora-23 kernel: audit: type=1105 audit(1452780120.276:111): pid=848 uid=0 auid=500 ses=2 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:session_open grantors=pam_loginuid,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="test" exe="/usr/sbin/atd" hostname=? addr=? terminal=atd res=success'
led 14 15:02:00 fedora-23 atd[855]: Not allowed to set exec context to unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 for user  test
                                    : No such file or directory
led 14 15:02:00 fedora-23 atd[855]: SELinux Failed to set context
                                    : No such file or directory
led 14 15:02:00 fedora-23 audit[848]: CRED_DISP pid=848 uid=0 auid=500 ses=2 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_env,pam_env,pam_unix acct="test" exe="/usr/sbin/atd" hostname=? addr=? terminal=atd res=success'
led 14 15:02:00 fedora-23 atd[848]: pam_unix(atd:session): session closed for user test
led 14 15:02:00 fedora-23 audit[848]: USER_END pid=848 uid=0 auid=500 ses=2 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:session_close grantors=pam_loginuid,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="test" exe="/usr/sbin/atd" hostname=? addr=? terminal=atd res=success'
led 14 15:02:00 fedora-23 systemd-logind[483]: Removed session 2.
led 14 15:02:00 fedora-23 audit[1]: USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='Unknown permission stop for class system exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
led 14 15:02:00 fedora-23 audit[1]: USER_AVC pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='Unknown permission stop for class system exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
led 14 15:02:00 fedora-23 systemd[1]: Stopping User Manager for UID 500...
led 14 15:02:00 fedora-23 systemd[850]: Reached target Shutdown.
led 14 15:02:00 fedora-23 systemd[850]: Starting Shutdown.
led 14 15:02:00 fedora-23 systemd[850]: Starting Exit the Session...
led 14 15:02:00 fedora-23 systemd[850]: Stopped target Default.
led 14 15:02:00 fedora-23 systemd[850]: Stopping Default.
led 14 15:02:00 fedora-23 systemd[850]: Stopped target Basic System.
led 14 15:02:00 fedora-23 systemd[850]: Stopping Basic System.
led 14 15:02:00 fedora-23 systemd[850]: Stopped target Timers.
led 14 15:02:00 fedora-23 systemd[850]: Stopping Timers.
led 14 15:02:00 fedora-23 systemd[850]: Stopped target Paths.
led 14 15:02:00 fedora-23 systemd[850]: Stopping Paths.
led 14 15:02:00 fedora-23 systemd[850]: Stopped target Sockets.
led 14 15:02:00 fedora-23 systemd[850]: Stopping Sockets.
led 14 15:02:00 fedora-23 systemd[850]: Received SIGRTMIN+24 from PID 857 (kill).
led 14 15:02:00 fedora-23 systemd[852]: pam_unix(systemd-user:session): session closed for user test
led 14 15:02:00 fedora-23 systemd[1]: Stopped User Manager for UID 500.
led 14 15:02:00 fedora-23 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=user@500 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
led 14 15:02:00 fedora-23 systemd[1]: Removed slice user-500.slice.
led 14 15:02:00 fedora-23 systemd[1]: Stopping user-500.slice.

I have now idea if this is bug in atd, SELinux policy, or systemd. My packages:

selinux-policy-3.13.1-158.fc23.noarch
at-3.1.16-6.fc23.x86_64
systemd-222-12.fc23.x86_64
glibc-2.22-7.fc23.x86_64

I first noticed this bug on 2016-01-12. It worked before Christmass.

Comment 1 Petr Pisar 2016-01-18 09:46:20 UTC

Still the same issue with selinux-policy-3.13.1-158.2.fc23.

Comment 2 Tomas Mraz 2016-01-18 09:49:49 UTC

Hmm could it be duplicate of 1298192?

If you switch to older kernel (i.e. kernel-4.2.8-300.fc23.x86_64), does it work for you?

Comment 3 Petr Pisar 2016-01-18 10:20:38 UTC

Booting that kernel helps. The "No such file or directory" error message disappears and the job is executed.

Please note the first comment has a bug in the reprodured. Because it's missing trailing new-line, it fails and sends e-mail to root (while I'd expect e-mail to the user who invoked the at command). Correct reproducer is:

$ printf 'touch ~/test\n' | at 'now + 1 minutes'

So yes, it is duplicate of #1298192. Thank you for the pointer.

*** This bug has been marked as a duplicate of bug 1298192 ***

Note You need to log in before you can comment on or make changes to this bug.