ui: log fps (#37927)

* log raylib fps

* log fps from frame time

* whitespace

* or just log frame time?

* init pubmaster in init window

* yield timings

* bump ordinal

* dont log on screen off

* UInt

* lint

* /0

* oops

* oops2

* more precise raylib frame time, can get fps with 1/ft

* don't crash on screen off

* NL

* no _

---------

Co-authored-by: Shane Smiskol <shane@smiskol.com>

cereal/log.capnp

@@ -2301,7 +2301,8 @@ struct Sentinel {
 }
 
 struct UIDebug {
-  drawTimeMillis @0 :Float32;
+  cpuTimeMillis @0 :Float32;
+  frameTimeMillis @1 :Float32;
 }
 
 struct ManagerState {

selfdrive/test/test_onroad.py

@@ -210,7 +210,7 @@ class TestOnroad:
 
     # other processes preempt ui while starting up
     offset = int(20 * LOG_OFFSET)
-    ts = self.ts['uiDebug']['drawTimeMillis'][offset:]
+    ts = self.ts['uiDebug']['cpuTimeMillis'][offset:]
     result += f"min  {min(ts):.2f}ms\n"
     result += f"max  {max(ts):.2f}ms\n"
     result += f"std  {np.std(ts):.2f}ms\n"

selfdrive/ui/mici/onroad/augmented_road_view.py

@@ -1,7 +1,6 @@
-import time
 import numpy as np
 import pyray as rl
-from cereal import messaging, car, log
+from cereal import car, log
 from msgq.visionipc import VisionStreamType
 from openpilot.selfdrive.ui.ui_state import ui_state, UIStatus
 from openpilot.selfdrive.ui.mici.onroad import SIDE_PANEL_WIDTH
@@ -159,9 +158,6 @@ class AugmentedRoadView(CameraView):
 
     self._fade_texture = gui_app.texture("icons_mici/onroad/onroad_fade.png")
 
-    # debug
-    self._pm = messaging.PubMaster(['uiDebug'])
-
   def is_swiping_left(self) -> bool:
     """Check if currently swiping left (for scroller to disable)."""
     return self._bookmark_icon.is_swiping_left()
@@ -189,7 +185,6 @@ class AugmentedRoadView(CameraView):
       self._offroad_label.render(self._rect)
       return
 
-    start_draw = time.monotonic()
     self._switch_stream_if_needed(ui_state.sm)
 
     # Update calibration before rendering
@@ -248,11 +243,6 @@ class AugmentedRoadView(CameraView):
 
     self._bookmark_icon.render(self.rect)
 
-    # publish uiDebug
-    msg = messaging.new_message('uiDebug')
-    msg.uiDebug.drawTimeMillis = (time.monotonic() - start_draw) * 1000
-    self._pm.send('uiDebug', msg)
-
   def _switch_stream_if_needed(self, sm):
     if sm['selfdriveState'].experimentalMode and WIDE_CAM in self.available_streams:
       v_ego = sm['carState'].vEgo

selfdrive/ui/onroad/augmented_road_view.py

@@ -1,7 +1,6 @@
-import time
 import numpy as np
 import pyray as rl
-from cereal import log, messaging
+from cereal import log
 from msgq.visionipc import VisionStreamType
 from openpilot.selfdrive.ui import UI_BORDER_SIZE
 from openpilot.selfdrive.ui.ui_state import ui_state, UIStatus
@@ -49,12 +48,8 @@ class AugmentedRoadView(CameraView):
     self.alert_renderer = AlertRenderer()
     self.driver_state_renderer = DriverStateRenderer()
 
-    # debug
-    self._pm = messaging.PubMaster(['uiDebug'])
-
   def _render(self, rect):
     # Only render when system is started to avoid invalid data access
-    start_draw = time.monotonic()
     if not ui_state.started:
       return
 
@@ -98,11 +93,6 @@ class AugmentedRoadView(CameraView):
     # Draw colored border based on driving state
     self._draw_border(rect)
 
-    # publish uiDebug
-    msg = messaging.new_message('uiDebug')
-    msg.uiDebug.drawTimeMillis = (time.monotonic() - start_draw) * 1000
-    self._pm.send('uiDebug', msg)
-
   def _handle_mouse_press(self, _):
     if not self._hud_renderer.user_interacting() and self._click_callback is not None:
       self._click_callback()

selfdrive/ui/ui.py

@@ -1,6 +1,7 @@
 #!/usr/bin/env python3
 import os
 
+from cereal import messaging
 from openpilot.system.hardware import TICI
 from openpilot.common.realtime import config_realtime_process, set_core_affinity
 from openpilot.system.ui.lib.application import gui_app
@@ -21,9 +22,16 @@ def main():
   else:
     MiciMainLayout()
 
-  for should_render in gui_app.render():
+  pm = messaging.PubMaster(['uiDebug'])
+  for should_render, frame_time, cpu_time in gui_app.render():
     ui_state.update()
+
     if should_render:
+      msg = messaging.new_message('uiDebug')
+      msg.uiDebug.cpuTimeMillis = cpu_time * 1000
+      msg.uiDebug.frameTimeMillis = frame_time * 1000
+      pm.send('uiDebug', msg)
+
       # reaffine after power save offlines our core
       if TICI and os.sched_getaffinity(0) != cores:
         try:

system/ui/lib/application.py

@@ -585,6 +585,8 @@ class GuiApplication:
         self._render_profiler.enable()
 
       while not (self._window_close_requested or rl.window_should_close()):
+        frame_start = time.monotonic()
+
         if PC:
           # Thread is not used on PC, need to manually add mouse events
           self._mouse._handle_mouse_event()
@@ -599,7 +601,7 @@ class GuiApplication:
           if PC:
             rl.poll_input_events()
           time.sleep(1 / self._target_fps)
-          yield False
+          yield False, 0.0, 0.0
           continue
 
         if self._render_texture:
@@ -621,7 +623,9 @@ class GuiApplication:
         for widget in self._nav_stack[-self._nav_stack_widgets_to_render:]:
           widget.render(rl.Rectangle(0, 0, self.width, self.height))
 
-        yield True
+        frame_time = rl.get_frame_time()
+        cpu_time = time.monotonic() - frame_start
+        yield True, frame_time, cpu_time
 
         if self._scale != 1.0:
           rl.rl_pop_matrix()

tools/clip/run.py

@@ -326,7 +326,7 @@ def clip(route: Route, output: str, start: int, end: int, headless: bool = True,
 
     frame_idx = 0
     with tqdm.tqdm(total=len(message_chunks), desc="Rendering", unit="frame") as pbar:
-      for should_render in gui_app.render():
+      for should_render, _, _ in gui_app.render():
         if frame_idx >= len(message_chunks):
           break
         _, frame_bytes = frame_queue.get()