April 24, 2019

Technical Memo: Apparmor starting errors in Ubuntu Bionic 18.04

1. System Degradation Issue

As usual, after installing some modules and modifying some user privileges, I performed a reboot for my home desktop computer. After the reboot, I always check for system start health and today is no different.

$ systemctl status
● stark
    State: degraded
     Jobs: 0 queued
   Failed: 1 units
    Since: Tue 2019-04-23 13:37:13 JST; 0h 4min ago
   CGroup: /
           ├─user.slice
           │ ├─user-1000.slice
           │ │ ├─user@1000.service
... 
 

2. What was the problem?

hm... I was quite surprised at this degradation of my system, so I look for the unit that fails to start at boot time.

$ systemctl list-units --failed
  UNIT             LOAD   ACTIVE SUB    DESCRIPTION           
● apparmor.service loaded failed failed AppArmor initialization

LOAD   = Reflects whether the unit definition was properly loaded.
ACTIVE = The high-level unit activation state, i.e. generalization of SUB.
SUB    = The low-level unit activation state, values depend on unit type.
1 loaded units listed. Pass --all to see loaded but inactive units, too.
To show all installed unit files use 'systemctl list-unit-files'.

$ systemctl status apparmor
● apparmor.service - AppArmor initialization
   Loaded: loaded (/lib/systemd/system/apparmor.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Wed 2019-04-24 10:06:09 JST; 5min ago
     Docs: man:apparmor(7)
           http://wiki.apparmor.net/
  Process: 20197 ExecStop=/etc/init.d/apparmor stop (code=exited, status=0/SUCCESS)
  Process: 20208 ExecStart=/etc/init.d/apparmor start (code=exited, status=123)
 Main PID: 20208 (code=exited, status=123)
...

 4月 24 10:06:07 stark apparmor[20208]: Warning from /var/lib/snapd/apparmor/profiles/snap.lxd.migrate (/var/lib/snapd/apparmor/profiles/snap.lxd.migrate line 484): Unconfined exec qualifier (ux) allows some dangerous environment variables to be passed to the unconfined process; 'man 5 apparmor.d' for details.
 4月 24 10:06:09 stark apparmor[20208]:    ...fail!
 4月 24 10:06:09 stark systemd[1]: apparmor.service: Main process exited, code=exited, status=123/n/a
 4月 24 10:06:09 stark systemd[1]: apparmor.service: Failed with result 'exit-code'.
 4月 24 10:06:09 stark systemd[1]: Failed to start AppArmor initialization.

Apparmor seems fail to initialize at startup. It's quite surprising because I didn't modify any apparmor-related things. I look for the status of apparmor to see what problem might happen.

Well, nothing special here. the apparmor service is complaining of some unconfined exec qualifier and it dies. Warnings cannot make a process fail to start because they are warnings! So I look at apparmor journal logs.

$ journalctl -u apparmor
...
 4月 23 16:25:41 stark apparmor[14865]: AppArmor parser error  for /etc/apparmor.d/usr.sbin.dhcpd in /etc/apparmor.d/usr.sbin.dhcpd at line 70: Could not open 'dhcpd.d'

The error at line 70 of profile file for dhcpd is the culprit causing apparmor failed to start. At that line is the following #include

  # allow packages to re-use dhcpd and provide their own specific directories
  #include

It seems that this apparmor's dhcpd profile looks for dhcpd.d directory in /etc/apparmor.d/ but fails to see this directory. So on theory, if I create this directory again, the apparmor parser will parse and I will not see any problem.

3. Temporary Solution

So I go and create the directory

$ sudo mkdir /etc/apparmor.d/dhcpd.d
$ sudo systemctl start apparmor
$ systemctl status apparmor
● apparmor.service - AppArmor initialization
   Loaded: loaded (/lib/systemd/system/apparmor.service; enabled; vendor preset: enabled)
   Active: active (exited) since Wed 2019-04-24 10:50:18 JST; 5s ago
     Docs: man:apparmor(7)
           http://wiki.apparmor.net/

  Process: 20197 ExecStop=/etc/init.d/apparmor stop (code=exited, status=0/SUCCESS)
  Process: 11297 ExecStart=/etc/init.d/apparmor start (code=exited, status=0/SUCCESS)
 Main PID: 11297 (code=exited, status=0/SUCCESS)
...

$ systemctl status
● stark
    State: running
     Jobs: 0 queued
   Failed: 0 units

Ok, it works!

4. Why?

I try to google around to see whether I'm the only person who see this issue. I did found out similar issue date back to 2015. The reason at that time was that Ubuntu developers forgot to add the empty directory dhcpd.d to the built package. However, the issue got fixed and released at 2.8.95~
2430-0ubuntu5.2. My apparmor package version was 2.12-4ubuntu5.1 (apt-cache showpkg apparmor) so it should be no issue at all. I'm curious to see whether my apt update affects this issue. so I issue a search command for apparmor to apt log

$ grep apparmor /var/log/apt/term.log
Skipping profile in /etc/apparmor.d/disable: usr.sbin.squid
Installing new version of config file /etc/apparmor.d/usr.lib.snapd.snap-confine.real ... 

2 promising lines did appear but it didn't relate to my issue.
At this time, I still need to finish my new employee training plan, so I leave this issue as it is. If due to some modification, the issue reappears, I will definitely raise a bug ticket to Ubuntu Launchpad.

No comments: