Ubuntu
cups package

CUPS not allowed to mknod to /var/log by apparmor

Asked by Greg Bell

I have a two-machine network, both running 14.04.1 but mostly updated. CUPS version is 1.7.2-0ubuntu1

Machine A - has printer attached
Machine B - printing to A doesn't work via CUPS

I cannot print to the CUPS-managed printer attached to A from B, except with a few apps which see the printer directly via avahi (e.g. Evince).

I can print to the printer from A.

/var/log/syslog on B shows:

ay 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/error_log" - Permission denied
May 13 09:50:29 server kernel: [47923.441374] type=1400 audit(1431474629.549:811): apparmor="DENIED" operation="mknod" profile="/usr/sbin/cupsd" name="/data/var/cache/cups/job.cache.N" pid=7814 comm="cupsd" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
May 13 09:50:29 server kernel: [47923.441413] type=1400 audit(1431474629.549:812): apparmor="DENIED" operation="mknod" profile="/usr/sbin/cupsd" name="/data/var/log/cups/error_log" pid=7814 comm="cupsd" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
May 13 09:50:29 server kernel: [47923.441421] type=1400 audit(1431474629.549:813): apparmor="DENIED" operation="chown" profile="/usr/sbin/cupsd" name="/data/var/log/cups/" pid=7814 comm="cupsd" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
May 13 09:50:29 server kernel: [47923.441444] type=1400 audit(1431474629.549:814): apparmor="DENIED" operation="mknod" profile="/usr/sbin/cupsd" name="/data/var/log/cups/error_log" pid=7814 comm="cupsd" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
May 13 09:50:29 server kernel: [47923.706282] type=1400 audit(1431474629.817:815): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/cups/backend/cups-pdf" pid=16874 comm="apparmor_parser"
May 13 09:50:29 server kernel: [47923.706551] type=1400 audit(1431474629.817:816): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/cupsd" pid=16874 comm="apparmor_parser"
May 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/access_log" - Permission denied
May 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/error_log" - Permission denied
May 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/page_log" - Permission denied
May 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/error_log" - Permission denied
May 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/error_log" - Permission denied
May 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/error_log" - Permission denied
May 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/error_log" - Permission denied
May 13 09:50:29 server cupsd: Unable to change ownership of "/var/log/cups" - Permission denied
May 13 09:50:29 server cupsd: Unable to open log file "/var/log/cups/error_log" - Permission denied
May 13 09:50:29 server kernel: [47923.710922] type=1400 audit(1431474629.821:817): apparmor="DENIED" operation="mknod" profile="/usr/sbin/cupsd" name="/data/var/log/cups/access_log" pid=16884 comm="cupsd" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
May 13 09:50:29 server kernel: [47923.710931] type=1400 audit(1431474629.821:818): apparmor="DENIED" operation="chown" profile="/usr/sbin/cupsd" name="/data/var/log/cups/" pid=16884 comm="cupsd" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
May 13 09:50:29 server kernel: [47923.710964] type=1400 audit(1431474629.821:819): apparmor="DENIED" operation="mknod" profile="/usr/sbin/cupsd" name="/data/var/log/cups/access_log" pid=16884 comm="cupsd" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
May 13 09:50:29 server kernel: [47923.710985] type=1400 audit(1431474629.821:820): apparmor="DENIED" operation="mknod" profile="/usr/sbin/cupsd" name="/data/var/log/cups/error_log" pid=16884 comm="cupsd" requested_mask="c" denied_mask="c" fsuid=0 ouid=0

Google search yields similar but significantly different (and ancient) bugs. For example https://bugs.launchpad.net/ubuntu/+source/cups/+bug/810687 didn't allow CUPS to start, but CUPS does start, just doesn't work. Also that bug was reportedly fixed in CUPS 1.4.7.

Question information

Language:
English Edit question
Status:
Solved
For:
Ubuntu cups Edit question
Assignee:
No assignee Edit question
Solved by:
Greg Bell
Solved:
Last query:
Last reply:

This question was originally filed as bug #1454463.

Revision history for this message
Greg Bell (gbell-spamless) said : 		#1

Thanks, that was it. Apologies for this turning out to be a 'support' question, not a bug. I was so sure.

I'm not used to symlinks breaking things in unix, so I didn't even suspect my moving of /var was a problem. My / is an SSD so I don't want logs writing to it. /data is a HDD.

Thanks again.

Revision history for this message
michael (yellupcm-gmail) said : 		#2

If problem is solved. Please mark solved. Thanks

Revision history for this message
Greg Bell (gbell-spamless) said : 		#3

.

Revision history for this message
Greg Bell (gbell-spamless) said : 		#4

Yikes, did turning this into a question delete the solution posted when it was a bug?

Revision history for this message
Greg Bell (gbell-spamless) said : 		#5

Here's the answer from Seth Arnold https://launchpad.net/~seth-arnold :

I noticed the following error early in the logs:

May 13 09:50:29 server kernel: [47923.441413] type=1400 audit(1431474629.549:812): apparmor="DENIED" operation="mknod" profile="/usr/sbin/cupsd" name="/data/var/log/cups/error_log" pid=7814 comm="cupsd" requested_mask="c" denied_mask="c" fsuid=0 ouid=0

This looks a lot like you have a symlink from /var to /data/var -- is this correct? what other symlinks do you have on your system?

You can rewrite apparmor policy in a single place to handle these kinds of symlinks using the 'alias' directive; put lines like:

alias /var/ -> /data/var/

into your /etc/apparmor.d/tunables/alias file and then reload policies with apparmor_parser --replace /etc/apparmor.d/

Then restart cups and see if it is allowed to access its logs again.

Thanks