Home / ubuntu / Questions / 52333
In Process
Mei
Asked: 2011-07-09 08:23:14 +0800 CST

File access: open fails for one program but not another

  • 772

This is the most unusual thing. I'm trying to start up mysqld with a different my.cnf (so I can have two MySQL daemons running without conflict). The file is /etc/mysql/my2.cnf but mysql won't open it.

When I run this command:

sudo -u mysql strace /usr/sbin/mysqld --defaults-file=/etc/mysql/my2.cnf

I see this in the output:

stat("/etc/mysql/my2.cnf", {st_mode=S_IFREG|0644, st_size=3574, ...}) = 0
open("/etc/mysql/my2.cnf", O_RDONLY)    = -1 EACCES (Permission denied)

However, when I change the command to:

sudo -u mysql strace cat /etc/mysql/my2.cnf > /dev/null

I see this in the output:

fstat(1, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 3), ...}) = 0
open("/etc/mysql/my2.cnf", O_RDONLY)    = 3

Same user - same kernel call - different results!

I checked file permissions - and extended permissions:

# ls -l $PWD/my2.cnf
-rw-r--r-- 1 root root 3574 2011-07-08 10:04 /etc/mysql/my2.cnf
# lsattr $PWD/my2.cnf
-----------------e- /etc/mysql/my2.cnf

Am I getting bit by some part of AppArmour or SELinux? I didn't see anything like that in the logs (including daemon.log, syslog, or messages).

How do I fix this problem?

kernel

1 Answers

  1. No one's answered, so I'll tell what I found out.

    The problem in short is the following: when the file /etc/mysql/my2.cnf is accessed by cat, we see this:

    open("/etc/mysql/my2.cnf", O_RDONLY)    = 3

    However, when mysqld makes the same call, it gets a different answer:

    open("/etc/mysql/my2.cnf", O_RDONLY)    = -1 EACCES (Permission denied)

    Thus, the answer lay in the kernel. Something in the kernel was differentiating between a call to open(2) by cat and by mysqld. The only thing that came to mind was AppArmor.

    Searching the packages on the system turned up several related to AppArmor. Listing files in the packages turned up the command apparmor_status; running this showed that mysqld is indeed covered under AppArmor:

    # apparmor_status
apparmor module is loaded.
6 profiles are loaded.
6 profiles are in enforce mode.
   /sbin/dhclient3
   /usr/lib/NetworkManager/nm-dhcp-client.action
   /usr/lib/connman/scripts/dhclient-script
   /usr/sbin/mysqld
   /usr/sbin/ntpd
   /usr/sbin/tcpdump
0 profiles are in complain mode.
3 processes have profiles defined.
3 processes are in enforce mode :
   /usr/sbin/mysqld (22699) 
   /usr/sbin/mysqld (6808) 
   /usr/sbin/ntpd (2800) 
0 processes are in complain mode.
0 processes are unconfined but have a profile defined.

    Reading the man pages for apparmor(7) showed that profiles were stored in /etc/apparmor.d; looking at this directory turns up the file usr.sbin.mysqld. This turns out to be the file to modify.

    Modifying the file is straightforward, copying the entries for the original standard directories and files and making them into the new directories and files. Once this is done, activate the new configuration with a service apparmor restart.

    I never did see any messages in syslog about "audit" (from AppArmor). The reason for this was that the messages went to /var/log/audit/audit.log instead of syslog or messages. This file contained entries like these:

    type=APPARMOR_DENIED msg=audit(1310141055.025:256):  operation="mknod" pid=28765 parent=28764 profile="/usr/sbin/mysqld" requested_mask="c::" de
nied_mask="c::" fsuid=104 ouid=104 name="/var/log/mysql2/error.log"
type=APPARMOR_DENIED msg=audit(1310141055.025:257):  operation="open" pid=28765 parent=28764 profile="/usr/sbin/mysqld" requested_mask="r::" den
ied_mask="r::" fsuid=104 ouid=104 name="/var/lib/mysql2/mysql/plugin.frm"
type=APPARMOR_DENIED msg=audit(1310141055.035:258):  operation="open" pid=28765 parent=28764 profile="/usr/sbin/mysqld" requested_mask="rw::" de
nied_mask="rw::" fsuid=104 ouid=104 name="/var/lib/mysql2/ibdata1"
type=APPARMOR_DENIED msg=audit(1310141097.085:259):  operation="open" pid=28780 parent=28779 profile="/usr/sbin/mysqld" requested_mask="::r" den
ied_mask="::r" fsuid=104 ouid=0 name="/etc/mysql/my2.cnf"
type=APPARMOR_DENIED msg=audit(1310141177.636:260):  operation="open" pid=28841 parent=28840 profile="/usr/sbin/mysqld" requested_mask="::r" den
ied_mask="::r" fsuid=104 ouid=0 name="/etc/mysql/my2.cnf"
type=APPARMOR_DENIED msg=audit(1310141614.953:261):  operation="open" pid=28903 parent=28902 profile="/usr/sbin/mysqld" requested_mask="::r" denied_mask="::r" fsuid=104 ouid=0 name="/etc/mysql/my2.cnf"
type=APPARMOR_DENIED msg=audit(1310141665.113:262):  operation="open" pid=28916 parent=28915 profile="/usr/sbin/mysqld" requested_mask="::r" denied_mask="::r" fsuid=104 ouid=0 name="/etc/mysql/my2.cnf"
type=APPARMOR_DENIED msg=audit(1310141739.863:263):  operation="open" pid=28926 parent=28925 profile="/usr/sbin/mysqld" requested_mask="::r" denied_mask="::r" fsuid=104 ouid=0 name="/etc/mysql/my2.cnf"
type=APPARMOR_DENIED msg=audit(1310142253.323:264):  operation="open" pid=28962 parent=19377 profile="/usr/sbin/mysqld" requested_mask="::r" denied_mask="::r" fsuid=104 ouid=0 name="/etc/mysql/conf2.d/"

    This proves my reasoning and investigation: AppArmor was rejecting the open(2) requests.

    Now that I knew what to look for I found blog entries relating to this - one article from all the way back in 2008.

    • 4