Skip to content

Did not receive initial ALS value in time #134

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.

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

Open
pasikonik opened this issue Jan 3, 2025 · 15 comments
Open

Did not receive initial ALS value in time #134

pasikonik opened this issue Jan 3, 2025 · 15 comments

Comments

@pasikonik
Copy link

pasikonik commented Jan 3, 2025

Intro

I have a long approach to the setup after buying a new laptop and unfortunately, I have a problem that I am unable to solve.

I have seen that this error repeats a few times and requires deep debugging. Unfortunately, I don't know Rust, so I'm not sure if I can help with this, but I will do everything in my power because I want this app so much.

I use Wayland and I have done permission section

What is the buggy behavior?

app crashes with Did not receive initial ALS value in time

What is the expected behavior?

don't crush

Logs

[2025-01-03T16:30:51Z DEBUG wluma] Using Config {
        als: Time {
            thresholds: {
                16: "normal",
                20: "night",
                0: "night",
                7: "dark",
                13: "bright",
                9: "dim",
                11: "normal",
                18: "dark",
            },
        },
        output: [
            Backlight(
                BacklightOutput {
                    name: "eDP-1",
                    path: "/sys/class/backlight/amdgpu_bl1",
                    capturer: None,
                    min_brightness: 1,
                },
            ),
            DdcUtil(
                DdcUtilOutput {
                    name: "DELL U2417H",
                    capturer: None,
                    min_brightness: 1,
                },
            ),
        ],
    }
[2025-01-03T16:30:51Z DEBUG wluma::brightness::backlight] Using direct write on /sys/class/backlight/amdgpu_bl1 to change brightness value
thread 'predictor-eDP-1' panicked at src/predictor/controller.rs:62:25:
Did not receive initial ALS value in time

Version

wluma 4.5.1

Environment

LSB Version:	n/a
Distributor ID:	ManjaroLinux
Description:	Manjaro Linux
Release:	24.2.1
Codename:	Yonada
Linux elrakieta 6.11.11-1-MANJARO #1 SMP PREEMPT_DYNAMIC Thu, 05 Dec 2024 16:26:44 +0000 x86_64 GNU/Linux
lib32-vulkan-icd-loader 1.4.303-1
lib32-vulkan-intel 1:24.2.8-1
lib32-vulkan-nouveau 1:24.2.8-1
lib32-vulkan-radeon 1:24.2.8-1
vulkan-headers 1:1.4.303-1
vulkan-icd-loader 1.4.303-1
vulkan-intel 1:24.2.8-1
vulkan-nouveau 1:24.2.8-1
vulkan-radeon 1:24.2.8-1
vulkan-validation-layers 1.3.296.0-1
zsh: command not found: dpkg
WLR_DRM_NO_MODIFIERS=
@maximbaz
Copy link
Owner

maximbaz commented Jan 3, 2025

Hey! Interesting 🤔 Does it reproduce every time, or only sometimes? Could you try without external display, does it reproduce too? Could you paste the logs with RUST_LOG=trace wluma (instead of debug)?

I tried on both the latest and 4.5.1 version, I am not sure how to reproduce 🤔 I don't have external display, that's the only difference 🤔

@pasikonik
Copy link
Author

pasikonik commented Jan 10, 2025

Indeed, you were right. I commented out the external monitor in config, and it seems to be working.

[2025-01-10T18:33:34Z DEBUG wluma] Using Config {
        als: Time {
            thresholds: {
                9: "dim",
                13: "bright",
                11: "normal",
                0: "night",
                16: "normal",
                7: "dark",
                18: "dark",
                20: "night",
            },
        },
        output: [
            Backlight(
                BacklightOutput {
                    name: "card1-eDP-1",
                    path: "/sys/class/backlight/amdgpu_bl1",
                    capturer: None,
                    min_brightness: 1,
                    predictor: Adaptive,
                },
            ),
        ],
    }
