1.. _profiler:
2
3========
4Profiler
5========
6
7As the complexity of the application increases, performance issues such as low FPS and frequent cache misses
8causing lag may arise. LVGL has internally set up some hooks for performance measurement to help developers
9analyze and locate performance issues.
10
11.. _profiler_introduction:
12
13Introduction
14************
15
16LVGL has a built-in trace system to track and record the timestamps of important events that occur during runtime,
17such as rendering events and user input events. These event timestamps serve as important metrics for performance analysis.
18
19The trace system has a configurable record buffer that stores the names of event functions and their timestamps.
20When the buffer is full, the trace system prints the log information through the provided user interface.
21
22The output trace logs are formatted according to Android's `systrace <https://developer.android.com/topic/performance/tracing>`_
23format and can be visualized using `Perfetto <https://ui.perfetto.dev>`_.
24
25.. _profiler_usage:
26
27Usage
28*****
29
30Configure profiler
31^^^^^^^^^^^^^^^^^^
32
33To enable the profiler, set :c:macro:`LV_USE_PROFILER` in ``lv_conf.h`` and configure the following options:
34
351. Enable the built-in profiler functionality by setting :c:macro:`LV_USE_PROFILER_BUILTIN`.
36
372. Buffer configuration: Set the value of :c:macro:`LV_PROFILER_BUILTIN_BUF_SIZE` to configure the buffer size. A larger buffer can store more trace event information, reducing interference with rendering. However, it also results in higher memory consumption.
38
393. Timestamp configuration: LVGL uses the :cpp:func:`lv_tick_get` function with a precision of 1ms by default to obtain timestamps when events occur. Therefore, it cannot accurately measure intervals below 1ms. If your system environment can provide higher precision (e.g., 1us), you can configure the profiler as follows:
40
41- Recommended configuration in **UNIX** environments:
42
43    .. code-block:: c
44
45        #include <sys/syscall.h>
46        #include <sys/types.h>
47        #include <time.h>
48        #include <unistd.h>
49
50        static uint64_t my_get_tick_cb(void)
51        {
52            struct timespec ts;
53            clock_gettime(CLOCK_MONOTONIC, &ts);
54            return ts.tv_sec * 1000000000 + ts.tv_nsec;
55        }
56
57        static int my_get_tid_cb(void)
58        {
59            return (int)syscall(SYS_gettid);
60        }
61
62        static int my_get_cpu_cb(void)
63        {
64            int cpu_id = 0;
65            syscall(SYS_getcpu, &cpu_id, NULL);
66            return cpu_id;
67        }
68
69        void my_profiler_init(void)
70        {
71            lv_profiler_builtin_config_t config;
72            lv_profiler_builtin_config_init(&config);
73            config.tick_per_sec = 1000000000; /* One second is equal to 1000000000 nanoseconds */
74            config.tick_get_cb = my_get_tick_cb;
75            config.tid_get_cb = my_get_tid_cb;
76            config.cpu_get_cb = my_get_cpu_cb;
77            lv_profiler_builtin_init(&config);
78        }
79
80- Recommended configuration in **Arduino** environments:
81
82    .. code-block:: c
83
84        static uint64_t my_get_tick_cb(void)
85        {
86            /* Use the microsecond time stamp provided by Arduino */
87            return micros();
88        }
89
90        void my_profiler_init(void)
91        {
92            lv_profiler_builtin_config_t config;
93            lv_profiler_builtin_config_init(&config);
94            config.tick_per_sec = 1000000; /* One second is equal to 1000000 microseconds */
95            config.tick_get_cb = my_get_tick_cb;
96            lv_profiler_builtin_init(&config);
97        }
98
994. Log output configuration: LVGL uses the :cpp:func:`LV_LOG` interface by default to output trace information. If you want to use another interface to output log information (e.g., file stream), you can redirect the log output using the following code:
100
101    .. code-block:: c
102
103        static void my_log_print_cb(const char * buf)
104        {
105            printf("%s", buf);
106        }
107
108        void my_profiler_init(void)
109        {
110            lv_profiler_builtin_config_t config;
111            lv_profiler_builtin_config_init(&config);
112            ... /* other configurations */
113            config.flush_cb = my_log_print_cb;
114            lv_profiler_builtin_init(&config);
115        }
116
117Run the test scenario
118^^^^^^^^^^^^^^^^^^^^^
119
120Run the UI scenario that you want to measure, such as scrolling a scrollable page up and down or entering/exiting an application.
121
122Process the logs
123^^^^^^^^^^^^^^^^
124
125Save the output log as `my_trace.txt`, use `trace_filter.py` for filtering and preprocessing:
126
127    .. code-block:: bash
128
129        ./lvgl/scripts/trace_filter.py my_trace.txt
130
131    or
132
133    .. code-block:: bash
134
135        python3 ./lvgl/scripts/trace_filter.py my_trace.txt
136
137You will obtain a processed text file named `trace.systrace`, which roughly contains the following content:
138
139    .. code-block:: text
140
141        # tracer: nop
142        #
143        LVGL-1 [0] 2892.002993: tracing_mark_write: B|1|lv_timer_handler
144        LVGL-1 [0] 2892.002993: tracing_mark_write: B|1|_lv_display_refr_timer
145        LVGL-1 [0] 2892.003459: tracing_mark_write: B|1|refr_invalid_areas
146        LVGL-1 [0] 2892.003461: tracing_mark_write: B|1|lv_draw_rect
147        LVGL-1 [0] 2892.003550: tracing_mark_write: E|1|lv_draw_rect
148        LVGL-1 [0] 2892.003552: tracing_mark_write: B|1|lv_draw_rect
149        LVGL-1 [0] 2892.003556: tracing_mark_write: E|1|lv_draw_rect
150        LVGL-1 [0] 2892.003560: tracing_mark_write: B|1|lv_draw_rect
151        LVGL-1 [0] 2892.003573: tracing_mark_write: E|1|lv_draw_rect
152        ...
153
154Import the processed `trace.systrace` file into `Perfetto <https://ui.perfetto.dev>`_ and wait for it to be parsed.
155
156Performance analysis
157^^^^^^^^^^^^^^^^^^^^
158
159If the log parsing is successful, you will see the following screen:
160
161.. image:: /misc/perfetto_ui.png
162
163In the Perfetto UI, use the :kbd:`A` or :kbd:`D` keys to pan the timeline horizontally
164and the :kbd:`W` or :kbd:`S` keys to zoom in or out on the timeline.
165Use the mouse to move the focus and click on functions on the timeline to observe their execution time.
166
167Add Measurement Point
168*********************
169
170Users can add their own measured functions:
171
172.. code-block:: c
173
174    void my_function_1(void)
175    {
176        LV_PROFILER_BEGIN;
177        do_something();
178        LV_PROFILER_END;
179    }
180
181    void my_function_2(void)
182    {
183        LV_PROFILER_BEGIN_TAG("do_something_1");
184        do_something_1();
185        LV_PROFILER_END_TAG("do_something_1");
186
187        LV_PROFILER_BEGIN_TAG("do_something_2");
188        do_something_2();
189        LV_PROFILER_END_TAG("do_something_2");
190    }
191
192.. _profiler_custom_implementation:
193
194Custom profiler implementation
195******************************
196
197If you wish to use a profiler method provided by your operating system, you can modify the following configurations in ``lv_conf.h``:
198
199- :c:macro:`LV_PROFILER_INCLUDE`: Provides a header file for the profiler function.
200- :c:macro:`LV_PROFILER_BEGIN`: Profiler start point function.
201- :c:macro:`LV_PROFILER_END`: Profiler end point function.
202- :c:macro:`LV_PROFILER_BEGIN_TAG`: Profiler start point function with custom tag.
203- :c:macro:`LV_PROFILER_END_TAG`: Profiler end point function with custom tag.
204
205
206Taking `NuttX <https://github.com/apache/nuttx>`_ RTOS as an example:
207
208.. code-block:: c
209
210    #define LV_PROFILER_INCLUDE "nuttx/sched_note.h"
211    #define LV_PROFILER_BEGIN          sched_note_begin(NOTE_TAG_ALWAYS)
212    #define LV_PROFILER_END            sched_note_end(NOTE_TAG_ALWAYS)
213    #define LV_PROFILER_BEGIN_TAG(str) sched_note_beginex(NOTE_TAG_ALWAYS, str)
214    #define LV_PROFILER_END_TAG(str)   sched_note_endex(NOTE_TAG_ALWAYS, str)
215
216.. _profiler_faq:
217
218FAQ
219***
220
221Perfetto log parsing fails
222^^^^^^^^^^^^^^^^^^^^^^^^^^
223
224Please check the completeness of the logs. If the logs are incomplete, it may be due to the following reasons:
225
2261. Serial port reception errors caused by a high baud rate. You need to reduce the baud rate.
2272. Data corruption caused by other thread logs inserted during the printing of trace logs. You need to disable the log output of other threads or refer to the configuration above to use a separate log output interface.
2283. Make sure that the string passed in by :c:macro:`LV_PROFILER_BEGIN_TAG` or :c:macro:`LV_PROFILER_END_TAG` is not a local variable on the stack or a string in shared memory, because currently only the string address is recorded and the content is not copied.
229
230Function execution time displayed as 0s in Perfetto
231^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
232
233If the function execution time is lower than the precision of the timestamps, this situation can occur. You can refer to the configuration instructions above to use a higher precision timestamp.
234
235Significant stuttering occurs during profiling
236^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
237
238When the buffer used to store trace events becomes full, the profiler will output all the data in the buffer, which can cause UI blocking and stuttering during the output. You can optimize this by taking the following measures:
239
2401. Increase the value of :c:macro:`LV_PROFILER_BUILTIN_BUF_SIZE`. A larger buffer can reduce the frequency of log printing, but it also consumes more memory.
2412. Optimize the execution time of log printing functions, such as increasing the serial port baud rate or improving file writing speed.
242
243Trace logs are not being output
244^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
245
246If the trace logs are not automatically printed when the buffer is not full, you can try the following methods to force the log output:
247
2481. Reduce the value of :c:macro:`LV_PROFILER_BUILTIN_BUF_SIZE` to fill the buffer more quickly and trigger automatic printing.
2492. Manually call or use a timer to call the :cpp:func:`lv_profiler_builtin_flush` function to force the log output.
250
251