Open Bug 1800357 Opened 2 years ago Updated 2 years ago

CLI start of firefox reports: update.go:85: cannot change mount namespace according to change mount

Categories

(Firefox Build System :: Third Party Packaging, defect, P4)

Firefox 106
defect

Tracking

(Not tracked)

UNCONFIRMED

People

(Reporter: riegler.b, Unassigned)

References

(Blocks 1 open bug)

Details

Attachments

(1 file)

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:106.0) Gecko/20100101 Firefox/106.0

Steps to reproduce:

platform Ubuntu 22.04LTS, firefox app as snap package, firefox version 106.0.5
just start firefox with CLI /snap/bin/firefox

Actual results:

bernie@prod:$ firefox
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/cups/doc-root /usr/share/cups/doc-root none bind,ro 0 0): cannot create directory "/usr/share/cups/doc-root": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/gimp/2.0/help /usr/share/gimp/2.0/help none bind,ro 0 0): cannot create directory "/usr/share/gimp/2.0": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/libreoffice/help /usr/share/libreoffice/help none bind,ro 0 0): cannot create directory "/usr/share/libreoffice/help": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/xubuntu-docs /usr/share/xubuntu-docs none bind,ro 0 0): cannot open directory "/var/lib": permission denied
Gtk-Message: 07:58:22.021: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
WARNING: Kernel has no file descriptor comparison support: Operation not permitted
bernie@prod:
$ firefox -V
Mozilla Firefox 106.0.5

User_Agent string "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:106.0) Gecko/20100101 Firefox/106.0 "

Expected results:

no reports for "update.go:85:" ... permission denied

The Bugbug bot thinks this bug should belong to the 'Firefox Build System::General' component, and is moving the bug to that component. Please correct in case you think the bot is wrong.

Component: Untriaged → General
Product: Firefox → Firefox Build System
Component: General → Third Party Packaging

The severity field is not set for this bug.
:gerard-majax, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(lissyx+mozillians)
Blocks: snap
Flags: needinfo?(lissyx+mozillians)

This looks like https://bugs.launchpad.net/ubuntu/+source/snapd/+bug/1991691 which is down to a kernel-level issue with a fix available, can you verify ?

Flags: needinfo?(riegler.b)
  1. I am running distribution Ubuntu 22.04 LTS which is at kernel version 5.15
    bernie@prod:/etc$ cat /etc/os-release
    PRETTY_NAME="Ubuntu 22.04.1 LTS"
    NAME="Ubuntu"
    VERSION_ID="22.04"
    VERSION="22.04.1 LTS (Jammy Jellyfish)"
    VERSION_CODENAME=jammy
    ID=ubuntu
    ID_LIKE=debian
    HOME_URL="https://www.ubuntu.com/"
    SUPPORT_URL="https://help.ubuntu.com/"
    BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
    PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
    UBUNTU_CODENAME=jammy

bernie@prod:/etc$ uname -a
Linux prod 5.15.0-53-generic #59-Ubuntu SMP Mon Oct 17 18:53:30 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
bernie@prod:/etc$

  1. I have switched off the service CUPS, because printing is very seldom on this system.
    root@prod:/home/bernie22/bin# cat off_cups.bash
    #! /bin/bash
    set -x

file: bin/on_cups.bash

UB='/usr/bin'

FILE=$UB/basename $0 .bash # strip off directory prefix and type postfix
echo "|$FILE|"

file name convention: ACTION_OBJECT.bash

ACTION=${FILE%} # remove shortest pattern from right
echo "|$ACTION|"
OBJ=${FILE#
} # remove shortest pattern from left
echo "|$OBJ|"

if [ $ACTION = 'on' ]
then

sub

$UB/systemctl unmask $OBJ.socket
$UB/systemctl enable $OBJ.socket

$UB/systemctl unmask $OBJ.path
$UB/systemctl enable $OBJ.path

main

$UB/systemctl unmask $OBJ.service
$UB/systemctl enable $OBJ.service

$UB/systemctl start $OBJ.service
fi

