Files
dragonpilot/tools/latencylogger
Lukas Petersson 65fca83abe Latency logging 2 (#24058)
* msg_order and gantt

* frameId in long/lat planner

* track frame id

* controls frame id

* graph tracked events

* graph json

* cloudlog timestamp

* c++ cloudlog

* add frame id

* bug fixes

* bug fixes

* frame id visionicp

* bug fixes and debug level

* timestamp log placement

* print timestamps in table

* translate events

* more logging

* bug fixes

* daemon boardd

* print logs with boardd

* more timestamp logs

* cleanup

* remove publish logs

* bug fix

* timestamp received

* timestamp received

* bug fixes

* use json lib

* ignore driver camera

* prep for new timestamp pipeline

* bug fix

* read new pipeline unfinnished

* read new pipeline

* bug fix

* add frame to controlsstate

* remove controlsstate

* print

* cleanup

* more cleanup + bug fix

* clock build issue

* remove unused imports

* format durations

* increase speed

* pr comments fixes

* conflicts

* set MANAGER_DAEMON for boardd

* clean script code

* bug fix + argparse

* remove rcv time

* bug fixes

* print without tabulate

* fix pre-commits

* plot gnatt

* color bug fix

* read without timestampextra

* bump panda

* mono time instead of frame id

* finnish script

* clean unused

* clean unused logging

* monotonic + json fixes

* del test

* remove whilelines

* bump laika

* cleanup

* remove deps

* logs nicer strings

* remove plotting from scirpt

* reset pipfile

* reset pipfile

* nicer strings

* bug fix

* bug fix

* pr comments cleaning

* remove plotting

* bug fix

* new demo route

* bump opendbc and panda

* cereal master

* cereal master

* script less komplex

* assertions

* matplotlib

* readme

* Update README.md

* graph html

* design fixes

* more code design

* Update common/logging_extra.py

Co-authored-by: Adeeb Shihadeh <adeebshihadeh@gmail.com>

* whitespace

Co-authored-by: Adeeb Shihadeh <adeebshihadeh@gmail.com>

* Update tools/latency_logger/latency_logger.py

Co-authored-by: Adeeb Shihadeh <adeebshihadeh@gmail.com>

* pr comments

* bug fix

* readme + env once

* clean swaglog

* bug fix

* Update tools/latencylogger/README.md

Co-authored-by: Adeeb Shihadeh <adeebshihadeh@gmail.com>

* revert

* revert

* clean swaglog with error

* remove typo file

* revert graph

* cereal

* submodules

* whitespaces

* update refs

Co-authored-by: Bruce Wayne <batman@workstation-openpilot2.internal>
Co-authored-by: Comma Device <device@comma.ai>
Co-authored-by: Adeeb Shihadeh <adeebshihadeh@gmail.com>
2022-04-05 21:05:45 -07:00
..
2022-04-05 21:05:45 -07:00
2022-04-05 21:05:45 -07:00

LatencyLogger

LatencyLogger is a tool to track the time from first pixel to actuation. Timestamps are printed in a table as well as plotted in a graph. Start openpilot with LOG_TIMESTAMPS=1 set to enable the necessary logging.

Usage

$ python latency_logger.py -h
usage: latency_logger.py [-h] [--relative] [--demo] [--plot] [route_or_segment_name]

A tool for analyzing openpilot's end-to-end latency

positional arguments:
  route_or_segment_name
                        The route to print (default: None)

optional arguments:
  -h, --help            show this help message and exit
  --relative            Make timestamps relative to the start of each frame (default: False)
  --demo                Use the demo route instead of providing one (default: False)
  --plot                If a plot should be generated (default: False)

Examples

Plotting with relative starts each process at time=0 and gives a nice overview. relself Plotting without relative provides info about the frames relative time. relfirst

Printed timestamps of a frame with internal durations.

Frame ID: 303
  camerad
    roadCameraState start of frame                       0.0
    wideRoadCameraState start of frame                   0.091926
    RoadCamera: Image set                                1.691696
    RoadCamera: Transformed                              1.812841
    roadCameraState published                            51.775466
    wideRoadCameraState published                        54.935164
    roadCameraState.processingTime                       1.6455530421808362
    wideRoadCameraState.processingTime                   4.790564067661762
  modeld
    Image added                                          56.628788
    Extra image added                                    57.459923
    Execution finished                                   75.091306
    modelV2 published                                    75.24797
    modelV2.modelExecutionTime                           20.00947669148445
    modelV2.gpuExecutionTime                             0.0
  plannerd
    lateralPlan published                                80.426861
    longitudinalPlan published                           85.722781
    lateralPlan.solverExecutionTime                      1.0600379901006818
    longitudinalPlan.solverExecutionTime                 1.3830000534653664
  controlsd
    Data sampled                                         89.436221
    Events updated                                       90.356522
    sendcan published                                    91.396092
    controlsState published                              91.77843
    Data sampled                                         99.885876
    Events updated                                       100.696855
    sendcan published                                    101.600489
    controlsState published                              101.941839
    Data sampled                                         110.087669
    Events updated                                       111.025365
    sendcan published                                    112.305921
    controlsState published                              112.70451
    Data sampled                                         119.692803
    Events updated                                       120.56774
    sendcan published                                    121.735016
    controlsState published                              122.142823
    Data sampled                                         129.264761
    Events updated                                       130.024282
    sendcan published                                    130.950364
    controlsState published                              131.281558
  boardd
    sending sendcan to panda: 250027001751393037323631   101.705487
    sendcan sent to panda: 250027001751393037323631      102.042462
    sending sendcan to panda: 250027001751393037323631   112.416961
    sendcan sent to panda: 250027001751393037323631      112.792269
    sending sendcan to panda: 250027001751393037323631   121.850952
    sendcan sent to panda: 250027001751393037323631      122.231103
    sending sendcan to panda: 250027001751393037323631   131.045206
    sendcan sent to panda: 250027001751393037323631      131.351296
    sending sendcan to panda: 250027001751393037323631   141.340592
    sendcan sent to panda: 250027001751393037323631      141.700744