Skip to content
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

fix(core): correct Delizia loader completion detection #4598

Open
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

romanz
Copy link
Contributor

@romanz romanz commented Feb 10, 2025

This issue was found while debugging a flaky click test on T3T1 emulator:
tests/click_tests/test_lock.py::test_hold_to_lock

Sample failures:
https://github.com/trezor/trezor-firmware/actions/runs/13209659963/job/36880750418
https://github.com/trezor/trezor-firmware/actions/runs/13189762414/job/36820368643
https://github.com/trezor/trezor-firmware/actions/runs/13146713535/job/36686537519
https://github.com/trezor/trezor-firmware/actions/runs/13124809110/job/36619045092
https://github.com/trezor/trezor-firmware/actions/runs/13103415015/job/36554567296
https://github.com/trezor/trezor-firmware/actions/runs/13093382180/job/36532710349

With the following logging added [1], the test failure seems to happen when the loader detects that it is ShrunkCompletely (probably due to animation events timing jitter) and stops the animation:

image

[1] Debug patch
diff --git a/core/embed/rust/src/ui/component/base.rs b/core/embed/rust/src/ui/component/base.rs
index 9b24c44fd..efe88e78b 100644
--- a/core/embed/rust/src/ui/component/base.rs
+++ b/core/embed/rust/src/ui/component/base.rs
@@ -575,6 +575,7 @@ impl EventCtx {
     }
 
     fn register_timer(&mut self, token: TimerToken, duration: Duration) {
+        dbg_println!("register_timer: {:?} {}ms", token, duration.to_millis());
         if self.timers.push((token, duration)).is_err() {
             // The timer queue is full, this would be a development error in the layout
             // layer. Let's panic in the debug env.
diff --git a/core/embed/rust/src/ui/layout/obj.rs b/core/embed/rust/src/ui/layout/obj.rs
index 4ec68214a..f546e9fce 100644
--- a/core/embed/rust/src/ui/layout/obj.rs
+++ b/core/embed/rust/src/ui/layout/obj.rs
@@ -285,6 +285,7 @@ impl LayoutObjInner {
 
         // Drain any pending timers into the callback.
         while let Some((token, duration)) = self.event_ctx.pop_timer() {
+            dbg_println!("timer_fn: {:?} {}ms", token, duration.to_millis());
             let token = token.try_into();
             let duration = duration.try_into();
             if let (Ok(token), Ok(duration)) = (token, duration) {
diff --git a/core/embed/rust/src/ui/layout_delizia/component/homescreen.rs b/core/embed/rust/src/ui/layout_delizia/component/homescreen.rs
index fe68b28a5..e80452b19 100644
--- a/core/embed/rust/src/ui/layout_delizia/component/homescreen.rs
+++ b/core/embed/rust/src/ui/layout_delizia/component/homescreen.rs
@@ -507,6 +507,7 @@ impl Homescreen {
     }
 
     fn event_hold(&mut self, ctx: &mut EventCtx, event: Event) -> bool {
+        dbg_println!("event_hold: {:?} animating={}", event, self.loader.is_animating());
         match event {
             Event::Touch(TouchEvent::TouchStart(_)) => {
                 if self.loader.is_animating() {
diff --git a/core/embed/rust/src/ui/layout_delizia/component/loader.rs b/core/embed/rust/src/ui/layout_delizia/component/loader.rs
index 158a0bc83..a67a160ce 100644
--- a/core/embed/rust/src/ui/layout_delizia/component/loader.rs
+++ b/core/embed/rust/src/ui/layout_delizia/component/loader.rs
@@ -180,15 +180,19 @@ impl Component for Loader {
                 if self.is_completely_grown(now) {
                     #[cfg(feature = "haptic")]
                     play(HapticEffect::HoldToConfirm);
+                    dbg_println!("Loader::event {:?} -> GrownCompletely", event);
                     return Some(LoaderMsg::GrownCompletely);
                 } else if self.is_completely_shrunk(now) {
+                    dbg_println!("Loader::event {:?} -> ShrunkCompletely", event);
                     return Some(LoaderMsg::ShrunkCompletely);
                 } else {
                     // There is further progress in the animation, request an animation frame event.
                     ctx.request_anim_frame();
+                    return None;
                 }
             }
         }
+        dbg_println!("Loader::event {:?} -> None", event);
         None
     }
 
diff --git a/tests/click_tests/test_lock.py b/tests/click_tests/test_lock.py
index 9a0340910..0f270d343 100644
--- a/tests/click_tests/test_lock.py
+++ b/tests/click_tests/test_lock.py
@@ -14,6 +14,7 @@
 # You should have received a copy of the License along with this library.
 # If not, see <https://www.gnu.org/licenses/lgpl-3.0.html>.
 
+import logging
 import time
 from typing import TYPE_CHECKING
 
@@ -28,6 +29,7 @@ if TYPE_CHECKING:
     from ..device_handler import BackgroundDeviceHandler
 
 
+LOG = logging.getLogger()
 PIN4 = "1234"
 
 
@@ -77,17 +79,20 @@ def test_hold_to_lock(device_handler: "BackgroundDeviceHandler"):
     hold(lock_duration)
     assert device_handler.features().unlocked is False
 
-    # unlock by touching
-    if debug.layout_type is LayoutType.Caesar:
-        debug.press_right()
-    else:
-        debug.click(buttons.INFO)
-    layout = debug.read_layout()
-    assert "PinKeyboard" in layout.all_components()
-    debug.input("1234")
-
-    assert device_handler.features().unlocked is True
-
-    # lock
-    hold(lock_duration)
-    assert device_handler.features().unlocked is False
+    for i in range(1000):
+        # unlock by touching
+        if debug.layout_type is LayoutType.Caesar:
+            debug.press_right()
+        else:
+            debug.click(buttons.INFO)
+        layout = debug.read_layout()
+        assert "PinKeyboard" in layout.all_components()
+        debug.input("1234")
+
+        assert device_handler.features().unlocked is True
+
+        # lock
+        LOG.info("LOCK: #%d", i)
+        hold(lock_duration)
+        LOG.info("STAT: #%d", i)
+        assert device_handler.features().unlocked is False

@romanz romanz self-assigned this Feb 10, 2025
@romanz romanz added core Trezor Core firmware. Runs on Trezor Model T and T2B1. tests Automated integration tests T3T1 Trezor Safe 5 emulator only Issue which does not appear on the physical device - but on emulator only. labels Feb 10, 2025
Copy link

core UI changes device test click test persistence test
T2T1 Model T test(screens) main(screens) test(screens) main(screens) test(screens) main(screens)
T3B1 Safe 3 test(screens) main(screens) test(screens) main(screens) test(screens) main(screens)
T3T1 Safe 5 test(screens) main(screens) test(screens) main(screens) test(screens) main(screens)
All main(screens)

@romanz
Copy link
Contributor Author

romanz commented Feb 10, 2025

Tested locally on T3T1 emulator:

core/emu.py -o debug.log -sea -c pytest tests/click_tests -k test_hold_to_lock -vx --color=yes --count 100 2>&1 | stamp
2025-02-10 12:57:25.684756 TREZOR_PATH=udp:127.0.0.1:21324
2025-02-10 12:57:25.684842 TREZOR_PROFILE_DIR=/var/tmp
2025-02-10 12:57:25.684857 TREZOR_UDP_PORT=21324
2025-02-10 12:57:25.684867 TREZOR_FIDO2_UDP_PORT=21326
2025-02-10 12:57:25.684877 TREZOR_SRC=/home/rzeyde/src/trezor-firmware/core/src
2025-02-10 12:57:25.686108 Waiting for emulator to come up...
2025-02-10 12:57:25.887237 Emulator ready after 0.201 seconds
2025-02-10 12:57:26.240309 ============================= test session starts ==============================
2025-02-10 12:57:26.240364 platform linux -- Python 3.10.10, pytest-8.3.2, pluggy-1.5.0 -- /home/rzeyde/src/trezor-firmware/.venv/bin/python
2025-02-10 12:57:26.240375 cachedir: .pytest_cache
2025-02-10 12:57:26.240385 hypothesis profile 'default' -> database=DirectoryBasedExampleDatabase('/home/rzeyde/src/trezor-firmware/.hypothesis/examples')
2025-02-10 12:57:26.240394 Using --random-order-bucket=module
2025-02-10 12:57:26.240403 Using --random-order-seed=877340
2025-02-10 12:57:26.240412 
2025-02-10 12:57:26.240421 rootdir: /home/rzeyde/src/trezor-firmware
2025-02-10 12:57:26.240430 configfile: setup.cfg
2025-02-10 12:57:26.240440 plugins: xdist-2.5.0, flaky-3.8.1, forked-1.4.0, hypothesis-6.36.1, ordering-0.6, repeat-0.9.3, timeout-2.1.0, random-order-1.0.4
2025-02-10 12:57:26.791454 collecting ... collected 8100 items / 8000 deselected / 100 selected
2025-02-10 13:13:05.558367 
2025-02-10 13:13:05.558379 =============== 100 passed, 8000 deselected in 939.36s (0:15:39) ===============
2025-02-10 13:13:05.807124 Terminating emulator...
2025-02-10 13:13:05.814661 Emulator shut down after 0.007 seconds

@romanz romanz marked this pull request as ready for review February 10, 2025 11:52
@romanz romanz requested a review from prusnak as a code owner February 10, 2025 11:52
@romanz romanz requested review from matejcik and removed request for prusnak February 10, 2025 11:53
@romanz
Copy link
Contributor Author

romanz commented Feb 10, 2025

Should I also fix similar Loader implementation for Bolt and Caesar layouts?

core/embed/rust/src/ui/layout_bolt/component/loader.rs
141:    pub fn is_completely_grown(&self, now: Instant) -> bool {
145:    pub fn is_completely_shrunk(&self, now: Instant) -> bool {

core/embed/rust/src/ui/layout_caesar/component/loader.rs
156:    pub fn is_completely_grown(&self, now: Instant) -> bool {
160:    pub fn is_completely_shrunk(&self, now: Instant) -> bool {

core/embed/rust/src/ui/layout_delizia/component/loader.rs
145:    pub fn is_completely_grown(&self, now: Instant) -> bool {
149:    pub fn is_completely_shrunk(&self, now: Instant) -> bool {

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
core Trezor Core firmware. Runs on Trezor Model T and T2B1. emulator only Issue which does not appear on the physical device - but on emulator only. T3T1 Trezor Safe 5 tests Automated integration tests
Projects
Status: 🔎 Needs review
Development

Successfully merging this pull request may close these issues.

1 participant