[Bug 1087753] New: Dovecot fails to start, complaining "Can't open log file /var/log/dovecot.log: Permission denied"
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753 Bug ID: 1087753 Summary: Dovecot fails to start, complaining "Can't open log file /var/log/dovecot.log: Permission denied" Classification: openSUSE Product: openSUSE Tumbleweed Version: Current Hardware: Other OS: Other Status: NEW Severity: Major Priority: P5 - None Component: AppArmor Assignee: suse-beta@cboltz.de Reporter: psychonaut@nothingisreal.com QA Contact: qa-bugs@suse.de Found By: --- Blocker: --- After upgrading from Tumbleweed 20180308 to Tumbleweed 20180331 today, the Dovecot service now refuses to start. The error message is "Can't open log file /var/log/dovecot.log: Permission denied". I tried twiddling the permissions on that file, but no luck. On account of Bug 1069470 and a similar problem report at https://serverfault.com/questions/903204/dovecot-cant-open-log-after-upgrade I suspect this may be a problem with AppArmor. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c1
--- Comment #1 from Christian Boltz
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c2
Luis Henriques
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c3
--- Comment #3 from Tristan Miller
The Dovecot AppArmor profile indeed assumes that Dovecot uses syslog for logging.
I suppose this is a recent (and unannounced?) change.
Can you please paste the relevant lines from /var/log/audit/audit.log or, if in doubt, attach the whole file?
type=AVC msg=audit(1522747195.548:1944): apparmor="ALLOWED" operation="mknod" profile="/usr/sbin/dovecot" name="/var/log/dovecot.log" pid=7033 comm="dovecot" requested_mask="c" denied_mask="c" fsuid=0 ouid=0 type=AVC msg=audit(1522747195.548:1945): apparmor="ALLOWED" operation="open" profile="/usr/sbin/dovecot" name="/var/log/dovecot.log" pid=7033 comm="dovecot" requested_mask="ac" denied_mask="ac" fsuid=0 ouid=465 type=AVC msg=audit(1522747195.552:1946): apparmor="ALLOWED" operation="file_perm" profile="/usr/sbin/dovecot" name="/var/log/dovecot.log" pid=7033 comm="dovecot" requested_mask="w" denied_mask="w" fsuid=0 ouid=465 type=AVC msg=audit(1522747195.556:1947): apparmor="DENIED" operation="capable" profile="/usr/lib/dovecot/log" pid=7036 comm="log" capability=1 capname="dac_override"
Also, did you specify /var/log/dovecot.log in your dovecot config, or is this part of the default config now?
It's specified in /etc/dovecot/dovecot.conf. I don't know if it's part of the default config. Very likely I was the one that put it there back when I first installed Dovecot a year or two ago. I can live with using syslog for logging, so for me the solution is to simply uncomment the log_path setting from dovecot.conf. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
Shad Sterling
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c4
--- Comment #4 from Christian Boltz
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c5
--- Comment #5 from Shad Sterling
## Logging anywhere but syslog is now prohibited by the default apparmor profile. ## You can customize the apparmor profile by editing /etc/apparmor.d/local/usr.sbin.dovecot
Even better if you have the necessary line as a comment in that file. For my system the necessary line is
/var/log/dovecot w,
-- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c6
--- Comment #6 from Shad Sterling
/var/lib/dovecot/ssl-parameters.dat r, capability dac_read_search,
In `usr.lib.dovecot.auth`:
/run/dovecot/old-stats-user w,
In `usr.sbin.dovecot`:
/usr/lib/dovecot/stats ix, /var/log/dovecot w,
In `usr.lib.dovecot.log`:
/var/log/dovecot w,
The `w` permission is needed for logs because apparmor denies `ac` and as far as I can tell there's no way to allow `open`s with `c`. I couldn't find any indication that there exists documentation with a list of open permissions, so there may be another way to allow "create and append" other than `w`. I used the `ix` permission for stats rather than `Px` because there is no `apparmor.d/user.lib.dovecot.stats` to include corresponding file in `/etc/apparmor.d/local`, and I thought it better to confine my edits to local. So basically this recent apparmor update totally clobbers dovecot's ability to function. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c7
--- Comment #7 from Christian Boltz
Actually, that last comment is completely wrong; it seemed to be working at first, but actually was not. After spending a few hours iterating on `/var/log/audit/audit.log` and editing several files in `/etc/apparmor.d/local`, it seems to be back to working.
In `usr.lib.dovecot.config`:
/var/lib/dovecot/ssl-parameters.dat r, capability dac_read_search,
I'm slightly surprised about these two - can you please paste the relevant audit.log lines?
In `usr.lib.dovecot.auth`:
/run/dovecot/old-stats-user w,
In `usr.sbin.dovecot`:
/usr/lib/dovecot/stats ix,
Please make that Px, and grab the dovecot/stats profile from bug 1088161 ;-)
/var/log/dovecot w,
In `usr.lib.dovecot.log`:
/var/log/dovecot w,
Please try with "a" instead of "w" (in both profiles that need to write the logfile), see below for details.
The `w` permission is needed for logs because apparmor denies `ac` and as far as I can tell there's no way to allow `open`s with `c`. I couldn't find any indication that there exists documentation with a list of open permissions, so there may be another way to allow "create and append" other than `w`.
'c' in the audit.log means "create". There is no exact match in the profile permissions to only allow "create", but both "a" and "w" include "create". So if you are lucky, using "a" in the profile is enough (and would be a major improvement because it blocks changes to existing log content).
I used the `ix` permission for stats rather than `Px` because there is no `apparmor.d/user.lib.dovecot.stats` to include corresponding file in `/etc/apparmor.d/local`, and I thought it better to confine my edits to local.
See above ;-) (there's no local/ sniplet for the dovecot/stats profile yet, but I'll of course add it when I package the profile)
So basically this recent apparmor update totally clobbers dovecot's ability to function.
Actually it's the other way round - dovecot was updated, and nobody told me that it needs AppArmor profile updates :-( (no blaming intended ;-) - and in the end, the important thing is to get it working again.) -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c8
--- Comment #8 from Tristan Miller
* writing dovecot.log by /usr/sbin/dovecot The package maintainer just told me that the packaged default is still to use syslog, so this is likely something you changed locally. Anyway - please add the following line to /etc/apparmor.d/local/usr.sbin.dovecot: /var/log/dovecot.log a, Then run rcapparmor reload and try again. (Obviously you'll have to re-enable log_path in the dovecot config.) I'm not sure if a is enough, the last log line indicates w may be needed (which would be bad because "a" allows append only and "w" full write access including changes to the existing logfile)
With this line in /etc/apparmor.d/local/usr.sbin.dovecot, starting dovecot still results in the same error message -- "Can't open log file /var/log/dovecot.log: Permission denied". But bizarrely, it *does* write to that log file, but only to complain that it can't write to the log file: Apr 11 09:17:10 master: Info: Dovecot v2.3.1 (8e2f634) starting up for imap Apr 11 09:17:10 master: Error: service(log): child 26965 returned error 80 (Can't open log file) Apr 11 09:17:10 master: Error: service(log): command startup failed, throttling for 2 secs The problem occurs whether I use "a" or "w". -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c9
--- Comment #9 from Christian Boltz
With this line in /etc/apparmor.d/local/usr.sbin.dovecot, starting dovecot still results in the same error message -- "Can't open log file /var/log/dovecot.log: Permission denied". But bizarrely, it *does* write to that log file, but only to complain that it can't write to the log file:
*lol*
Apr 11 09:17:10 master: Info: Dovecot v2.3.1 (8e2f634) starting up for imap Apr 11 09:17:10 master: Error: service(log): child 26965 returned error 80 (Can't open log file) Apr 11 09:17:10 master: Error: service(log): command startup failed, throttling for 2 secs
The problem occurs whether I use "a" or "w".
When dovecot writes these log messages, do you get any messages in audit.log? If so, please paste them. (Ideally test with "a" in the rule.) -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c10
--- Comment #10 from Christian Boltz
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c12
--- Comment #12 from Shad Sterling
(In reply to Shad Sterling from comment #6)
Actually, that last comment is completely wrong; it seemed to be working at first, but actually was not. After spending a few hours iterating on `/var/log/audit/audit.log` and editing several files in `/etc/apparmor.d/local`, it seems to be back to working.
In `usr.lib.dovecot.config`:
/var/lib/dovecot/ssl-parameters.dat r, capability dac_read_search,
I'm slightly surprised about these two - can you please paste the relevant audit.log lines?
`grep usr.lib.dovecot.config /var/log/audit/audit.log* | tail`:
/var/log/audit/audit.log.4:type=AVC msg=audit(1523334722.592:204589): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523334782.682:204638): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523334842.780:204690): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523334902.866:204741): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523334962.916:204792): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523335022.966:204842): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523335084.008:204893): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523335144.090:204943): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523335204.208:204996): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 /var/log/audit/audit.log.4:type=AVC msg=audit(1523335264.250:205048): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/config" name="/var/lib/dovecot/ssl-parameters.dat" pid=21775 comm="config" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
`grep dac_read_search /var/log/audit/audit.log* | tail`:
/var/log/audit/audit.log.3:type=AVC msg=audit(1523372677.043:240323): apparmor="DENIED" operation="capable" profile="/usr/lib/dovecot/config" pid=29574 comm="config" capability=2 capname="dac_read_search" /var/log/audit/audit.log.3:type=AVC msg=audit(1523373414.162:241172): apparmor="DENIED" operation="capable" profile="/usr/lib/dovecot/config" pid=31468 comm="config" capability=2 capname="dac_read_search" /var/log/audit/audit.log.3:type=AVC msg=audit(1523373805.425:241689): apparmor="DENIED" operation="capable" profile="/usr/lib/dovecot/config" pid=400 comm="config" capability=2 capname="dac_read_search" /var/log/audit/audit.log.4:type=AVC msg=audit(1523316897.764:190139): apparmor="DENIED" operation="capable" profile="/usr/lib/dovecot/config" pid=21775 comm="config" capability=2 capname="dac_read_search"
/var/log/dovecot w,
In `usr.lib.dovecot.log`:
/var/log/dovecot w,
Please try with "a" instead of "w" (in both profiles that need to write the logfile), see below for details.
You really think I spent hours on this and didn't try that? It doesn't work. Omitting `/var/log/dovecot` results in a deny for "ac". Specifying "a" results in a deny for "c". Specifying "ac" is a malformed profile. If there's any documentation about it, it's hard to find. There are posts where people report on this, but none I found explained it. I decided to stop short of reading the code that implements it. It doesn't matter if the file must actually be created, it's enough that the process open it with create access.
The `w` permission is needed for logs because apparmor denies `ac` and as far as I can tell there's no way to allow `open`s with `c`. I couldn't find any indication that there exists documentation with a list of open permissions, so there may be another way to allow "create and append" other than `w`.
'c' in the audit.log means "create". There is no exact match in the profile permissions to only allow "create", but both "a" and "w" include "create". So if you are lucky, using "a" in the profile is enough (and would be a major improvement because it blocks changes to existing log content).
The inability to permit an operation that can be denied is a bug in apparmor.
So basically this recent apparmor update totally clobbers dovecot's ability to function.
Actually it's the other way round - dovecot was updated, and nobody told me that it needs AppArmor profile updates :-( (no blaming intended ;-) - and in the end, the important thing is to get it working again.)
My dovecot config is based on the defaults when I first configured it, which I thought was more than a decade ago but I can only confirm it back to 2012; my dovecot logfile has not changed in at least six years and it just stopped working with this update. Comments with instructions to "migrate from old ssl-parameters.dat" made it into my `/etc/dovecot/conf.d/10-ssl.conf` with this update; use of that file does not appear to be new (if anything it's recently deprecated). "stats" does not appear anywhere in `/etc/dovecot` and hasn't for more than a year, so any change in that doesn't appear to be configurable. It looks like an update to the apparmor profile for dovecot broke any old configurations like mine. Why isn't the apparmor profile for dovecot part of the dovecot package? -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c13
--- Comment #13 from Tristan Miller
When dovecot writes these log messages, do you get any messages in audit.log? If so, please paste them. (Ideally test with "a" in the rule.)
No, no messages appear in audit.log. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753
http://bugzilla.opensuse.org/show_bug.cgi?id=1087753#c14
--- Comment #14 from Tristan Miller
(In reply to Christian Boltz from comment #9)
When dovecot writes these log messages, do you get any messages in audit.log? If so, please paste them. (Ideally test with "a" in the rule.)
No, no messages appear in audit.log.
Oh, sorry -- I had forgotten to re-enable logging in /etc/dovecot/dovecot.conf. I re-enabled it and tried again just now. Here's what gets written to audit.log when starting dovecot: type=AVC msg=audit(1524165468.008:2651): apparmor="ALLOWED" operation="open" profile="/usr/sbin/dovecot" name="/var/log/dovecot.log" pid=8197 comm="dovecot" requested_mask="c" denied_mask="c" fsuid=0 ouid=0 type=AVC msg=audit(1524165468.008:2652): apparmor="ALLOWED" operation="file_perm" profile="/usr/sbin/dovecot" name="/var/log/dovecot.log" pid=8197 comm="dovecot" requested_mask="w" denied_mask="w" fsuid=0 ouid=0 type=AVC msg=audit(1524165468.016:2653): apparmor="DENIED" operation="open" profile="/usr/lib/dovecot/log" name="/var/log/dovecot.log" pid=8200 comm="log" requested_mask="ac" denied_mask="ac" fsuid=0 ouid=0 -- You are receiving this mail because: You are on the CC list for the bug.
participants (1)
-
bugzilla_noreply＠novell.com