Bug 1744059 - Workstation live installer does not run due to /usr/sbin preceding /usr/bin in liveuser's $PATH since GDM 3.33.90
Summary: Workstation live installer does not run due to /usr/sbin preceding /usr/bin i...
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: 31
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: openqa
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-08-21 08:41 UTC by František Zatloukal
Modified: 2019-09-21 22:11 UTC (History)
29 users (show)

Fixed In Version: systemd-243-1.fc31
Clone Of:
Environment:
Last Closed: 2019-09-21 22:11:27 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
GNOME Gitlab GNOME/gdm/merge_requests/71 0 None None None 2019-08-22 20:40:40 UTC
Github systemd systemd pull 13406 0 None None None 2019-08-26 13:30:45 UTC

Description František Zatloukal 2019-08-21 08:41:32 UTC
Description of problem:
Welcome to Fedora application cannot launch anaconda in order to install Fedora 31 from Workstation Live. Launching Anaconda directly (skipping Welcome to Fedora) works just fine.

Interesting part of the journal:
Aug 21 04:33:57 localhost-live fedora-welcome.desktop[1892]: /usr/sbin/setenforce:  setenforce() failed
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/pci0000:00/0000:00:07.0/virtio3/block/vda/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/pci0000:00/0000:00:07.0/virtio3/block/vda/vda1/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/pci0000:00/0000:00:07.0/virtio3/block/vda/vda2/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/pci0000:00/0000:00:07.0/virtio3/block/vda/vda3/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/pci0000:00/0000:00:07.0/virtio3/block/vda/vda4/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/pci0000:00/0000:00:0a.0/ata1/host0/target0:0:0/0:0:0:0/block/sr0/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/virtual/block/loop0/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/virtual/block/loop1/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/virtual/block/loop2/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/virtual/block/zram0/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/virtual/block/dm-0/uevent': Permission denied
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Failed to write 'change' to '/sys/devices/virtual/block/dm-1/uevent': Permission denied
Aug 21 04:33:58 localhost-live udisksd[1035]: Loading module libudisks2_iscsi.so...
Aug 21 04:33:58 localhost-live udisksd[1035]: g_object_notify: object class 'UDisksObjectSkeleton' has no property named 'manager-iscsi-initiator'
Aug 21 04:33:58 localhost-live udisksd[1035]: Error probing device: Error sending ATA command IDENTIFY PACKET DEVICE to '/dev/sr0': Unexpected sense data returned:
                                              0000: 70 00 05 00  00 00 00 0a  00 58 00 01  21 04 00 00    p........X..!...
                                              0010: 00 00 00 00  00 00 00 00  00 00 00 00  00 00 00 00    ................
                                               (g-io-error-quark, 0)
Aug 21 04:33:58 localhost-live python3[2315]: detected unhandled Python exception in '/usr/bin/anaconda-cleanup'
Aug 21 04:33:58 localhost-live python3[2315]: can't communicate with ABRT daemon, is it running? [Errno 2] No such file or directory
Aug 21 04:33:58 localhost-live python3[2315]: error sending data to ABRT daemon: 
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: Traceback (most recent call last):
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/bin/anaconda-cleanup", line 80, in <module>
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     devicetree.populate(cleanup_only=True)
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/threads.py", line 53, in run_with_lock
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     return m(*args, **kwargs)
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/populator/populator.py", line 414, in populate
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     self._populate()
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/threads.py", line 53, in run_with_lock
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     return m(*args, **kwargs)
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/populator/populator.py", line 459, in _populate
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     self.handle_device(dev)
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/threads.py", line 53, in run_with_lock
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     return m(*args, **kwargs)
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/populator/populator.py", line 265, in handle_device
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     device = helper_class(self, info).run()
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/populator/helpers/partition.py", line 100, in run
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     exists=True, parents=[disk])
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/threads.py", line 53, in run_with_lock
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     return m(*args, **kwargs)
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:   File "/usr/lib/python3.7/site-packages/blivet/devices/partition.py", line 185, in __init__
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]:     self._parted_partition = self.disk.format.parted_disk.getPartitionByPath(self.path)
Aug 21 04:33:58 localhost-live fedora-welcome.desktop[1892]: AttributeError: 'NoneType' object has no attribute 'getPartitionByPath'
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Loading information about products from /etc/anaconda/product.d.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found Fedora Workstation at /etc/anaconda/product.d/fedora-workstation.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found Red Hat Enterprise Linux at /etc/anaconda/product.d/rhel.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found Fedora at /etc/anaconda/product.d/fedora.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found CentOS Linux at /etc/anaconda/product.d/centos.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found Fedora Server at /etc/anaconda/product.d/fedora-server.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found Fedora Silverblue at /etc/anaconda/product.d/fedora-silverblue.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found Fedora Workstation Live at /etc/anaconda/product.d/fedora-workstation-live.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found Fedora AtomicHost at /etc/anaconda/product.d/fedora-atomic-host.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: Found Scientific Linux at /etc/anaconda/product.d/scientific-linux.conf.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: core.configuration.product: The product Fedora Workstation Live is supported.
Aug 21 04:33:59 localhost-live fedora-welcome.desktop[1892]: Starting installer, one moment...
Aug 21 04:33:59 localhost-live fedora-welcome.desktop[1892]: terminal size detection failed, using default width
Aug 21 04:33:59 localhost-live fedora-welcome.desktop[1892]: 04:33:59 anaconda must be run as root.
Aug 21 04:33:59 localhost-live anaconda[2331]: anaconda: stdout: anaconda must be run as root.
Aug 21 04:33:59 localhost-live fedora-welcome.desktop[1892]: /usr/sbin/setenforce:  setenforce() failed


Version-Release number of selected component (if applicable):
anaconda-31.22.2-1.fc31.x86_64


How reproducible:
Always

Steps to Reproduce:
1. Boot Fedora 31 Workstation Live in VM
2. Click on "Install to hard drive" button in Welcome to Fedora window

Actual results:
Nothing happens.

Expected results:
Anaconda should be launched.

Additional info:
https://openqa.fedoraproject.org/tests/433964#

Comment 1 Fedora Blocker Bugs Application 2019-08-21 08:52:48 UTC
Proposed as a Blocker for 31-beta by Fedora user frantisekz using the blocker tracking app because:

 'Launched normally' means from the boot menu on a dedicated installer image, and from the desktop on a live image.

Comment 2 František Zatloukal 2019-08-21 08:54:26 UTC
Damn, the reasoning should be "The installer must run when launched normally from the release-blocking images."

Sorry for the noise.

Comment 3 Adam Williamson 2019-08-21 16:52:13 UTC
Yeah, openqa hit this too. +1 blocker.

Comment 4 Jiri Konecny 2019-08-21 17:37:20 UTC
Looks like it could be a duplicate of this bug 1723979.

Switching component to blivet for further triaging.

Comment 5 Jiri Konecny 2019-08-21 17:39:53 UTC
Ohh sorry, you are talking about problem of running anaconda in the welcome screen. Switching back.

I guess I should end up with work for today...

Comment 6 Vendula Poncova 2019-08-22 13:10:06 UTC
From anaconda.log:
02:51:57,875 ERR stdout: anaconda must be run as root.

Anaconda fails because it is not run with root privileges.

From journalctl on Rawhide:
Aug 22 08:34:09 localhost-live userhelper[2183]: running '/usr/sbin/liveinst' with root privileges on behalf of 'liveuser'

When I compare the logs from Rawhide and Fedora 31, this line is missing on Fedora 31.

I doesn't seem to be a bug in Anaconda.

Comment 7 Adam Williamson 2019-08-22 18:33:47 UTC
The problem here is that /usr/sbin is on liveuser's $PATH in F31:

[liveuser@localhost-live ~]$ echo $PATH
/home/liveuser/.local/bin:/home/liveuser/bin:/usr/share/Modules/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin

liveinst is set up to work via consolehelper, which works by having /usr/bin/liveinst as a symlink to consolehelper, which acquires root privileges then runs /usr/sbin/liveinst . But because /usr/sbin is on liveuser's path, when liveuser runs 'liveinst' that simply becomes a call to /usr/sbin/liveinst directly and the whole consolehelper mechanism is skipped. To prove this, if you run '/usr/bin/liveinst' as liveuser, it works fine.

So, the question becomes 'why is /usr/sbin on liveuser's $PATH now?'

Comment 8 Adam Williamson 2019-08-22 18:39:41 UTC
...or to be more precise, the problem is that /usr/sbin is *before /usr/bin* in liveuser's $PATH. In F30, both are there, but /usr/bin is first:

[liveuser@localhost-live ~]$ echo $PATH
/home/liveuser/.local/bin:/home/liveuser/bin:/usr/share/Modules/bin:/usr/local/bin:/usr/local/sbin:/usr/bin:/usr/sbin

Comment 9 Adam Williamson 2019-08-22 19:46:55 UTC
So, I kicked this about a bit with sgallagh and nirik. More info we figured out:

* Fedora-Rawhide-20190820.n.0 is OK
* Fedora-31-20190804.n.0 is BAD
* Fedora-Rawhide-20190822.n.1 is BAD

so, the thing that broke this must be in both Fedora-31-20190804.n.0 and Fedora-Rawhide-20190822.n.1 but not in Fedora-Rawhide-20190820.n.0. I also confirmed that KDE lives from 'bad' composes are fine, so this is somehow specific to GNOME.

Given the above, our best suspect so far is this GDM commit: https://gitlab.gnome.org/GNOME/gdm/commit/2802e92d27450d86d81b6356dd532ec80e797223

which arrived in GDM 3.33.90, which did indeed appear in the two affected composes but was *not* in Fedora-Rawhide-20190820.n.0 .

So, assigning to GDM. I'm gonna do a quick test to confirm that commit is indeed the problem.

Comment 10 Adam Williamson 2019-08-22 20:32:56 UTC
OK, testing confirms that commit is indeed the problem. per halfline, that commit means gdm now creates user sessions with the $PATH that systemd sets, and per `man systemd.exec`:

       $PATH
           Colon-separated list of directories to use when launching executables. systemd uses a fixed value of
           /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin.

So that's our problem. At this point it's arguable whether the fix should be in gdm or systemd, so leaving assigned to GDM but CCing Zbigniew. I will do a GDM build for Rawhide and F31 with the commit reverted for now, but that's probably not the ideal fix.

Comment 11 Adam Williamson 2019-08-22 20:34:32 UTC
Zbigniew, what do you think of changing systemd here? halfline and I both reckon the convention for $PATH is that sbin directories come before bin directories for root, but bin comes before sbin for non-root. This is, for e.g., what /etc/profile does - see the block at the top involving pathmunge.

Comment 12 Adam Williamson 2019-08-26 02:04:46 UTC
The GDM build I did with the commit reverted does avoid this bug, so it's not affecting current composes any more. I don't want to close it just yet as we may want to find a better fix, but I'm dropping the blocker nomination as it's definitely not blocking any more.

Comment 13 Zbigniew Jędrzejewski-Szmek 2019-08-26 07:20:57 UTC
Damn, we discussed this before: https://github.com/systemd/systemd/issues/733. I'll revive my PR to change this.

Comment 14 Zbigniew Jędrzejewski-Szmek 2019-08-26 13:30:46 UTC
https://github.com/systemd/systemd/pull/13406

Comment 15 Zbigniew Jędrzejewski-Szmek 2019-09-21 22:11:27 UTC
This patch was included in v243.


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