if [ $ACTION = 'off' ]
then

main

$UB/systemctl stop $OBJ.service

$UB/systemctl disable $OBJ.service
$UB/systemctl mask $OBJ.service

sub

$UB/systemctl disable $OBJ.socket
$UB/systemctl mask $OBJ.socket

$UB/systemctl disable $OBJ.path
$UB/systemctl mask $OBJ.path
fi

  1. if I let the service CUPS running, all 4 messages "update.go:85: ... permission denied" are gone.
Flags: needinfo?(riegler.b)

Thanks, what if you keep CUPS off and you disconnect cups-control from snap connections firefox ?

Flags: needinfo?(riegler.b)

kernel 5.15.0-54, disabling cups:

sudo systemctl stop cups.service 
sudo systemctl stop cups.socket
sudo systemctl stop cups.path
sudo systemctl disable cups.service 
sudo systemctl disable cups.socket
sudo systemctl disable cups.path
sudo systemctl mask cups.service 
sudo systemctl mask cups.socket
sudo systemctl mask cups.path

And I dont have problem running Firefox.

thanks for pointing me to "snap connections"
I have now CUPS off with systemctl and disconnected cups-control in snap for firefox.
reboot and first activity.

bernie@prod:$ snap connections firefox |grep cups
cups-control firefox:cups-control - -
bernie@prod:
$ firefox
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/cups/doc-root /usr/share/cups/doc-root none bind,ro 0 0): cannot create directory "/usr/share/cups/doc-root": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/gimp/2.0/help /usr/share/gimp/2.0/help none bind,ro 0 0): cannot create directory "/usr/share/gimp/2.0": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/libreoffice/help /usr/share/libreoffice/help none bind,ro 0 0): cannot create directory "/usr/share/libreoffice/help": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/xubuntu-docs /usr/share/xubuntu-docs none bind,ro 0 0): cannot open directory "/var/lib": permission denied
Gtk-Message: 16:49:26.308: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
bernie@prod:$ firefox
Gtk-Message: 16:49:38.131: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
bernie@prod:
$ firefox
Gtk-Message: 16:49:50.222: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.

the effect is only at the first time after reboot.

Flags: needinfo?(riegler.b)

(In reply to Bernhard Riegler from comment #7)

thanks for pointing me to "snap connections"
I have now CUPS off with systemctl and disconnected cups-control in snap for firefox.
reboot and first activity.

bernie@prod:$ snap connections firefox |grep cups
cups-control firefox:cups-control - -
bernie@prod:
$ firefox
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/cups/doc-root /usr/share/cups/doc-root none bind,ro 0 0): cannot create directory "/usr/share/cups/doc-root": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/gimp/2.0/help /usr/share/gimp/2.0/help none bind,ro 0 0): cannot create directory "/usr/share/gimp/2.0": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/libreoffice/help /usr/share/libreoffice/help none bind,ro 0 0): cannot create directory "/usr/share/libreoffice/help": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/xubuntu-docs /usr/share/xubuntu-docs none bind,ro 0 0): cannot open directory "/var/lib": permission denied
Gtk-Message: 16:49:26.308: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
bernie@prod:$ firefox
Gtk-Message: 16:49:38.131: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
bernie@prod:
$ firefox
Gtk-Message: 16:49:50.222: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.

the effect is only at the first time after reboot.

Thanks, does it means that subsequent launches works after you unplug the cups-control piece ?

From the above log, it sounds like Firefox started in both case, you just get some extra error messages (which are related to some stuff to allow access to HTML documentation, but I dont know more about why you have permission denied).

Here is the related info from "journalctl -b"

