Ok, by random chance my craasneto does currently experience the issue. It was sitting in idle for maybe a week (plugged in with chargecontrol idle set). Let me get some logs.
Had to edit this, because discourse wouldn’t let me do more than 3 replies in a row xD.
Here’s the EC console when closing the lid, waiting a while, then reopening the lid. It did not turn the screen on with opening the lid so I pressed the power.
[1390721.781000 lid close]
[1390721.782000 KB disable_scanning_mask changed: 0x00000001]
[1390721.783300 KB Clear Buffer]
[1390721.785500 SW 0x04]
[1390721.787000 Tablet mode set while disabled (ignoring)!]
[1390721.793900 mkbp switches: 0]
[1390721.797900 MKBP common FIFO depth 16 reached]
[1390721.996100 KB Clear Buffer]
[1390852.925700 lid open]
[1390852.926600 KB disable_scanning_mask changed: 0x00000000]
[1390852.929300 SW 0x05]
[1390852.930200 mkbp switches: 1]
[1390852.932500 MKBP common FIFO depth 16 reached]
[1390859.895800 KB disable_scanning_mask changed: 0x00000002]
[1390859.897200 KB Clear Buffer]
[1390859.926000 power button pressed]
[1390859.927100 mkbp buttons: 1]
[1390859.928000 MKBP common FIFO depth 16 reached]
[1390859.929200 PB pressed]
[1390859.932800 PB task 1 = pressed]
[1390859.935000 SW 0x07]
[1390859.936900 PB PCH pwrbtn=LOW]
[1390859.944700 PB task 2 = t0, wait 20100]
[1390859.970400 PB task 2 = t0]
[1390859.971400 PB PCH pwrbtn=HIGH]
[1390859.972400 PB task 3 = t1, wait 3966000]
[1390860.029600 KS disable]
[1390860.030500 KB Clear Buffer]
[1390860.036200 KS enable]
[1390860.037100 KB Clear Buffer]
[1390860.062900 KB disable_scanning_mask changed: 0x00000000]
[1390860.064400 power button released]
[1390860.065400 mkbp buttons: 0]
[1390860.066600 MKBP common FIFO depth 16 reached]
[1390860.072100 PB released]
[1390860.076200 PB task 6 = released]
[1390860.078300 SW 0x05]
[1390860.080200 PB PCH pwrbtn=HIGH]
[1390860.088400 PB task 0 = idle, wait -1]
Here’s dmesg for that time period:
[764958.110328] PM: suspend entry (s2idle)
[764958.127582] Filesystems sync: 0.017 seconds
[764958.144148] Freezing user space processes
[764958.145439] Freezing user space processes completed (elapsed 0.001 seconds)
[764958.145447] OOM killer disabled.
[764958.145450] Freezing remaining freezable tasks
[764958.146645] Freezing remaining freezable tasks completed (elapsed 0.001 seconds)
[764958.146656] printk: Suspending console(s) (use no_console_suspend to debug)
[764958.216866] wlan0: deauthenticating from 94:2a:6f:b6:d7:9f by local choice (Reason: 3=DEAUTH_LEAVING)
[764958.655988] ACPI: EC: interrupt blocked
[765096.187151] ACPI: EC: interrupt unblocked
[765096.234756] i915 0000:00:02.0: [drm] GT0: GuC firmware i915/tgl_guc_70.bin version 70.49.4
[765096.234768] i915 0000:00:02.0: [drm] GT0: HuC firmware i915/tgl_huc.bin version 7.9.3
[765096.241680] i915 0000:00:02.0: [drm] GT0: HuC: authenticated for all workloads
[765096.283322] i915 0000:00:02.0: [drm] GT0: GUC: submission enabled
[765096.283332] i915 0000:00:02.0: [drm] GT0: GUC: SLPC enabled
[765096.287696] i915 0000:00:02.0: [drm] GT0: GUC: RC enabled
[765096.791800] mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_ops [i915])
[765096.792271] OOM killer enabled.
[765096.792277] Restarting tasks ...
[765096.792833] mei_pxp 0000:00:16.0-fbf6fcf1-96cf-4e2e-a6a6-1bab8cbe36b1: bound 0000:00:02.0 (ops i915_pxp_tee_component_ops [i915])
[765096.794188] done.
[765096.794205] random: crng reseeded on system resumption
[765096.796251] PM: suspend exit
[765097.667057] wlan0: authenticate with 94:2a:6f:b6:d7:9f (local address=a0:d3:65:93:5c:47)
[765097.668015] wlan0: send auth to 94:2a:6f:b6:d7:9f (try 1/3)
[765097.749867] wlan0: authenticated
[765097.750815] wlan0: associate with 94:2a:6f:b6:d7:9f (try 1/3)
[765097.775775] wlan0: RX AssocResp from 94:2a:6f:b6:d7:9f (capab=0x1111 status=0 aid=1)
[765097.789952] wlan0: associated
And here’s a run of S0ixSelftestTool:
$ sudo ./s0ix-selftest-tool.sh -s
---Check S2idle path S0ix Residency---:
The system OS Kernel version is:
Linux archlinux 6.14.5-arch1-1 #1 SMP PREEMPT_DYNAMIC Sat, 03 May 2025 13:34:12 +0000 x86_64 GNU/Linux
---Check whether your system supports S0ix or not---:
Low Power S0 Idle is:1
Your system supports low power S0 idle capability.
---Check whether intel_pmc_core sysfs files exit---:
The pmc_core debug sysfs files are OK on your system.
---Judge PC10, S0ix residency available status---:
Test system supports S0ix.y substate
S0ix substate before S2idle:
S0i2.0 S0i3.0
S0ix substate residency before S2idle:
5688158 104697991842
Turbostat output:
14.850017 sec
CPU%c1 CPU%c6 CPU%c7 Pkg%pc2 Pkg%pc3 Pkg%pc6 Pkg%pc8 Pk%pc10 SYS%LPI
0.79 0.20 98.39 1.71 1.34 1.14 0.04 92.40 88.78
1.00 0.15 98.54 1.71 1.34 1.14 0.04 92.40 88.78
0.40 0.13 99.03
0.88 0.28 98.21
0.90 0.24 97.77
CPU Core C7 residency after S2idle is: 98.39
CPU Package C-state 2 residency after S2idle is: 1.71
CPU Package C-state 3 residency after S2idle is: 1.34
CPU Package C-state 6 residency after S2idle is: 1.14
CPU Package C-state 8 residency after S2idle is: 0.04
CPU Package C-state 10 residency after S2idle is: 92.40
S0ix residency after S2idle is: 88.78
S0ix substate after S2idle:
S0i2.0 S0i3.0
S0ix substate residency after S2idle:
5688158 104711174857
S0ix substates residency delta value: S0i2.0 0
S0ix substates residency delta value: S0i3.0 13183015
Congratulations! Your system achieved the deepest S0ix substate!
Here is the S0ix substates status:
Substate Residency
S0i2.0 5688158
S0i3.0 104711174857
If anyone else is digging around trying to figure out what’s going on. I got a kernel stack trace for when the “ACPI: EC: interrupt blocked” line is being printed in dmesg using bpftrace:
@stacks[
acpi_ec_suspend_noirq+5
dpm_run_callback+71
device_suspend_noirq+140
dpm_suspend_noirq+256
suspend_devices_and_enter+886
pm_suspend.cold+771
state_store+108
kernfs_fop_write_iter+312
vfs_write+653
ksys_write+116
do_syscall_64+123
entry_SYSCALL_64_after_hwframe+118
]: 1
Also, that craasneto is running kernel 6.14.5.
Another update:
I’m pretty sure it’s an issue on the kenel / ACPI side, not the EC. I can get the device to sleep correctly by manually sending HOST_SLEEP_EVENT_S0IX_SUSPEND just before closing the lid (has to be just before, otherwise the EC will detect the AP suspend timing out and will wake the AP up). Then after opening the lid I need to manually send HOST_SLEEP_EVENT_S0IX_RESUME, otherwise stuff is more broken.
So the AP is not sending the sleep events to the EC, but if you send them manually everything seems to work correctly. The big question is: Why is the AP not sending those events? This only happens rarely, but when it does the issue remains until reboot.
On the other hand in dmesg there is no indication of anything being wrong. The log looks exactly the same on my craasneto that currently has the issue and my roric that sleeps correctly right now.
Also: the 3 reply in a row limit is annoying…
Update:
Looking through journalctl and dmesg I noticed this: On this boot of craasneto as well as sometimes in the past I see this:
$ sudo dmesg | grep -i cros_ec
[ 4.358557] cros_ec_lpcs GOOG0004:00: bad packet checksum 95
[ 5.359213] cros_ec_lpcs GOOG0004:00: EC response timed out
[ 5.359220] cros_ec_lpcs GOOG0004:00: Transfer error 2/4: -5
[ 5.359344] cros_ec_lpcs GOOG0004:00: EC response timed out
[ 5.360806] cros_ec_lpcs GOOG0004:00: Cannot identify the EC: error -5
[ 5.362360] cros_ec_lpcs GOOG0004:00: couldn't register ec_dev (-5)
[ 5.363817] cros_ec_lpcs GOOG0004:00: probe with driver cros_ec_lpcs failed with error -5
@MrChromebox are there multiple ways to communicate with the EC from the AP? I have now seen reference to both LPC as well as eSPI. In this case cros_ec_lpcs fails, but I can still use ectool, are they using the same bus?
Update:
ectool communicates via lpc:
$ sudo ./ectool --interface=lpc hello
EC says hello!
$ sudo ./ectool --interface=i2c hello
Cannot find I2C adapter
Unable to establish host communication
Couldn't find EC
Using --interface=dev works on roric but not this boot of craasneto as the device does not exist.
This means communicating to the EC over lpc actually works but failed during init of cros_ec_lpcs. Timing issue? Race condition?
Update:
Just reloading the module like this makes the device sleep correctly:
$ sudo modprobe -r cros_ec_lpcs
$ sudo modprobe cros_ec_lpcs
This confirms that this specific issue is just related to initialization of cros_ec_lpcs during boot. But why does it fail sometimes?
Update:
Tried to reproduce the init issue by unloading and loading the module in a loop a bunch of times. Doesn’t seem to ever fail. So it’s probably a timing issue / race condition that only occurs on boot.
Calling ectool --interface=lpc hello in a loop I was able to get one hello to fail after a while (for whatever that’s worth):
...
EC says hello!
EC response has invalid checksum
EC says hello!
...
Maybe just adding a simple retry logic to cros_ec_lpcs would be an easy fix for this issue.
@SublimeYadon and @Legume9117 @Tonno87 : I want to see if your issue is the same. I would like the output from these commands when you experience the issue:
$ sudo dmesg | grep -i cros_ec
$ lsmod | grep -i cros_ec
and then try unloading and reloading the module and see if that fixes it:
$ sudo modprobe -r cros_ec_lpcs
$ sudo modprobe cros_ec_lpcs