Bug 78200 - [regression] Backlight too dim to use from kernel 3.14 and systemd error
Summary: [regression] Backlight too dim to use from kernel 3.14 and systemd error
Status: RESOLVED FIXED
Alias: None
Product: systemd
Classification: Unclassified
Component: general (show other bugs)
Version: unspecified
Hardware: x86 (IA32) Linux (All)
: medium normal
Assignee: systemd-bugs
QA Contact: systemd-bugs
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-05-02 16:56 UTC by Mike C
Modified: 2014-05-15 02:43 UTC (History)
2 users (show)

See Also:
i915 platform:
i915 features:


Attachments
systemd journal log when booted with drm.debug=6 (140.87 KB, text/plain)
2014-05-06 13:05 UTC, Mike C
Details
Output of ps -eaf after logging in to KDE (14.56 KB, text/plain)
2014-05-06 13:06 UTC, Mike C
Details
systemd journal log when systemd.restore_state=0 (103.26 KB, text/plain)
2014-05-07 10:25 UTC, Mike C
Details
system log for drm.debug=0xe systemd.restore_state=0 (138.16 KB, text/plain)
2014-05-07 15:16 UTC, Mike C
Details
system log for drm.debug=0xe systemd.restore_state=0 (138.96 KB, text/plain)
2014-05-07 15:50 UTC, Mike C
Details

Description Mike C 2014-05-02 16:56:38 UTC
Since kernel 3.14 was released to arch linux in my Samsung Q35 laptop the boot starts with normal screen brightness but when X starts it dims to a level where the screen is unusable.  The brightness can be restored using the keyboard key combinations.  

I reverted to kernel 3.13.7-1-ARCH and the screen brightness seemed normal but an investigation of the systemd journal showed there were errors that are relevant to this issue:

May 02 17:08:49 samsung1 systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:intel_backlight...
May 02 17:08:49 samsung1 systemd-backlight[191]: Failed to write system attribute: Invalid argument
May 02 17:08:49 samsung1 systemd[1]: systemd-backlight@backlight:intel_backlight.service: main process exited, code=exited, status=1/FAI
May 02 17:08:49 samsung1 systemd[1]: Failed to start Load/Save Screen Backlight Brightness of backlight:intel_backlight.
May 02 17:08:49 samsung1 systemd[1]: Unit systemd-backlight@backlight:intel_backlight.service entered failed state.


# lspci
00:00.0 Host bridge: Intel Corporation Mobile 945GM/PM/GMS, 943/940GML and 945GT Express Memory Controller Hub (rev 03)
00:02.0 VGA compatible controller: Intel Corporation Mobile 945GM/GMS, 943/940GML Express Integrated Graphics Controller (rev 03)
00:02.1 Display controller: Intel Corporation Mobile 945GM/GMS/GME, 943/940GML Express Integrated Graphics Controller (rev 03)
00:1b.0 Audio device: Intel Corporation NM10/ICH7 Family High Definition Audio Controller (rev 02)
00:1c.0 PCI bridge: Intel Corporation NM10/ICH7 Family PCI Express Port 1 (rev 02)
00:1c.1 PCI bridge: Intel Corporation NM10/ICH7 Family PCI Express Port 2 (rev 02)
00:1d.0 USB controller: Intel Corporation NM10/ICH7 Family USB UHCI Controller #1 (rev 02)
00:1d.1 USB controller: Intel Corporation NM10/ICH7 Family USB UHCI Controller #2 (rev 02)
00:1d.2 USB controller: Intel Corporation NM10/ICH7 Family USB UHCI Controller #3 (rev 02)
00:1d.3 USB controller: Intel Corporation NM10/ICH7 Family USB UHCI Controller #4 (rev 02)
00:1d.7 USB controller: Intel Corporation NM10/ICH7 Family USB2 EHCI Controller (rev 02)
00:1e.0 PCI bridge: Intel Corporation 82801 Mobile PCI Bridge (rev e2)
00:1f.0 ISA bridge: Intel Corporation 82801GBM (ICH7-M) LPC Interface Bridge (rev 02)
00:1f.1 IDE interface: Intel Corporation 82801G (ICH7 Family) IDE Controller (rev 02)
00:1f.3 SMBus: Intel Corporation NM10/ICH7 Family SMBus Controller (rev 02)
02:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)
05:05.0 Ethernet controller: Broadcom Corporation BCM4401-B0 100Base-TX (rev 02)
05:09.0 CardBus bridge: Ricoh Co Ltd RL5c476 II (rev b4)
05:09.1 FireWire (IEEE 1394): Ricoh Co Ltd R5C552 IEEE 1394 Controller (rev 09)
05:09.2 SD Host controller: Ricoh Co Ltd R5C822 SD/SDIO/MMC/MS/MSPro Host Adapter (rev 18)
05:09.3 System peripheral: Ricoh Co Ltd R5C592 Memory Stick Bus Host Adapter (rev 09)
05:09.4 System peripheral: Ricoh Co Ltd xD-Picture Card Controller (rev 04)
Comment 1 Mike C 2014-05-02 19:40:09 UTC
After update to kernel 3.14.2-1-ARCH the corresponding section of the journal is:

May 02 20:32:34 samsung1 systemd[1]: Starting system-systemd\x2dbacklight.slice.
May 02 20:32:34 samsung1 systemd[1]: Created slice system-systemd\x2dbacklight.slice.
May 02 20:32:34 samsung1 systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:intel_backlight...
May 02 20:32:35 samsung1 kernel: microcode: CPU1 sig=0x6e8, pf=0x20, revision=0x39
May 02 20:32:35 samsung1 kernel: microcode: Microcode Update Driver: v2.00 <tigran@aivazian.fsnet.co.uk>, Peter Oruba
May 02 20:32:35 samsung1 kernel: psmouse serio4: synaptics: Touchpad model: 1, fw: 6.2, id: 0x25a0b1, caps: 0xa04713/0x200000/0x0, board
May 02 20:32:35 samsung1 kernel: input: SynPS/2 Synaptics TouchPad as /devices/platform/i8042/serio4/input/input16
May 02 20:32:35 samsung1 kernel: mousedev: PS/2 mouse device common for all mice
May 02 20:32:35 samsung1 systemd[1]: Started Load/Save RF Kill Switch Status of rfkill0.
May 02 20:32:35 samsung1 systemd[1]: Started Load/Save Screen Backlight Brightness of backlight:intel_backlight.

The screen dims to an unusable, but not quite black, level during the early phases of boot.

If I use the Fn+up arrow key clicked once only the brightness returns to full but a short time later it dims again when the login screen for KDE is presented. I can use the keyboard to again return the brightness to full, and can then login to KDE. At the point where KDE is logged in the screen again dims to unusable, but I can still use the keyboard to set the brightness up again.

I have systemd as a mkinitcpio hook, and I will replace that with udev and base and see if that makes any difference.
Comment 2 Mike C 2014-05-02 20:01:53 UTC
Changing mkinicpio made no difference.

I have also tried adding acpi_osi=Linux acpi_backlight=vendor to the kernel line for boot and that makes no difference either.
Comment 3 Mike C 2014-05-02 21:01:32 UTC
Also with kernel 3.14.2-1-ARCH after increasing the brightness once logged in to KDE so that I can work the brightness parameters are:

# ls -1 /sys/class/backlight/intel_backlight/*brightness | xargs -I % sh -c "echo % ; cat %"
/sys/class/backlight/intel_backlight/actual_brightness
3793125
/sys/class/backlight/intel_backlight/brightness
14875
/sys/class/backlight/intel_backlight/max_brightness
3793125
Comment 4 Mike C 2014-05-05 20:40:21 UTC
May be related to https://bugzilla.kernel.org/show_bug.cgi?id=72491
Comment 5 Chris Wilson 2014-05-06 12:32:19 UTC
This sounds like userspace being silly. But can you check to see which commit makes the difference in the kernel? Also a drm.debug=6 should capture the backlight values as they are changed - I guess reporting the pid would help in this case though.
Comment 6 Mike C 2014-05-06 13:05:23 UTC
Created attachment 98558 [details]
systemd journal log when booted with drm.debug=6

Responding to comment #5 here is the system log for drm.debug=6 but I was not sure which PID was requested i.e. for which process? I will attach the output of ps -eaf as a file next.
Comment 7 Mike C 2014-05-06 13:06:39 UTC
Created attachment 98559 [details]
Output of ps -eaf after logging in to KDE

ps -eaf output to possible provide PID info for the journal log if this helps
Comment 8 Mike C 2014-05-06 13:10:51 UTC
Brightness parameters after the two attachments sent are:

$ ls -1 /sys/class/backlight/intel_backlight/*brightness | xargs -I % sh -c "echo % ; cat %"
/sys/class/backlight/intel_backlight/actual_brightness
3544500
/sys/class/backlight/intel_backlight/brightness
13900
/sys/class/backlight/intel_backlight/max_brightness
3793125
Comment 9 Mike C 2014-05-06 16:47:19 UTC
I am not set up for kernel bisect and the machine concerned is very slow. It would be nice to know the commit responsible but maybe the other data I posted will help.
Comment 10 Jani Nikula 2014-05-07 07:46:01 UTC
(In reply to comment #0)
> I reverted to kernel 3.13.7-1-ARCH and the screen brightness seemed normal
> but an investigation of the systemd journal showed there were errors that
> are relevant to this issue:
> 
> May 02 17:08:49 samsung1 systemd[1]: Starting Load/Save Screen Backlight
> Brightness of backlight:intel_backlight...
> May 02 17:08:49 samsung1 systemd-backlight[191]: Failed to write system
> attribute: Invalid argument
> May 02 17:08:49 samsung1 systemd[1]:
> systemd-backlight@backlight:intel_backlight.service: main process exited,
> code=exited, status=1/FAI
> May 02 17:08:49 samsung1 systemd[1]: Failed to start Load/Save Screen
> Backlight Brightness of backlight:intel_backlight.
> May 02 17:08:49 samsung1 systemd[1]: Unit
> systemd-backlight@backlight:intel_backlight.service entered failed state.

Looking at the systemd source, it seems to me this happens because there's a too high saved value for backlight. I don't know how it got there, but the clamping and error handling don't take this into account. Try removing, uh, the relevant looking files from /var/lib/systemd/backlight/ - there should be file(s) containing the saved values, named with escaped names of the interfaces.

If that doesn't help, try systemd.restore_state=0 on the kernel command line. There may be a way to pass that to systemd directly too, but I'm rather clueless about systemd details. Let us know if that helps.

Finally, please try 3.15-rc kernels; I think there's a fix or two there that haven't propagated to stable kernels yet.
Comment 11 Jani Nikula 2014-05-07 07:51:42 UTC
Oh, and the systemd failure to restore the saved backlight value might be the reason 3.13 works for you!
Comment 12 Mike C 2014-05-07 10:22:17 UTC
There was a single file in /var/lib/systemd/backlight/ which I deleted - on rebooting the symptoms were the same as before, and the file was recreated.

I also booted with systemd.restore_state=0 on the kernel line, and this did make a difference in that the brightness then remained full until and including when the KDM login greeter was on the screen, but once I entered the user password the screen then dimmed, as before, between entering the login details and the user being logged in to the KDE desktop. Again using the keyboard Fn+up arrow just once restores the brightness.

There was a boot error on the screen during this test with the systemd failure to save/restore but it went past quickly so I will attach the journal log shortly soon after the boot and login.

This was with kernel 3.14.2-1-ARCH.  I had previously built kernel 3.15rc3-1 and tested on the same laptop but it made no difference to the screen dimming issue. (It takes over three hours to build a kernel on that machine and I have no other 32 bit machine to run builds for that architecture.)  So unless there has been commits that might provide a fix since rc3 then I guess that this issue remains unresolved.

I am still not clear if this is a kernel issue or a systemd issue? However the same version of systemd gave a working system for the earlier 3.13 kernels and a broken system with 3.14 and 3.15 so maybe the answer lies in the kernel?
Comment 13 Mike C 2014-05-07 10:25:11 UTC
Created attachment 98613 [details]
systemd journal log when systemd.restore_state=0
Comment 14 Jani Nikula 2014-05-07 12:57:12 UTC
(In reply to comment #13)
> Created attachment 98613 [details]
> systemd journal log when systemd.restore_state=0

Please do this with drm.debug=0xe module parameter to get useful logging from the driver.
Comment 15 Mike C 2014-05-07 15:16:23 UTC
Created attachment 98630 [details]
system log for drm.debug=0xe systemd.restore_state=0

This is with kernel 3.14.2-1 as before
Comment 16 Mike C 2014-05-07 15:44:07 UTC
The addition of systemd.restore_state does actually fix the issue - the behaviour of the screen dimming after entering the KDE login info is my fault and due to a file that I had previously set up to execute on KDE login which sets the screen brightness - but the numerical value that goes into the command I have changed to:

echo 3793125  > /sys/class/backlight/intel_backlight/brightness

and this works fine as this value is the same as the max brightness.

The value previously was originally very low, but matched the max brightness parameter that used to be listed in the same directory, and so dimmed the screen - it seems that in one of the recent updates presumably to the kernel the max brightness numerical value increased by over a factor of 20 and therefore the value I had set during KDE login was no longer appropriate.

However during the boot process without the kernel parameter systemd.restore_state=0 the screen still dims to almost black soon after the initial hard drive fsck lines on the screen, so the workaround gets the brightness working through the boot and through the desktop login, but without it the brightness problem remains.

I will upload a new journal log shortly.

Executing the command as root:
echo 3413812  > /sys/class/backlight/intel_backlight/brightness

dims the screen a little as expected.
Comment 17 Mike C 2014-05-07 15:50:27 UTC
Created attachment 98633 [details]
system log for drm.debug=0xe systemd.restore_state=0

System log with systemd.restore_state=0 and drm debug which gives normal brightness throughout boot and through to KDE login.

brightness Load/save error was still visible during boot.
Comment 18 Mike C 2014-05-07 16:54:08 UTC
This bug is resolved and was indeed due to the script that I had executing during KDE login that set the screen brightness. After changing my kde script and rebooting an appropriate brightness value was stored, and then used at next login.

After making the change to my script and rebooting the brightness no longer exhibited a problem.

Therefore there is no kernel or systemd bug, and I will close this report as resolved.

The problem that led to my confusion was that at some point a kernel update changed the max_brightness value from the driver for my system, but my original script set the brightness at login numerically and this value became inappropriate after the kernel change.  However using the Fn + Up Arrow keys did not reset the value in /sys/class/backlight/intel_backlight/brightness despite the screen becoming normal brightness, and so this low value persisted when systemd saved the current value and restored it at next boot.

Sorry it took me so long to recognise that it was my kde script that was causing the symptoms.
Comment 19 Jani Nikula 2014-05-07 19:25:08 UTC
(In reply to comment #18)
> Therefore there is no kernel or systemd bug, and I will close this report as
> resolved.
> 
> The problem that led to my confusion was that at some point a kernel update
> changed the max_brightness value from the driver for my system

This is likely because of the fix

commit b6ab66aa5d376583a17137cbb2d3a728f29acae2
Author: Jani Nikula <jani.nikula@intel.com>
Date:   Tue Feb 25 13:11:47 2014 +0200

    drm/i915: use backlight legacy combination mode also for i915gm/i945gm

which would have that effect, and it matches your platform.

I think you trying different kernel versions with and without that patch lead to systemd saving and then using out of range saved brightness value on 3.13. I think it's a bug in systemd, while it's not the root cause here. I sent a bug report in the disguise of a patch to systemd [1] to fix this:

http://mid.gmane.org/1399453261-31967-1-git-send-email-jani.nikula@intel.com

> However using the Fn + Up
> Arrow keys did not reset the value in
> /sys/class/backlight/intel_backlight/brightness despite the screen becoming
> normal brightness, and so this low value persisted when systemd saved the
> current value and restored it at next boot.

This is probably due to ACPI handling the keys. Depending on the BIOS on your system, it's possible we sync that to the intel_backlight brightness too in recent kernels.

> Sorry it took me so long to recognise that it was my kde script that was
> causing the symptoms.

No worries. Thanks for following up, and I'm glad you figured it out.
Comment 20 Mike C 2014-05-07 21:01:27 UTC
Thank you Jani for sending the systemd patch and hopefully that will get followed up.
Comment 21 Zbigniew Jedrzejewski-Szmek 2014-05-08 00:07:05 UTC
Patch applied in http://cgit.freedesktop.org/systemd/systemd/commit/?id=0c9d8f1d/
Comment 22 Mike C 2014-05-08 07:23:27 UTC
Looking at the link in #21 there is a message "Bad object id: 0c9d8f1d/" - I guess it is a simple error to fix.
Comment 23 Jani Nikula 2014-05-08 08:13:38 UTC
(In reply to comment #22)
> Looking at the link in #21 there is a message "Bad object id: 0c9d8f1d/" - I
> guess it is a simple error to fix.

http://cgit.freedesktop.org/systemd/systemd/commit/?id=0c9d8f1d


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.