aa-logprof fails with unknown mode "reweive"

Bug #1577051 reported by Me on 2016-04-30
56
This bug affects 9 people
Affects Status Importance Assigned to Milestone
AppArmor
Undecided
Christian Boltz
2.10
Undecided
Christian Boltz
apparmor (Ubuntu)
Medium
Tyler Hicks
Xenial
Medium
Tyler Hicks

Bug Description

[Impact]

AppArmor policy developers cannot use aa-logprof without it exiting with a traceback on certain denial messages.

[Test Case]

$ echo 'Apr 30 21:53:05 nova kernel: [24668.960760] audit: \
type=1400 audit(1462045985.636:2154): apparmor="DENIED" \
operation="file_perm" profile="foo" pid=12529 comm="java" \
laddr=::ffff:127.0.0.1 lport=8080 faddr=::ffff:127.0.0.1 fport=52308 \
family="inet6" sock_type="stream" ^Cotocol=6 requested_mask="receive" \
denied_mask="receive"' > /tmp/log
$ mkdir -p /tmp/profiles && printf "profile foo {\n}" > /tmp/profiles/foo
$ aa-logprof -f /tmp/log -d /tmp/profiles

Expected output of the last command is:

Reading log entries from /tmp/log.
Updating AppArmor profiles in /tmp/profiles.

[Regression Potential]

There is little potential for regression. This "hotfix" could result in some slight confusion because the problematic denial messages will simply be ignored but it allows aa-logprof to do its intended job without unexpectedly exiting.

[Original Report]

Ubuntu 16.04.

Profiling apache tomcat.

1) aa-genprof on the catalina.sh script that is used to start and stop tomcat.
2) Start and stop tomcat.
3) Scan and save the profile.
4) aa-complain on the tomcat profile
5) Start tomcat again and this time also send a http request to tomcat.
6) Run aa-logprof which fails with this message

Reading log entries from /var/log/syslog.
Updating AppArmor profiles in /etc/apparmor.d.
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/apparmor/logparser.py", line 402, in read_log
    self.add_event_to_tree(event)
  File "/usr/lib/python3/dist-packages/apparmor/logparser.py", line 206, in add_event_to_tree
    e = self.parse_event_for_tree(e)
  File "/usr/lib/python3/dist-packages/apparmor/logparser.py", line 303, in parse_event_for_tree
    raise AppArmorException(_('Log contains unknown mode %s') % rmask)
apparmor.common.AppArmorException: 'Log contains unknown mode reweive'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/sbin/aa-logprof", line 50, in <module>
    apparmor.do_logprof_pass(logmark)
  File "/usr/lib/python3/dist-packages/apparmor/aa.py", line 2189, in do_logprof_pass
    log = log_reader.read_log(logmark)
  File "/usr/lib/python3/dist-packages/apparmor/logparser.py", line 407, in read_log
    raise AppArmorBug(ex_msg) # py3-only: from None
apparmor.common.AppArmorBug: Log contains unknown mode reweive

This error was caused by the log line:
Apr 30 21:53:05 nova kernel: [24668.960760] audit: type=1400 audit(1462045985.636:2154): apparmor="ALLOWED" operation="file_perm" profile="/usr/local/apache-tomcat-8.0.33/bin/catalina.sh///usr/local/jdk1.8.0_92/bin/java" pid=12529 comm="java" laddr=::ffff:127.0.0.1 lport=8080 faddr=::ffff:127.0.0.1 fport=52308 family="inet6" sock_type="stream" protocol=6 requested_mask="receive" denied_mask="receive"

An unexpected error occoured!

For details, see /tmp/apparmor-bugreport-wj6gamog.txt
Please consider reporting a bug at https://bugs.launchpad.net/apparmor/
and attach this file.

Me (wmsopou) wrote :
Christian Boltz (cboltz) on 2016-05-01
tags: added: aa-tools
Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in apparmor (Ubuntu):
status: New → Confirmed
lysdexia (doug-shawhan) wrote :

Same results when attempting to profile nginx.

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 16.04 LTS
Release: 16.04
Codename: xenial

lysdexia (doug-shawhan) wrote :

Same results when attempting to profile php-fpm5.6

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 16.04 LTS
Release: 16.04
Codename: xenial

php 5.6 and attendant modules installed from ppa:ondrej/php

Christian Boltz (cboltz) on 2016-05-06
Changed in apparmor:
status: New → Confirmed
Christian Boltz (cboltz) wrote :

This is caused by denied_mask="receive" in the log line and can possibly affect all profiles. (To explain the "reweive" - "c" (create) file log events get mapped to "w" (write) ;-)

