138 lines · plain
1=========================2Performance Investigation3=========================4 5Multiple factors contribute to the time it takes to analyze a file with Clang Static Analyzer.6A translation unit contains multiple entry points, each of which take multiple steps to analyze.7 8Performance analysis using ``-ftime-trace``9===========================================10 11You can add the ``-ftime-trace=file.json`` option to break down the analysis time into individual entry points and steps within each entry point.12You can explore the generated JSON file in a Chromium browser using the ``chrome://tracing`` URL,13or using `perfetto <https://ui.perfetto.dev>`_ or `speedscope <https://speedscope.app>`_.14Once you narrow down to specific analysis steps you are interested in, you can more effectively employ heavier profilers,15such as `Perf <https://perfwiki.github.io/main/>`_ and `Callgrind <https://valgrind.org/docs/manual/cl-manual.html>`_.16 17Each analysis step has a time scope in the trace, corresponds to processing of an exploded node, and is designated with a ``ProgramPoint``.18If the ``ProgramPoint`` is associated with a location, you can see it on the scope metadata label.19 20Here is an example of a time trace produced with21 22.. code-block:: bash23 :caption: Clang Static Analyzer invocation to generate a time trace of string.c analysis.24 25 clang -cc1 -analyze -verify clang/test/Analysis/string.c \26 -analyzer-checker=core,unix,alpha.unix.cstring,debug.ExprInspection \27 -ftime-trace=trace.json -ftime-trace-granularity=128 29.. image:: ../images/speedscope.png30 31On the speedscope screenshot above, under the first time ruler is the bird's-eye view of the entire trace that spans a little over 60 milliseconds.32Under the second ruler (focused on the 18.09-18.13ms time point) you can see a narrowed-down portion.33The second box ("HandleCode memset...") that spans entire screen (and actually extends beyond it) corresponds to the analysis of ``memset16_region_cast()`` entry point that is defined in the "string.c" test file on line 1627.34Below it, you can find multiple sub-scopes each corresponding to processing of a single exploded node.35 36- First: a ``PostStmt`` for some statement on line 1634. This scope has a selected subscope "CheckerManager::runCheckersForCallEvent (Pre)" that takes 5 microseconds.37- Four other nodes, too small to be discernible at this zoom level38- Last on this screenshot: another ``PostStmt`` for a statement on line 1635.39 40In addition to the ``-ftime-trace`` option, you can use ``-ftime-trace-granularity`` to fine-tune the time trace.41 42- ``-ftime-trace-granularity=NN`` dumps only time scopes that are longer than NN microseconds.43- ``-ftime-trace-verbose`` enables some additional dumps in the frontend related to template instantiations.44 At the moment, it has no effect on the traces from the static analyzer.45 46Note: Both Chrome-tracing and speedscope tools might struggle with time traces above 100 MB in size.47Luckily, in most cases the default max-steps boundary of 225 000 produces the traces of approximately that size48for a single entry point.49You can use ``-analyze-function=get_global_options`` together with ``-ftime-trace`` to narrow down analysis to a specific entry point.50 51 52Performance analysis using ``perf``53===================================54 55`Perf <https://perfwiki.github.io/main/>`_ is a tool for conducting sampling-based profiling.56It's easy to start profiling, you only have 2 prerequisites.57Build with ``-fno-omit-frame-pointer`` and debug info (``-g``).58You can use release builds, but probably the easiest is to set the ``CMAKE_BUILD_TYPE=RelWithDebInfo``59along with ``CMAKE_CXX_FLAGS="-fno-omit-frame-pointer"`` when configuring ``llvm``.60Here is how to `get started <https://llvm.org/docs/CMake.html#quick-start>`_ if you are in trouble.61 62.. code-block:: bash63 :caption: Running the Clang Static Analyzer through ``perf`` to gather samples of the execution.64 65 # -F: Sampling frequency, use `-F max` for maximal frequency66 # -g: Enable call-graph recording for both kernel and user space67 perf record -F 99 -g -- clang -cc1 -analyze -verify clang/test/Analysis/string.c \68 -analyzer-checker=core,unix,alpha.unix.cstring,debug.ExprInspection69 70Once you have the profile data, you can use it to produce a Flame graph.71A Flame graph is a visual representation of the stack frames of the samples.72Common stack frame prefixes are squashed together, making up a wider bar.73The wider the bar, the more time was spent under that particular stack frame,74giving a sense of how the overall execution time was spent.75 76Clone the `FlameGraph <https://github.com/brendangregg/FlameGraph>`_ git repository,77as we will use some scripts from there to convert the ``perf`` samples into a Flame graph.78It's also useful to check out Brendan Gregg's (the author of FlameGraph)79`homepage <https://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html>`_.80 81 82.. code-block:: bash83 :caption: Converting the ``perf`` profile into a Flamegraph, then opening it in Firefox.84 85 perf script | /path/to/FlameGraph/stackcollapse-perf.pl > perf.folded86 /path/to/FlameGraph/flamegraph.pl perf.folded > perf.svg87 firefox perf.svg88 89.. image:: ../images/flamegraph.png90 91 92Performance analysis using ``uftrace``93======================================94 95`uftrace <https://github.com/namhyung/uftrace/wiki/Tutorial#getting-started>`_ is a great tool to generate rich profile data96that you can use to focus and drill down into the timeline of your application.97We will use it to generate Chromium trace JSON.98In contrast to ``perf``, this approach statically instruments every function, so it should be more precise and thorough than the sampling-based approaches like ``perf``.99In contrast to using ``-ftime-trace``, functions don't need to opt-in to be profiled using ``llvm::TimeTraceScope``.100All functions are profiled due to automatic static instrumentation.101 102There is only one prerequisite to use this tool.103You need to build the binary you are about to instrument using ``-pg`` or ``-finstrument-functions``.104This will make it run substantially slower but allows rich instrumentation.105It will also consume many gigabites of storage for a single trace unless filter flags are used during recording.106 107.. code-block:: bash108 :caption: Recording with ``uftrace``, then dumping the result as a Chrome trace JSON.109 110 uftrace record clang -cc1 -analyze -verify clang/test/Analysis/string.c \111 -analyzer-checker=core,unix,alpha.unix.cstring,debug.ExprInspection112 uftrace dump --filter=".*::AnalysisConsumer::HandleTranslationUnit" --time-filter=300 --chrome > trace.json113 114.. image:: ../images/uftrace_detailed.png115 116In this picture, you can see the functions below the Static Analyzer's entry point, which takes at least 300 nanoseconds to run, visualized by Chrome's ``about:tracing`` page117You can also see how deep function calls we may have due to AST visitors.118 119Using different filters can reduce the number of functions to record.120For the common options, refer to the ``uftrace`` `documentation <https://github.com/namhyung/uftrace/blob/master/doc/uftrace-record.md#common-options>`_.121 122Similar filters can be applied for dumping too. That way you can reuse the same (detailed)123recording to selectively focus on some special part using a refinement of the filter flags.124Remember, the trace JSON needs to fit into Chrome's ``about:tracing`` or `speedscope <https://speedscope.app>`_,125thus it needs to be of a limited size.126If you do not apply filters on recording, you will collect a large trace and every dump operation127would need to sieve through the much larger recording which may be annoying if done repeatedly.128 129If the trace JSON is still too large to load, have a look at the dump as plain text and look for frequent entries that refer to non-interesting parts.130Once you have some of those, add them as ``--hide`` flags to the ``uftrace dump`` call.131To see what functions appear frequently in the trace, use this command:132 133.. code-block:: bash134 135 cat trace.json | grep -Po '"name":"(.+)"' | sort | uniq -c | sort -nr | head -n 50136 137``uftrace`` can also dump the report as a Flame graph using ``uftrace dump --framegraph``.138