[2025-01-10T18:33:34Z DEBUG wluma::brightness::backlight] Using direct write on /sys/class/backlight/amdgpu_bl1 to change brightness value
[2025-01-10T18:33:34Z INFO  wluma] Continue adjusting brightness and wluma will learn your preference over time.
[2025-01-10T18:33:34Z TRACE wluma::als::time] ALS (time): dark (19)
[2025-01-10T18:33:34Z TRACE wluma::als::time] ALS (time): dark (19)
[2025-01-10T18:33:34Z TRACE wluma::als::time] ALS (time): dark (19)
[2025-01-10T18:33:34Z TRACE wluma::als::time] ALS (time): dark (19)
[2025-01-10T18:33:34Z TRACE wluma::als::time] ALS (time): dark (19)
[2025-01-10T18:33:34Z TRACE wluma::als::time] ALS (time): dark (19)

It's a shame becuase, unfortunately. I use external monitor all the time :/.
ah, so close...

@maximbaz
Copy link
Owner

I'm not really sure it's related to external screens specifically (does it work if you comment out the internal display instead?). If it still works, it sounds more like an issue with having multiple screens, whereas if it doesn't work then it sounds more like an issue specifically with external screen.

@pasikonik
Copy link
Author

It turns out to be an issue with multiple screens. After commenting out the internal monitor, it works correctly.

@maximbaz
Copy link
Owner

maximbaz commented Jan 10, 2025

Okay, good to know! Hmm I can't imagine how it's possible that nobody else has reported this so far, I thought there are plenty of users using it with multiple screens 🤔

Unfortunately I don't have an easy way to get a second screen to try this, how interested would you be to try to debug this?

The first simple thing could be to just run the latest code from main with RUST_LOG=trace cargo run with both monitors enabled in the config, I just pushed some additional debugging code that might help us figure out what's wrong.

@Harmiess-01
Copy link

I'm receiving the same error on my Surface Laptop Studio but am only using the built in monitor. I followed both the permissions and systemd methods in the README. However, using the webcam does work with the same monitor output.

Logs
Ambient light sensor:

[2025-01-20T21:46:52Z DEBUG wluma] Using Config {
        als: Iio {
            path: "/sys/bus/iio/devices",
            thresholds: {
                20: "dark",
                250: "normal",
                80: "dim",
                500: "bright",
                800: "outdoors",
                0: "night",
            },
        },
        output: [
            Backlight(
                BacklightOutput {
                    name: "eDP-1",
                    path: "/sys/class/backlight/intel_backlight",
                    capturer: None,
                    min_brightness: 1,
                    predictor: Adaptive,
                },
            ),
        ],
    }
[2025-01-20T21:46:52Z DEBUG wluma::brightness::backlight] Using direct write on /sys/class/backlight/intel_backlight to change brightness value
[2025-01-20T21:46:52Z INFO  wluma] Continue adjusting brightness and wluma will learn your preference over time.
thread 'predictor-eDP-1' panicked at src/predictor/controller/adaptive.rs:31:25:
Did not receive initial ALS value in time
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Webcam:

[2025-01-20T21:55:46Z DEBUG wluma] Using Config {
        als: Webcam {
            video: 0,
            thresholds: {
                30: "dim",
                60: "bright",
                0: "night",
                45: "normal",
                75: "outdoors",
                15: "dark",
            },
        },
        output: [
            Backlight(
                BacklightOutput {
                    name: "eDP-1",
                    path: "/sys/class/backlight/intel_backlight",
                    capturer: None,
                    min_brightness: 1,
                    predictor: Adaptive,
                },
            ),
        ],
    }
[2025-01-20T21:55:46Z DEBUG wluma::brightness::backlight] Using direct write on /sys/class/backlight/intel_backlight to change brightness value
[2025-01-20T21:55:46Z INFO  wluma] Continue adjusting brightness and wluma will learn your preference over time.

Version
4.6.1-1

Environment
Package: wluma AUR
DE: KDE Plasma 6.2.5
WM: KWin (Wayland)

LSB Version:    n/a
Distributor ID: EndeavourOS
Description:    EndeavourOS Linux
Release:        rolling
Codename:       rolling
Linux eos-surface 6.12.7-arch1-1-surface #1 SMP PREEMPT_DYNAMIC Sat, 28 Dec 2024 04:04:04 +0000 x86_64 GNU/Linux
egrep: warning: egrep is obsolescent; using grep -E
lib32-vulkan-icd-loader 1.4.303-1
vulkan-headers 1:1.4.303-1
vulkan-icd-loader 1.4.303-1
vulkan-tools 1.4.303-2
bash: dpkg: command not found
egrep: warning: egrep is obsolescent; using grep -E
WLR_DRM_NO_MODIFIERS=

@maximbaz
Copy link
Owner

Thanks for sharing your details! Does it crash right away or does it really wait 5 seconds and then crash?

4.6.1 unfortunately doesn't include the additional debugging I pushed for this issue, so we don't have much info to work against. Would you be interested to try debugging this locally, just adding some logs here and there to see where it gets stuck? Key locations are src/als/controller.rs and src/als/iio.rs.

@pasikonik
Copy link
Author

Sorry for being away for a bit, I forgot about this thread. I'll try to provide more logs soon.

@pasikonik
Copy link
Author

pasikonik commented Mar 24, 2025

Result of RUST_LOG=trace wluma so far.
After startup, unfortunately, the laptop's display froze.

[2025-03-24T13:21:25Z DEBUG wluma] == wluma v4.9.0 ==
[2025-03-24T13:21:25Z DEBUG wluma] Using Config {
        als: Time {
            thresholds: {
                0: "night",
                7: "dark",
                18: "dark",
                16: "normal",
                20: "night",
                11: "normal",
                9: "dim",
                13: "bright",
            },
        },
        output: [
            Backlight(
                BacklightOutput {
                    name: "card1-eDP-1",
                    path: "/sys/class/backlight/amdgpu_bl1",
                    capturer: None,
                    min_brightness: 1,
                    predictor: Adaptive,
                },
            ),
            DdcUtil(
                DdcUtilOutput {
                    name: "DELL U2417H",
                    capturer: None,
                    min_brightness: 1,
                    predictor: Adaptive,
                },
            ),
        ],
    }
[2025-03-24T13:21:25Z DEBUG wluma::brightness::backlight] Using direct write on /sys/class/backlight/amdgpu_bl1 to change brightness value
[2025-03-24T13:21:25Z TRACE ddc_hi] DisplayInfo::from_edid(I2cDevice, 22786)
[2025-03-24T13:21:30Z TRACE ddc_hi] DisplayInfo::from_capabilities(I2cDevice, 22786)
[2025-03-24T13:21:30Z DEBUG wluma::brightness::ddcutil] Discovered displays (check_caps=true): ["DELL U2417H 5K9YD87J128L DEL"]
[2025-03-24T13:21:30Z DEBUG wluma::brightness::ddcutil] Using display 'DELL U2417H 5K9YD87J128L DEL' for config 'DELL U2417H' (check_caps=true)

thread 'predictor-card1-eDP-1' panicked at src/predictor/controller/adaptive.rs:31:25:
Did not receive initial ALS value in time: Timeout
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

I'll try to do some debugging locally.

@pasikonik
Copy link
Author

pasikonik commented Mar 24, 2025

Unfortunately. I tried adding logs everywhere (controller.rs and iio.rs) where it might be helpful, and I didn't get any output except for the ones I have in the message above.

I was using: log::trace!

@maximbaz
Copy link
Owner

Please try using branch issue143, I added some extra logs around the initialization, that happens just before your timeout occurs, lets see what happens now, I'm especially curious to see the time of the log messages.

@pasikonik
Copy link
Author

pasikonik commented Mar 26, 2025

[2025-03-26T15:18:01Z DEBUG wluma::brightness::backlight] Using direct write on /sys/class/backlight/amdgpu_bl1 to change brightness value
[2025-03-26T15:18:01Z DEBUG wluma::predictor::controller::adaptive] Inside adaptive controller, waiting for initial ALS value
[2025-03-26T15:18:01Z TRACE ddc_hi] DisplayInfo::from_edid(I2cDevice, 22786)
[2025-03-26T15:18:01Z TRACE ddc_hi] DisplayInfo::from_edid(I2cDevice, 22796)
[2025-03-26T15:18:06Z TRACE ddc_hi] DisplayInfo::from_capabilities(I2cDevice, 22786)
[2025-03-26T15:18:06Z DEBUG wluma::brightness::ddcutil] Discovered displays (check_caps=true): ["DELL U2417H 5K9YD87J128L DEL"]
[2025-03-26T15:18:06Z DEBUG wluma::brightness::ddcutil] Using display 'DELL U2417H 5K9YD87J128L DEL' for config 'DELL U2417H' (check_caps=true)
[2025-03-26T15:18:06Z DEBUG wluma::predictor::controller::adaptive] Inside adaptive controller, timeout waiting for initial ALS value

@maximbaz
Copy link
Owner

Very curious, does the code execution not reach this line at all? Could you try to debug where it gets stuck inside main.rs?

std::thread::Builder::new()

@pasikonik
Copy link
Author

pasikonik commented Mar 26, 2025

anything here helpful?

[2025-03-26T17:27:53Z DEBUG wluma] Spawning backlight thread: backlight-card1-eDP-1
[2025-03-26T17:27:53Z DEBUG wluma] Spawning predictor thread: predictor-card1-eDP-1
[2025-03-26T17:27:53Z TRACE wluma] Processing output: DdcUtil(DdcUtilOutput { name: "DELL U2417H", capturer: None, min_brightness: 1, predictor: Adaptive })
[2025-03-26T17:27:53Z TRACE wluma] Channels created for output.
[2025-03-26T17:27:53Z TRACE wluma] Output 'DELL U2417H': name=DELL U2417H, capturer=None
[2025-03-26T17:27:53Z TRACE wluma] Starting predictor thread
[2025-03-26T17:27:53Z TRACE wluma] Starting predictor thread
[2025-03-26T17:27:53Z DEBUG wluma::predictor::controller::adaptive] Inside adaptive controller, waiting for initial ALS value
[2025-03-26T17:27:53Z TRACE ddc_hi] DisplayInfo::from_edid(I2cDevice, 22786)
[2025-03-26T17:27:53Z WARN  ddc_hi] Failed to enumerate a display: Failed to read EDID for i2c-22796
[2025-03-26T17:27:58Z TRACE ddc_hi] DisplayInfo::from_capabilities(I2cDevice, 22786)
[2025-03-26T17:27:58Z DEBUG wluma::brightness::ddcutil] Discovered displays (check_caps=true): ["DELL U2417H 5K9YD87J128L DEL"]
[2025-03-26T17:27:58Z DEBUG wluma::brightness::ddcutil] Using display 'DELL U2417H 5K9YD87J128L DEL' for config 'DELL U2417H' (check_caps=true)
[2025-03-26T17:27:58Z DEBUG wluma::predictor::controller::adaptive] Inside adaptive controller, timeout waiting for initial ALS value
[2025-03-26T17:27:58Z TRACE wluma] Panic occurred: PanicHookInfo { payload: Any { .. }, location: Location { file: "src/predictor/controller/adaptive.rs", line: 36, col: 25 }, can_unwind: true, force_no_backtrace: false }

@maximbaz
Copy link
Owner

We can see two "Starting predictor thread", so at least we know the code executes these lines (twice):

https://github.com/maximbaz/wluma/blob/ea4c8c6ae689655950ccbc1c2c214f5c0e4562ee/src/main.rs#L76-L78C26

And at the same time we only see one of "Inside adaptive controller, waiting for initial ALS value", so not for each of the two threads, but just from one of them...

And we don't see any logs from als thread, which starts here:

std::thread::Builder::new()

So I'm really puzzled as to why and actually exactly where it gets stuck. I don't have multiple screens, but if I try to "simulate" your experience with special hacks by defining the same screen twice, I can't reproduce this 😕

It would be helpful if you could flood main.rs with lots of debug!() everywhere, just to be able to trace exactly, which lines it executes and which ones it doesn't, so that we can understand where it gets stuck. I'm sure it will be something obvious in retrospect, but I just can't see this for now...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants