aa-logprof fails with unknown mode "reweive"

Bug #1577051 reported by Me
56
This bug affects 9 people
Affects Status Importance Assigned to Milestone
AppArmor
Fix Released
Undecided
Christian Boltz
2.10
Fix Released
Undecided
Christian Boltz
apparmor (Ubuntu)
Fix Released
Medium
Tyler Hicks
Xenial
Fix Released
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.

Revision history for this message
Me (wmsopou) wrote :
Christian Boltz (cboltz)
tags: added: aa-tools
Revision history for this message
Launchpad Janitor (janitor) wrote :

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

Changed in apparmor (Ubuntu):
status: New → Confirmed
Revision history for this message
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

Revision history for this message
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)
Changed in apparmor:
status: New → Confirmed
Revision history for this message
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 ;-)

Revision history for this message
lysdexia (doug-shawhan) wrote : Re: [Bug 1577051] Re: aa-logprof fails with unknown mode "reweive"

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
>

Revision history for this message
Christian Boltz (cboltz) wrote :

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

Revision history for this message
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.

Revision history for this message
Launchpad Janitor (janitor) wrote :

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

Changed in apparmor (Ubuntu Xenial):
status: New → Confirmed
Revision history for this message
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)
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)
description: updated
Revision history for this message
Martin Pitt (pitti) wrote : Please test proposed package

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
Revision history for this message
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"

Revision history for this message
Niklas Janz (7-niklas) wrote :
Revision history for this message
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.

Revision history for this message
Niklas Janz (7-niklas) wrote :

You're the best! Thanks ;-)

Revision history for this message
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)
no longer affects: linuxmint
Revision history for this message
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!

Revision history for this message
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
Revision history for this message
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
Revision history for this message
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
Revision history for this message
Brian Murray (brian-murray) wrote : Update 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)
Changed in apparmor:
assignee: nobody → Christian Boltz (cboltz)
Christian Boltz (cboltz)
Changed in apparmor:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.