[Bug 2107332] Re: AppArmor denied audit messages related to __pycache__ in dmesg

Renan Rodrigo 2107332 at bugs.launchpad.net
Wed Apr 16 18:40:38 UTC 2025


Hello @sitsofe, @ahasenack

First of all, I could reproduce this problem exactly as described - thanks for the details!
The full server install has ubuntu-pro-client seeded and server-minimal does not have it.

## Debugging the problem

The timestamp hint was a good start for me to check what is happening.

- When installing the regular, non-minimal, server the files are copied (rsyncd? I am not sure) so the metadata for the python files have the moment of installation as the timestamp. Example:
```
(...)
-rw-r--r--   1 root root 14590 Apr 16  2025 actions.py
drwxr-xr-x   4 root root  4096 Apr 16  2025 api
-rw-r--r--   1 root root  8516 Apr 16  2025 apt_news.py
-rw-r--r--   1 root root 35095 Apr 16  2025 apt.py
(...)
```
Likewise, the existing __pycache__folder has the same timestamps, but it's because the .pyc files have been most probably *copied*, not generated.
```
(...)
-rw-r--r--  1 root root 19057 Apr 16  2025 actions.cpython-312.pyc
-rw-r--r--  1 root root 42981 Apr 16  2025 apt.cpython-312.pyc
-rw-r--r--  1 root root 11914 Apr 16  2025 apt_news.cpython-312.pyc
(...)
```

Looking at cpython's behavior, "But in general, it doesn't recompile if
the bytecode if finds the .pyc file and if the size and timestamp of the
.py file hasn't changed." (Source:
https://github.com/python/cpython/issues/107631)

So, given the content is the same (I diff-ed the directories to make sure), the timestamps of the .py files are different than the ones used when the .pyc files were generated, regardless of when it happened, as the .py files keep the timestamps in the .deb. That's verifiable by running
```
sudo apt install --reinstall ubuntu-advantage-tools
```

Now, the __pycache__ has been re-generated. But looking at the python files, after the reinstall, we see the original timestamps.
```
(...)
-rw-r--r--   1 root root 14590 Sep  6  2024 actions.py
drwxr-xr-x   4 root root  4096 Apr 16  2025 api
-rw-r--r--   1 root root  8516 Aug  8  2024 apt_news.py
-rw-r--r--   1 root root 35095 Aug  8  2024 apt.py
(...)
```

So the problem is that the __pycache__ is being generated based on the
files contained in the deb, with the old timestamps, and then there are
new timestamps in the seeded version after installation.

## If so, why it's not happening to other python packages that are
seeded?

Well it may be! haha
But ubuntu-pro-client installs services (like apt-news or esm-cache), which other packages may not do.
And we have active apparmor profiles, which other packages may not have.
Without apparmor, our service would just regenerate the .pyc files at runtime.

It would be interesting to check other python packages which have
apparmor backed services to see if this happens too, but I won't have
the time now unfortunately.

## What could be done?

I don't know :D

- Could the ubuntu-pro-client apparmor profile allow the services to
write the files in __pycache__? I don't think so. The client is behaving
the way it should, and relaxing those profiles for such a corner case
could lead to unforeseen (and some foreseen? hehe) security issues -
like modifying the service to inject whatever in the .pyc files.

- Could subiquity keep the original .py files metadata (from the deb)
when copying the files to disk? If so, would it be worth it? I am
targetting subiquity people here so they can add their opinion.

** Bug watch added: github.com/python/cpython/issues #107631
   https://github.com/python/cpython/issues/107631

** Also affects: subiquity (Ubuntu)
   Importance: Undecided
       Status: New

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to subiquity in Ubuntu.
https://bugs.launchpad.net/bugs/2107332

Title:
  AppArmor denied audit messages related to __pycache__ in dmesg

Status in subiquity package in Ubuntu:
  New
Status in ubuntu-advantage-tools package in Ubuntu:
  Triaged

Bug description:
  Description of the problem
  Every night AppArmor denial logs related to trying to write to /lib/python3/dist-packages/uaclient/__pycache__/ are reported in the kernel logs. 

  Steps to reproduce:
  1. Install latest server version of Ubuntu 24.04?

  Expected result:
  Kernel logs to only have unusual messages.

  Actual result:
  Each night output like the following appears in the kernel logs:
  [592502.661712] kauditd_printk_skb: 89 callbacks suppressed
  [592502.661714] audit: type=1400 audit(1744604059.356:1017): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_apt_news" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/__init__.cpython-312.pyc.126322914539312" pid=91895 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.667012] audit: type=1400 audit(1744604059.361:1018): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_apt_news" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/apt.cpython-312.pyc.126322914712960" pid=91895 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.676280] audit: type=1400 audit(1744604059.370:1019): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_esm_cache" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/__init__.cpython-312.pyc.135222400273840" pid=91896 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.677457] audit: type=1400 audit(1744604059.372:1020): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_esm_cache" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/log.cpython-312.pyc.135222401808656" pid=91896 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.684794] audit: type=1400 audit(1744604059.379:1021): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_esm_cache" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/defaults.cpython-312.pyc.135222399178672" pid=91896 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.685174] audit: type=1400 audit(1744604059.379:1022): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_esm_cache" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/secret_manager.cpython-312.pyc.135222399178672" pid=91896 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.689781] audit: type=1400 audit(1744604059.384:1023): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_esm_cache" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/system.cpython-312.pyc.135222399180720" pid=91896 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.699986] audit: type=1400 audit(1744604059.394:1024): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_esm_cache" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/exceptions.cpython-312.pyc.135222399544752" pid=91896 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.706501] audit: type=1400 audit(1744604059.401:1025): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_esm_cache" name="/usr/lib/python3/dist-packages/uaclient/messages/__pycache__/__init__.cpython-312.pyc.135222398418480" pid=91896 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
  [592502.706551] audit: type=1400 audit(1744604059.401:1026): apparmor="DENIED" operation="mknod" class="file" profile="ubuntu_pro_apt_news" name="/usr/lib/python3/dist-packages/uaclient/__pycache__/event_logger.cpython-312.pyc.126322909730864" pid=91895 comm="python3" requested_mask="c" denied_mask="c" fsuid=0 ouid=0

  How reproducible is the problem?
  The problem happens every day.

  Version information
  Ubuntu 24.04.2 LTS
  ubuntu-pro-client 34~24.04 amd64

  Additional information
  Running
  sudo systemctl restart apt-news.service
  makes the messages appear in the logs straightaway.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/subiquity/+bug/2107332/+subscriptions




More information about the foundations-bugs mailing list