type=AVC msg=audit(1403622580.061:96): avc: denied { write } for pid=1331 comm="mysqld_safe" name="/" dev="dm-0" ino=256 scontext=system_u:system_r:mysqld_safe_t:s0 tcontext=system_u:object_r:root_t:s0 tclass=dir
type=SYSCALL msg=audit(1403622580.061:96): arch=c000003e syscall=269 success=yes exit=0 a0=ffffffffffffff9c a1=7f5e09bfe798 a2=2 a3=2 items=0 ppid=1109 pid=1331 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="mysqld_safe" exe="/bin/dash" subj=system_u:system_r:mysqld_safe_t:s0 key=(null)
For a long time (probably years) I’ve been seeing messages like the above in the log from auditd (/var/log/audit/audit.log) when starting mysqld. I haven’t fixed it because the amount of work exceeded the benefit, it’s just a couple of lines logged at every system boot. But today I decided to fix it.
The first step was to find out what was going on, I ran a test system in permissive mode and noticed that there were no attempts to create a file (that would have been easy to fix). Then I needed to discover which system call was triggering this. The syscall number is 269, the file linux/x86_64/syscallent.h in the strace source shows that 269 is the system call faccessat. faccessat(2) and access(2) are annoying cases, they do all the permission checks for access but don’t involve doing the operation so when a program uses those system calls but for some reason doesn’t perform the operation in question (in this case writing to the root directory) then we just get a log entry but nothing happening to examine.
A quick look at the shell script didn’t make the problem obvious, note that this is probably obvious to people who are more skilled at shell scripting than me – but it’s probably good for me to describe how to solve these problems every step of the way. So the next step was to use gdb. Here is the start of my gdb session:
# gdb /bin/sh
[skipped]
Reading symbols from /bin/dash…(no debugging symbols found)…done.
(gdb) b faccessat
Breakpoint 1 at 0x3960
(gdb) r -x /usr/bin/mysqld_safe
[lots skipped]
+ test -r /usr/my.cnf
Breakpoint 1, 0x00007ffff7b0c7e0 in faccessat ()
from /lib/x86_64-linux-gnu/libc.so.6
After running gdb on /bin/sh (which is a symlink to /bin/dash) I used the “b” command to set a breakpoint on the function faccessat (which is a library call from glibc that calls the system call sys_faccessat()). A breakpoint means that program execution will stop when the function is called. I run the shell script with “-x” as the first parameter to instruct the shell to show me the shell commands that are run so I can match shell commands to system calls. The above output shows the first call to faccessat() which isn’t interesting (it’s testing for read access).
I then ran the “c” command in gdb to continue execution and did so a few times until I found something interesting.
+ test -w / -o root = root
Breakpoint 1, 0x00007ffff7b0c7e0 in faccessat ()
from /lib/x86_64-linux-gnu/libc.so.6
Above is the interesting part of the gdb output. It shows that the offending shell command is “test -w /“.
I filed Debian bug #752593 [1] with a patch to fix this problem.
I also filed a wishlist bug against strace asking for an easier way to discover the name of a syscall [2].
Couldn’t you just run “strace -oout -etrace=write,faccessat -f -x”?
It should show you the shell commands as they are run (via the write syscalls) interleaved with the offending syscall(s).
Yes, that should work too.