[pkg-apparmor] Bug#1120454: Bug#1120454: apparmor.service takes time to finish with the 6.17.6+deb14-amd64 kernel

[Christian Boltz]

Hello,

Am Dienstag, 11. November 2025, 02:49 schrieb Vincent Lefevre:
> On 2025-11-10 21:29:06 +0100, Christian Boltz wrote:
> > Am Montag, 10. November 2025, 04:29 schrieb Vincent Lefevre:
> > > [    *] Job apparmor.service/start running (16s / no limit)
> > 
> > Just to clarify/exclude the most obvious possibe reason:
> > 
> > Do you see this long start time with _every_ boot of the new kernel,
> > or was it only on the first boot after the kernel update?
> 
> This is not reproducible, not even after another kernel update
> (6.17.7+deb14+1-amd64).

Ok, then it really sounds like a cache rebuild after the 6.16.x -> 
6.17.x update.

> > (If it was only during the first boot after the kernel update,
> > that's
> > probably because the profile cache was rebuilt for the new kernel.)
> 
> When is the profile cache rebuilt? Why didn't this occur in the past
> after kernel upgrades?

The cache gets rebuild if the feature set supported by the kernel 
changes - typically with major kernel releases (like your 6.16.x -> 
6.17.x update).

Note that not every major kernel release comes with new AppArmor 
features. Looking at
https://gitlab.com/apparmor/apparmor/-/wikis/Kernel_Feature_Matrix
you can see that the last kernels which got new AppArmor features were 
6.7, 6.8, 6.13 and then 6.17. (Minor releases don't introduce new 
AppArmor features.)

Without new features, no cache rebuild is necessary.
(That's why the minor update 6.17.x -> 6.17.y didn't need a rebuild.)


Other reasons for a cache rebuild are new userspace versions (especially 
apparmor_parser) and of course updates in the profiles or abstractions. 
(In these cases, the cache rebuild is typically done directly after the 
package updates, so that you don't notice it at boot.)

> For the concerned boot, the unfiltered journalctl output gives
> 
> [...]
> Nov 07 17:40:29 cventin systemd[1]: Starting systemd-sysctl.service -
> Apply Kernel Variables... Nov 07 17:40:29 cventin systemd[1]:
> Finished systemd-sysctl.service - Apply Kernel Variables. 
> Nov 07 17:40:46 cventin kernel: kauditd_printk_skb: 111 callbacks 
> suppressed
> Nov 07 17:40:46 cventin kernel: audit: type=1400
> audit(1762533646.806:123): apparmor="STATUS" operation="profile_load"
> profile="unconfined" name="libreoffice-soffice" pid=787
> comm="apparmor_parser"

> I don't know whether this could be related to the issue,
> but these "audit" lines about libreoffice-soffice normally
> do not appear during the boot.

These lines says that the profile was loaded into the kernel, so it's 
quite boring ;-)

I'd guess the reason why you don't always see it is that IIRC there is a 
limit of log messages per second, so it could be lost because of that 
limit.

If you have auditd running, check /var/log/audit/audit.log. AFAIK it's 
not affected by the rate limiting, and should contain profile_load lines 
for all profiles.


Regards,

Christian Boltz
-- 
> got a patch?
-ENOTMYJOB
[> Markus Rueckert and Bernhard Walle in opensuse-packaging]
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 870 bytes
Desc: This is a digitally signed message part.
URL: <http://alioth-lists.debian.net/pipermail/pkg-apparmor-team/attachments/20251111/5ce7e2b0/attachment-0001.sig>