Bug 1704488 - groupadd command error on first operation in fresh Fedora 30 install [NEEDINFO]
Summary: groupadd command error on first operation in fresh Fedora 30 install
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: dbus-broker
Version: 31
Hardware: All
OS: All
unspecified
high
Target Milestone: ---
Assignee: David Rheinsberg
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-04-29 22:15 UTC by Adam Williamson
Modified: 2020-05-04 08:34 UTC (History)
11 users (show)

Fixed In Version: dbus-broker-21-2.fc30
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-05-04 08:34:12 UTC
Type: Bug
daherrma: needinfo? (mchehab)


Attachments (Terms of Use)
launch: mark new services as loaded on configuration reload (1.79 KB, patch)
2019-05-02 10:05 UTC, David Rheinsberg
no flags Details | Diff

Description Adam Williamson 2019-04-29 22:15:20 UTC
To reproduce:

1. Install a clean Fedora 30 (I did a minimal install from Everything netinst image)
2. Boot, log in as root, and install mock with 'dnf install mock'
3. Try to do something in a mock chroot: I did 'mock -r fedora-30-x86_64 --install lorax-lmc-novirt'

The result is that mock will start up and run through init, till it does its initial base system package install (not the operation to actually install lorax-lmc-novirt). Shortly after that completes, it shows an error and exits:

Finish: dnf install
ERROR: Command failed:
 # /usr/bin/systemd-nspawn -q -M (randomstring) -D /var/lib/mock/fedora-30-x86_64/root -a --setenv=TERM=vt100 --setenv=SHELL=/bin/bash --setenv=HOME=/builddir --setenv=HOSTNAME=mock --setenv=PATH=/usr/bin:/bin:/usr/sbin:/sbin --setenv=PROMPT_COMMAND=printf "\033]0;<mock-chroot>\007" --setenv=PS1=<mock-chroot> \s-\v\$  --setenv=LANG=en_US.UTF-8 /usr/sbin/groupadd -g 135 mock

(that's retyped by hand, sorry for any typos). This is new in the last few days. It's actually breaking one of the openQA tests, which is why it's a problem for me. I think the difference is mock 1.4.14 vs 1.4.15, but I'm verifying that and looking into the details now.

Comment 1 Adam Williamson 2019-04-29 22:39:57 UTC
With a bit more debugging I get this:

DEBUG: Executing command: ['/usr/bin/systemd-nspawn', '-q', '-M', '3fcebf55d9624c2e84db560a6ca77a8e', '-D', '/var/lib/mock/fedora-30-x86_64/root', '-a', '--setenv=TERM=vt100', '--setenv=SHELL=/bin/bash', '--setenv=HOME=/builddir', '--setenv=HOSTNAME=mock', '--setenv=PATH=/usr/bin:/bin:/usr/sbin:/sbin', '--setenv=PROMPT_COMMAND=printf "\\033]0;<mock-chroot>\\007"', '--setenv=PS1=<mock-chroot> \\s-\\v\\$ ', '--setenv=LANG=en_US.utf8', '/usr/sbin/groupdel', 'mock'] with env {'TERM': 'vt100', 'SHELL': '/bin/bash', 'HOME': '/builddir', 'HOSTNAME': 'mock', 'PATH': '/usr/bin:/bin:/usr/sbin:/sbin', 'PROMPT_COMMAND': 'printf "\\033]0;<mock-chroot>\\007"', 'PS1': '<mock-chroot> \\s-\\v\\$ ', 'LANG': 'en_US.utf8'} and shell False
DEBUG: BUILDSTDERR: DEBUG: Unsharing. Flags: 134217728
DEBUG: BUILDSTDERR: Failed to register machine: The name is not activatable
DEBUG: Child return code was: 1

also this happens with mock 1.4.14 too, so it seems like 1.4.14 vs. 1.4.15 is not why this suddenly started happening. I can't imagine what *is* the reason, though.

Comment 2 Adam Williamson 2019-04-29 23:05:43 UTC
The difference seems to be dbus-broker-20-4 (vs. dbus-broker-20-3)...and reboots. Odd.

Briefly:

* If you have dbus-broker-20-4 running, do 'dnf -y install mock' and then immediately 'mock -r fedora-30-x86_64 --shell', it will fail.

* If you have dbus-broker-20-4 running, do 'dnf -y install mock', *reboot* and then do 'mock -r fedora-30-x86_64 --shell', it will work.

* If you have dbus-broker-20-3 running, do 'dnf -y install mock' and then immediately 'mock -r fedora-30-x86_64 --shell', it will work.

Comment 3 Adam Williamson 2019-04-29 23:13:58 UTC
Doing a 'systemctl restart dbus-broker' seems to have the same effect as rebooting: it makes it work. With dbus-broker-20-4 running, after first doing 'dnf install mock', you can run 'mock -r fedora-30-x86_64 --shell' as many times as you like and it will fail each time. If you run 'systemctl restart dbus-broker' and try again, it will succeed.

Comment 4 David Rheinsberg 2019-04-30 11:41:24 UTC
Is it sufficient to reload the configuration instead of restarting/rebooting?

`busctl call org.freedesktop.DBus /org/freedesktop/DBus org.freedesktop.DBus ReloadConfig`

Also, does your log print any dbus-broker related *errors*? This really sounds like a failing configuration reload, which should be printed in the logs. It does not really explain why `20-3` works, though. Mhh

Comment 5 David Rheinsberg 2019-04-30 12:25:32 UTC
I discussed this with Tom, and there is one more addition:

With `20-3` and earlier, an incorrect configuration causes a dbus-broker crash, and as such dbus-broker is automatically restarted. This would explain why an explicit restart is needed with `20-4` and later. So yes, the logs should point at the problematic configuration and the package that provides it. I will try to reproduce this in the meantime.

Comment 6 Adam Williamson 2019-05-01 18:06:14 UTC
"Is it sufficient to reload the configuration instead of restarting/rebooting?

`busctl call org.freedesktop.DBus /org/freedesktop/DBus org.freedesktop.DBus ReloadConfig`"

No. The mock command still fails after doing this.

"Also, does your log print any dbus-broker related *errors*?"

So, I re-ran this whole process:

1. Started from fresh install
2. Installed mock
3. Tried 'mock -r fedora-30-x86_64 --shell', it failed
4. Did the ReloadConfig command
5. Tried 'mock -r fedora-30-x86_64 --shell' again, it failed again
6. Did 'systemctl restart dbus-broker.service'
7. Tried 'mock -r fedora-30-x86_64 --shell' again, it succeeded

And noted the output of 'journalctl -b | grep -i dbus' at each point. Here is the full contents, with indications of when each set of messages showed up:

Apr 29 14:58:26 localhost.localdomain audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=dbus-broker comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 29 14:58:26 localhost.localdomain dbus-broker-lau[704]: Ready
Apr 29 14:58:27 localhost.localdomain dbus-broker-launch[704]: Activation request for 'org.freedesktop.resolve1' failed: The systemd unit 'dbus-org.freedesktop.resolve1.service' could not be found.
Apr 29 14:58:30 localhost.localdomain NetworkManager[713]: <warn>  [1556575110.3053] dns-sd-resolved[0x55720e99e840]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
Apr 29 14:58:30 localhost.localdomain NetworkManager[713]: <warn>  [1556575110.3054] dns-sd-resolved[0x55720e99e840]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
Apr 29 14:58:30 localhost.localdomain NetworkManager[713]: <warn>  [1556575110.3056] dns-sd-resolved[0x55720e99e840]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
Apr 29 14:58:30 localhost.localdomain NetworkManager[713]: <warn>  [1556575110.3057] dns-sd-resolved[0x55720e99e840]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.

=== ABOVE MESSAGES ARE PRESENT JUST ON SYSTEM BOOT AND LOGIN ===

Apr 29 15:01:37 localhost.localdomain dbus-broker-launch[704]: Noticed file-system modification, trigger reload.
Apr 29 15:01:37 localhost.localdomain dbus-broker-launch[704]: Noticed file-system modification, trigger reload.

=== ABOVE MESSAGES APPEARED AFTER 'dnf -y install mock' ===

=== NO NEW MESSAGES APPEARED DURING STEPS 3 THROUGH 5 ===

May 01 11:00:36 localhost.localdomain dbus-broker[705]: Dispatched 2048 messages @ 7(±20)μs / message.
May 01 11:00:36 localhost.localdomain NetworkManager[713]: <warn>  [1556733636.0762] ifcfg-rh: dbus: com.redhat.ifcfgrh1 bus closed
May 01 11:00:36 localhost.localdomain systemd[1]: dbus-broker.service: Succeeded.
May 01 11:00:36 localhost.localdomain audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=dbus-broker comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 01 11:00:36 localhost.localdomain audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=dbus-broker comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 01 11:00:36 localhost.localdomain dbus-broker-lau[9342]: Ready

=== ABOVE MESSAGES APPEARED AFTER RESTARTING DBUS-BROKER ===

=== NO NEW MESSAGES APPEARED DURING THE SUCCESFUL 'mock' RUN AFTER RESTARTING THE BROKER ===

Comment 7 David Rheinsberg 2019-05-02 10:05:02 UTC
Created attachment 1561489 [details]
launch: mark new services as loaded on configuration reload

Comment 8 David Rheinsberg 2019-05-02 10:06:17 UTC
I can now reproduce this (it didn't reproduce in docker, but with a VM+minimalinstall I see the issue). I attached a patch for dbus-broker and will verify that it fixes the issue. If it does, I will open a PR to the dbus-broker package and backport the patch.

Thanks a lot for your investigation!

Comment 9 Fedora Update System 2019-05-02 14:56:57 UTC
dbus-broker-21-1.fc30 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-1c0ab31d35

Comment 10 Fedora Update System 2019-05-03 04:12:26 UTC
dbus-broker-21-1.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-1c0ab31d35

Comment 11 Fedora Update System 2019-05-03 12:37:59 UTC
dbus-broker-21-2.fc30 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-4c057073ca

Comment 12 Fedora Update System 2019-05-04 01:57:41 UTC
dbus-broker-21-2.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-4c057073ca

Comment 13 Fedora Update System 2019-05-06 00:45:34 UTC
dbus-broker-21-2.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.

Comment 14 Adam Williamson 2019-05-21 20:37:10 UTC
Thanks for the fix! Sorry I didn't reply earlier, I went on vacation. :)

Comment 15 Plamen Vasilev 2019-09-13 11:52:41 UTC
The problem still persist on Fedora 30 and
dbus-broker-21-3.fc30.x86_64

--
Sep 13 07:56:54 localhost.localdomain NetworkManager[990]: <warn>  [1568350614.2455] dns-sd-resolved[0x5624754e3c60]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
Sep 13 07:56:54 localhost.localdomain NetworkManager[990]: <warn>  [1568350614.2455] dns-sd-resolved[0x5624754e3c60]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
Sep 13 08:37:47 localhost.localdomain NetworkManager[1073]: <warn>  [1568353067.2437] dns-sd-resolved[0x55e25dd73c30]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
Sep 13 08:37:47 localhost.localdomain NetworkManager[1073]: <warn>  [1568353067.2438] dns-sd-resolved[0x55e25dd73c30]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
Sep 13 08:37:47 localhost.localdomain NetworkManager[1073]: <warn>  [1568353067.2438] dns-sd-resolved[0x55e25dd73c30]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
Sep 13 08:37:47 localhost.localdomain NetworkManager[1073]: <warn>  [1568353067.2438] dns-sd-resolved[0x55e25dd73c30]: Failed: GDBus.Error:org.freedesktop.DBus.Error.NameHasNoOwner: Could not activate remote peer.
--

Comment 16 Mauro Carvalho Chehab 2019-11-20 09:01:22 UTC
I'm getting this error with a machine recently upgraded to Fedora 31.

DEBUG util.py:427:  Unsharing. Flags: 134217728
DEBUG util.py:596:  Failed to register machine: The name is not activatable
DEBUG util.py:596:  Parent died too early
DEBUG util.py:744:  Child return code was: 1
DEBUG util.py:763:  child environment: None
DEBUG util.py:686:  Using nspawn with args None
DEBUG util.py:689:  Executing command: ['/usr/bin/systemd-nspawn', '-q', '-M', 'da0ac7e0a1294faaac01bdd994ec8a5e', '-D', '/var
/lib/mock/fedora-31-x86_64/root', '-a', '--setenv=TERM=vt100', '--setenv=SHELL=/bin/bash', '--setenv=HOME=/builddir', '--seten
v=HOSTNAME=mock', '--setenv=PATH=/usr/bin:/bin:/usr/sbin:/sbin', '--setenv=PROMPT_COMMAND=printf "\\033]0;<mock-chroot>\\007"'
, '--setenv=PS1=<mock-chroot> \\s-\\v\\$ ', '--setenv=LANG=pt_BR.UTF-8', '/usr/sbin/groupadd', '-g', '135', 'mock'] with env {
'TERM': 'vt100', 'SHELL': '/bin/bash', 'HOME': '/builddir', 'HOSTNAME': 'mock', 'PATH': '/usr/bin:/bin:/usr/sbin:/sbin', 'PROM
PT_COMMAND': 'printf "\\033]0;<mock-chroot>\\007"', 'PS1': '<mock-chroot> \\s-\\v\\$ ', 'LANG': 'pt_BR.UTF-8'} and shell False
DEBUG util.py:427:  Unsharing. Flags: 134217728
DEBUG util.py:596:  Failed to register machine: The name is not activatable
DEBUG util.py:596:  Parent died too early
DEBUG util.py:744:  Child return code was: 1
DEBUG util.py:329:  kill orphans
DEBUG util.py:763:  child environment: None
DEBUG util.py:689:  Executing command: ['/bin/umount', '-n', '/var/lib/mock/fedora-31-x86_64/root/var/cache/dnf/'] with env {'
TERM': 'vt100', 'SHELL': '/bin/sh', 'HOME': '/builddir', 'HOSTNAME': 'mock', 'PATH': '/usr/bin:/bin:/usr/sbin:/sbin', 'LANG': 
'pt_BR.UTF-8'} and shell False
DEBUG util.py:744:  Child return code was: 0

When I try to test if a new srpm for rasdaemon builds:

   $ mock `rpm --eval %{_topdir}`/SRPMS/rasdaemon-0.6.4*.src.rpm

I'm using the unmodified /etc/mock/default.cfg with comes with F31 package. Mock version is:

   mock-1.4.21-1.fc31.noarch

Comment 17 David Rheinsberg 2020-02-17 16:43:56 UTC
@Mauro Can you tell me how to reproduce that? I doubt this is related to the initial report, and we should CC the correct people. I am unsure, though, how you triggered this?


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