root@prod:/home/bernie22/config_22.04LTS/_root/collect# grep 'profile="snap-update-ns.firefox"' journalctl
[ 137.086120] prod audit[10255]: AVC apparmor="DENIED" operation="mkdir" profile="snap-update-ns.firefox" name="/usr/share/cups/doc-root/" pid=10255 comm="5" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[ 137.086326] prod audit[10255]: AVC apparmor="DENIED" operation="mkdir" profile="snap-update-ns.firefox" name="/usr/share/gimp/2.0/" pid=10255 comm="5" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[ 137.086615] prod audit[10255]: AVC apparmor="DENIED" operation="mkdir" profile="snap-update-ns.firefox" name="/usr/share/libreoffice/help/" pid=10255 comm="5" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[ 137.086780] prod audit[10255]: AVC apparmor="DENIED" operation="open" profile="snap-update-ns.firefox" name="/var/lib/" pid=10255 comm="5" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[ 137.176017] prod kernel: audit: type=1400 audit(1669823366.030:58): apparmor="DENIED" operation="mkdir" profile="snap-update-ns.firefox" name="/usr/share/cups/doc-root/" pid=10255 comm="5" requested_mask="c" denied_mask="c" fsuid=0 ouid=0

YES, firefox works in all cases.

oh, could it be you dont have package providing /usr/share/cups/doc-root/, /usr/share/gimp/2.0/ nor /usr/share/libreoffice/help/ ?

root@prod:/home/bernie22# dpkg-query -S /usr/share/cups/doc-root/
cups-server-common: /usr/share/cups/doc-root

root@prod:/usr/share/cups# ll -d .
drwxr-xr-x 18 root root 4096 Sep 26 11:12 ./

root@prod:/usr/share/cups# ll -d doc-root
drwxr-xr-x 11 root root 4096 Jun 1 14:13 doc-root/

this is root area.
a normal user can not do a "mkdir" in this directories. this is nosense.
gimp was here at the LTS cold install time. I deleted the complete product "gimp".
the tree /usr/share/gimp/ is non existent.
I wonder where this info survived in the file-system for the CANONICAL supplied firefox (snap package)

root@prod:/usr/share# snap list --all
Name Version Rev Tracking Publisher Notes
bare 1.0 5 latest/stable canonical✓ base
core 16-2.57.6 14399 latest/stable canonical✓ core
core20 20221027 1695 latest/stable canonical✓ base
firefox 107.0-2 2088 latest/stable/… mozilla✓ disabled
firefox 107.0.1-1 2154 latest/stable/… mozilla✓ -
gnome-3-38-2004 0+git.6f39565 119 latest/stable/… canonical✓ -
gtk-common-themes 0.1-81-g442e511 1535 latest/stable/… canonical✓ -
snap-store 41.3-66-gfe1e325 638 latest/stable/… canonical✓ -
snapd 2.57.6 17883 latest/stable canonical✓ snapd
snapd-desktop-integration 0.1 14 latest/stable/… canonical✓ -
thunderbird 102.5.0-2 276 latest/stable canonical✓ -

kernel strace after reboot
starting "firefox" with root power.
extract of the strace ... for the first 2 "update.go:85" messages

22948 07:14:27.808508 openat(AT_FDCWD, "/", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY) = 3 <0.000010>
22948 07:14:27.808668 mkdirat(3, "usr", 0755 <unfinished ...>
22948 07:14:27.808705 <... mkdirat resumed>) = -1 EEXIST (File exists) <0.000024>
22948 07:14:27.808728 openat(3, "usr", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY <unfinished ...>
22948 07:14:27.808755 <... openat resumed>) = 6 <0.000015>
22948 07:14:27.808851 mkdirat(6, "share", 0755 <unfinished ...>
22948 07:14:27.808876 <... mkdirat resumed>) = -1 EEXIST (File exists) <0.000013>
22948 07:14:27.808911 openat(6, "share", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY <unfinished ...>
22948 07:14:27.808937 <... openat resumed>) = 7 <0.000013>
22948 07:14:27.809063 mkdirat(7, "cups", 0755) = 0 <0.000010>
22948 07:14:27.809100 openat(7, "cups", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY <unfinished ...>
22948 07:14:27.809130 <... openat resumed>) = 8 <0.000016>
22948 07:14:27.809207 close(7 <unfinished ...>
22948 07:14:27.809237 <... close resumed>) = 0 <0.000014>
22948 07:14:27.809271 close(6 <unfinished ...>
22948 07:14:27.809292 <... close resumed>) = 0 <0.000013>
22948 07:14:27.809315 close(3) = 0 <0.000007>
22948 07:14:27.809345 mkdirat(8, "doc-root", 0755) = -1 EACCES (Permission denied) <0.000037>
22948 07:14:27.809655 close(8) = 0 <0.000010>
22948 07:14:27.809774 write(2, "update.go:85: cannot change mount namespace according to change mount (/var/lib/"..., 231 <unfinished ...>
22948 07:14:27.809995 openat(AT_FDCWD, "/", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY <unfinished ...>
22948 07:14:27.810033 <... openat resumed>) = 3 <0.000019>
22948 07:14:27.810143 mkdirat(3, "usr", 0755 <unfinished ...>
22948 07:14:27.810170 <... mkdirat resumed>) = -1 EEXIST (File exists) <0.000013>
22948 07:14:27.810198 openat(3, "usr", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY) = 6 <0.000009>
22948 07:14:27.810323 mkdirat(6, "share", 0755) = -1 EEXIST (File exists) <0.000007>
22948 07:14:27.810358 openat(6, "share", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY) = 7 <0.000009>
22948 07:14:27.810484 mkdirat(7, "gimp", 0755) = 0 <0.000011>
22948 07:14:27.810520 openat(7, "gimp", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY <unfinished ...>
22948 07:14:27.810547 <... openat resumed>) = 8 <0.000014>
22948 07:14:27.810613 mkdirat(8, "2.0", 0755) = -1 EACCES (Permission denied) <0.000024>
22948 07:14:27.810673 close(8 <unfinished ...>
22948 07:14:27.810698 <... close resumed>) = 0 <0.000016>
22948 07:14:27.810714 close(7) = 0 <0.000006>
22948 07:14:27.810742 close(6) = 0 <0.000006>
22948 07:14:27.810770 close(3 <unfinished ...>
22948 07:14:27.810793 <... close resumed>) = 0 <0.000013>
22948 07:14:27.810819 write(2, "update.go:85: cannot change mount namespace according to change mount (/var/lib/"..., 226) = 226 <0.000013>

Right but none of this code relates directly to FIrefox nor it's packaging itself, but rather directly snapd: https://github.com/snapcore/snapd/blob/2.57.6/interfaces/builtin/system_packages_doc.go

There's likely something wrong on your system, but I dont know what and I dont know where to debug that.

22948 07:14:27.808508 openat(AT_FDCWD, "/", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY) = 3 <0.000010>
22948 07:14:27.808668 mkdirat(3, "usr", 0755 <unfinished ...>
22948 07:14:27.808705 <... mkdirat resumed>) = -1 EEXIST (File exists) <0.000024>
22948 07:14:27.808728 openat(3, "usr", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY <unfinished ...>
22948 07:14:27.808755 <... openat resumed>) = 6 <0.000015>
22948 07:14:27.808851 mkdirat(6, "share", 0755 <unfinished ...>
22948 07:14:27.808876 <... mkdirat resumed>) = -1 EEXIST (File exists) <0.000013>
22948 07:14:27.808911 openat(6, "share", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY <unfinished ...>
22948 07:14:27.808937 <... openat resumed>) = 7 <0.000013>
22948 07:14:27.809063 mkdirat(7, "cups", 0755) = 0 <0.000010>
22948 07:14:27.809100 openat(7, "cups", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_DIRECTORY <unfinished ...>
22948 07:14:27.809130 <... openat resumed>) = 8 <0.000016>
22948 07:14:27.809207 close(7 <unfinished ...>
22948 07:14:27.809237 <... close resumed>) = 0 <0.000014>
22948 07:14:27.809271 close(6 <unfinished ...>
22948 07:14:27.809292 <... close resumed>) = 0 <0.000013>
22948 07:14:27.809315 close(3) = 0 <0.000007>
22948 07:14:27.809345 mkdirat(8, "doc-root", 0755) = -1 EACCES (Permission denied) <0.000037>

From that we can see it issues a serie of mkdir() on each component of /usr/share/cups that all succeeds with return code 0, and then doc-root part issues a EACCES.

What's your snapd version? snap info snapd should reveal it.

root@prod:/home/bernie22# snap info snapd
name: snapd
summary: Daemon and tooling that enable snap packages
publisher: Canonical✓
store-url: https://snapcraft.io/snapd
license: GPL-3.0
description: |
Install, configure, refresh and remove snap packages. Snaps are
'universal' packages that work across many different Linux systems,
enabling secure distribution of the latest apps and utilities for
cloud, servers, desktops and the internet of things.

Start with 'snap list' to see installed snaps.
type: snapd
snap-id: PMrrV4ml8uWuEUDBT8dSGnKUYbevVhc4
tracking: latest/stable
refresh-date: 2 days ago, at 12:17 CET
channels:
latest/stable: 2.57.6 2022-11-29 (17883) 52MB -
latest/candidate: 2.57.6 2022-11-28 (17883) 52MB -
latest/beta: 2.57.5+git955.g8ac464e 2022-11-18 (17825) 52MB -
latest/edge: 2.57.6+git1129.gf273664 2022-12-01 (17939) 54MB -
installed: 2.57.6 (17883) 52MB snapd

root@prod:/home/bernie22# snap list --all
Name Version Rev Tracking Publisher Notes
bare 1.0 5 latest/stable canonical✓ base
core 16-2.57.6 14399 latest/stable canonical✓ core
core20 20221027 1695 latest/stable canonical✓ base
firefox 107.0.1-1 2154 latest/stable/… mozilla✓ -
gnome-3-38-2004 0+git.6f39565 119 latest/stable/… canonical✓ -
gtk-common-themes 0.1-81-g442e511 1535 latest/stable/… canonical✓ -
snap-store 41.3-66-gfe1e325 638 latest/stable/… canonical✓ -
snapd 2.57.6 17883 latest/stable canonical✓ snapd
snapd-desktop-integration 0.1 43 latest/stable/… canonical✓ -
thunderbird 102.5.1-1 278 latest/stable canonical✓ -

I just have "thunderbird" and "firefox" in snap containment.

So I've asked some of the snapd developper about that matter on IRC, specifically considering comment 17, and it seems there is either a fix not yet released or some more fix required, his words were "actually wait, I can see something strange on my pc too". I'll update when I get more infos.

thanks for all your investigation.
I also find Ubuntu 22.10 activity. this fix need then a backport to Ubuntu 22.04LTS and the snap packaged firefox.
I have it instant on my Ubuntu 22.04LTS machine if more data is required.

Can you share content of /var/lib/snapd/apparmor/profiles/snap-update-ns.firefox ? From IRC, it looks like we need to file an upstream issue but I don't have access to them on https://github.com/snapcore/snapd :(

Flags: needinfo?(riegler.b)

requested file compressed with bzip2

Flags: needinfo?(riegler.b)

The severity field is not set for this bug.
:gerard-majax, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(lissyx+mozillians)
Severity: -- → S4
Flags: needinfo?(lissyx+mozillians)
Priority: -- → P4

today the number of messages changed from 4 down to 2 for Ubuntu 22.04LTS with the latest update.

bernie@prod:~$ firefox
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/gimp/2.0/help /usr/share/gimp/2.0/help none bind,ro 0 0): cannot open directory "/var/lib": permission denied
update.go:85: cannot change mount namespace according to change mount (/var/lib/snapd/hostfs/usr/share/xubuntu-docs /usr/share/xubuntu-docs none bind,ro 0 0): cannot open directory "/var/lib": permission denied
Gtk-Message: 18:20:51.123: Not loading module "atk-bridge": The functionality is provided by GTK natively. Please try to not load it.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.
ATTENTION: default value of option mesa_glthread overridden by environment.

cups and libreoffice is fixed.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: