FS#41390 - [linux/xf86-video-intel] Screen brightness incorrectly restored by systemd at boot

Attached to Project: Arch Linux
Opened by Mike Cloaked (mcloaked) - Tuesday, 29 July 2014, 20:03 GMT
Last edited by Andreas Radke (AndyRTR) - Monday, 13 October 2014, 18:49 GMT
Task Type Bug Report
Category Upstream Bugs
Status Closed
Assigned To Jan de Groot (JGC)
Andreas Radke (AndyRTR)
Laurent Carlier (lordheavy)
Architecture All
Severity Low
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 5
Private No

Details

Description:

After updates to xorg server 1.16 and related packages, Thinkpad S540 has screen brightness restored to very low value at boot and shutdown. KDE sets usable normal brightness after login so the system is usable, but the bug needs to be fixed so that if watching for errors before X starts or at shutdown the screen should be properly visible. Possible systemd bug.


Additional info:
* package version(s)
* config and/or log files etc.

The current kernel and version of xorg server, and systemd, are:
$ uname -r
3.15.7-1-ARCH

$ pacman -Q xorg-server
xorg-server 1.16.0-5

$ sudo pacman -Q systemd
systemd 215-4

Brightness values when logged in to KDE are:

$ ls -1 /sys/class/backlight/intel_backlight/*brightness | xargs -I % sh -c "echo % ; cat %"
/sys/class/backlight/intel_backlight/actual_brightness
937
/sys/class/backlight/intel_backlight/brightness
937
/sys/class/backlight/intel_backlight/max_brightness
937
$ ls -1 /sys/class/backlight/acpi_video0/*brightness | xargs -I % sh -c "echo % ; cat %"
/sys/class/backlight/acpi_video0/actual_brightness
100
/sys/class/backlight/acpi_video0/brightness
100
/sys/class/backlight/acpi_video0/max_brightness
100

However the journal log shows the likely problem:
Jul 29 17:56:28 lenovo1 systemd[1]: Created slice system-systemd\x2dbacklight.slice.
Jul 29 17:56:28 lenovo1 systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:acpi_video0...
Jul 29 17:56:28 lenovo1 kernel: thinkpad_acpi: ThinkPad ACPI Extras v0.25
Jul 29 17:56:28 lenovo1 kernel: thinkpad_acpi: http://ibm-acpi.sf.net/
Jul 29 17:56:28 lenovo1 kernel: thinkpad_acpi: ThinkPad BIOS GPET58WW (1.58 ), EC unknown
Jul 29 17:56:28 lenovo1 kernel: thinkpad_acpi: Lenovo ThinkPad S5-S540, model 20B3CTO1WW
Jul 29 17:56:28 lenovo1 systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:intel_backlight...
Jul 29 17:56:28 lenovo1 kernel: snd_hda_intel 0000:00:1b.0: irq 61 for MSI/MSI-X
Jul 29 17:56:28 lenovo1 kernel: tpm_tis 00:0b: 1.2 TPM (device-id 0x0, rev-id 78)
Jul 29 17:56:28 lenovo1 kernel: ACPI Error: [\_SB_.PCI0.GFX0.DD02._BCL] Namespace lookup failure, AE_NOT_FOUND (20
Jul 29 17:56:28 lenovo1 kernel: ACPI Error: Method parse/execution failed [\_SB_.PCI0.RP05.PEGP.DD02._BCL] (Node f
Jul 29 17:56:28 lenovo1 kernel: thinkpad_acpi: detected a 8-level brightness capable ThinkPad
Jul 29 17:56:28 lenovo1 kernel: thinkpad_acpi: This ThinkPad has standard ACPI backlight brightness control, suppo
Jul 29 17:56:28 lenovo1 kernel: thinkpad_acpi: Disabling thinkpad-acpi brightness events by default...
Jul 29 17:56:28 lenovo1 systemd-backlight[200]: Saved brightness 11 too low; increasing to 46.
Jul 29 17:56:28 lenovo1 kernel: snd_hda_intel 0000:00:03.0: irq 62 for MSI/MSI-X
Jul 29 17:56:28 lenovo1 kernel: ACPI Exception: AE_BAD_PARAMETER, Returned by Handler for [EmbeddedControl] (20140
Jul 29 17:56:28 lenovo1 kernel: ACPI Error: Method parse/execution failed [\_TZ_.TZ01._TMP] (Node ffff880226839cd0
Jul 29 17:56:28 lenovo1 kernel: ACPI Exception: AE_BAD_PARAMETER, Returned by Handler for [EmbeddedControl] (20140
Jul 29 17:56:28 lenovo1 kernel: ACPI Error: Method parse/execution failed [\_TZ_.TZ01._TMP] (Node ffff880226839cd0
Jul 29 17:56:28 lenovo1 systemd[1]: Started Load/Save Screen Backlight Brightness of backlight:acpi_video0.
Jul 29 17:56:28 lenovo1 systemd[1]: Started Load/Save Screen Backlight Brightness of backlight:intel_backlight.


Steps to reproduce:

Update system, reboot.

Since this may be an upstream bug I have filed also at https://bugs.freedesktop.org/show_bug.cgi?id=81884 where there are journal logs with diagnostics information.
This task depends upon

Closed by  Andreas Radke (AndyRTR)
Monday, 13 October 2014, 18:49 GMT
Reason for closing:  Fixed
Additional comments about closing:  and upstream anyways.
Comment by Laurent Carlier (lordheavy) - Tuesday, 29 July 2014, 20:13 GMT
probable an xf86-video-intel bug. can you try this fix?
http://cgit.freedesktop.org/xorg/driver/xf86-video-intel/commit/?id=5935c93ce77a5da09aab9b45b1a5710d681c171e
Comment by Mike Cloaked (mcloaked) - Tuesday, 29 July 2014, 20:16 GMT
I have not done building packages with patches applied to the source so I would need to learn how to do that. If there is a package file with that patch already applied that I can download from a server then I could easily pacman install to test it.

For completeness this is the current update for the package in the system today:
/var/log/pacman.log:[2014-07-29 15:17] [PACMAN] upgraded xf86-video-intel (2.99.912-2 -> 2.99.914-1)
Comment by Mike Cloaked (mcloaked) - Wednesday, 30 July 2014, 13:31 GMT
It looks like systemd is not storing the brightness values correctly so maybe xf86-video-intel is involved as well as systemd? Anyway I checked the values that systemd stored and they look as follows:

# cat /var/lib/systemd/backlight/pci-0000\:00\:02.0\:backlight\:acpi_video0
100
# cat /var/lib/systemd/backlight/pci-0000\:00\:02.0\:backlight\:intel_backlight
11

So the value in intel_backlight is certainly incorrect - the above values were checked after KDE resets the brightness correctly. So the numbers in the /sys/ area are set right but on shutdown it seems that the saved values by systemd are wrong:

# ls -1 /sys/class/backlight/*/*brightness | xargs -I % sh -c "echo % ; cat %"
/sys/class/backlight/acpi_video0/actual_brightness
100
/sys/class/backlight/acpi_video0/brightness
100
/sys/class/backlight/acpi_video0/max_brightness
100
/sys/class/backlight/intel_backlight/actual_brightness
937
/sys/class/backlight/intel_backlight/brightness
937
/sys/class/backlight/intel_backlight/max_brightness
937

These values are not getting saved by systemd but the intel value is somehow becoming 11 instead of 937
Comment by Dave Reisner (falconindy) - Wednesday, 30 July 2014, 14:35 GMT
> I have not done building packages with patches applied to the source so I would need to learn how to do that.
Now's a great time to do that: https://wiki.archlinux.org/index.php/Patch

> It looks like systemd is not storing the brightness values correctly so maybe xf86-video-intel is involved as well as systemd?
I think you're jumping to conclusions rather prematurely. The commit you were linked shows that there's a bug in how brightness values are updated when switching out of Xorg and into a VT. systemd is just reading (and storing) whatever's in sysfs at shutdown.
Comment by Mike Cloaked (mcloaked) - Wednesday, 30 July 2014, 19:12 GMT
Thank you Dave - I'll do some reading and try to compile with the patch in between other tasks. Yes you are right about premature conclusion. When I ask the system to shut down from KDE it comes out of X into a VT and then reduces the brightness level for the rest of the shutdown. When I get a chance to patch the xf86-video-intel package and test it it will help pin this down a bit more.
Comment by Mike Cloaked (mcloaked) - Wednesday, 30 July 2014, 19:51 GMT
I got the package xf86-video-intel package built in abs including the patch referenced above, and installed it in my system to replace the package from [extra]. Unfortunately it makes no difference to the symptoms, and after rebooting several times there was no change and I verified that the saved value in /var/lib/systemd/backlight/pci-0000\:00\:02.0\:backlight\:intel_backlight remains at the value 11.
Comment by Mike Cloaked (mcloaked) - Wednesday, 30 July 2014, 21:27 GMT
I have some progress now. After doing a pacman update that included upgraded kdelibs (4.13.3-1 -> 4.13.3-2), and then shutting down completely and booting from cold seems to have resolved the issue! I checked the stored brightness value which is at /var/lib/systemd/backlight/pci-0000\:00\:02.0\:backlight\:intel_backlight and it gives 937 which is correct!

I tested by reverting the xf86-video-intel package to that in [core] and the problem with brightness returned. Re-installing the amended package containing the patch http://cgit.freedesktop.org/xorg/driver/xf86-video-intel/commit/?id=5935c93ce77a5da09aab9b45b1a5710d681c171e fixes the issue again. So indeed the patch did "seem" fix the problem. Whether additionally I needed to fully shutdown and boot from cold only, or whether the additional update to kdelibs was crucial I don't know, but with both the version 4.13.3-2 of kdelibs as well as the patched xf86-video-intel this seemed resolved.
Comment by Mike Cloaked (mcloaked) - Wednesday, 30 July 2014, 21:44 GMT
I spoke too soon - after thinking this was resolved - I shut down the laptop - the brightness went dim again. Booting from cold showed the same low brightness again! After logging in to KDE I checked the stored value and it was back to 11 again! So this problem seems to be recurring at random now instead of being there every time I boot!
Comment by Mike Cloaked (mcloaked) - Thursday, 31 July 2014, 09:43 GMT
I was trying to find any clues to further this issue. I restarted the systemd backlight service and then looked at the two stored values.

# systemctl restart systemd-backlight@backlight:acpi_video0.service
yielding in the journal log:
Jul 31 10:35:15 lenovo1 systemd[1]: Stopping Load/Save Screen Backlight Brightness of backlight:acpi_video0...
Jul 31 10:35:15 lenovo1 systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:acpi_video0...
Jul 31 10:35:15 lenovo1 systemd[1]: Started Load/Save Screen Backlight Brightness of backlight:acpi_video0.

Then looking at timestamps for the stored values:
$ ls -l /var/lib/systemd/backlight/pci-0000\:00\:02.0\:backlight\:*
-rw-r--r-- 1 root root 4 Jul 31 10:35 /var/lib/systemd/backlight/pci-0000:00:02.0:backlight:acpi_video0
-rw-r--r-- 1 root root 3 Jul 31 10:14 /var/lib/systemd/backlight/pci-0000:00:02.0:backlight:intel_backlight

So the intel value has a timestamp related to the boot time whereas the acpi value was updated when the systemd-backlight service restarted. It is the intel value that is incorrect, and it is also a puzzle as to where the numerical value of 11 has come from. If it is reading the values from the /sys/ area then none of the values seems related and should be 937.
Comment by Mike Cloaked (mcloaked) - Thursday, 31 July 2014, 20:50 GMT
One further piece of information - if during the boot process or after login to KDE I use the function key plus brightness down button and then function key plus brightness up button to return to full brightness, and then reboot the machine, this next reboot does not show the display dimming problem. But subsequent boots will again show the display dimming until the system is logged back in to KDE again.

Yet the value of the stored brightness remains at 11 even when using the above technique.

$ cat /var/lib/systemd/backlight/pci-0000\:00\:02.0\:backlight\:*
100
11

Comment by Luca Viggiani (lviggiani) - Friday, 01 August 2014, 15:02 GMT
I have the same issue on Intel HD 3000.

I discovered that:

1) Set the brightness to 50% with fn keys
2) Manually stop systemd-backlight@backlight:acpi_video0.service FROM GNOME terminal (while gdm is running)
3) Reboot

Brightness is restored at 50% as expected.
It looks like, in normal condition, systemd-backlight service is stopped after xsession has terminated and we are at VT when screen brightness is pushed to 100%.
Comment by Miroslav Koškár (mkoskar) - Friday, 01 August 2014, 22:21 GMT
On recommendation reposting from https://bbs.archlinux.org/viewtopic.php?id=184949 here.

My observations, test-case:

Boot.
Systemd restores values of 'acpi_video0' / 'intel_backlight' correctly.
Log into vc1.
Change backlight by writing to 'acpi_video0' or 'intel_backlight' (both work for me).
Start X session by "startx" like script manually.
Backlight is kept as set in vc1 before.

But now, whenever I switch to other virtual console, or I just quit X, brightness is reset.
It would just all be fine if X server (or probably the driver for that matter) wouldn't do anything and just keep the brightness as is.

I've tried to play with X server "intel"'s driver "Backlight" setting without any success.
E.g. having backlight set to '10' via 'acpi_video0' in X I get:

/sys/class/backlight/acpi_video0: 10 from 15
/sys/class/backlight/intel_backlight: 1287 from 4437

Switching to vc2 (having started X with "Backlight" "acpi_video0") I get:

/sys/class/backlight/acpi_video0: 15 from 15
/sys/class/backlight/intel_backlight: 52 from 4437

and screen is dimmed to reflect the "52" above.

Switching to vc2 (having started X with "Backlight" "intel_backlight") I get:

/sys/class/backlight/acpi_video0: 10 from 15
/sys/class/backlight/intel_backlight: 4437 from 4437

here the screen is reset to full brightness.

Everytime when I switch back to X virtual console, brightness is reset to the value which was set there before (just before switching to text virtual console) or the new one which was manually set in virtual console by writing to 'acpi_video0' or 'intel_backlight'.

Booting with "video.use_native_backlight=1 acpi_backlight=vendor" doesn't make any difference in regards to this issue.
Comment by Mike Cloaked (mcloaked) - Saturday, 02 August 2014, 11:37 GMT
This is the current journal log with drm.debug=0xe added to the kernel line to help in diagnosis - all packages are up to date, including today's update to xorg-xrandr 1.4.3-1
   journal-log-debug-2.log (183.6 KiB)
Comment by Mike Cloaked (mcloaked) - Wednesday, 13 August 2014, 08:59 GMT
After update to kernel 3.16.0-2-ARCH this issue is resolved, so I am presuming this was a kernel bug that was fixed in the 3.16 kernel.
Comment by Luca Viggiani (lviggiani) - Saturday, 13 September 2014, 21:14 GMT
  • Field changed: Percent Complete (100% → 0%)
I still have this bug with linux-3.16.1-1
Comment by Andreas Radke (AndyRTR) - Sunday, 12 October 2014, 08:34 GMT
Fixed for me in kernel 3.17.0 and LTS kernel also works for me.
Comment by Bartłomiej Piotrowski (Barthalion) - Sunday, 12 October 2014, 21:07 GMT
Works for me on linux-lts. Seems we can close it.

Loading...