The problem is that operation="file_perm" indicates a file event, but the log event obviously is a network event.

I'll probably need to implement a way to check file vs. network event that is not based on the operation= part.

BTW: No need for more debug logs ;-)

But . . . But . . . I've worked years on this collection. Most of my debug
logs are mint-in-box! Some are from Slackware 3.1!
On May 6, 2016 5:06 PM, "Christian Boltz" <email address hidden>
wrote:

> ** Changed in: apparmor
> Status: New => Confirmed
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1577051
>
> Title:
> aa-logprof fails with unknown mode "reweive"
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/apparmor/+bug/1577051/+subscriptions
>

Christian Boltz (cboltz) wrote :

See also bug 1582374 for the "send" version of this bug.

Christian Boltz (cboltz) wrote :

Hotfix commited to bzr trunk r3460, 2.10 branch r3333 and 2.9 branch r3011.

This hotfix avoids the crash by ignoring these events. The long-term fix will be to handle these events as what they are - network events, but that will need some bigger changes.

Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in apparmor (Ubuntu Xenial):
status: New → Confirmed
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package apparmor - 2.10.95-4ubuntu2

---------------
apparmor (2.10.95-4ubuntu2) yakkety; urgency=medium

  * Drop the following change now that click-apparmor has been updated:
    - Continue installing aa-exec into /usr/sbin/ for now since
      click-apparmor's aa-exec-click autopkgtest expects it to be there
  * debian/patches/allow-stacking-tests-to-use-system.patch,
    debian/patches/r3430-allow-stacking-tests-to-use-system.patch: Replace
    patch with the final version that landed upstream and annotate the patch
    headers accordingly
  * debian/patches/r3460-ignore-file-events-with-send-or-receive-request.patch:
    Prevent an aa-logprof crash by ignoring file events that contains
    send or receive in the request mask. (LP: #1577051, LP: #1582374)
  * debian/patches/r3463-r3475-change-profile-exec-modes.patch: Allow policy
    authors to specify if the environment should scrubbed during exec
    transitions allowed by a change_profile rule. (LP: #1584069)
  * debian/patches/r3478-make-overlapping-safe-and-unsafe-rules-conflict.patch:
    Make sure that multiple change_profile rules with overlapping safe and
    unsafe exec modes conflict when they share the same exec conditional
    (LP: #1588069)
  * debian/patches/r3479-create-fcitx-abstractions.patch: Include fcitx and
    fcitx-strict abstractions that fcitx client profiles can reuse.
  * debian/control: Do a conffile move of /etc/apparmor.d/abstractions/fcitx
    from the fcitx-data to apparmor by setting up the correct Breaks and
    Replaces.
  * debian/patches/r3480-create-mozc-abstraction.patch: Include a mozc
    abstraction that mozc client profiles can reuse.
  * debian/patches/r3488-r3489-fix-racy-onexec-test.patch: Fix racy regression
    test so that the kernel SRU process is not interrupted by the onexec.sh
    periodically failing
  * debian/patches/r3490-utils-handle-change-profile-exec-modes.patch: Update
    the Python utilities to handle the new exec mode keywords in
    change_profile rules. (LP: #1584069)
  * debian/patches/r3492-allow-dbus-user-session-path.patch: Allow read/write
    access to the dbus-user-session socket file. (LP: #1604872)

 -- Tyler Hicks <email address hidden> Tue, 26 Jul 2016 23:03:05 -0500

Changed in apparmor (Ubuntu):
status: Confirmed → Fix Released
Tyler Hicks (tyhicks) on 2016-07-28
Changed in apparmor (Ubuntu Xenial):
status: Confirmed → In Progress
Changed in apparmor (Ubuntu):
importance: Undecided → Medium
Changed in apparmor (Ubuntu Xenial):
importance: Undecided → Medium
assignee: nobody → Tyler Hicks (tyhicks)
Changed in apparmor (Ubuntu):
assignee: nobody → Tyler Hicks (tyhicks)
Tyler Hicks (tyhicks) on 2016-07-28
description: updated

Hello Me, or anyone else affected,

Accepted apparmor into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/apparmor/2.10.95-0ubuntu2.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

Changed in apparmor (Ubuntu Xenial):
status: In Progress → Fix Committed
tags: added: verification-needed
Niklas Janz (7-niklas) wrote :

Hello Martin.

Although I'm not getting exact "reweive"-crashes with aa-logprof anymore it still crashed on other similar events:

~# aa-logprof
Reading log entries from /var/log/syslog.
Updating AppArmor profiles in /etc/apparmor.d.
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/apparmor/logparser.py", line 409, in read_log
    self.add_event_to_tree(event)
  File "/usr/lib/python3/dist-packages/apparmor/logparser.py", line 206, in add_event_to_tree
    e = self.parse_event_for_tree(e)
  File "/usr/lib/python3/dist-packages/apparmor/logparser.py", line 310, in parse_event_for_tree
    raise AppArmorException(_('Log contains unknown mode %s') % rmask)
apparmor.common.AppArmorException: 'Log contains unknown mode senw reweive'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/sbin/aa-logprof", line 50, in <module>
    apparmor.do_logprof_pass(logmark)
  File "/usr/lib/python3/dist-packages/apparmor/aa.py", line 2189, in do_logprof_pass
    log = log_reader.read_log(logmark)
  File "/usr/lib/python3/dist-packages/apparmor/logparser.py", line 414, in read_log
    raise AppArmorBug(ex_msg) # py3-only: from None
apparmor.common.AppArmorBug: Log contains unknown mode senw reweive

This error was caused by the log line:
Jul 29 11:42:05 files kernel: [483212.877816] audit: type=1400 audit(1469785325.122:21021): apparmor="ALLOWED" operation="file_inherit" profile="/usr/bin/nginx-amplify-agent.py//null-/bin/dash" pid=18239 comm="sh" laddr=192.168.10.3 lport=50758 faddr=54.153.70.241 fport=443 family="inet" sock_type="stream" protocol=6 requested_mask="send receive" denied_mask="send receive"

Niklas Janz (7-niklas) wrote :
Christian Boltz (cboltz) wrote :

Nice finding.

The code is:

            if e['request_mask'] in ('send', 'receive'):
                self.debug_logger.debug('UNHANDLED (request_mask is send or receive): %s' % e)
                return None

so with requested_mask="send receive" I'm not surprised that you still see a crash ;-)

I just sent a patch to the mailinglist for review.

Niklas Janz (7-niklas) wrote :

You're the best! Thanks ;-)

Christian Boltz (cboltz) wrote :

Patch commited to bzr trunk r3498, 2.10 branch r3341 and 2.9 branch r3016.

Updating the Ubuntu update package is ENOTMYJOB ;-)

Niklas Janz (7-niklas) on 2016-07-30
no longer affects: linuxmint
Martin Pitt (pitti) wrote :

Hello Me, or anyone else affected,

Accepted apparmor into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/apparmor/2.10.95-0ubuntu2.2 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

Tyler Hicks (tyhicks) wrote :

I've thoroughly tested apparmor 2.10.95-0ubuntu2.2 in xenial-proposed. I've verified that this bug is fixed (via the Test Case in the description) and I've also went through the AppArmor Test Plan (excluding the Ubuntu Touch specific tests):

  https://wiki.ubuntu.com/Process/Merges/TestPlans/AppArmor

The Test Plan includes running the entire set of upstream AppArmor tests, a number of integration tests, libvirt tests, LXC/LXD tests, docker.io tests, Snappy confinement tests, etc.

tags: added: verification-done
removed: verification-needed
Christian Boltz (cboltz) wrote :

This bugreport is getting quite long ;-) and starts to get confusing.

I just opened https://bugs.launchpad.net/apparmor/+bug/1613061 as reminder that logparser.py needs to switch based on the event details instead of the operation= keyword.

The crashes reported in this bug are (hot)fixed in all supported releases (see the exact commits in the comments above), therefore I'm closing this bug.

Changed in apparmor:
milestone: none → 2.11
status: Confirmed → Fix Committed
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package apparmor - 2.10.95-0ubuntu2.2

---------------
apparmor (2.10.95-0ubuntu2.2) xenial; urgency=medium

  * r3498-r3499-ignore-net-events-that-look-like-file-events.patch: Prevent an
    aa-logprof crash by ignoring file events that contains send *and* receive
    in the request mask. This is an improvement to the previous fix that only
    addressed events that contained send *or* receive.
    (LP: #1577051, LP: #1582374)
    - debian/rules: Create a new empty file, needed for the test added by this
      patch, since quilt is unable to do so.

 -- Tyler Hicks <email address hidden> Mon, 01 Aug 2016 18:03:36 -0500

Changed in apparmor (Ubuntu Xenial):
status: Fix Committed → Fix Released

The verification of the Stable Release Update for apparmor has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

Christian Boltz (cboltz) on 2016-12-06
Changed in apparmor:
assignee: nobody → Christian Boltz (cboltz)
Christian Boltz (cboltz) on 2017-01-10
Changed in apparmor:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers