Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] intel_backlight is broken #247

Closed
mq1 opened this issue Mar 22, 2022 · 10 comments
Closed

[BUG] intel_backlight is broken #247

mq1 opened this issue Mar 22, 2022 · 10 comments
Labels
bug Something isn't working f35 Related to Fedora 35 f36 Related to Fedora 36

Comments

@mq1
Copy link

mq1 commented Mar 22, 2022

Describe the bug
systemd-backlight@backlight:intel_backlight.service fails to start and screen brightness is reset on reboot

To Reproduce
Boot up a clean install of Fedora Silverblue on an intel laptop

Expected behavior
The service starts and the screen brightness level doesn't reset on reboot

Screenshots

× systemd-backlight@backlight:intel_backlight.service - Load/Save Screen Backlight Brightness of backlight:intel_backlight
     Loaded: loaded (/usr/lib/systemd/system/systemd-backlight@.service; static)
     Active: failed (Result: exit-code) since Tue 2022-03-22 11:17:37 CET; 11min ago
       Docs: man:systemd-backlight@.service(8)
    Process: 852 ExecStart=/usr/lib/systemd/systemd-backlight load backlight:intel_backlight (code=exited, status=238/STATE_DIRECTORY)
   Main PID: 852 (code=exited, status=238/STATE_DIRECTORY)
        CPU: 2ms

Mar 22 11:17:37 mq1-laptop systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:intel_backlight...
Mar 22 11:17:37 mq1-laptop systemd[852]: systemd-backlight@backlight:intel_backlight.service: Failed to set up special execution directory in /var/lib: Read-only file system
Mar 22 11:17:37 mq1-laptop systemd[852]: systemd-backlight@backlight:intel_backlight.service: Failed at step STATE_DIRECTORY spawning /usr/lib/systemd/systemd-backlight: Read-only file system
Mar 22 11:17:37 mq1-laptop systemd[1]: systemd-backlight@backlight:intel_backlight.service: Main process exited, code=exited, status=238/STATE_DIRECTORY
Mar 22 11:17:37 mq1-laptop systemd[1]: systemd-backlight@backlight:intel_backlight.service: Failed with result 'exit-code'.
Mar 22 11:17:37 mq1-laptop systemd[1]: Failed to start Load/Save Screen Backlight Brightness of backlight:intel_backlight.

OS version:

State: idle
BootedDeployment:
● fedora:fedora/35/x86_64/silverblue
                   Version: 35.20220322.0 (2022-03-22T02:56:22Z)
                BaseCommit: d0a7a3e317538cd5a04c55545a2cb32f8d37f736bbf8dfb3a511c286c947ea2d
              GPGSignature: Valid signature by 787EA6AE1147EEE56C40B30CDB4639719867C58F
           LayeredPackages: gnome-shell-extension-appindicator tailscale
@tpopela
Copy link
Contributor

tpopela commented Mar 22, 2022

Looks like this is coreos/fedora-coreos-tracker#488 that was supposed to be resolved in ostree-2020.3-4 - @jlebon @dustymabe any idea ?

@jlebon
Copy link
Member

jlebon commented Mar 22, 2022

Not sure what's going on there. Do you have a separate partition for /var? Can you show the output of ostree-remount.service and var.mount?

Actually, just the full journal for the boot would be helpful.

@mq1
Copy link
Author

mq1 commented Mar 22, 2022

Not sure what's going on there. Do you have a separate partition for /var? Can you show the output of ostree-remount.service and var.mount?

I don't have a separate partition for /var, actually I used the default Fedora partitioning for an ancrypted install

[mq1@mq1-laptop ~]$ systemctl status ostree-remount.service
● ostree-remount.service - OSTree Remount OS/ Bind Mounts
     Loaded: loaded (/usr/lib/systemd/system/ostree-remount.service; enabled; vendor preset: enabled)
     Active: active (exited) since Tue 2022-03-22 18:42:49 CET; 3min 10s ago
       Docs: man:ostree(1)
    Process: 852 ExecStart=/usr/lib/ostree/ostree-remount (code=exited, status=0/SUCCESS)
   Main PID: 852 (code=exited, status=0/SUCCESS)
        CPU: 8ms

Mar 22 18:42:49 mq1-laptop systemd[1]: Starting OSTree Remount OS/ Bind Mounts...
Mar 22 18:42:49 mq1-laptop ostree-remount[852]: Remounted rw: /sysroot
Mar 22 18:42:49 mq1-laptop ostree-remount[852]: Remounted rw: /var
Mar 22 18:42:49 mq1-laptop systemd[1]: Finished OSTree Remount OS/ Bind Mounts.

● var.mount - /var
     Loaded: loaded (/run/systemd/generator/var.mount; generated)
     Active: active (mounted) since Tue 2022-03-22 18:42:49 CET; 4min 21s ago
      Where: /var
       What: /dev/mapper/luks-c9490e19-6b48-4a79-9c09-9384a5df69f7
       Docs: man:ostree(1)
      Tasks: 0 (limit: 9185)
     Memory: 4.0K
        CPU: 3ms
     CGroup: /system.slice/var.mount

Mar 22 18:42:49 mq1-laptop systemd[1]: Mounting /var...
Mar 22 18:42:49 mq1-laptop systemd[1]: Mounted /var.

Actually, just the full journal for the boot would be helpful.

How can I provide you this?

@tpopela
Copy link
Contributor

tpopela commented Mar 22, 2022 via email

@mq1
Copy link
Author

mq1 commented Mar 22, 2022

Dne út 22. 3. 2022 18:55 uživatel Manuel Quarneti @.***> napsal:
Actually, just the full journal for the boot would be helpful. How can I provide you this?
Attach the output of journalctl -b here.
…

boot.txt

@har7an
Copy link

har7an commented Mar 31, 2022 •
edited
Loading

Hi, I've hit the same issue on a different PC that I installed Silverblue on a few days ago. It seems to me that /var/lib is r/o during system startup, or at least when the backlight systemd service tries to create the directories in it.
Once the system is booted, you can manually call:

sudo mkdir -p /var/lib/systemd/backlight

The next time you reboot you will see the services no longer fail and start as expected. You can then change the screen brightness and the setting will be saved/restored as expected.

EDIT: Also note this doesn't only affect intel_backlight but in fact any sort of backlight controlled by systemd.

@mq1
Copy link
Author

mq1 commented May 11, 2022

This seems resolved as of fedora 36

@tpopela
Copy link
Contributor

tpopela commented May 12, 2022

Thank you @mq1 ! Let us know if it shows up again.

@tpopela tpopela closed this as completed May 12, 2022
@MateusRodCosta
Copy link

Happening for me right now on Fedora 36:

● fedora:fedora/36/x86_64/silverblue
                   Version: 36.20220512.1 (2022-05-12T20:00:12Z)
                BaseCommit: 298486a9757785902e07482e5a71008e521e9d1c92d7a98e6bc25ac53c966f9f
              GPGSignature: Valid signature by 53DED2CB922D8B8D9E63FD18999F7CBF38AB71F4

systemctl status:

[mateusrc@centauro ~]$ systemctl status systemd-backlight@backlight\:intel_backlight.service 
× systemd-backlight@backlight:intel_backlight.service - Load/Save Screen Backlight Brightness of backlight:intel_backlight
     Loaded: loaded (/usr/lib/systemd/system/systemd-backlight@.service; static)
     Active: failed (Result: exit-code) since Fri 2022-05-13 17:42:51 -03; 13min ago
       Docs: man:systemd-backlight@.service(8)
    Process: 1072 ExecStart=/usr/lib/systemd/systemd-backlight load backlight:intel_backlight (code=exited, status=238/STATE_DIRECTORY)
   Main PID: 1072 (code=exited, status=238/STATE_DIRECTORY)
        CPU: 1ms

mai 13 17:42:51 centauro systemd[1]: Starting systemd-backlight@backlight:intel_backlight.service - Load/Save Screen Backlight Brightness of backlight:intel_backlight...
mai 13 17:42:51 centauro systemd[1072]: systemd-backlight@backlight:intel_backlight.service: Failed to set up special execution directory in /var/lib: Read-only file system
mai 13 17:42:51 centauro systemd[1072]: systemd-backlight@backlight:intel_backlight.service: Failed at step STATE_DIRECTORY spawning /usr/lib/systemd/systemd-backlight: Read-only file system
mai 13 17:42:51 centauro systemd[1]: systemd-backlight@backlight:intel_backlight.service: Main process exited, code=exited, status=238/STATE_DIRECTORY
mai 13 17:42:51 centauro systemd[1]: systemd-backlight@backlight:intel_backlight.service: Failed with result 'exit-code'.
mai 13 17:42:51 centauro systemd[1]: Failed to start systemd-backlight@backlight:intel_backlight.service - Load/Save Screen Backlight Brightness of backlight:intel_backlight.

And logs from around that time:

mai 13 17:42:51 centauro systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems.
mai 13 17:42:51 centauro systemd[1]: var.mount: Directory /var to mount over is not empty, mounting anyway.
mai 13 17:42:51 centauro kernel: input: Dell WMI hotkeys as /devices/platform/PNP0C14:05/wmi_bus/wmi_bus-PNP0C14:05/9DBB5994-A997-11DA-B012-B622A1EF5492/input/input17
mai 13 17:42:51 centauro systemd[1]: Mounting var.mount - /var...
mai 13 17:42:51 centauro systemd[1]: Starting systemd-fsck@dev-disk-by\x2duuid-20533e09\x2d3e5b\x2d4573\x2da5ed\x2d6e6f5a2ea374.service - File System Check on /dev/disk/by-uuid/20533e09-3e5b-4573-a5ed-6e6f5a2ea374...
mai 13 17:42:51 centauro systemd[1]: Starting systemd-fsck@dev-disk-by\x2duuid-9188\x2d6415.service - File System Check on /dev/disk/by-uuid/9188-6415...
mai 13 17:42:51 centauro systemd[1]: Mounted var.mount - /var.
mai 13 17:42:51 centauro systemd[1]: Mounting var-home.mount - /var/home...
mai 13 17:42:51 centauro systemd[1]: var-lib-machines.mount - Virtual Machine and Container Storage (Compatibility) was skipped because of a failed condition check (ConditionPathExists=/var/lib/machines.raw).
mai 13 17:42:51 centauro systemd[1]: Starting ostree-remount.service - OSTree Remount OS/ Bind Mounts...
mai 13 17:42:51 centauro systemd[1]: Starting systemd-backlight@backlight:intel_backlight.service - Load/Save Screen Backlight Brightness of backlight:intel_backlight...
mai 13 17:42:51 centauro systemd[1072]: systemd-backlight@backlight:intel_backlight.service: Failed to set up special execution directory in /var/lib: Read-only file system
mai 13 17:42:51 centauro systemd[1072]: systemd-backlight@backlight:intel_backlight.service: Failed at step STATE_DIRECTORY spawning /usr/lib/systemd/systemd-backlight: Read-only file system
mai 13 17:42:51 centauro systemd[1]: Mounted var-home.mount - /var/home.
mai 13 17:42:51 centauro systemd[1]: systemd-backlight@backlight:intel_backlight.service: Main process exited, code=exited, status=238/STATE_DIRECTORY
mai 13 17:42:51 centauro systemd[1]: systemd-backlight@backlight:intel_backlight.service: Failed with result 'exit-code'.
mai 13 17:42:51 centauro systemd[1]: Failed to start systemd-backlight@backlight:intel_backlight.service - Load/Save Screen Backlight Brightness of backlight:intel_backlight.
mai 13 17:42:51 centauro audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-backlight@backlight:intel_backlight comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
mai 13 17:42:51 centauro kernel: RAPL PMU: API unit is 2^-32 Joules, 5 fixed counters, 655360 ms ovfl timer
mai 13 17:42:51 centauro kernel: RAPL PMU: hw unit of domain pp0-core 2^-14 Joules
mai 13 17:42:51 centauro kernel: RAPL PMU: hw unit of domain package 2^-14 Joules
mai 13 17:42:51 centauro kernel: RAPL PMU: hw unit of domain dram 2^-14 Joules
mai 13 17:42:51 centauro kernel: RAPL PMU: hw unit of domain pp1-gpu 2^-14 Joules
mai 13 17:42:51 centauro kernel: RAPL PMU: hw unit of domain psys 2^-14 Joules
mai 13 17:42:51 centauro systemd-fsck[1078]: fsck.fat 4.2 (2021-01-31)
mai 13 17:42:51 centauro systemd-fsck[1078]: /dev/nvme0n1p1: 17 files, 2501/153296 clusters
mai 13 17:42:51 centauro systemd-fsck[1077]: /dev/nvme0n1p2: limpo, 30/65536 ficheiros, 34088/262144 blocos
mai 13 17:42:51 centauro systemd[1]: Finished systemd-fsck@dev-disk-by\x2duuid-9188\x2d6415.service - File System Check on /dev/disk/by-uuid/9188-6415.
mai 13 17:42:51 centauro audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-fsck@dev-disk-by\x2duuid-9188\x2d6415 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
mai 13 17:42:51 centauro systemd[1]: Finished systemd-fsck@dev-disk-by\x2duuid-20533e09\x2d3e5b\x2d4573\x2da5ed\x2d6e6f5a2ea374.service - File System Check on /dev/disk/by-uuid/20533e09-3e5b-4573-a5ed-6e6f5a2ea374.
mai 13 17:42:51 centauro audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-fsck@dev-disk-by\x2duuid-20533e09\x2d3e5b\x2d4573\x2da5ed\x2d6e6f5a2ea374 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
mai 13 17:42:51 centauro systemd[1]: Found device dev-zram0.device - /dev/zram0.
mai 13 17:42:51 centauro systemd[1]: Starting systemd-zram-setup@zram0.service - Create swap on /dev/zram0...
mai 13 17:42:51 centauro kernel: usb 1-5: Found UVC 1.00 device Integrated_Webcam_HD (0c45:671f)
mai 13 17:42:51 centauro kernel: zram0: detected capacity change from 0 to 16777216
mai 13 17:42:51 centauro zram-generator[1086]: Configurando espaço de swap versão 1, tamanho = 8 GiB (8589930496 bytes)
mai 13 17:42:51 centauro zram-generator[1086]: LABEL=zram0, UUID=b4945e53-fab1-42a9-8901-faab2722ac7b
mai 13 17:42:51 centauro systemd-makefs[1085]: /dev/zram0 successfully formatted as swap (label "zram0", uuid b4945e53-fab1-42a9-8901-faab2722ac7b)
mai 13 17:42:51 centauro ostree-remount[1071]: Remounted rw: /sysroot
mai 13 17:42:51 centauro ostree-remount[1071]: Remounted rw: /var

Those were asked above, so sending as well:

[mateusrc@centauro ~]$ systemctl status ostree-remount.service 
● ostree-remount.service - OSTree Remount OS/ Bind Mounts
     Loaded: loaded (/usr/lib/systemd/system/ostree-remount.service; enabled; vendor preset: enabled)
     Active: active (exited) since Fri 2022-05-13 17:42:51 -03; 26min ago
       Docs: man:ostree(1)
    Process: 1071 ExecStart=/usr/lib/ostree/ostree-remount (code=exited, status=0/SUCCESS)
   Main PID: 1071 (code=exited, status=0/SUCCESS)
        CPU: 22ms

mai 13 17:42:51 centauro systemd[1]: Starting ostree-remount.service - OSTree Remount OS/ Bind Mounts...
mai 13 17:42:51 centauro ostree-remount[1071]: Remounted rw: /sysroot
mai 13 17:42:51 centauro ostree-remount[1071]: Remounted rw: /var
mai 13 17:42:51 centauro systemd[1]: Finished ostree-remount.service - OSTree Remount OS/ Bind Mounts.

[mateusrc@centauro ~]$ systemctl status var.mount
● var.mount - /var
     Loaded: loaded (/run/systemd/generator/var.mount; generated)
     Active: active (mounted) since Fri 2022-05-13 17:42:51 -03; 25min ago
      Until: Fri 2022-05-13 17:42:51 -03; 25min ago
      Where: /var
       What: /dev/mapper/luks-<snip>
       Docs: man:ostree(1)
      Tasks: 0 (limit: 18875)
     Memory: 4.0K
        CPU: 2ms
     CGroup: /system.slice/var.mount

mai 13 17:42:51 centauro systemd[1]: Mounting var.mount - /var...
mai 13 17:42:51 centauro systemd[1]: Mounted var.mount - /var.

Actually, looking at my logs, it looks like /var is mounted first as read only, which is probably why it's given a go to systemd-backlight to run. Problem is, the ostree-remount.service is delayed by the need of doing an fsck on my disk, so systemd-backlight ran before /var was remounted as rw.

I believe the problem here is not that ostree-remount.service is running at the wrong time (it most likely shouldn't run before the fsck), but that systemd-backlight should wait for it to run for ostree-remount.service to run first.

If it's really due to fsck, this might explain why the problem might appear fixed, as your system will likely not run a fsck every time.

For reference, this is my ostree-remount.service right now:

[mateusrc@centauro ~]$ systemctl cat ostree-remount.service 
# /usr/lib/systemd/system/ostree-remount.service
# Copyright (C) 2013 Colin Walters <walters@verbum.org>
#
# This library is free software; you can redistribute it and/or
# modify it under the terms of the GNU Lesser General Public
# License as published by the Free Software Foundation; either
# version 2 of the License, or (at your option) any later version.
#
# This library is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
# Lesser General Public License for more details.
#
# You should have received a copy of the GNU Lesser General Public
# License along with this library. If not, see <https://www.gnu.org/licenses/>.

[Unit]
Description=OSTree Remount OS/ Bind Mounts
Documentation=man:ostree(1)
DefaultDependencies=no
ConditionKernelCommandLine=ostree
OnFailure=emergency.target
Conflicts=umount.target
# Run after core mounts
After=-.mount var.mount
After=systemd-remount-fs.service
# But we run *before* most other core bootup services that need write access to /etc and /var
Before=local-fs.target umount.target
Before=systemd-random-seed.service plymouth-read-write.service systemd-journal-flush.service
Before=systemd-tmpfiles-setup.service systemd-rfkill.service systemd-rfkill.socket

[Service]
Type=oneshot
RemainAfterExit=yes
ExecStart=/usr/lib/ostree/ostree-remount
StandardInput=null
StandardOutput=journal
StandardError=journal+console

[Install]
WantedBy=local-fs.target

Probably every other service that is marked on "Before" that needs /var rw is also broken.

IMHO, there are two fixes:

The one that will fix this for now would be to add a snippet to systemd-backlight@.service to add "After=ostree-remount.service" so it is ordered after /var is rw.

The other fix and the one that I think would be the true fix (although it would most likely require upstream changes to systemd) is the creation of a var-rw.target, which units that need to write to /var should add rules to run after it's reached. Not sure if it will be only useful for ostree system or might be extended to other types too.

Also, btw, if you do implement any of the two fixes, please restore /sysroot ro.

@travier travier added bug Something isn't working help wanted labels Jun 13, 2022
@travier travier reopened this Jun 13, 2022
@travier travier added f35 Related to Fedora 35 f36 Related to Fedora 36 labels May 15, 2023
@travier
Copy link
Member

travier commented May 15, 2023

Fedora 36 is about to go EOL so I'll close this issue. Please provide updated information if this is still an issue.

@travier travier closed this as not planned Won't fix, can't repro, duplicate, stale May 15, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working f35 Related to Fedora 35 f36 Related to Fedora 36
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@tpopela @jlebon @MateusRodCosta @mq1 @travier @har7an