search

genodelabs / genode

Genode OS Framework
https://genode.org/
Other
1.06k stars 251 forks source link

Manual instrumentation utilities for performance analysis #4066

Closed nfeske closed 2 years ago

nfeske commented 3 years ago

Even though we have the Trace::timestamp utility readily available, it remains barely used for manual instrumentation because such instrumentations require too much labor: allocation of state variables for gathering the statistics, computing time differences, traffic-shaping of the debug noise (needed whenever investigating highly frequently called code). These tasks should better be covered by a utility so that friction-less performance analysis can become a regular part of our development work.

nfeske commented 3 years ago

Addressed by https://github.com/genodelabs/genode/commit/1ba2df6bd09889710fc81d7282bd44ce0f5c3b06. Over the Easter holidays, I intensively used this utility to investigate the boot time of Sculpt OS on Qemu. The two macros GENODE_LOG_TSC and GENODE_LOG_TSC_NAMED are provided by the new debug/log.h header.

I found the utilities so delightful and handy that I considered adding them to the regular base/log.h header. Strictly speaking, these macros are mere debugging features. So by principle, they would not qualify being part of the base API. On the other hand, they are not complex in terms of lines of code and having them always available would lower the friction of using them even more by eliminating the need to include the dedicated debug/log.h header. The manual adding and removing of #include statements was the only spoiler of the fun while using them throughout the code base.

Are there any opinions?

nfeske commented 3 years ago

After an offline consultation with @chelmuth, I added the fixup https://github.com/nfeske/genode/commit/caab614117eb944cd57c763b3795cdc004255c4b, which makes the mechanism more flexible and cleaner, and makes it part of the regular base/log.h header.

chelmuth commented 3 years ago

The current version perfectly fits my needs.

nfeske commented 2 years ago

While investigating the performance of the VT exit handlers in VirtualBox6, I longed for a way to use the GENODE_LOG_TSC utility, but targeting the trace mechanism instead of the log. In this case, regular log messages are not viable because of the high volume/frequency of the captured information and the costs of printing them. I suggest adding a flavor GENODE_TRACE_TSC to accommodate such demanding scenarios.

nfeske commented 2 years ago

Fixed by 34a3209e9bff91bf8c624cb7ad6cd694d93230fc in master.