[Test Failed] FAILED: gen/src/controller/tests/data_model/TestRead_run.pw_pystamp tests/TestRead ERR ../../third_party/pigweed/repo/targets/host/run_test exited with status 255 OUT [Pid: 22671] '#0:','TestRead'

[woody-apple]

Test issue(s)

https://github.com/project-chip/connectedhomeip/actions/runs/5490169427/jobs/10005272854

FAILED: gen/src/controller/tests/data_model/TestRead_run.pw_pystamp  python3 ../../third_party/pigweed/repo/pw_build/py/pw_build/python_runner.py --gn-root ../../ --current-path ../../src/controller/tests/data_model --default-toolchain=//build/toolchain/host:mac_x64_gcc --current-toolchain=//build/toolchain/host:mac_x64_gcc --touch gen/src/controller/tests/data_model/TestRead_run.pw_pystamp --capture-output --module pw_unit_test.test_runner --python-virtualenv-config python/gen/matter_build_venv/venv_metadata.json --python-dep-list-files gen/src/controller/tests/data_model/TestRead_run_metadata_path_list.txt -- --runner ../../third_party/pigweed/repo/targets/host/run_test --test tests/TestRead ERR ../../third_party/pigweed/repo/targets/host/run_test exited with status 255 OUT [Pid: 22671] '#0:','TestRead'

Anything else?

No response

[bzbarsky-apple]

[1688763688702] [22672:90774] [DMG] Refresh LivenessCheckTime for 5224 milliseconds with SubscriptionId = 0xd14279e6 Peer = 02:0000000011223344
...
[1688763692084] [22672:90774] [DMG] IM RH moving to [AwaitingDestruction]
src/controller/tests/data_model/TestRead.cpp:1804: assertion failed: "callback.mOnError == 1"
src/controller/tests/data_model/TestRead.cpp:1805: assertion failed: "callback.mLastError == CHIP_ERROR_TIMEOUT"
src/controller/tests/data_model/TestRead.cpp:1806: assertion failed: "callback.mOnDone == 1"
'#3:','TestSubscribeAttributeTimeout                             ','FAILED'

No useful timestamps on those failures, but what is conspicuously missing is a line that says: Subscription Liveness timeout with SubscriptionID....

In other words, we are checking for "we timed out" before we actually time out.

The relevant part of the test looks like this:

        ctx.GetIOContext().DriveIOUntil(ComputeSubscriptionTimeout(System::Clock::Seconds16(maxIntervalCeilingSeconds)),
                                        [&]() { return callback.mOnError >= 1; });

where ComputeSubscriptionTimeout adds 100ms of slack on top of what I would expect the liveness timer to be set to. But if we lose the timeslice for > 100ms, it's possible that we will break out of the loop before we have processed the timer....

We should probably just use slightly more slack here.