led0 brightness file doesn't update after echo/write on kernel 5.10.63-v7+

[GravelSocks]

System
Hardware: Raspberry Pi 3B
OS: Raspian 10/Buster
Kernel Version: Linux raspberrypi 5.10.63-v7+ #1459 SMP Wed Oct 6 16:41:10 BST 2021 armv71 GNU/Linux
Firmware: Sep 30 2021 19:22:24
version 51215b4f6e3966401ecd99652a35cf1c25069113
Overlay: default -- not using the led overlay for gpio control

Describe the bug
After the recent kernel update (in the last week or so), /sys/class/leds/led0/brightness (or /sys/devices/platform/leds/leds/led0/brightness) no longer updates properly. I can turn led0 on/off manually with an echo command, but the value in the brightness file doesn't change (or only changes intermittently). The same function on led1 works normally and triggers for both leds are set to none.

To reproduce

1. set trigger for led0 to none
2. make /sys/class/leds/led0/brightness writeable. permissions of 666 (or use sudo for echo)
3. echo 0 > /sys/class/leds/led0/brightness
   -> turns off LED0 (green)
4. cat /sys/class/leds/led0/brightness
   -> reads back 255 -- brightness value was not updated
   -- or the same thing happens in reverse -- echo 1, light turns on, but value reads back as 0
5. It seems to update intermittently - maybe every other time I try the command. It is obviously being intercepted because led0 turns on and off. But, the value never gets written to brightness.

Generalized Testing
*The same tests work properly for led1 (red) and brightness is stored and reads properly
*Flushing the output doesn't seem to change the behavior
*Using tee or sudo doesn't seem to change the behavior
*/sys/class/leds/led1/brightness updates properly, as above
*This functionality was working fine on led0 prior to the recent kernel update

Expected behaviour
When echoing 1 to brightness, the led should turn on and brightness should update and cat as 255
When echoing 0 to brightness, the led should turn off and brightness should update and cat as 0

[pelwell]

3B is different from most other Pis in that its green LED is controlled by the firmware, with a dedicated kernel driver to manage the communications, so the problem might be due to a firmware change. However, the most useful information is the version of the last-known-good firmware+kernel.

On this page (https://github.com/raspberrypi/rpi-firmware/commits/master) is a list of software releases that can be installed using the rpi-update utility. The strings of hexadecimal characters on the right of the page are commit hashes that can be used with rpi-update to install that particular version. For example, sudo rpi-update ad5406d will install a release from August 12th. Pick a release far enough back that you are fairly confident that the LED was working as expected and install it. If it works, that is your "good" marker, and the "bad" marker is the top-of-tree. If it doesn't work, make that the "bad" marker and go back further, repeating until you find a "good". You then pick the mid-point between the two, install and test it, updating either the "bad" or "good" marker depending on the outcome. Eventually they should converge on the last-known good (or the first bad) release.

[GravelSocks]

Hi - thanks for the quick reply.

As in the report above, I think my 3B was fully updated and working properly before the newest release, so the last known good marker should be the latest official release right before the new kernel update. And, there is no trouble controlling the green LED/led0 at the hardware level - that part seems to work OK when I write new values to brightness. The problem seems like it is that the brightness file is not being updated when writing the new value - so OS bug? (unless that value comes from the firmware in real time every time a user opens the brightness file, in which case it would be a firmware/hardware state read-back issue, since the LED is physicially turning on and off immediately when I issue the echo statment).

When I issue...

echo 0/1 > /sys/class/leds/led0/brightness

...the green LED immediately turns off and on, respectively, on the board (but the brightness file in the OS does not always update).

When I issue...

echo 0/1 > /sys/class/leds/led1/brightness

...the red LED immediately turns off and on, respectively, and the brightness file always updates/reads back correctly.

Anyway, I am happy to try to regress the problem to help. However, before I do that, can someone see if it is reproducible on the dev side on a 3B so that I don't chase my tail for hours with multiple kernel reinstalls in the event that I screwed something else up and didn't realize it? It might be an easy/obvious fix and it should just take a couple of echos and cats on a current system with the 3B plugged in. Thank you for your help!

[pelwell]

I can confirm that I see the same behaviour on a 3B using the latest rpi-update kernel and firmware. 4B is not affected, and neither are 2B and B+, making me think it is due to some interaction with that virtual GPIO driver.

[pelwell]

Having read the driver, I don't see how reading back the brightness can ever have given the expected results consistently. The protocol between the driver and the firmware is designed to guarantee that any "on", however brief, results in the LED being lit for that period (roughly 100ms), but for it then to switched off unless there has been more activity. The .get method, however, is written as if it was just an array of bits, one per LED, leading to apparently random results - it's as if every change of the LED is another roll of the dice.

[pelwell]

Note that there is no back channel from the firmware to the driver, making it impossible for the driver to know the actual state of the LED now, but it should be able to return the eventual value assuming there are no more changes.

[pelwell]

Should be fixed by 03ab887, which will be in future kernel builds.

[GravelSocks]

Wow! Thanks for the quick response and help! I really appreciate you taking a look at it and doing the fix! Good job! From your review, did you happen to see why this issue didn't affect the red/led1 led? Thanks!

[pelwell]

Both of the LEDs on a 3B are driven by a GPIO expander that is controlled by the firmware from I2C0. The kernel SD/MMC drivers expect to be able drive the green activity LED frequently and rapidly, and we didn't like the idea of a kernel -> firmware -> kernel round trip each time, hence the creation of this special mechanism that decouples the two sides. The red power LED is also controlled remotely by the firmware on behalf of the kernel, but because we didn't think it would be accessed so frequently (and because it is also used to read the low-power detector) it uses the normal synchronous remote GPIO driver, which didn't have the same bug.

[GravelSocks]

Ah - very interesting - thanks for the explanation and great job! This fix is extremely helpful for me as a 3B user.

And, you just convinced me to buy RPi4 for my home automation system!

In case it helps anyone in the future, below is my updated led test code. Sorry for not posting it yesterday - was on my main computer. (If needed on Python 3.7 or earlier, convert match to if/else. And, am very new to Python, so sorry if there are any style issues. I want a semi-colon :'''( ^_^ )

[GravelSocks]

Hmm...pasting the python code didn't work very well -- surprising -- here is the file:
LED_Class.py.zip
.

[pelwell]

Use three backticks (```) in a row on lines of their own to begin and end chunks of code, like this:

#!/bin/sh
echo Hello World!

[GravelSocks]

Hmm...OK - I originally hit the code tag from the TinyMCE and it just gave me single backticks. So...using the manual backticks...yep...that works. So, the code tag button in the TinyMCE (greater/less than brackets icon) doesn't do the right thing - only generates single backticks.

#----------------------------------------------------------
#File: LED_Class.py
#Environment: Raspberry Pi 3B/Python 3.10
#Purpose: Class to control the built-in LEDs on the Raspberry Pie 3B/1.2
#Author: github.com/GravelSocks
#Date: 2021.10.18
#----------------------------------------------------------

class RPi_LED:

#----------------------------------------------------------
#constructor
    def __init__(self,led_name):
        match (led_name):
            case 'sys_red':
                self.name = 'led1'
            case 'sys_green':
                self.name = 'led0'
        self.location = '/sys/class/leds/'
        self.control = self.location+self.name+'/brightness'
        self.on = '1'
        self.off = '0'
        self.state = 0 
        print("created RPi_LED class for: ",self.name)
        
#----------------------------------------------------------
#destructor
    def __del__(self):
        print("Deleted RPi_LED class for: ",self.name)

#----------------------------------------------------------
    def get_led(self):
        """
        Function: get_led: get the LED state
        Description: check if the led for this class is on or off
        Parameters: N/A
        Returns: 1 if on, 0 if off, or error value
        """
 
        cmd = 'cat '+self.control
        import subprocess
        result = subprocess.check_output(cmd,shell=True).decode('utf-8').strip()
# Alternate parsing method, but subprocess may be preferable
#       import os
#       result = os.popen(cmd).read().strip()
        match (result):
            case '255':
                return 1
            case '0':
                return 0
            case _:
                print("Error in get_led - unexpected value: ",result)
                return result

#class methods
#----------------------------------------------------------
    def set_led(self,state):
        """
        Function: set_led: set the LED state
        Description: turn the LED on or off
        Parameters: state(int): state to set. 0: off; 1: on
        Returns: N/A
        """
        import os
#        import sys
        match (state):
            case 0:
                level = self.off
                self.state = state
            case 1:
                level = self.on
                self.state = state
            case _:
                print("bad brightness level")
#flush any pending output - needed?
#        sys.stdout.flush()
#write the command
        os.system('echo '+level+' > '+self.control)
#flush our output just in case - value is out of sync - needed?
#        sys.stdout.flush()

#----------------------------------------------------------
    def led_on(self,debug=False):
        """
        Function: led_on: turn on the led for this class
        Description: macro method to call set_led to turn on led
        Parameters: debug: debug flag to print activity
        Returns: N/A
        """
        if (debug):
            print("turning on: ",self.name)
        self.set_led(1)

#----------------------------------------------------------
    def led_off(self,debug=False):
        """
        Function: led_off: turn off the led for this class
        Description: macro method to call set_led to turn off led
        Parameters: debug: debug flag to print activity
        Returns: N/A
        """
        if (debug):
            print("turning off: ",self.name)
        self.set_led(0)

#----------------------------------------------------------
    def check_led(self,debug=False):
        """
        Function: check_led: check led status
        Description: compare the brightness value with the last known state
        Parameters: debug: debug flag to print status - default is False
        Returns: the value stored in brightness
        """
        result = self.get_led()
        if (debug):
            if (result != self.state):
                print ("ERROR: ",self.name," STATE IS INCORRECT")
            else:
                print (self.name," state matches last write")
        return result
    
#----------------------------------------------------------

def test_leds(args=None):
    #create the objects
    green = RPi_LED('sys_green')
    red = RPi_LED('sys_red')

    #turn on both system LEDs
    green.led_on(True)
    red.led_on(True)

    #check the LED status
    print("green on: ",green.check_led(True),flush=True)
    print("red on: ",red.check_led(True),flush=True)

    #turn off both system LEDs
    green.led_off(True)
    red.led_off(True)

    #check the LED status
    print("green off: ",green.check_led(True),flush=True)
    print("red off: ",red.check_led(True),flush=True)

    #delete the objects
    del green
    del red

def main(args=None):
    test_leds()
    
if __name__ == '__main__':
    main()

[GravelSocks]

Thanks for moving this fix forward and congrats on the PiZero 2W! Very cool/sleek! Is there an imminent kernel update on deck, especially considering the new 2W, or is 5.10.76(+) a month or 2 away along the lines of the usual RPi release heartbeat?

If still off in the future, I might try kernel building, assuming I can get the sphinx path to work. When there is gravel in your socks, it hurts your feet. ^_^

Also, my 8gb Pi4 B shows up in a few days, so that should distract me for a while (and won't have this bug). I am standing on a giant, flying SoC package singing "A Whole New World" from Aladdin.

[pelwell]

The stable firmware branch was updated today, and that should be in apt very soon (if it isn't there already).

[GravelSocks]

Thanks, pelwell! I don't see it yet, but I will look out for it and post the regression verification as soon as the new kernel is available. And, the Pi4 arrives today! w00t!

[GravelSocks]

Confirmed that the RPi4B does not have this issue on 5.10.63-v7l+ (expected outcome).

[GravelSocks]

Works great in kernel 5.15.0-v7+ on RPi3B/a02082 and RPi4B! My test program above returns no errors. Thx! It's so helpful to be able to use the system/internal LEDs for debugging! Resolved!