Skip to content

Instantly share code, notes, and snippets.

@simonhf

simonhf/_cwrap_3.md

Last active January 2, 2020 18:11
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save simonhf/1bd9df10aabffe81bb7a1eab0d87dae7 to your computer and use it in GitHub Desktop.
Save simonhf/1bd9df10aabffe81bb7a1eab0d87dae7 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
_cwrap_3.md

Experiments with gcc auto instrumentration of C/C++ source code for run-time function call tree tracing... a working example!

Background

  • In the original experiments [1] we managed to auto instrument C but not C++ via auto generating a wrapper function for every real function to be instrumented. However, this method does not lend itself well to C++, for example, it does not seem possible to double the number of functions in a class without modifying the class source code in place, thus displacing the original source lines.
  • In the further experiments [2] it was possible to auto instrument both C and C++ via the somewhat brittle CastXML mechanism. While this method works, CastXML is not very refined and somewhat slow, making this mechanism a little heavyweight. Also, it relies on the attribute cleanup mechanism too, which isn't the fastest if the instrumentation for a particular function is disabled.
  • In this working example below we show a new mechanism (but also using some elements of both previous experiments) with the following advantages:
    • Each function instrumented gets its own individually addressable verbosity, e.g. 80,000 instrumented functions means 80,000 individually addressable function verbosities.
    • Both the global verbosity and function verbosity can be dynamically manipulated at run-time to produce any desired level of verbosity, but limited to the precise area of source code under investigation.
    • The overhead of disabled instrumentation at run-time is essentially the overhead of an inline if(verbosity >= function_verbosity){...} statement.
    • The gcc -finstrument-functions switch is used to identify function enter and leave points, which is faster, less brittle, and more lightweight than using CastXML.
    • By compiling C/C++ to assembler to object, the assembler can be modified to add an if() clause around the __cyg_profile_func_(enter|exit) calls.
    • The C++ managled function name -- not available in C++, but available in assembler -- e.g. _ZN3FooC2EPKc is unique and can be used to create a unique data block for each instrumented function, e.g. cwrap_data__ZN3FooC2EPKc.
    • Other non-enter, non-leave instrumentation can also have the if() clause, and the C++ mangled function name is determined automatically using the C++ __PRETTY_FUNCTION__ macro which is the demangled form of the mangled function name.

The disadvantage of this mechanism is that it currently only works with gcc (although clang should work but is untested) and Intel assembler (although other assemblers can be supported in the future).

[1] Original auto instrumentation experiments [2] Further auto instrumentation experiments [3] gcc -finstrument-functions

What is the mechanism powering this new working example?

The following steps are used to automatically instrument a C/C++ project:

  • The project makefile is run with CC pointing to cwrap.pl.
  • cwrap.pl is invoked whenever gcc is normally invoked by make.
  • cwrap.pl modifies the command line to add -finstrument-functions [1], and also -S [2] to compile to assembler. --include cwrap.h is also added to the command line.
  • cwrap.pl executes gcc with the modified command line, generating the assembler output.
  • cwrap.pl modifies the output assembler adding and/or modifying the if() statements as necessary.
  • cwrap.pl executes gcc again, on the modified assembler, assembling to the object file(s).
  • These steps are repeated for all compiled C/C++ files.
  • Upon linking cwrap.pl collects the n undefined reference errors for all the undefined function structs (try to use the very fast nm, or falling back to the much slower gcc linker if necessary).
  • cwrap.pl generates cwrap.c on-the-fly with all necessary function structs.
  • cwrap.pl executes gcc to link against the newly compiled cwrap.c.

[1] gcc -finstrument-functions [2] gcc -S

Which special cases caused problems during the development?

  • The assembler produced by the C and C++ compilers -- even on the same source code -- can produce a slightly different format assembler output.
  • Differing levels of optimization can cause different assembler to be generated for __cyg_profile_func_(enter|exit) calls. Therefore, automated tests were created which test with -O0, -O1, -O2, and -O3 for both C and C++. There seem to be two different patterns used by the compiler to generate assembler; one regular pattern, and one pattern used for sometimes optimizing inline function calls. Testing needs to be done on larger code bases.
  • C++ template functions needed special treatment because __PRETTY_FUNCTION__ and internal assembler representation unexpectedly differ, e.g. int get_max<int>(int, int) versus my_type get_max(my_type, my_type) [with my_type = int].
  • Created a special output mode called 'curt' which compacts the number of instrumented output lines greatly for enhanced human readability. However, due to limitations with the instrumentation mechanism, it wasn't possible to make the curt output perfect.
  • Could not find a demangling library or utility that 'just works' and existing tools disagree demangled output [1].
  • Some demangled names can be 100s of KB long e.g. due to very many nested templates, so these names are 'skeletonized' to form a non-unique demangled name.
  • The number of variants of non-unique skeletonized names are tracked.

[1] https://gist.github.com/simonhf/0d60bb94f2d90c1b32e4786b2d1062ad

Testing strategy

  • Create a smaller piece of source code which uses most types of instrumentable language features and which can be compiled either as C (with only a subset of functionality, e.g. C has no 'classes') or C++.
  • Create two sets of makefiles; one compiles and links everything with one command line, and one compiles and links everything on separate command lines.
  • Compile all variations of C or C++, 1 or n line makefile, no or curt or long instrumentation, and all levels of compiler optimation.
  • Check that inline function special case happened during at least one tested project compilation.
  • Test the demangled name skelotonization code with some different cases.
$ time perl cwrap-test.pl
- test: strategy: build common source code in all combinations of C / C++, without / with curt / with long cwrap, few / many gcc commands, O0 / 1 / 2 / 3 gcc optimization
- test: wiping folder: build/
- test: running: cd build ; make -j 2>&1
> cd language-c---example-1-cwrap-exclude------make-via-1-line-opt-O0 ; (time make -f c---example-1.via-1-line.mak OPT="-O0") > build.log 2>&1
> cd language-c---example-1-cwrap-exclude------make-via-1-line-opt-O1 ; (time make -f c---example-1.via-1-line.mak OPT="-O1") > build.log 2>&1
> cd language-c---example-1-cwrap-exclude------make-via-1-line-opt-O2 ; (time make -f c---example-1.via-1-line.mak OPT="-O2") > build.log 2>&1
> cd language-c---example-1-cwrap-exclude------make-via-1-line-opt-O3 ; (time make -f c---example-1.via-1-line.mak OPT="-O3") > build.log 2>&1
> cd language-c---example-1-cwrap-exclude------make-via-n-line-opt-O0 ; (time make -f c---example-1.via-n-line.mak OPT="-O0") > build.log 2>&1
> cd language-c---example-1-cwrap-exclude------make-via-n-line-opt-O1 ; (time make -f c---example-1.via-n-line.mak OPT="-O1") > build.log 2>&1
> cd language-c---example-1-cwrap-exclude------make-via-n-line-opt-O2 ; (time make -f c---example-1.via-n-line.mak OPT="-O2") > build.log 2>&1
> cd language-c---example-1-cwrap-exclude------make-via-n-line-opt-O3 ; (time make -f c---example-1.via-n-line.mak OPT="-O3") > build.log 2>&1
> cd language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O0 ; (time make -f c---example-1.via-1-line.mak OPT="-O0" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O1 ; (time make -f c---example-1.via-1-line.mak OPT="-O1" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O2 ; (time make -f c---example-1.via-1-line.mak OPT="-O2" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O3 ; (time make -f c---example-1.via-1-line.mak OPT="-O3" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O0 ; (time make -f c---example-1.via-n-line.mak OPT="-O0" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O1 ; (time make -f c---example-1.via-n-line.mak OPT="-O1" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O2 ; (time make -f c---example-1.via-n-line.mak OPT="-O2" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O3 ; (time make -f c---example-1.via-n-line.mak OPT="-O3" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-c---example-1-cwrap-include-long-make-via-1-line-opt-O0 ; (time make -f c---example-1.via-1-line.mak OPT="-O0" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-c---example-1-cwrap-include-long-make-via-1-line-opt-O1 ; (time make -f c---example-1.via-1-line.mak OPT="-O1" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-c---example-1-cwrap-include-long-make-via-1-line-opt-O2 ; (time make -f c---example-1.via-1-line.mak OPT="-O2" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-c---example-1-cwrap-include-long-make-via-1-line-opt-O3 ; (time make -f c---example-1.via-1-line.mak OPT="-O3" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-c---example-1-cwrap-include-long-make-via-n-line-opt-O0 ; (time make -f c---example-1.via-n-line.mak OPT="-O0" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-c---example-1-cwrap-include-long-make-via-n-line-opt-O1 ; (time make -f c---example-1.via-n-line.mak OPT="-O1" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-c---example-1-cwrap-include-long-make-via-n-line-opt-O2 ; (time make -f c---example-1.via-n-line.mak OPT="-O2" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-c---example-1-cwrap-include-long-make-via-n-line-opt-O3 ; (time make -f c---example-1.via-n-line.mak OPT="-O3" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O0 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O1 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O2 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O2") > build.log 2>&1
> cd language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O3 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O3") > build.log 2>&1
> cd language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O0 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O1 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O2 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O2") > build.log 2>&1
> cd language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O3 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O3") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O0 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O0" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O1 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O1" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O2 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O2" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O3 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O3" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O0 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O0" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O1 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O1" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O2 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O2" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O3 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O3" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O0 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O0" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O1 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O1" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O2 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O2" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O3 ; (time make -f cpp-example-1.via-1-line.mak OPT="-O3" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O0 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O0" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O1 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O1" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O2 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O2" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
> cd language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O3 ; (time make -f cpp-example-1.via-n-line.mak OPT="-O3" CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0") > build.log 2>&1
ok 1 - test: build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O0
ok 2 - test: build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O1
ok 3 - test: build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O2
ok 4 - test: build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O3
ok 5 - test: build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O0
ok 6 - test: build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O1
ok 7 - test: build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O2
ok 8 - test: build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O3
ok 9 - test: build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O0
ok 10 - test: build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O1
ok 11 - test: build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O2
ok 12 - test: build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O3
ok 13 - test: build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O0
ok 14 - test: build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O1
ok 15 - test: build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O2
ok 16 - test: build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O3
ok 17 - test: build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O0
ok 18 - test: build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O1
ok 19 - test: build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O2
ok 20 - test: build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O3
ok 21 - test: build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O0
ok 22 - test: build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O1
ok 23 - test: build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O2
ok 24 - test: build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O3
ok 25 - test: build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O0
ok 26 - test: build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O1
ok 27 - test: build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O2
ok 28 - test: build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O3
ok 29 - test: build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O0
ok 30 - test: build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O1
ok 31 - test: build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O2
ok 32 - test: build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O3
ok 33 - test: build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O0
ok 34 - test: build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O1
ok 35 - test: build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O2
ok 36 - test: build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O3
ok 37 - test: build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O0
ok 38 - test: build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O1
ok 39 - test: build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O2
ok 40 - test: build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O3
ok 41 - test: build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O0
ok 42 - test: build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O1
ok 43 - test: build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O2
ok 44 - test: build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O3
ok 45 - test: build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O0
ok 46 - test: build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O1
ok 47 - test: build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O2
ok 48 - test: build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O3
ok 49 - test: as expected, at least one build has 'movq cwrap_data_.*, %rxx' where rxx is not rdi
ok 50 - test: compressed 100 bytes unique demangled name to expected 23 bytes non-unique name: (&std::forward<>()) [9]
ok 51 - test: compressed 109 bytes unique demangled name to expected 58 bytes non-unique name: caf::data_processor<>::apply()::{unnamed-type}::operator()
ok 52 - test: compressed 130 bytes unique demangled name to expected 32 bytes non-unique name: (*std::_Any_data::_M_access<>())
ok 53 - test: compressed 138 bytes unique demangled name to expected 13 bytes non-unique name: delete_each<>
ok 54 - test: compressed 175 bytes unique demangled name to expected 37 bytes non-unique name: caf::detail::tuple_inspect_delegate<>
ok 55 - test: compressed 178 bytes unique demangled name to expected 19 bytes non-unique name: (&std::forward<>())
ok 56 - test: compressed 299 bytes unique demangled name to expected 41 bytes non-unique name: caf::(anonymous-namespace)::fill_builtins
ok 57 - test: compressed 490 bytes unique demangled name to expected 70 bytes non-unique name: broker::core_actor()::{lambda()}::operator()()::{lambda()}::operator()
ok 58 - test: compressed 573 bytes unique demangled name to expected 60 bytes non-unique name: broker::detail::network_cache::fetch<>()::{lambda()}::~fetch
ok 59 - test: compressed 773 bytes unique demangled name to expected 16 bytes non-unique name: std::transform<>
ok 60 - test: compressed 1542 bytes unique demangled name to expected 42 bytes non-unique name: std::caf::default_sum_type_access<>::get<>
ok 61 - test: compressed 1944 bytes unique demangled name to expected 23 bytes non-unique name: std::forward_as_tuple<>
ok 62 - test: compressed 6200 bytes unique demangled name to expected 136 bytes non-unique name: caf::io::middleman::remote_group()::{lambda()}::operator()()::{lambda()}::operator()()::{lambda()}::operator()()::{lambda()}::operator()
ok 63 - test: compressed 6793 bytes unique demangled name to expected 33 bytes non-unique name: std::_Tuple_impl<>::_Tuple_impl<>
1..63

real    0m2.223s

Executable output size each test build

  • For C, executable size without instrumentation ranges from 22,368 to 32,328 bytes.
  • For C, executable size with curt instrumentation ranges from 49,960 to 68,008 bytes.
  • For C, executable size with long instrumentation ranges from 49,952 to 68,008 bytes.
  • For C++, executable size without instrumentation ranges from 30,080 to 42,992 bytes.
  • For C++, executable size with curt instrumentation ranges from 64,376 to 104,984 bytes.
  • For C++, executable size with long instrumentation ranges from 64,376 to 104,984 bytes.
  • Whether C or C++, and compiling with instrumentation, compiling n gcc command lines always results in a larger executable than compiling the same code with 1 gcc comand line. Not sure why.
$ find build/ -type f | egrep exe | sort | xargs wc --bytes
  22360 build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O0/c---example-1.via-1-line.exe
  28616 build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O1/c---example-1.via-1-line.exe
  29328 build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O2/c---example-1.via-1-line.exe
  32320 build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O3/c---example-1.via-1-line.exe
  22360 build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O0/c---example-1.via-n-line.exe
  28616 build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O1/c---example-1.via-n-line.exe
  29328 build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O2/c---example-1.via-n-line.exe
  32320 build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O3/c---example-1.via-n-line.exe
  49960 build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O0/c---example-1.via-1-line.exe
  67600 build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O1/c---example-1.via-1-line.exe
  68000 build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O2/c---example-1.via-1-line.exe
  68008 build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O3/c---example-1.via-1-line.exe
  49952 build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O0/c---example-1.via-n-line.exe
  55616 build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O1/c---example-1.via-n-line.exe
  55728 build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O2/c---example-1.via-n-line.exe
  55736 build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O3/c---example-1.via-n-line.exe
  49960 build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O0/c---example-1.via-1-line.exe
  67600 build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O1/c---example-1.via-1-line.exe
  68000 build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O2/c---example-1.via-1-line.exe
  68008 build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O3/c---example-1.via-1-line.exe
  49952 build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O0/c---example-1.via-n-line.exe
  55616 build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O1/c---example-1.via-n-line.exe
  55728 build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O2/c---example-1.via-n-line.exe
  55736 build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O3/c---example-1.via-n-line.exe
  30080 build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O0/cpp-example-1.via-1-line.exe
  41208 build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O1/cpp-example-1.via-1-line.exe
  42360 build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O2/cpp-example-1.via-1-line.exe
  42992 build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O3/cpp-example-1.via-1-line.exe
  30080 build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O0/cpp-example-1.via-n-line.exe
  41208 build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O1/cpp-example-1.via-n-line.exe
  42360 build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O2/cpp-example-1.via-n-line.exe
  42992 build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O3/cpp-example-1.via-n-line.exe
  71992 build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O0/cpp-example-1.via-1-line.exe
 103512 build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O1/cpp-example-1.via-1-line.exe
 104984 build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O2/cpp-example-1.via-1-line.exe
 104984 build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O3/cpp-example-1.via-1-line.exe
  64376 build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O0/cpp-example-1.via-n-line.exe
  83888 build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O1/cpp-example-1.via-n-line.exe
  85216 build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O2/cpp-example-1.via-n-line.exe
  85216 build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O3/cpp-example-1.via-n-line.exe
  71992 build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O0/cpp-example-1.via-1-line.exe
 103512 build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O1/cpp-example-1.via-1-line.exe
 104984 build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O2/cpp-example-1.via-1-line.exe
 104984 build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O3/cpp-example-1.via-1-line.exe
  64376 build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O0/cpp-example-1.via-n-line.exe
  83888 build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O1/cpp-example-1.via-n-line.exe
  85216 build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O2/cpp-example-1.via-n-line.exe
  85216 build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O3/cpp-example-1.via-n-line.exe

Lines output by each test build

  • Long auto instrumentation produces output which is about twice the number of lines whether C or C++.
  • I.e. C without instrumentation is 40 lines, and with long instrumentation is 76 lines.
  • I.e. C++ without instrumentation is 64 lines, and with long instrumentation is 132 lines.
  • Interestingly the 'curt' instrumentation example produces less output lines than non-instrumented!
  • I.e. C without instrumentation is 40 lines, and with curt instrumentation is 40 lines.
  • I.e. C++ without instrumentation is 64 lines, and with long instrumentation is 58 lines.
$ find build/ -type f | egrep run | sort | xargs -n 1 perl -e '$f=$ARGV[0]; @l=`cat $f | egrep -v "(call.s. to|verbosity|cwrap_log_)"`; printf qq[%3d %s\n], scalar @l, $f;'
 40 build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O0/run.log
 40 build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O1/run.log
 40 build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O2/run.log
 40 build/language-c---example-1-cwrap-exclude------make-via-1-line-opt-O3/run.log
 40 build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O0/run.log
 40 build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O1/run.log
 40 build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O2/run.log
 40 build/language-c---example-1-cwrap-exclude------make-via-n-line-opt-O3/run.log
 41 build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O0/run.log
 41 build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O1/run.log
 41 build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O2/run.log
 41 build/language-c---example-1-cwrap-include-curt-make-via-1-line-opt-O3/run.log
 41 build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O0/run.log
 41 build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O1/run.log
 41 build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O2/run.log
 41 build/language-c---example-1-cwrap-include-curt-make-via-n-line-opt-O3/run.log
 87 build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O0/run.log
 87 build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O1/run.log
 87 build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O2/run.log
 87 build/language-c---example-1-cwrap-include-long-make-via-1-line-opt-O3/run.log
 87 build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O0/run.log
 87 build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O1/run.log
 87 build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O2/run.log
 87 build/language-c---example-1-cwrap-include-long-make-via-n-line-opt-O3/run.log
 67 build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O0/run.log
 67 build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O1/run.log
 67 build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O2/run.log
 67 build/language-cpp-example-1-cwrap-exclude------make-via-1-line-opt-O3/run.log
 67 build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O0/run.log
 67 build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O1/run.log
 67 build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O2/run.log
 67 build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O3/run.log
 85 build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O0/run.log
 85 build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O1/run.log
 85 build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O2/run.log
 85 build/language-cpp-example-1-cwrap-include-curt-make-via-1-line-opt-O3/run.log
 85 build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O0/run.log
 85 build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O1/run.log
 85 build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O2/run.log
 85 build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O3/run.log
164 build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O0/run.log
164 build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O1/run.log
164 build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O2/run.log
164 build/language-cpp-example-1-cwrap-include-long-make-via-1-line-opt-O3/run.log
164 build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O0/run.log
164 build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O1/run.log
164 build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O2/run.log
164 build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O3/run.log

Notes on C++ build example output without instrumentation

  • There are already some 64 printf() statements in the code which give hints as to what is happening at run-time:
$ cat build/language-cpp-example-1-cwrap-exclude------make-via-n-line-opt-O0/run.log
arg1=my_struct_1
constructing my_struct
arg1=my_struct_2
constructing my_struct
r=2
r=3
r=4
a=0
a=1
r=2
r=2
a=1
a=2
r=3
r=3
a=2
a=3
r=4
r=4
hello world
a=1
r=2
a=12345, b=67890
r=67890
a=43, b=21
r=43
arg1=my_struct_2
constructing my_struct
arg1=my_struct_3, arg2=a
constructing my_struct
constructing Foo
inside Foo
arg1=my_struct_3, arg2=b
constructing my_struct
constructing Foo
inside Foo
a=100
hello my_public
a=101
a=102
a=103
r=104
r=104
r=104
r=104
a=104
a=105
r=106
r=106
b=106
deconstructing Foo
inside ~Foo
deconstructing my_struct
deconstructing Foo
inside ~Foo
deconstructing my_struct
deconstructing my_struct
my_int=5
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via main()
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via baz()
deconstructing my_struct
deconstructing my_struct

Notes on C++ build example output with curt instrumentation

  • The existing 64 printf() statements mixed with the auto instrumentation output curt results in 58 output lines excluding the cwrap_log_verbosity_set() and cwrap_log_stats() functions.
  • cwrap_log_verbosity_set() is an example of how the individual verbosity of a function can be manipulated at run-time dynamically. In this example the function bar() is called many times, but output is disabled after the first invocation.
  • cwrap_log_stats() is an example of how all instrumented functions can be enumerated at run-time if need be to do reporting, in this example reporting on how many calls to each instrumented function.
  • C0 is shown in the first column which identifies the coroutine which is always '0' in this example.
  • Other items can also be shown in the first columns such as CPU time and stack position and thread ID, but these have been disabled in the automated tests because they are not deterministic.
$ cat build/language-cpp-example-1-cwrap-include-curt-make-via-n-line-opt-O0/run.log
cwrap_log_init() {} // CWRAP_LOG: _VERBOSITY_SET_ALL=1 _STATS=1 _CURT=1 _FILE=0 _COR_ID=1 _THREAD_ID=0 _STACK_PTR=0 _TIMESTAMP=0
C0 + cwrap_log_verbosity_set_all(verbosity=1) {} // #1 set verbosity for 23 functions instrumented
C0 + _GLOBAL__sub_I_cpp_example_1_a_cpp() {
C0   + __static_initialization_and_destruction_0() {
C0     + my_struct::my_struct(arg1=my_struct_1) {} // #1 constructing my_struct
C0     } // __static_initialization_and_destruction_0() #1
C0   } // _GLOBAL__sub_I_cpp_example_1_a_cpp() #1
C0 + _GLOBAL__sub_I_cpp_example_1_b_cpp() {
C0   + __static_initialization_and_destruction_0() {
C0     + my_struct::my_struct(arg1=my_struct_2) {} // #2 constructing my_struct
C0     } // __static_initialization_and_destruction_0() #2
C0   } // _GLOBAL__sub_I_cpp_example_1_b_cpp() #1
C0 + main() {
C0   + qux() {
C0     + quux() {} = r=2 // #1
C0     + quux() {} = r=3 // #2
C0     + quux() {} = r=4 // #3
C0     } // qux() #1
C0   + bar(a=0) {
C0     + baz(a=1) {} = r=2 // #1
C0     } = r=2 // bar() #1
C0   + cwrap_log_verbosity_set(verbosity=2, name=bar) {} // #1 setting verbosity to 2 (was 1) for function bar()
C0   + baz(a=2) {} = r=3 // #2
C0   + baz(a=3) {} = r=4 // #3
C0   - hello world
C0   + baz(a=1) {} = r=2 // #4
C0   + int get_max<>(a=12345, b=67890) {} = r=67890 // #1
C0   + char get_max<>(a=43, b=21) {} = r=43 // #1
C0   + my_struct::my_struct(arg1=my_struct_2) {} // #3 constructing my_struct
C0   + Foo::Foo() {
C0     + my_struct::my_struct(arg1=my_struct_3, arg2=a) {} // #1 constructing my_struct
C0     - constructing Foo
C0     - inside Foo
C0     } // Foo::Foo() #1
C0   + Foo::Foo() {
C0     + my_struct::my_struct(arg1=my_struct_3, arg2=b) {} // #2 constructing my_struct
C0     - constructing Foo
C0     - inside Foo
C0     } // Foo::Foo() #2
C0   + Foo::my_public(a=100) {
C0     - hello my_public
C0     + Foo::my_private(a=101) {
C0       + baz(a=103) {} = r=104 // #5
C0       } = r=104 // Foo::my_private() #1
C0     } = r=104 // Foo::my_public() #1
C0   + baz(a=105) {} = r=106 // #6
C0   - return b=106
C0   + Foo::~Foo() { // deconstructing Foo
C0     - inside ~Foo
C0     + my_struct::~my_struct() {} // #1 deconstructing my_struct
C0     } // Foo::~Foo() #1
C0   + Foo::~Foo() { // deconstructing Foo
C0     - inside ~Foo
C0     + my_struct::~my_struct() {} // #2 deconstructing my_struct
C0     } // Foo::~Foo() #2
C0   + my_struct::~my_struct() {} // #3 deconstructing my_struct
C0   + clean_up() {} // #1 my_int=5
C0   } // main() #1
C0 + bye_baz() {} // #1 called via atexit() via baz()
C0 + bye_baz() {} // #2 called via atexit() via baz()
C0 + bye_baz() {} // #3 called via atexit() via baz()
C0 + bye() {} // #1 called via atexit() via main()
C0 + bye_baz() {} // #4 called via atexit() via baz()
C0 + bye_baz() {} // #5 called via atexit() via baz()
C0 + bye_baz() {} // #6 called via atexit() via baz()
C0 + my_struct::~my_struct() {} // #4 deconstructing my_struct
C0 + my_struct::~my_struct() {} // #5 deconstructing my_struct
C0 + cwrap_log_stats() {
C0   - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set() 
C0   - 1 calls to 1 of 1 function variation for cwrap_log_stats() 
C0   - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set_all() 
C0   - 1 calls to 1 of 1 function variation for main() 
C0   - 5 calls to 1 of 1 function variation for my_struct::~my_struct() 
C0   - 2 calls to 2 of 2 function variation for my_struct::my_struct() 
C0   - 3 calls to 1 of 2 function variation for my_struct::my_struct() 
C0   - 2 calls to 1 of 1 function variation for Foo::~Foo() 
C0   - 2 calls to 1 of 1 function variation for Foo::Foo() 
C0   - 1 calls to 1 of 1 function variation for Foo::my_public() 
C0   - 1 calls to 1 of 1 function variation for Foo::my_private() 
C0   - 3 calls to 1 of 1 function variation for quux() 
C0   - 1 calls to 1 of 1 function variation for qux() 
C0   - 1 calls to 1 of 1 function variation for bar() 
C0   - 1 calls to 1 of 1 function variation for clean_up() 
C0   - 1 calls to 1 of 1 function variation for int get_max<>() 
C0   - 1 calls to 1 of 1 function variation for char get_max<>() 
C0   - 6 calls to 1 of 1 function variation for bye_baz() 
C0   - 2 calls to 1 of 1 function variation for __static_initialization_and_destruction_0() 
C0   - 1 calls to 1 of 1 function variation for bye() 
C0   - 6 calls to 1 of 1 function variation for baz() 
C0   - 1 calls to 1 of 1 function variation for _GLOBAL__sub_I_cpp_example_1_b_cpp() 
C0   - 1 calls to 1 of 1 function variation for _GLOBAL__sub_I_cpp_example_1_a_cpp() 
C0   - 45 calls to 23 of 23 functions instrumented
C0   } // cwrap_log_stats() #1

Notes on C++ build example output with long instrumentation

  • The existing 64 printf() statements mixed with the auto instrumentation output curt results in 132 output lines excluding the cwrap_log_verbosity_set() and cwrap_log_stats() functions.
$ cat build/language-cpp-example-1-cwrap-include-long-make-via-n-line-opt-O0/run.log
cwrap_log_init() {} // CWRAP_LOG: _VERBOSITY_SET_ALL=1 _STATS=1 _CURT=0 _FILE=0 _COR_ID=1 _THREAD_ID=0 _STACK_PTR=0 _TIMESTAMP=0
C0 + cwrap_log_verbosity_set_all() {
C0   - verbosity=1
C0   - set verbosity for 23 functions instrumented
C0   } // cwrap_log_verbosity_set_all() #1
C0 + _GLOBAL__sub_I_cpp_example_1_a_cpp() {
C0   + __static_initialization_and_destruction_0() {
C0     + my_struct::my_struct() {
C0       - arg1=my_struct_1
C0       - constructing my_struct
C0       } // my_struct::my_struct() #1
C0     } // __static_initialization_and_destruction_0() #1
C0   } // _GLOBAL__sub_I_cpp_example_1_a_cpp() #1
C0 + _GLOBAL__sub_I_cpp_example_1_b_cpp() {
C0   + __static_initialization_and_destruction_0() {
C0     + my_struct::my_struct() {
C0       - arg1=my_struct_2
C0       - constructing my_struct
C0       } // my_struct::my_struct() #2
C0     } // __static_initialization_and_destruction_0() #2
C0   } // _GLOBAL__sub_I_cpp_example_1_b_cpp() #1
C0 + main() {
C0   + qux() {
C0     + quux() {
C0       - return r=2
C0       } // quux() #1
C0     + quux() {
C0       - return r=3
C0       } // quux() #2
C0     + quux() {
C0       - return r=4
C0       } // quux() #3
C0     } // qux() #1
C0   + bar() {
C0     - a=0
C0     + baz() {
C0       - a=1
C0       - return r=2
C0       } // baz() #1
C0     - return r=2
C0     } // bar() #1
C0   + cwrap_log_verbosity_set() {
C0     - verbosity=2, name=bar
C0     - setting verbosity to 2 (was 1) for function bar()
C0     } // cwrap_log_verbosity_set() #1
C0   + baz() {
C0     - a=2
C0     - return r=3
C0     } // baz() #2
C0   + baz() {
C0     - a=3
C0     - return r=4
C0     } // baz() #3
C0   - hello world
C0   + baz() {
C0     - a=1
C0     - return r=2
C0     } // baz() #4
C0   + int get_max<>() {
C0     - a=12345, b=67890
C0     - return r=67890
C0     } // int get_max<>() #1
C0   + char get_max<>() {
C0     - a=43, b=21
C0     - return r=43
C0     } // char get_max<>() #1
C0   + my_struct::my_struct() {
C0     - arg1=my_struct_2
C0     - constructing my_struct
C0     } // my_struct::my_struct() #3
C0   + Foo::Foo() {
C0     + my_struct::my_struct() {
C0       - arg1=my_struct_3, arg2=a
C0       - constructing my_struct
C0       } // my_struct::my_struct() #1
C0     - constructing Foo
C0     - inside Foo
C0     } // Foo::Foo() #1
C0   + Foo::Foo() {
C0     + my_struct::my_struct() {
C0       - arg1=my_struct_3, arg2=b
C0       - constructing my_struct
C0       } // my_struct::my_struct() #2
C0     - constructing Foo
C0     - inside Foo
C0     } // Foo::Foo() #2
C0   + Foo::my_public() {
C0     - a=100
C0     - hello my_public
C0     + Foo::my_private() {
C0       - a=101
C0       + baz() {
C0         - a=103
C0         - return r=104
C0         } // baz() #5
C0       - return r=104
C0       } // Foo::my_private() #1
C0     - return r=104
C0     } // Foo::my_public() #1
C0   + baz() {
C0     - a=105
C0     - return r=106
C0     } // baz() #6
C0   - return b=106
C0   + Foo::~Foo() {
C0     - deconstructing Foo
C0     - inside ~Foo
C0     + my_struct::~my_struct() {
C0       - deconstructing my_struct
C0       } // my_struct::~my_struct() #1
C0     } // Foo::~Foo() #1
C0   + Foo::~Foo() {
C0     - deconstructing Foo
C0     - inside ~Foo
C0     + my_struct::~my_struct() {
C0       - deconstructing my_struct
C0       } // my_struct::~my_struct() #2
C0     } // Foo::~Foo() #2
C0   + my_struct::~my_struct() {
C0     - deconstructing my_struct
C0     } // my_struct::~my_struct() #3
C0   + clean_up() {
C0     - my_int=5
C0     } // clean_up() #1
C0   } // main() #1
C0 + bye_baz() {
C0   - called via atexit() via baz()
C0   } // bye_baz() #1
C0 + bye_baz() {
C0   - called via atexit() via baz()
C0   } // bye_baz() #2
C0 + bye_baz() {
C0   - called via atexit() via baz()
C0   } // bye_baz() #3
C0 + bye() {
C0   - called via atexit() via main()
C0   } // bye() #1
C0 + bye_baz() {
C0   - called via atexit() via baz()
C0   } // bye_baz() #4
C0 + bye_baz() {
C0   - called via atexit() via baz()
C0   } // bye_baz() #5
C0 + bye_baz() {
C0   - called via atexit() via baz()
C0   } // bye_baz() #6
C0 + my_struct::~my_struct() {
C0   - deconstructing my_struct
C0   } // my_struct::~my_struct() #4
C0 + my_struct::~my_struct() {
C0   - deconstructing my_struct
C0   } // my_struct::~my_struct() #5
C0 + cwrap_log_stats() {
C0   - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set() 
C0   - 1 calls to 1 of 1 function variation for cwrap_log_stats() 
C0   - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set_all() 
C0   - 1 calls to 1 of 1 function variation for main() 
C0   - 5 calls to 1 of 1 function variation for my_struct::~my_struct() 
C0   - 2 calls to 2 of 2 function variation for my_struct::my_struct() 
C0   - 3 calls to 1 of 2 function variation for my_struct::my_struct() 
C0   - 2 calls to 1 of 1 function variation for Foo::~Foo() 
C0   - 2 calls to 1 of 1 function variation for Foo::Foo() 
C0   - 1 calls to 1 of 1 function variation for Foo::my_public() 
C0   - 1 calls to 1 of 1 function variation for Foo::my_private() 
C0   - 3 calls to 1 of 1 function variation for quux() 
C0   - 1 calls to 1 of 1 function variation for qux() 
C0   - 1 calls to 1 of 1 function variation for bar() 
C0   - 1 calls to 1 of 1 function variation for clean_up() 
C0   - 1 calls to 1 of 1 function variation for int get_max<>() 
C0   - 1 calls to 1 of 1 function variation for char get_max<>() 
C0   - 6 calls to 1 of 1 function variation for bye_baz() 
C0   - 2 calls to 1 of 1 function variation for __static_initialization_and_destruction_0() 
C0   - 1 calls to 1 of 1 function variation for bye() 
C0   - 6 calls to 1 of 1 function variation for baz() 
C0   - 1 calls to 1 of 1 function variation for _GLOBAL__sub_I_cpp_example_1_b_cpp() 
C0   - 1 calls to 1 of 1 function variation for _GLOBAL__sub_I_cpp_example_1_a_cpp() 
C0   - 45 calls to 23 of 23 functions instrumented
C0   } // cwrap_log_stats() #1
Raw
c---example-1.a.c
#include "cpp-example-1.a.cpp"
Raw
c---example-1.b.c
#include "cpp-example-1.b.cpp"
Raw
c---example-1.exclude-----.output.txt
r=2
r=3
r=4
a=0
a=1
r=2
r=2
a=1
a=2
r=3
r=3
a=2
a=3
r=4
r=4
hello world
a=1
r=2
a=100
hello my_public
a=101
a=102
a=103
r=104
r=104
r=104
r=104
a=104
a=105
r=106
r=106
b=106
my_int=5
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via main()
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via baz()
Raw
c---example-1.include-curt.output.txt
cwrap_log_init() {} // CWRAP_LOG: _VERBOSITY_SET_ALL=1 _STATS=1 _CURT=1 _FILE=0 _COR_ID=1 _THREAD_ID=0 _STACK_PTR=0 _TIMESTAMP=0
C0 + cwrap_log_verbosity_set_all(verbosity=1) {} // #1 set verbosity for 13 functions instrumented
C0 + main() {
C0 + qux() {
C0 + quux() {} = r=2 // #1
C0 + quux() {} = r=3 // #2
C0 + quux() {} = r=4 // #3
C0 } // qux() #1
C0 + bar(a=0) {
C0 + baz(a=1) {} = r=2 // #1
C0 } = r=2 // bar() #1
C0 + cwrap_log_verbosity_set(verbosity=2, name=bar) {} // #1 setting verbosity to 2 (was 1) for function bar()
C0 + baz(a=2) {} = r=3 // #2
C0 + baz(a=3) {} = r=4 // #3
C0 - hello world
C0 + baz(a=1) {} = r=2 // #4
C0 + my_public(a=100) {
C0 - hello my_public
C0 + my_private(a=101) {
C0 + baz(a=103) {} = r=104 // #5
C0 } = r=104 // my_private() #1
C0 } = r=104 // my_public() #1
C0 + baz(a=105) {} = r=106 // #6
C0 - return b=106
C0 + clean_up() {} // #1 my_int=5
C0 } // main() #1
C0 + bye_baz() {} // #1 called via atexit() via baz()
C0 + bye_baz() {} // #2 called via atexit() via baz()
C0 + bye_baz() {} // #3 called via atexit() via baz()
C0 + bye() {} // #1 called via atexit() via main()
C0 + bye_baz() {} // #4 called via atexit() via baz()
C0 + bye_baz() {} // #5 called via atexit() via baz()
C0 + bye_baz() {} // #6 called via atexit() via baz()
C0 + cwrap_log_stats() {
C0 - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set()
C0 - 1 calls to 1 of 1 function variation for cwrap_log_stats()
C0 - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set_all()
C0 - 1 calls to 1 of 1 function variation for qux()
C0 - 3 calls to 1 of 1 function variation for quux()
C0 - 1 calls to 1 of 1 function variation for my_public()
C0 - 1 calls to 1 of 1 function variation for my_private()
C0 - 1 calls to 1 of 1 function variation for main()
C0 - 1 calls to 1 of 1 function variation for clean_up()
C0 - 6 calls to 1 of 1 function variation for bye_baz()
C0 - 1 calls to 1 of 1 function variation for bye()
C0 - 6 calls to 1 of 1 function variation for baz()
C0 - 1 calls to 1 of 1 function variation for bar()
C0 - 25 calls to 13 of 13 functions instrumented
C0 } // cwrap_log_stats() #1
Raw
c---example-1.include-long.output.txt
cwrap_log_init() {} // CWRAP_LOG: _VERBOSITY_SET_ALL=1 _STATS=1 _CURT=0 _FILE=0 _COR_ID=1 _THREAD_ID=0 _STACK_PTR=0 _TIMESTAMP=0
C0 + cwrap_log_verbosity_set_all() {
C0 - verbosity=1
C0 - set verbosity for 13 functions instrumented
C0 } // cwrap_log_verbosity_set_all() #1
C0 + main() {
C0 + qux() {
C0 + quux() {
C0 - return r=2
C0 } // quux() #1
C0 + quux() {
C0 - return r=3
C0 } // quux() #2
C0 + quux() {
C0 - return r=4
C0 } // quux() #3
C0 } // qux() #1
C0 + bar() {
C0 - a=0
C0 + baz() {
C0 - a=1
C0 - return r=2
C0 } // baz() #1
C0 - return r=2
C0 } // bar() #1
C0 + cwrap_log_verbosity_set() {
C0 - verbosity=2, name=bar
C0 - setting verbosity to 2 (was 1) for function bar()
C0 } // cwrap_log_verbosity_set() #1
C0 + baz() {
C0 - a=2
C0 - return r=3
C0 } // baz() #2
C0 + baz() {
C0 - a=3
C0 - return r=4
C0 } // baz() #3
C0 - hello world
C0 + baz() {
C0 - a=1
C0 - return r=2
C0 } // baz() #4
C0 + my_public() {
C0 - a=100
C0 - hello my_public
C0 + my_private() {
C0 - a=101
C0 + baz() {
C0 - a=103
C0 - return r=104
C0 } // baz() #5
C0 - return r=104
C0 } // my_private() #1
C0 - return r=104
C0 } // my_public() #1
C0 + baz() {
C0 - a=105
C0 - return r=106
C0 } // baz() #6
C0 - return b=106
C0 + clean_up() {
C0 - my_int=5
C0 } // clean_up() #1
C0 } // main() #1
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #1
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #2
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #3
C0 + bye() {
C0 - called via atexit() via main()
C0 } // bye() #1
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #4
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #5
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #6
C0 + cwrap_log_stats() {
C0 - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set()
C0 - 1 calls to 1 of 1 function variation for cwrap_log_stats()
C0 - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set_all()
C0 - 1 calls to 1 of 1 function variation for qux()
C0 - 3 calls to 1 of 1 function variation for quux()
C0 - 1 calls to 1 of 1 function variation for my_public()
C0 - 1 calls to 1 of 1 function variation for my_private()
C0 - 1 calls to 1 of 1 function variation for main()
C0 - 1 calls to 1 of 1 function variation for clean_up()
C0 - 6 calls to 1 of 1 function variation for bye_baz()
C0 - 1 calls to 1 of 1 function variation for bye()
C0 - 6 calls to 1 of 1 function variation for baz()
C0 - 1 calls to 1 of 1 function variation for bar()
C0 - 25 calls to 13 of 13 functions instrumented
C0 } // cwrap_log_stats() #1
Raw
c---example-1.via-1-line.mak
all: c---example-1.via-1-line.exe
@echo - Makefile: 1 line: Running $<
CWRAP_LOG_VERBOSITY_SET_ALL=1 CWRAP_LOG_STATS=1 ./$< 2>&1 | tee run.log
c---example-1.via-1-line.exe: c---example-1.*.c cpp-example-1.*.cpp cpp-example-1.*.hpp
@echo - Makefile: 1 line: Building and linking $@
$(CC) $(OPT) -Werror -g -o $@ c---example-1.*.c
Raw
c---example-1.via-n-line.mak
all: c---example-1.via-n-line.exe
@echo - Makefile: n line: Running $<
CWRAP_LOG_VERBOSITY_SET_ALL=1 CWRAP_LOG_STATS=1 ./$< 2>&1 | tee run.log
c---example-1.a.o: c---example-1.a.c cpp-example-1.a.cpp cpp-example-1.*.hpp
@echo - Makefile: n lines: Building $@
$(CC) $(OPT) -Werror -g -o $@ -c $<
c---example-1.b.o: c---example-1.b.c cpp-example-1.b.cpp cpp-example-1.*.hpp
@echo - Makefile: n lines: Building $@
$(CC) $(OPT) -Werror -g -o $@ -c $<
c---example-1.via-n-line.exe: c---example-1.a.o c---example-1.b.o
@echo - Makefile: n lines: Linking $@
$(CC) -Werror -g -o $@ $^
Raw
cpp-example-1.a.cpp
#include <stdio.h>
#include <stdlib.h>
#include "cpp-example-1.a.hpp"
#define INLINE inline __attribute__((always_inline))
extern void clean_up(int * my_int);
void bye_baz (void ) { append_printf("called via atexit() via baz()\n"); }
void bye (void ) { append_printf("called via atexit() via main()\n"); }
int baz (int a ) { atexit(bye_baz); params_printf("a=%d\n", a); int r = (1 + a); result_printf("r=%d\n", r); return r; }
static INLINE int bar (int a ) { params_printf("a=%d\n", a); int r = baz(1 + a); result_printf("r=%d\n", r); return r; }
static INLINE int quux (int a ) { int r = (1 + a); result_printf("r=%d\n", r); return r; }
static void qux (void ) { for (int i = 0; i < 3; i++) { quux(1 + i); } }
#ifdef __cplusplus
class Foo {
private:
my_struct my_struct_3;
#endif
int my_private(int a) { params_printf("a=%d\n", a); int r = bar(1 + a); result_printf("r=%d\n", r); return r; }
#ifdef __cplusplus
public:
Foo(const char* arg1) : my_struct_3("my_struct_3", arg1) { append_printf( "constructing Foo\n"); debug_printf("inside Foo\n"); }
~Foo() { append_printf("deconstructing Foo\n"); debug_printf("inside ~Foo\n"); }
#endif
int my_public(int a) { params_printf("a=%d\n", a); debug_printf("hello my_public\n"); int r = my_private(1 + a); result_printf("r=%d\n", r); return r; }
#ifdef __cplusplus
};
#endif
#ifdef __cplusplus
my_struct my_struct_1("my_struct_1");
#endif
int main() {
qux();
for (int i = 0; i < 3; i++) {
bar(i);
#ifdef CWRAP
if (0 == i) {
cwrap_log_verbosity_set(2, "bar");
}
#endif
}
atexit(bye);
int my_int __attribute__ ((__cleanup__(clean_up))) = 1;
my_int = 5;
debug_printf("hello world\n");
int b = baz(1);
#ifdef __cplusplus
int x1 = 12345, y1 = 67890;
get_max <int> (x1,y1);
char x2 = 43, y2 = 21;
get_max <char> (x2,y2);
my_struct my_struct_2("my_struct_2");
Foo foo_1("a");
Foo foo_2("b");
b = bar(foo_1.my_public(100));
#else
b = bar( my_public(100));
#endif
result_printf("b=%d\n", b);
return b;
}
Raw
cpp-example-1.a.hpp
#ifndef debug_printf
#define debug_printf(...) printf(__VA_ARGS__)
#define params_printf(...) printf(__VA_ARGS__)
#define result_printf(...) printf(__VA_ARGS__)
#define append_printf(...) printf(__VA_ARGS__)
#endif
#include "cpp-example-1.b.hpp"
Raw
cpp-example-1.b.cpp
#include <stdio.h>
#include "cpp-example-1.a.hpp"
#ifdef __cplusplus
my_struct my_struct_2("my_struct_2");
#endif
void clean_up(int * my_int) { append_printf("my_int=%d\n", *my_int); }
Raw
cpp-example-1.b.hpp
#ifdef __cplusplus
struct my_struct {
my_struct(const char *f ) { f_ = f; params_printf("arg1=%s\n" , f_ ); append_printf( "constructing my_struct\n"); }
my_struct(const char *f, const char *b) { f_ = f; params_printf("arg1=%s, arg2=%s\n", f_, b); append_printf( "constructing my_struct\n"); }
~my_struct( ) { append_printf("deconstructing my_struct\n"); }
const char *f_;
};
template <class my_type>
my_type get_max (my_type a, my_type b) { params_printf("a=%d, b=%d\n", a, b); my_type r = (a > b) ? a : b; result_printf("r=%d\n", r); return r; }
#endif
Raw
cpp-example-1.exclude-----.output.txt
arg1=my_struct_1
constructing my_struct
arg1=my_struct_2
constructing my_struct
r=2
r=3
r=4
a=0
a=1
r=2
r=2
a=1
a=2
r=3
r=3
a=2
a=3
r=4
r=4
hello world
a=1
r=2
a=12345, b=67890
r=67890
a=43, b=21
r=43
arg1=my_struct_2
constructing my_struct
arg1=my_struct_3, arg2=a
constructing my_struct
constructing Foo
inside Foo
arg1=my_struct_3, arg2=b
constructing my_struct
constructing Foo
inside Foo
a=100
hello my_public
a=101
a=102
a=103
r=104
r=104
r=104
r=104
a=104
a=105
r=106
r=106
b=106
deconstructing Foo
inside ~Foo
deconstructing my_struct
deconstructing Foo
inside ~Foo
deconstructing my_struct
deconstructing my_struct
my_int=5
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via main()
called via atexit() via baz()
called via atexit() via baz()
called via atexit() via baz()
deconstructing my_struct
deconstructing my_struct
Raw
cpp-example-1.include-curt.output.txt
cwrap_log_init() {} // CWRAP_LOG: _VERBOSITY_SET_ALL=1 _STATS=1 _CURT=1 _FILE=0 _COR_ID=1 _THREAD_ID=0 _STACK_PTR=0 _TIMESTAMP=0
C0 + cwrap_log_verbosity_set_all(verbosity=1) {} // #1 set verbosity for 23 functions instrumented
C0 + _GLOBAL__sub_I_cpp_example_1_a_cpp() {
C0 + __static_initialization_and_destruction_0() {
C0 + my_struct::my_struct(arg1=my_struct_1) {} // #1 constructing my_struct
C0 } // __static_initialization_and_destruction_0() #1
C0 } // _GLOBAL__sub_I_cpp_example_1_a_cpp() #1
C0 + _GLOBAL__sub_I_cpp_example_1_b_cpp() {
C0 + __static_initialization_and_destruction_0() {
C0 + my_struct::my_struct(arg1=my_struct_2) {} // #2 constructing my_struct
C0 } // __static_initialization_and_destruction_0() #2
C0 } // _GLOBAL__sub_I_cpp_example_1_b_cpp() #1
C0 + main() {
C0 + qux() {
C0 + quux() {} = r=2 // #1
C0 + quux() {} = r=3 // #2
C0 + quux() {} = r=4 // #3
C0 } // qux() #1
C0 + bar(a=0) {
C0 + baz(a=1) {} = r=2 // #1
C0 } = r=2 // bar() #1
C0 + cwrap_log_verbosity_set(verbosity=2, name=bar) {} // #1 setting verbosity to 2 (was 1) for function bar()
C0 + baz(a=2) {} = r=3 // #2
C0 + baz(a=3) {} = r=4 // #3
C0 - hello world
C0 + baz(a=1) {} = r=2 // #4
C0 + int get_max<>(a=12345, b=67890) {} = r=67890 // #1
C0 + char get_max<>(a=43, b=21) {} = r=43 // #1
C0 + my_struct::my_struct(arg1=my_struct_2) {} // #3 constructing my_struct
C0 + Foo::Foo() {
C0 + my_struct::my_struct(arg1=my_struct_3, arg2=a) {} // #1 constructing my_struct
C0 - constructing Foo
C0 - inside Foo
C0 } // Foo::Foo() #1
C0 + Foo::Foo() {
C0 + my_struct::my_struct(arg1=my_struct_3, arg2=b) {} // #2 constructing my_struct
C0 - constructing Foo
C0 - inside Foo
C0 } // Foo::Foo() #2
C0 + Foo::my_public(a=100) {
C0 - hello my_public
C0 + Foo::my_private(a=101) {
C0 + baz(a=103) {} = r=104 // #5
C0 } = r=104 // Foo::my_private() #1
C0 } = r=104 // Foo::my_public() #1
C0 + baz(a=105) {} = r=106 // #6
C0 - return b=106
C0 + Foo::~Foo() { // deconstructing Foo
C0 - inside ~Foo
C0 + my_struct::~my_struct() {} // #1 deconstructing my_struct
C0 } // Foo::~Foo() #1
C0 + Foo::~Foo() { // deconstructing Foo
C0 - inside ~Foo
C0 + my_struct::~my_struct() {} // #2 deconstructing my_struct
C0 } // Foo::~Foo() #2
C0 + my_struct::~my_struct() {} // #3 deconstructing my_struct
C0 + clean_up() {} // #1 my_int=5
C0 } // main() #1
C0 + bye_baz() {} // #1 called via atexit() via baz()
C0 + bye_baz() {} // #2 called via atexit() via baz()
C0 + bye_baz() {} // #3 called via atexit() via baz()
C0 + bye() {} // #1 called via atexit() via main()
C0 + bye_baz() {} // #4 called via atexit() via baz()
C0 + bye_baz() {} // #5 called via atexit() via baz()
C0 + bye_baz() {} // #6 called via atexit() via baz()
C0 + my_struct::~my_struct() {} // #4 deconstructing my_struct
C0 + my_struct::~my_struct() {} // #5 deconstructing my_struct
C0 + cwrap_log_stats() {
C0 - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set()
C0 - 1 calls to 1 of 1 function variation for cwrap_log_stats()
C0 - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set_all()
C0 - 1 calls to 1 of 1 function variation for main()
C0 - 5 calls to 1 of 1 function variation for my_struct::~my_struct()
C0 - 2 calls to 2 of 2 function variation for my_struct::my_struct()
C0 - 3 calls to 1 of 2 function variation for my_struct::my_struct()
C0 - 2 calls to 1 of 1 function variation for Foo::~Foo()
C0 - 2 calls to 1 of 1 function variation for Foo::Foo()
C0 - 1 calls to 1 of 1 function variation for Foo::my_public()
C0 - 1 calls to 1 of 1 function variation for Foo::my_private()
C0 - 3 calls to 1 of 1 function variation for quux()
C0 - 1 calls to 1 of 1 function variation for qux()
C0 - 1 calls to 1 of 1 function variation for bar()
C0 - 1 calls to 1 of 1 function variation for clean_up()
C0 - 1 calls to 1 of 1 function variation for int get_max<>()
C0 - 1 calls to 1 of 1 function variation for char get_max<>()
C0 - 6 calls to 1 of 1 function variation for bye_baz()
C0 - 2 calls to 1 of 1 function variation for __static_initialization_and_destruction_0()
C0 - 1 calls to 1 of 1 function variation for bye()
C0 - 6 calls to 1 of 1 function variation for baz()
C0 - 1 calls to 1 of 1 function variation for _GLOBAL__sub_I_cpp_example_1_b_cpp()
C0 - 1 calls to 1 of 1 function variation for _GLOBAL__sub_I_cpp_example_1_a_cpp()
C0 - 45 calls to 23 of 23 functions instrumented
C0 } // cwrap_log_stats() #1
Raw
cpp-example-1.include-long.output.txt
cwrap_log_init() {} // CWRAP_LOG: _VERBOSITY_SET_ALL=1 _STATS=1 _CURT=0 _FILE=0 _COR_ID=1 _THREAD_ID=0 _STACK_PTR=0 _TIMESTAMP=0
C0 + cwrap_log_verbosity_set_all() {
C0 - verbosity=1
C0 - set verbosity for 23 functions instrumented
C0 } // cwrap_log_verbosity_set_all() #1
C0 + _GLOBAL__sub_I_cpp_example_1_a_cpp() {
C0 + __static_initialization_and_destruction_0() {
C0 + my_struct::my_struct() {
C0 - arg1=my_struct_1
C0 - constructing my_struct
C0 } // my_struct::my_struct() #1
C0 } // __static_initialization_and_destruction_0() #1
C0 } // _GLOBAL__sub_I_cpp_example_1_a_cpp() #1
C0 + _GLOBAL__sub_I_cpp_example_1_b_cpp() {
C0 + __static_initialization_and_destruction_0() {
C0 + my_struct::my_struct() {
C0 - arg1=my_struct_2
C0 - constructing my_struct
C0 } // my_struct::my_struct() #2
C0 } // __static_initialization_and_destruction_0() #2
C0 } // _GLOBAL__sub_I_cpp_example_1_b_cpp() #1
C0 + main() {
C0 + qux() {
C0 + quux() {
C0 - return r=2
C0 } // quux() #1
C0 + quux() {
C0 - return r=3
C0 } // quux() #2
C0 + quux() {
C0 - return r=4
C0 } // quux() #3
C0 } // qux() #1
C0 + bar() {
C0 - a=0
C0 + baz() {
C0 - a=1
C0 - return r=2
C0 } // baz() #1
C0 - return r=2
C0 } // bar() #1
C0 + cwrap_log_verbosity_set() {
C0 - verbosity=2, name=bar
C0 - setting verbosity to 2 (was 1) for function bar()
C0 } // cwrap_log_verbosity_set() #1
C0 + baz() {
C0 - a=2
C0 - return r=3
C0 } // baz() #2
C0 + baz() {
C0 - a=3
C0 - return r=4
C0 } // baz() #3
C0 - hello world
C0 + baz() {
C0 - a=1
C0 - return r=2
C0 } // baz() #4
C0 + int get_max<>() {
C0 - a=12345, b=67890
C0 - return r=67890
C0 } // int get_max<>() #1
C0 + char get_max<>() {
C0 - a=43, b=21
C0 - return r=43
C0 } // char get_max<>() #1
C0 + my_struct::my_struct() {
C0 - arg1=my_struct_2
C0 - constructing my_struct
C0 } // my_struct::my_struct() #3
C0 + Foo::Foo() {
C0 + my_struct::my_struct() {
C0 - arg1=my_struct_3, arg2=a
C0 - constructing my_struct
C0 } // my_struct::my_struct() #1
C0 - constructing Foo
C0 - inside Foo
C0 } // Foo::Foo() #1
C0 + Foo::Foo() {
C0 + my_struct::my_struct() {
C0 - arg1=my_struct_3, arg2=b
C0 - constructing my_struct
C0 } // my_struct::my_struct() #2
C0 - constructing Foo
C0 - inside Foo
C0 } // Foo::Foo() #2
C0 + Foo::my_public() {
C0 - a=100
C0 - hello my_public
C0 + Foo::my_private() {
C0 - a=101
C0 + baz() {
C0 - a=103
C0 - return r=104
C0 } // baz() #5
C0 - return r=104
C0 } // Foo::my_private() #1
C0 - return r=104
C0 } // Foo::my_public() #1
C0 + baz() {
C0 - a=105
C0 - return r=106
C0 } // baz() #6
C0 - return b=106
C0 + Foo::~Foo() {
C0 - deconstructing Foo
C0 - inside ~Foo
C0 + my_struct::~my_struct() {
C0 - deconstructing my_struct
C0 } // my_struct::~my_struct() #1
C0 } // Foo::~Foo() #1
C0 + Foo::~Foo() {
C0 - deconstructing Foo
C0 - inside ~Foo
C0 + my_struct::~my_struct() {
C0 - deconstructing my_struct
C0 } // my_struct::~my_struct() #2
C0 } // Foo::~Foo() #2
C0 + my_struct::~my_struct() {
C0 - deconstructing my_struct
C0 } // my_struct::~my_struct() #3
C0 + clean_up() {
C0 - my_int=5
C0 } // clean_up() #1
C0 } // main() #1
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #1
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #2
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #3
C0 + bye() {
C0 - called via atexit() via main()
C0 } // bye() #1
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #4
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #5
C0 + bye_baz() {
C0 - called via atexit() via baz()
C0 } // bye_baz() #6
C0 + my_struct::~my_struct() {
C0 - deconstructing my_struct
C0 } // my_struct::~my_struct() #4
C0 + my_struct::~my_struct() {
C0 - deconstructing my_struct
C0 } // my_struct::~my_struct() #5
C0 + cwrap_log_stats() {
C0 - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set()
C0 - 1 calls to 1 of 1 function variation for cwrap_log_stats()
C0 - 1 calls to 1 of 1 function variation for cwrap_log_verbosity_set_all()
C0 - 1 calls to 1 of 1 function variation for main()
C0 - 5 calls to 1 of 1 function variation for my_struct::~my_struct()
C0 - 2 calls to 2 of 2 function variation for my_struct::my_struct()
C0 - 3 calls to 1 of 2 function variation for my_struct::my_struct()
C0 - 2 calls to 1 of 1 function variation for Foo::~Foo()
C0 - 2 calls to 1 of 1 function variation for Foo::Foo()
C0 - 1 calls to 1 of 1 function variation for Foo::my_public()
C0 - 1 calls to 1 of 1 function variation for Foo::my_private()
C0 - 3 calls to 1 of 1 function variation for quux()
C0 - 1 calls to 1 of 1 function variation for qux()
C0 - 1 calls to 1 of 1 function variation for bar()
C0 - 1 calls to 1 of 1 function variation for clean_up()
C0 - 1 calls to 1 of 1 function variation for int get_max<>()
C0 - 1 calls to 1 of 1 function variation for char get_max<>()
C0 - 6 calls to 1 of 1 function variation for bye_baz()
C0 - 2 calls to 1 of 1 function variation for __static_initialization_and_destruction_0()
C0 - 1 calls to 1 of 1 function variation for bye()
C0 - 6 calls to 1 of 1 function variation for baz()
C0 - 1 calls to 1 of 1 function variation for _GLOBAL__sub_I_cpp_example_1_b_cpp()
C0 - 1 calls to 1 of 1 function variation for _GLOBAL__sub_I_cpp_example_1_a_cpp()
C0 - 45 calls to 23 of 23 functions instrumented
C0 } // cwrap_log_stats() #1
Raw
cpp-example-1.via-1-line.mak
all: cpp-example-1.via-1-line.exe
@echo - Makefile: 1 line: Running $<
CWRAP_LOG_VERBOSITY_SET_ALL=1 CWRAP_LOG_STATS=1 ./$< 2>&1 | tee run.log
cpp-example-1.via-1-line.exe: cpp-example-1.*.cpp cpp-example-1.*.hpp
@echo - Makefile: 1 line: Building and linking $@
$(CC) $(OPT) -Werror -g -o $@ cpp-example-1.*.cpp -lstdc++
Raw
cpp-example-1.via-n-line.mak
all: cpp-example-1.via-n-line.exe
@echo - Makefile: n line: Running $<
CWRAP_LOG_VERBOSITY_SET_ALL=1 CWRAP_LOG_STATS=1 ./$< 2>&1 | tee run.log
cpp-example-1.a.o: cpp-example-1.a.cpp cpp-example-1.*.hpp
@echo - Makefile: n lines: Building $@
$(CC) $(OPT) -Werror -g -o $@ -c $<
cpp-example-1.b.o: cpp-example-1.b.cpp cpp-example-1.*.hpp
@echo - Makefile: n lines: Building $@
$(CC) $(OPT) -Werror -g -o $@ -c $<
cpp-example-1.via-n-line.exe: cpp-example-1.a.o cpp-example-1.b.o
@echo - Makefile: n lines: Linking $@
$(CC) -Werror -g -o $@ $^ -lstdc++
Raw
cwrap-test.pl
use strict;
use Test::More;
$|++;
printf qq[- test: strategy: build common source code in all combinations of C / C++, without / with curt / with long cwrap, few / many gcc commands, O0 / 1 / 2 / 3 gcc optimization\n];
printf qq[- test: wiping folder: build/\n];
printf qq[ - test: rmdir folder: build/\n] if ($ARGV[0] =~ m~debug~i); `rm -rf build/`;
printf qq[ - test: mkdir folder: build/\n] if ($ARGV[0] =~ m~debug~i); `mkdir build/`;
my $mak_all = "all:";
my $mak_targets;
foreach my $pass (1..2) {
foreach my $number (1..1) {
foreach my $language (qw(c---example cpp-example)) {
foreach my $cwrap (qw(exclude----- include-curt include-long)) {
foreach my $make (qw(via-1-line via-n-line)) {
foreach my $opt (qw(O0 O1 O2 O3)) {
#next if($opt !~ m~O0~);
my $build_folder = sprintf qq[language-%s-%d-cwrap-%s-make-%s-opt-%s], $language, $number, $cwrap, $make, $opt;
my $build_path = sprintf qq[build/%s], $build_folder;
if (1 == $pass) {
my $cc;
$cc = qq[ CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=1"] if ($cwrap eq 'include-curt');
$cc = qq[ CC="perl ../../cwrap.pl -DCWRAP_LOG_CURT=0"] if ($cwrap eq 'include-long');
my $build_command = sprintf qq[cd %s ; (time make -f %s-%d.%s.mak OPT="-%s"%s) > build.log 2>&1], $build_folder, $language, $number, $make, $opt, $cc;
$mak_all .= sprintf qq[ %s/run.log], $build_folder;
$mak_targets .= sprintf qq[%s/run.log:\n\t%s\n\n], $build_folder, $build_command;
if(not -e $build_path) { printf qq[ - test: mkdir %s\n], $build_path if ($ARGV[0] =~ m~debug~i); `mkdir $build_path`; die qq[ERROR: test: build folder not created!\n] if(not -e $build_path); }
printf qq[ - test: copy example source files\n] if ($ARGV[0] =~ m~debug~i); `cp c*example-*.* $build_path/.`;
#`echo foo >> $build_path/cpp-example.1.cpp` $build_folder eq 'language-cpp-example-cwrap-include-make-via-n-line-opt-O3'); # cause a build to fail!
} # if (1 == $pass)
if (2 == $pass) {
my $compare_file = sprintf qq[%s-%d.%s.output.txt], $language, $number, $cwrap;
my $compare_command = sprintf qq[diff --brief %s %s/run.log], $compare_file, $build_path;
printf qq[ - test: running: %s\n], $compare_command if ($ARGV[0] =~ m~debug~i);
my $output = `$compare_command 2>&1`;
my $success = ($output =~ m~^\s*$~i) ? 1 : 0;
if (0 == $success) {
my $build_output = `cat $build_path/build.log`;
$build_output =~ s~^(.*)$~> $1~gm;
$build_output =~ s~\s+$~~s;
printf qq[%s\n], $build_output;
printf qq[- test: diff command failed: %s\n], $compare_command;
$output =~ s~^(.*)$~> $1~gm;
$output =~ s~\s+$~~s;
printf qq[%s\n], $output;
}
ok($success, "test: " . $build_path);
exit(1) if (0 == $success);
} # if (2 == $pass)
} # foreach my $opt
} # foreach my $make
} # foreach my $cwrap
} # foreach my $language
} # foreach my $number
if (1 == $pass) {
my $mak_file = sprintf qq[build/makefile];
open(MAK, '>', $mak_file) || die sprintf qq[ERROR: test: cannot open file for writing: %s; $!\n], $mak_file;
printf MAK qq[%s\n\n], $mak_all;
printf MAK qq[%s\n\n], $mak_targets;
close MAK;
my $make_command = sprintf qq[cd build ; make -j 2>&1];
printf qq[- test: running: %s\n], $make_command;
my $output = `$make_command`;
$output =~ s~^(.*)$~> $1~gm;
$output =~ s~\s+$~~s;
printf qq[%s\n], $output;
}
} # foreach my $pass
my $check_rbp_command = sprintf qq[find build/ -type f | sort | egrep "\.a.s.2.s" | xargs egrep "movq.*cwrap_data_" | egrep -v rdi];
printf qq[ - test: running: %s\n], $check_rbp_command if ($ARGV[0] =~ m~debug~i);
my $output = `$check_rbp_command 2>&1`;
my $success = ($output =~ m~, \%rbp~i) ? 1 : 0; # e.g. leaq cwrap_data_bar(%rip), %rbp
ok($success, "test: as expected, at least one build has 'movq cwrap_data_.*, \%rxx' where rxx is not rdi");
require "./cwrap.pl";
my $expected = q[(&std::forward<>()) [9]] ; compress_demangled_name(q[char const (&std::forward<char const (&) [9]>(std::remove_reference<char const (&) [9]>::type&)) [9]], $expected);
my $expected = q[caf::data_processor<>::apply()::{unnamed-type}::operator()] ; compress_demangled_name(q[caf::data_processor<caf::serializer>::apply(bool&)::{unnamed type#1}::operator()(unsigned char&, bool&) const], $expected);
my $expected = q[(*std::_Any_data::_M_access<>())] ; compress_demangled_name(q[void (* const&std::_Any_data::_M_access<void (*)(caf::scheduled_actor*, caf::error&)>() const)(caf::scheduled_actor*, caf::error&)], $expected);
my $expected = q[delete_each<>] ; compress_demangled_name(q[void delete_each<std::vector<BroSubstring*, std::allocator<BroSubstring*> > >(std::vector<BroSubstring*, std::allocator<BroSubstring*> >*)], $expected);
my $expected = q[caf::detail::tuple_inspect_delegate<>] ; compress_demangled_name(q[decltype ({parm#2}((get<0ul>)({parm#1}))) caf::detail::tuple_inspect_delegate<3ul, 0ul, std::tuple<caf::actor>, caf::deserializer>(std::tuple<caf::actor>&, caf::deserializer&)], $expected);
my $expected = q[(&std::forward<>())] ; compress_demangled_name(q[void (&std::forward<void (&)(caf::scheduled_actor*, caf::error&)>(std::remove_reference<void (&)(caf::scheduled_actor*, caf::error&)>::type&))(caf::scheduled_actor*, caf::error&)], $expected);
my $expected = q[caf::(anonymous-namespace)::fill_builtins] ; compress_demangled_name(q[caf::(anonymous namespace)::fill_builtins(std::array<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::function<std::unique_ptr<caf::type_erased_value, std::default_delete<caf::type_erased_value> > ()> >, 43ul>&, caf::detail::type_list<>, unsigned long)], $expected);
my $expected = q[broker::core_actor()::{lambda()}::operator()()::{lambda()}::operator()] ; compress_demangled_name(q[broker::core_actor(caf::stateful_actor<broker::core_state, caf::event_based_actor>*, std::vector<broker::topic, std::allocator<broker::topic> >, broker::broker_options, broker::endpoint::clock*)::{lambda(caf::stream<broker::node_message> const&, std::vector<broker::topic, std::allocator<broker::topic> >&, caf::actor&)#8}::operator()(caf::stream<broker::node_message> const&, std::vector<broker::topic, std::allocator<broker::topic> >&, caf::actor&) const::{lambda()#1}::operator()() const], $expected);
my $expected = q[broker::detail::network_cache::fetch<>()::{lambda()}::~fetch] ; compress_demangled_name(q[broker::detail::network_cache::fetch<broker::core_state::emit_peer_added_status(caf::actor, char const*)::{lambda(broker::network_info)#2}, broker::core_state::emit_peer_added_status(caf::actor, char const*)::{lambda(caf::error)#3}>(caf::actor const&, broker::core_state::emit_peer_added_status(caf::actor, char const*)::{lambda(broker::network_info)#2}, broker::core_state::emit_peer_added_status(caf::actor, char const*)::{lambda(caf::error)#3})::{lambda(broker::core_state::emit_peer_added_status(caf::actor, char const*)::{lambda(broker::network_info)#2}&)#2}::~fetch()], $expected);
my $expected = q[std::transform<>] ; compress_demangled_name(q[__gnu_cxx::__normal_iterator<char*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > std::transform<__gnu_cxx::__normal_iterator<char*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, __gnu_cxx::__normal_iterator<char*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, int (*)(int) noexcept>(__gnu_cxx::__normal_iterator<char*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, __gnu_cxx::__normal_iterator<char*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, __gnu_cxx::__normal_iterator<char*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, int (*)(int) noexcept)], $expected);
my $expected = q[std::caf::default_sum_type_access<>::get<>] ; compress_demangled_name(q[std::vector<broker::data, std::allocator<broker::data> >& caf::default_sum_type_access<caf::variant<broker::none, bool, unsigned long, long, double, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, broker::address, broker::subnet, broker::port, std::chrono::time_point<std::chrono::_V2::system_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >, std::chrono::duration<long, std::ratio<1l, 1000000000l> >, broker::enum_value, std::set<broker::data, std::less<broker::data>, std::allocator<broker::data> >, std::map<broker::data, broker::data, std::less<broker::data>, std::allocator<std::pair<broker::data const, broker::data> > >, std::vector<broker::data, std::allocator<broker::data> > > >::get<std::vector<broker::data, std::allocator<broker::data> >, 14>(caf::variant<broker::none, bool, unsigned long, long, double, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, broker::address, broker::subnet, broker::port, std::chrono::time_point<std::chrono::_V2::system_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >, std::chrono::duration<long, std::ratio<1l, 1000000000l> >, broker::enum_value, std::set<broker::data, std::less<broker::data>, std::allocator<broker::data> >, std::map<broker::data, broker::data, std::less<broker::data>, std::allocator<std::pair<broker::data const, broker::data> > >, std::vector<broker::data, std::allocator<broker::data> > >&, caf::sum_type_token<std::vector<broker::data, std::allocator<broker::data> >, 14>)], $expected);
my $expected = q[std::forward_as_tuple<>] ; compress_demangled_name(q[std::tuple<broker::store::request<broker::data, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data>(caf::atom_constant<(caf::atom_value)4115129> const&, broker::data&&, broker::data&&) const::{lambda(broker::data&)#1}&&, broker::store::request<broker::data, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data>(caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&) const::{lambda(caf::error&)#2}&&> std::forward_as_tuple<broker::store::request<broker::data, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data>(caf::atom_constant<(caf::atom_value)4115129> const&, broker::data&&, broker::data&&) const::{lambda(broker::data&)#1}, broker::store::request<broker::data, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data>(caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&) const::{lambda(caf::error&)#2}>(broker::store::request<broker::data, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data>(caf::atom_constant<(caf::atom_value)4115129> const&, broker::data&&, broker::data&&) const::{lambda(broker::data&)#1}, broker::store::request<broker::data, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data>(caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&, caf::atom_constant<(caf::atom_value)4115129> const&, broker::data, broker::data&&) const::{lambda(caf::error&)#2})], $expected);
my $expected = q[caf::io::middleman::remote_group()::{lambda()}::operator()()::{lambda()}::operator()()::{lambda()}::operator()()::{lambda()}::operator()]; compress_demangled_name(q[caf::io::middleman::remote_group(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, unsigned short)::{lambda(caf::event_based_actor*, caf::typed_actor<caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)69675774307885>, unsigned short, caf::intrusive_ptr<caf::actor_control_block>, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool>, caf::output_tuple<unsigned short> >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)265509555>, unsigned short, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool>, caf::output_tuple<unsigned short> >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)68776180492857>, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, unsigned short>, caf::output_tuple<caf::node_id, caf::intrusive_ptr<caf::actor_control_block>, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > > >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)286769531740155437>, caf::actor_addr, unsigned short>, caf::output_tuple<void> >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)16790277674>, unsigned short>, caf::output_tuple<void> >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)17059704627>, caf::node_id, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, caf::message, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > >, caf::output_tuple<caf::intrusive_ptr<caf::actor_control_block> > >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)4115129>, caf::node_id>, caf::output_tuple<caf::node_id, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, unsigned short> > >)#1}::operator()(caf::event_based_actor*, caf::typed_actor<caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)69675774307885>, unsigned short, caf::intrusive_ptr<caf::actor_control_block>, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool>, caf::output_tuple<unsigned short> >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)265509555>, unsigned short, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool>, caf::output_tuple<unsigned short> >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)68776180492857>, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, unsigned short>, caf::output_tuple<caf::node_id, caf::intrusive_ptr<caf::actor_control_block>, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > > >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)286769531740155437>, caf::actor_addr, unsigned short>, caf::output_tuple<void> >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)16790277674>, unsigned short>, caf::output_tuple<void> >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)17059704627>, caf::node_id, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, caf::message, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > >, caf::output_tuple<caf::intrusive_ptr<caf::actor_control_block> > >, caf::typed_mpi<caf::detail::type_list<caf::atom_constant<(caf::atom_value)4115129>, caf::node_id>, caf::output_tuple<caf::node_id, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, unsigned short> > >) const::{lambda(caf::atom_constant<(caf::atom_value)4115129>)#1}::operator()(caf::atom_constant<(caf::atom_value)4115129>) const::{lambda(caf::node_id const&, caf::intrusive_ptr<caf::actor_control_block>&, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > const&)#1}::operator()({lambda(caf::atom_constant<(caf::atom_value)4115129>)#1}, caf::node_id const, caf::intrusive_ptr<caf::actor_control_block>&)::{lambda(caf::group&)#1}::operator()({lambda(caf::node_id const&, caf::intrusive_ptr<caf::actor_control_block>&, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > const&)#1})], $expected);
my $expected = q[std::_Tuple_impl<>::_Tuple_impl<>] ; compress_demangled_name(q[std::_Tuple_impl<6ul, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::connection_handle)#8}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::io::acceptor_closed_msg const&)#9}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)69675774307885>, caf::intrusive_ptr<caf::io::doorman>&, unsigned short, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::actor_control_block> const&, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::char_traits>, std::allocator<std::char_traits> >&)#11}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda({lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::io::scribe>&, unsigned short, caf::actor_control_block, std::less<std::char_traits>)#12}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)68776180492857>, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)69675774307885>, caf::intrusive_ptr<caf::io::doorman>&, unsigned short, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::actor_control_block> const&, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::char_traits>, std::allocator<std::char_traits> >&)#11}, unsigned short)#13}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::node_id const&, unsigned long)#14}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::atom_constant<(caf::atom_value)68776180492857>, unsigned long, caf::error&)#15}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)286769531740155437>, caf::actor_addr const&, unsigned short)#16}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)16790277674>, unsigned short)#17}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)4115129>, caf::atom_constant<(caf::atom_value)68776180492857>)#18}>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)266791472>, unsigned long)#19}> >::_Tuple_impl<{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::connection_handle)#8}, caf::io::acceptor_closed_msg const&, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::io::acceptor_closed_msg const&)#9}>, std::allocator<std::char_traits>, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)69675774307885>, caf::intrusive_ptr<caf::io::doorman>&, unsigned short, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::actor_control_block> const&, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::char_traits>, std::allocator<std::char_traits> >&)#11}>, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::io::scribe>&, {lambda(caf::atom_constant<(caf::atom_value)68776180492857>, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)69675774307885>, caf::intrusive_ptr<caf::io::doorman>&, unsigned short, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::actor_control_block> const&, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::char_traits>, std::allocator<std::char_traits> >&)#11}, unsigned short)#13}, caf::node_id const, caf::error&, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::atom_constant<(caf::atom_value)68776180492857>, unsigned long, caf::error&)#15}>, caf::actor_addr const, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)286769531740155437>, caf::actor_addr const&, unsigned short)#16}, void>({lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::connection_handle)#8}&&, caf::io::acceptor_closed_msg const&, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::io::acceptor_closed_msg const&)#9}>&&, std::allocator<std::char_traits>&&, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)69675774307885>, caf::intrusive_ptr<caf::io::doorman>&, unsigned short, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::actor_control_block> const&, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::char_traits>, std::allocator<std::char_traits> >&)#11}>&&, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::io::scribe>&, {lambda(caf::atom_constant<(caf::atom_value)68776180492857>, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)69675774307885>, caf::intrusive_ptr<caf::io::doorman>&, unsigned short, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::io::accept_handle)#10}<caf::actor_control_block> const&, std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::char_traits>, std::allocator<std::char_traits> >&)#11}, unsigned short)#13}&&, caf::node_id const&&, caf::error&, caf::trivial_match_case<caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)1075533229674>, caf::atom_constant<(caf::atom_value)68776180492857>, unsigned long, caf::error&)#15}>&&, caf::actor_addr const&&, caf::io::basp_broker::make_behavior()::{lambda(caf::atom_constant<(caf::atom_value)286769531740155437>, caf::actor_addr const&, unsigned short)#16}&&)], $expected);
done_testing();
Raw
cwrap.pl
#!/usr/bin/perl
# Copyright (c) 2012 Simon Hardy-Francis.
#
# Permission is hereby granted, free of charge, to any person obtaining a copy
# of this software and associated documentation files (the "Software"), to deal
# in the Software without restriction, including without limitation the rights
# to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
# copies of the Software, and to permit persons to whom the Software is
# furnished to do so, subject to the following conditions:
#
# The above copyright notice and this permission notice shall be included in
# all copies or substantial portions of the Software.
#
# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
# IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
# FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
# AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
# LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
# OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
# THE SOFTWARE.
use strict;
use Cwd;
use Time::HiRes;
use List::MoreUtils qw(first_index indexes);
use File::Basename; # for fileparse()
use FFI::Platypus::Lang::CPP::Demangle::XS;
use Test::More;
if ($0 =~ m~test~) {
# come here if required by cwrap-test.pl
goto ONLY_REQUIRED_FOR_SUBS;
}
$| ++;
my $log;
my $cwd = getcwd;
my $ts = Time::HiRes::time();
my $arguments = "";
for ( my $c = 0; $c < @ARGV; $c++ ) {
my $tmp = $ARGV[$c];
$tmp =~ s~"~\\"~g;
$arguments .= ' ' . $tmp;
}
$arguments =~ s~^\s+~~; # e.g. gcc -O0 -g -o c---example.via-1-line.exe c---example.1.c c---example.2.c
if ($arguments =~ m~\.(cc|cpp|cxx|hpp|hxx)~) { $arguments = "g++ " . $arguments; }
else { $arguments = "gcc " . $arguments; }
my ($gcc_out_file) = $arguments =~ m~-o\s+([^\s]+)~;
my ($gcc_out_path,
$gcc_out_name,
$gcc_out_ext ) = get_path_name_and_ext($gcc_out_file) if (defined $gcc_out_file);
$log .= sprintf qq[%f - cwrap: timestamp : %s AKA %f\n], Time::HiRes::time() - $ts, scalar localtime, Time::HiRes::time();
$log .= sprintf qq[%f - cwrap: arguments : %s\n] , Time::HiRes::time() - $ts, $arguments;
$log .= sprintf qq[%f - cwrap: cwd : %s\n] , Time::HiRes::time() - $ts, $cwd;
$log .= sprintf qq[%f - cwrap: gcc_out_file: %s\n] , Time::HiRes::time() - $ts, $gcc_out_file;
$log .= sprintf qq[%f - cwrap: gcc_out_path: %s\n] , Time::HiRes::time() - $ts, $gcc_out_path;
$log .= sprintf qq[%f - cwrap: gcc_out_name: %s\n] , Time::HiRes::time() - $ts, $gcc_out_name;
$log .= sprintf qq[%f - cwrap: gcc_out_ext : %s\n] , Time::HiRes::time() - $ts, $gcc_out_ext ;
my $cwrap_c = sprintf "%s.cwrap.c", $gcc_out_name; # generate one unique .cwrap.c file per binary output
if ($cwd =~ m~(/CMakeFiles/CMakeTmp|/CMakeFiles/.*/CompilerIdC)~) {
# come here to compile cmake test programs without modifying the gcc command line
my $gcc = $arguments;
$log .= sprintf qq[%f - cwrap: unchanged: running: %s\n], Time::HiRes::time() - $ts, $gcc;
my $output = `$gcc 2>&1`;
my $exit_code = $? >> 8; # perldoc perlvar: the exit value of the subprocess is really ("$? >> 8")
my $output_2_log = $output;
$output_2_log = "<no output>\n" if ($output =~ m~^\s*$~s);
$output_2_log .= sprintf "<exit(%d)>\n", $exit_code if ($output =~ m~^\s*$~s);
$output_2_log =~ s~^(.*)$~> $1~gm;
$log .= $output_2_log;
$log .= sprintf qq[%f - cwrap: done with exit(%d)\n], Time::HiRes::time() - $ts, $exit_code;
printf qq[%s], $output;
exit($exit_code);
}
cwrap_die(sprintf qq[%f ERROR: cwrap cannot detect gcc -o command line option in arguments!\n], Time::HiRes::time() - $ts) if ($gcc_out_file =~ m~^$~);
my @argument_array = split(m~\s+~, $arguments);
my @source_file_arguments;
foreach my $argument (@argument_array) {
if ($argument =~ m~\.(cpp|cxx|cc|hpp|hxx|h|c)$~) {
push @source_file_arguments, $argument;
}
}
my @exe_file_arguments;
if ($gcc_out_file !~ m~\.o$~) {
push @exe_file_arguments, $gcc_out_file;
}
$log .= sprintf qq[%f - cwrap: source file arguments: %d (@source_file_arguments)\n], Time::HiRes::time() - $ts, scalar @source_file_arguments;
$log .= sprintf qq[%f - cwrap: exe file arguments: %d (@exe_file_arguments)\n] , Time::HiRes::time() - $ts, scalar @exe_file_arguments;
if (scalar @source_file_arguments > 0) {
source_to_assembler_to_object_or_executable();
}
if ($gcc_out_ext =~ m~\.o~) {
#$log .= sprintf qq[%f - cwrap: gcc arguments create object\n], Time::HiRes::time() - $ts;
}
else {
if (0 == scalar @source_file_arguments) {
$log .= sprintf qq[%f - cwrap: gcc arguments create executable\n], Time::HiRes::time() - $ts;
my $gcc_4_exe = $arguments;
assembler_to_object_or_executable_via_command($gcc_4_exe);
}
}
sub END {
# come here when Perl exits to write log file
if ($gcc_out_name !~ m~^\s*$~) {
$log .= sprintf qq[%f - cwrap: todo: figure out building with ninja instead of make\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: integrate home-grown, non-assembler corountines with cwrap\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: integrate third party, assembler coroutines with cwrap via generic API\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: mechanism to exclude arbitrary functions from instrumentation at compile time\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: logging to memory buffer to file\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: logging to memory buffer and only to file at exit\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: options to auto switch off function instrumentation if calls become too high at run-time\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: multi-threaded has been neglected up until now; finish off\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: try out cwrap with other open source C/C++ code bases\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: auto detect if trying to build without gcc and abort\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: implement cwrap for gcc for ARM\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: consider cloning __PRETTY_FUNCTION__ in gcc, to implement __MANGLED_FUNCTION__\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: consider building if(verbosity){..} mechanism into gcc -finstrument-functions option\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: consider adding performance option to replace if(verbosity){..} mechanism with jump switch\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: consider adding HTML run-time interface for easier browsing of run-time call-tree\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: consider keeping run-time performance stats\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: consider colored output to stdout\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: consider extra cwrap_log_init() functionality such as dump instrumentation info\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: add more scenarios to cwrap test, e.g. static and shared libraries\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: todo: do not remove -flto if file being ignored\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: done in %f seconds\n], Time::HiRes::time() - $ts, Time::HiRes::time() - $ts;
my $log_file = sprintf "%s.cwrap.log", $gcc_out_name;
open(my $out, '>', $log_file) || cwrap_die(sprintf qq[%s ERROR: cwrap: cannot open file for writing: %s\n], Time::HiRes::time() - $ts, $log_file);
syswrite($out, $log, length($log));
close $out;
}
}
sub cwrap_die {
my ($format) = shift @_;
my $die_message = sprintf $format, @_;
$log .= $die_message;
die $die_message;
}
sub source_to_assembler_to_object_or_executable {
my ($o_file) = $arguments =~ m~-o ([^\s]+)~;
my $gcc_2_s = $arguments;
$gcc_2_s =~ s~-o [^\s]+~-S -fPIC~; # fPIC needed if objects put into shared object?
$gcc_2_s .= qq[ -finstrument-functions -I. --include cwrap.h];
create_cwrap_h() if (not -e 'cwrap.h');
if ($gcc_2_s =~ s~\s+-flto(\s+)~$1~g) { # https://stackoverflow.com/questions/29972192/how-does-gccs-linktime-optimisation-flto-flag-work
$log .= sprintf qq[%f - cwrap: c/cpp to assembler: note:: removed any -flto instances otherwise assembler output optimized\n], Time::HiRes::time() - $ts;
}
$log .= sprintf qq[%f - cwrap: c/cpp to assembler: running: %s\n], Time::HiRes::time() - $ts, $gcc_2_s;
my $t1 = Time::HiRes::time();
my $output = `$gcc_2_s 2>&1`;
my $t2 = Time::HiRes::time();
my $exit_code = $? >> 8; # perldoc perlvar: the exit value of the subprocess is really ("$? >> 8")
my $output_2_log = $output;
$output_2_log = "<no output>\n" if ($output =~ m~^\s*$~s);
$output_2_log .= sprintf "<exit(%d)> in %f seconds building assembler for %s\n", $exit_code, $t2 - $t1, $o_file;
$output_2_log =~ s~^(.*)$~> $1~gm;
$log .= $output_2_log;
if ($exit_code != 0) {
$log .= sprintf qq[%f ERROR: cwrap: compilation to assembler has unexpected errors\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: done with exit(%d)\n], Time::HiRes::time() - $ts, $exit_code;
printf qq[%s], $output;
exit($exit_code);
}
$log .= sprintf qq[%f - cwrap: munging assembler files\n], Time::HiRes::time() - $ts;
foreach my $source_file_argument (@source_file_arguments) {
my ($path, $name, $exit) = get_path_name_and_ext($source_file_argument);
my $s_file = $cwd . '/' . $name . '.s';
read_modify_rewrite_assembler_file($s_file);
} # foreach my $source_file_argument
my $gcc_4_s = $arguments;
foreach my $source_file_argument (@source_file_arguments) {
my ($path, $name, $exit) = get_path_name_and_ext($source_file_argument);
my $s_file = $cwd . '/' . $name . '.s';
$gcc_4_s =~ s~$source_file_argument~$s_file.2.s~;
} # foreach my $source_file_argument
assembler_to_object_or_executable_via_command($gcc_4_s);
} # source_to_assembler_to_object_or_executable()
sub assembler_to_object_or_executable_via_command {
my ($gcc_command) = @_;
my ($o_file ) = $gcc_command =~ m~-o ([^\s]+)~;
my $output;
my $output_2_log;
if ((0 == scalar @exe_file_arguments) # if no undefined cwrap_data_* because assembling to object files, or
|| ($gcc_command =~ m~\-shared~ )) { # if no undefined cwrap_data_* because creating a shared object
# come here if gxx operation results in no undefined cwrap_data_*
$log .= sprintf qq[%f - cwrap: no undefined cwrap_data_*: running: %s\n], Time::HiRes::time() - $ts, $gcc_command;
my $t1 = Time::HiRes::time();
$output = `$gcc_command 2>&1`;
my $t2 = Time::HiRes::time();
my $exit_code = $? >> 8; # perldoc perlvar: the exit value of the subprocess is really ("$? >> 8")
$output_2_log = $output;
$output_2_log = "<no output>\n" if ($output =~ m~^\s*$~s);
$output_2_log .= sprintf "<exit(%d)> in %f seconds building object or shared object for %s\n", $exit_code, $t2 - $t1, $o_file;
$output_2_log =~ s~^(.*)$~> $1~gm;
}
else {
# come here if linking object files into a binary causing undefined cwrap_data_*
my $output_type;
if (scalar @source_file_arguments > 0) { # if compiling to binary directly from source files
$log .= sprintf qq[%f - cwrap: object to binary #1: running via gxx (because source files detected): %s\n], Time::HiRes::time() - $ts, $gcc_command;
$output = `$gcc_command 2>&1`;
$output_type = 'gxx';
}
else {
# use nm instead of gcc/g++ because nm takes about 0.07 seconds instead of over 75 seconds for gcc/g++ !!!
$log .= sprintf qq[%f - cwrap: constructing two nm commands from gcc command\n], Time::HiRes::time() - $ts;
# Why two nm commands? Because second one uses --dynamic option:
# https://stackoverflow.com/questions/54052534/why-nm-libc-so-reports-no-symbols
# https://stackoverflow.com/questions/15345543/when-to-use-dynamic-option-in-nm
undef $output;
foreach my $nm_command_number (1..2) {
my $nm_command = qq[nm --print-file-name --no-sort --undefined-only];
$nm_command .= qq[ --dynamic] if (2 == $nm_command_number);
my @gcc_command_parts = split(m~\s+~, $gcc_command);
foreach my $gcc_command_part (@gcc_command_parts) {
if (($gcc_command_part =~ m~^\-~ ) # e.g. -Wl,-soname,libcaf_core.so.0.17.3
|| ($gcc_command_part !~ m~\.(o|a|so[\.0-9]*)$~)) { # e.g. logging/writers/sqlite/CMakeFiles/plugin-Zeek-SQLiteWriter.dir/sqlite.bif.init.cc.o ../aux/paraglob/src/ahocorasick/libahocorasick.a ../aux/broker/lib/./libcaf_openssl.so ../aux/broker/lib/libbroker.so.1.2
$log .= sprintf qq[%f - cwrap: discarding gcc command line option: %s\n], Time::HiRes::time() - $ts, $gcc_command_part;
}
else {
$nm_command .= ' ' . $gcc_command_part;
}
}
$nm_command .= qq[ 2>&1 | egrep cwrap_data_];
$log .= sprintf qq[%f - cwrap: object to binary #1: running via nm #%d (because no source files detected and nm faster than gxx): %s\n], Time::HiRes::time() - $ts, $nm_command_number, $nm_command;
$output .= `$nm_command 2>&1`;
}
$output_type = 'nm';
}
$log .= sprintf qq[%f - cwrap: using undefines from %s; auto generating: %s\n], Time::HiRes::time() - $ts, $output_type, $cwrap_c;
using_undefind_error_write_cwrap_c($output, $output_type);
# see https://en.wikipedia.org/wiki/Gold_%28linker%29
$gcc_command .= sprintf qq[ -fPIC %s -Wl,--undefined,cwrap_log_init -fuse-ld=gold], $cwrap_c;
$log .= sprintf qq[%f - cwrap: object to binary #2: running: %s\n], Time::HiRes::time() - $ts, $gcc_command;
my $t1 = Time::HiRes::time();
$output = `$gcc_command 2>&1`;
my $t2 = Time::HiRes::time();
my $exit_code = $? >> 8; # perldoc perlvar: the exit value of the subprocess is really ("$? >> 8")
$output_2_log = $output;
$output_2_log = "<no output>\n" if ($output =~ m~^\s*$~s);
$output_2_log .= sprintf "<exit(%d)> in %f seconds building binary for %s\n", $exit_code, $t2 - $t1, $o_file;
$output_2_log =~ s~^(.*)$~> $1~gm;
if ($exit_code != 0) {
$log .= $output_2_log;
$log .= sprintf qq[%f ERROR: cwrap: compilation to object or executable has unexpected errors\n], Time::HiRes::time() - $ts;
$log .= sprintf qq[%f - cwrap: done with exit(%d)\n], Time::HiRes::time() - $ts, $exit_code;
printf qq[%s], $output;
exit($exit_code);
}
}
$log .= $output_2_log;
printf qq[%s], $output;
} # assembler_to_object_or_executable_via_command()
sub get_path_name_and_ext {
my ($path_name_ext) = @_;
#debug $log .= sprintf qq[debug: (?, ?, ?)=fileparse(%s)\n], $path_name_ext;
my ($f, $path, $s) = fileparse($path_name_ext, "", qr/\.[^.]*/); # suffix maybe nothing or .something
$path = '' if ($path eq './');
my $name = $f ; # e.g. 'connection' in 'connection.o'
my $ext = $s ; # e.g. '.o' in 'connection.o'
#debug $log .= sprintf qq[debug: ($f, $d, $s)=fileparse(%s) // %s=path %s=name %s=ext\n], $path_name_ext, $folder, $name, $ext;
return ($path, $name, $ext);
} # get_path_name_and_ext()
sub pretty_asm {
my ($asm_line) = @_;
$asm_line =~ s~\t~ ~gs;
$asm_line =~ s~^\s+~~s;
$asm_line =~ s~\s+$~~s;
return $asm_line;
}
sub demangle_name {
my ( $mangled_name) = @_;
my $demangled_name;
if ( $mangled_name =~ m~^_Z~) {
# first try with Perl inline demangler which only seems to work on 99%+ mangled names, but it's fast :-)
$demangled_name = FFI::Platypus::Lang::CPP::Demangle::XS::demangle($mangled_name) if($mangled_name =~ m~^_Z~); # faster and more scalable than c++filt or llvm-cppfilt
goto GOT_DEMANGLED_NAME if (($mangled_name ne $demangled_name) && (length($demangled_name) > 0));
# try with c++filt which has the command line option --no-recursion-limit:
my $cxx_filt_command = sprintf qq[c++filt --no-recursion-limit %s], $mangled_name;
$demangled_name = `$cxx_filt_command`;
chomp $demangled_name;
$log .= sprintf qq[%f - cwrap: ran %s giving %s\n], Time::HiRes::time() - $ts, $cxx_filt_command, $demangled_name;
goto GOT_DEMANGLED_NAME if (($mangled_name ne $demangled_name) && (length($demangled_name) > 0));
# try with llvm-cxxfilt which seems a little more reliable and consistent than c++filt from gcc:
my $llvm_cxx_filt_command = sprintf qq[llvm-cxxfilt %s], $mangled_name;
$demangled_name = `$llvm_cxx_filt_command`;
chomp $demangled_name;
$log .= sprintf qq[%f - cwrap: ran %s giving %s\n], Time::HiRes::time() - $ts, $llvm_cxx_filt_command, $demangled_name;
goto GOT_DEMANGLED_NAME if (($mangled_name ne $demangled_name) && (length($demangled_name) > 0));
# own KISS demangling... obviously this is not good... why can CXX simply not demangle properly?!
my ($len, $rest);
$rest = $mangled_name;
$rest =~ s~^[^\d]+~~;
my @name_parts;
push @name_parts, 'CWRAP_DEMANGLE_FAIL';
while ($rest =~ m~^(\d+)(.*)$~) {
($len, $rest) = ($1, $2);
my $name_part = substr($rest, 0, $len);
push @name_parts, $name_part;
#debug printf qq[- %d bytes: %s in %s\n\n], $len, $name_part, $rest;
substr($rest, 0, $len) = '';
}
$demangled_name = join('::', @name_parts);
$log .= sprintf qq[%f WARNING: internal: failed to demangle name using c++filt or llvm-cxxfilt: %s\n], Time::HiRes::time() - $ts, $mangled_name;
GOT_DEMANGLED_NAME:;
$demangled_name =~ s~char const~const char~g;
}
else {
$demangled_name = $mangled_name;
}
cwrap_die sprintf qq[%f ERROR: internal: unexpected zero length demangled name from mangled name: %s\n], Time::HiRes::time() - $ts, $mangled_name if (0 == length($demangled_name));
return $demangled_name;
}
sub read_modify_rewrite_assembler_file {
my ($s_file) = @_;
cwrap_die(sprintf qq[%f ERROR: internal: cwrap: expected assembler file does not exist: %s\n], Time::HiRes::time() - $ts, $s_file) if (not -e $s_file);
my $s_file_line = `cat $s_file`;
my @s_file_lines = split(m~\n~, $s_file_line);
$log .= sprintf qq[%f - cwrap: assembler file: name : < %s <-- %d lines\n], Time::HiRes::time() - $ts, $s_file, scalar @s_file_lines;
my $debug_search = 0;
#
# 1. search for __cyg_profile_func_(enter|exit)
# 2. work backwards to the correct leaq <unique mangled function name> and replace with leaq cwrap_data_<unique mangled function name>
#
# leaq main(%rip), %rdi
# leaq inc_a(%rip), %rbp
# ...
# call __cyg_profile_func_enter@PLT
# ...
# movq %rbp, %rdi
# call __cyg_profile_func_enter@PLT <-- inline function #1 enter via rbp
# ...
# movq %rbp, %rdi
# call __cyg_profile_func_exit@PLT <-- inline function #1 leave via rbp
# ...
# leaq inc_b(%rip), %rdi
# call __cyg_profile_func_enter@PLT <-- inline function #2 enter
# ...
# leaq inc_b(%rip), %rdi
# call __cyg_profile_func_exit@PLT <-- inline function #2 enter
# ...
# leaq main(%rip), %rdi
# call __cyg_profile_func_exit@PLT
# movq _ZN6binpac9ExceptionC2EPKc@GOTPCREL(%rip), %rax
# movq %rax, %rdi
# call __cyg_profile_func_enter@PLT
my $t1 = Time::HiRes::time();
my @s_file_line_index = indexes { m~(call|jmp)\s+__cyg_profile_func_(enter|exit)~ } @s_file_lines; # (call|jmp) __cyg_profile_func_exit
my $t2 = Time::HiRes::time();
$log .= sprintf qq[%f - cwrap: found __cyg_profile_func_(enter|exit}() calls: %d in %fs\n], Time::HiRes::time() - $ts, scalar @s_file_line_index, $t2 - $t1;
my $enable_munge_cyg_profile_func = 1;
if (0) {
$log .= sprintf qq[%f - cwrap: NOTE: disabling munging __cyg_profile_func_(enter|exit}() calls\n], Time::HiRes::time() - $ts;
$enable_munge_cyg_profile_func = 0;
}
my $h_labels_to_rewrite;
my $h_mangled_2_demangled;
my $h_demangled_2_mangled;
foreach my $i (@s_file_line_index) {
my ($type) = $s_file_lines[$i -0] =~ m~__cyg_profile_func_(enter|exit)~;
$log .= sprintf qq[%f - cwrap: starting at line %d: %s\n], Time::HiRes::time() - $ts, $i, pretty_asm($s_file_lines[$i -0]) if($debug_search);
cwrap_die(sprintf qq[%f ERROR: cwrap: cannot determine enter or exit type!\n], Time::HiRes::time() - $ts) if (not defined $type);
my $instruction;
my $mangled_name;
my $mangled_name_line;
my $mangled_name_rest;
my $register = "\%rdi"; # rdi is Linux calling convention parameter #1; https://en.wikipedia.org/wiki/X86_calling_conventions#System_V_AMD64_ABI
my $lines_back = 1;
do {
if ($s_file_lines[$i -$lines_back] =~ m~(leaq|movq)\s+cwrap_data_([_A-Za-z0-9\.]+)(.*),.*$register~) {
$log .= sprintf qq[%f - cwrap: found %s at %d lines back: %s <-- already instrumented!\n], Time::HiRes::time() - $ts, $register, $lines_back, pretty_asm($s_file_lines[$i -$lines_back]) if($debug_search);
$instruction = $1;
$mangled_name = $2; # e.g. leaq _ZN3FooD2Ev(%rip), %rdi
$mangled_name_rest = $3;
$mangled_name_line = -1;
goto FOUND_LEAQ;
}
elsif ($s_file_lines[$i -$lines_back] =~ m~(leaq|movq)\s+([_A-Za-z0-9\.]+)(.*),.*$register~) {
$log .= sprintf qq[%f - cwrap: found %s at %d lines back: %s <-- instrumenting\n], Time::HiRes::time() - $ts, $register, $lines_back, pretty_asm($s_file_lines[$i -$lines_back]) if($debug_search);
$instruction = $1;
$mangled_name = $2; # e.g. leaq _ZN3FooD2Ev(%rip), %rdi
$mangled_name_rest = $3;
$mangled_name_line = $i - $lines_back;
goto FOUND_LEAQ;
}
elsif ($s_file_lines[$i -$lines_back] =~ m~movq\s+(\%[_A-Za-z0-9\.]+).*,.*$register~) { # movq %rbp, %rdi
$log .= sprintf qq[%f - cwrap: found %s at %d lines back: %s\n], Time::HiRes::time() - $ts, $register, $lines_back, pretty_asm($s_file_lines[$i -$lines_back]) if($debug_search);
$register = $1;
}
elsif ($s_file_lines[$i -$lines_back] =~ m~^([^\.][_A-Za-z0-9\.]+):\s*$~) { # _Z41__static_initialization_and_destruction_0ii.cold
$mangled_name = $1;
$mangled_name =~ s~\.cold$~~;
$mangled_name_line = undef; # do not rewrite labels!
$log .= sprintf qq[%f - cwrap: found label %d lines back: %s\n], Time::HiRes::time() - $ts, $lines_back, pretty_asm($s_file_lines[$i -$lines_back]) if($debug_search);
goto FOUND_LEAQ;
}
$lines_back ++;
} while ($lines_back < $i);
cwrap_die(sprintf qq[%f ERROR: internal: cwrap: cannot find leaq/movq instruction in assembler file before line %d!\n], Time::HiRes::time() - $ts, 1 + $i);
FOUND_LEAQ:;
my $note;
if ($mangled_name =~ m~\.~) {
# note: unbelievably, some labels can have dots in them, e.g.: _GLOBAL__sub_I_cpp_example_1.b.cpp <-- bug in gcc ?
my $mangled_name_with_dot = $mangled_name;
my $mangled_name_no___dot = $mangled_name;
$mangled_name_no___dot =~ s~\.~_~g;
$h_labels_to_rewrite->{$mangled_name_with_dot} = $mangled_name_no___dot;
$note = " (converted dots to underscores)";
}
if (not exists $h_mangled_2_demangled->{$mangled_name}) {
my $demangled_name = demangle_name($mangled_name);
$h_mangled_2_demangled->{$mangled_name } = $demangled_name;
$h_demangled_2_mangled->{$demangled_name} = $mangled_name;
}
my $fpic;
my $fpic_note;
if ($mangled_name_rest !~ m~GOTPCREL~i) {
$fpic = '@GOTPCREL';
$fpic_note = ' (append GOTPCREL)';
}
$log .= sprintf qq[%f - cwrap: line %d: %-5s %s AKA %s demangled%s%s%s\n], Time::HiRes::time() - $ts, $i, $type, $mangled_name, $h_mangled_2_demangled->{$mangled_name}, ($mangled_name_line >= 0) ? "" : " (via $register register!)", $note, $fpic_note;
$log .= sprintf qq[%f - cwrap:\n], Time::HiRes::time() - $ts if($debug_search);
if ($mangled_name_line >= 0) {
if ($enable_munge_cyg_profile_func) {
if ($instruction eq 'leaq') { $s_file_lines[$mangled_name_line] =~ s~leaq(\s+)($mangled_name)~movq$1cwrap_data_$2$fpic~; }
elsif ($instruction eq 'movq') { $s_file_lines[$mangled_name_line] =~ s~movq(\s+)($mangled_name)~movq$1cwrap_data_$2$fpic~; }
else {
# come here if e.g. no leaq / movq but instead .cold label found? so do nothing...
}
}
}
# use edx below because call __cyg_profile_func_(enter|exit) only uses 2 parameters, RDI & RSI, therefore use 3rd parameter RDX for comparison; see https://en.wikipedia.org/wiki/X86_calling_conventions#System_V_AMD64_ABI
my $skip_label = sprintf qq[.L_cwrap_skip_%s_%d], "cyg_profile_func", $i;
my $save_call = $s_file_lines[$i];
# todo: consider eliminating cwrap_log_verbosity and just testing cwrap_data_$mangled_name as zero or non-zero? faster?
# non -fPIC code: movl cwrap_data_$mangled_name(%rip), %edx
# non -fPIC code: cmpl cwrap_log_verbosity(%rip), %edx
# non -fPIC code: jg $skip_label
$s_file_lines[$i] = <<EOF;
movq cwrap_log_verbosity\@GOTPCREL(%rip), %rax
movl (%rax), %edx
movq cwrap_data_$mangled_name\@GOTPCREL(%rip), %rax
movl (%rax), %eax
cmpl %eax, %edx
jl $skip_label
EOF
$s_file_lines[$i] .= sprintf qq[%s\n], $save_call; # original call to __cyg_profile_func_(enter|exit)
$s_file_lines[$i] .= sprintf qq[%s:\n], $skip_label;
if($save_call =~ m~jmp~) {
$s_file_lines[$i] .= sprintf qq[\tret\n];
}
$s_file_lines[$i] .= sprintf qq[\n];
} # foreach my $i
#
# 1. search for pushsection / asciz / popsection,
# 2. determine unique unmangled function name containing if(...)
# 3. replace movl cwrap_log_verbosity_dummy with cwrap_data_<unique mangled function name>...
# 4. todo: delete pushsection / asciz / popsection and ascii name
#
# C: .type __PRETTY_FUNCTION__.3193, @object
# C: .size __PRETTY_FUNCTION__.3193, 5
# C:__PRETTY_FUNCTION__.3193:
# C: .string "main"
# C:...
# C:#APP
# C:# 41 "cpp-example-1.a.cpp" 1
# C: .pushsection __cwrap, "S", @note; .int 9; .asciz "$__PRETTY_FUNCTION__.3193"; .popsection
# C:
# C:# 0 "" 2
# C: .loc 1 41 5 view .LVU77
# C:#NO_APP
# C: movl cwrap_log_verbosity(%rip), %eax
# C: cmpl %eax, 36+cwrap_log_verbosity_dummy(%rip)
# C: jle .L21
# CPP:.LC13:
# CPP: .string "int main()"
# CPP:...
# CPP:#APP
# CPP:# 41 "cpp-example-1.a.cpp" 1
# CPP: .pushsection __cwrap, "S", @note; .int 9; .asciz "$.LC13"; .popsection
# CPP:
# CPP:# 0 "" 2
# CPP: .loc 1 41 5 view .LVU190
# CPP:#NO_APP
# CPP: movl cwrap_log_verbosity(%rip), %eax
# CPP: cmpl %eax, 36+cwrap_log_verbosity_dummy(%rip)
# CPP: jle .L51
my $t1 = Time::HiRes::time();
my @s_file_line_index = indexes { m~pushsection __cwrap.*\.int.*\.asciz "\$([^"]+)"~ } @s_file_lines;
my $t2 = Time::HiRes::time();
$log .= sprintf qq[%f - cwrap: found pushsection __cwrap instances: %d in %fs\n], Time::HiRes::time() - $ts, scalar @s_file_line_index, $t2 - $t1;
my $s_file_line = join("\n", @s_file_lines);
foreach my $i (@s_file_line_index) {
my ($line, $label) = $s_file_lines[$i -0] =~ m~pushsection __cwrap.*\.int (\d+); \.asciz "\$([^"]+)"~;
my ($pretty_function) = $s_file_line =~ m~$label\:\s+\.string\s+"([^"]+)"~s;
cwrap_die(sprintf qq[%f ERROR: cwrap: cannot find pretty_function via label: %s!\n], Time::HiRes::time() - $ts, $label) if (not defined $pretty_function);
my $demangled = $pretty_function;
if ($demangled =~ m~ \[with ([^\s]+)\s*=\s*(.*)]~) { # e.g. my_type get_max(my_type, my_type) [with my_type = int]
# come here to make this e.g. int get_max<int>(int, int)
my ($my_var, $my_type) = ($1, $2);
$log .= sprintf qq[%f - cwrap: converting assembler to pretty function demangled function: %s\n], Time::HiRes::time() - $ts, $demangled if (not exists $h_demangled_2_mangled->{$demangled});
$demangled =~ s~$my_var~$my_type~g;
$demangled =~ s~\(~<$my_type>(~;
$demangled =~ s~ \[with .*~~; # stip [with ...] part
}
else {
$demangled =~ s~^[^\s\(]+\s+~~; # strip return type from e.g. int main()
}
if (not exists $h_demangled_2_mangled->{$demangled}) {
$log .= sprintf qq[%f - cwrap: removing (...) because cannot find demangled function: %s\n], Time::HiRes::time() - $ts, $demangled if (not exists $h_demangled_2_mangled->{$demangled});
$demangled =~ s~\(.*$~~; # strip (<params>) from e.g. int main()
}
if (not exists $h_demangled_2_mangled->{$demangled}) {
foreach my $demangled_key (sort keys %{$h_demangled_2_mangled}) {
$log .= sprintf qq[%f - cwrap: non-matching demangled key: %d bytes: %s\n], Time::HiRes::time() - $ts, length($demangled_key), $demangled_key;
}
cwrap_die(sprintf qq[%f ERROR: cwrap: cannot find mangled function via demangled function: %s // via pretty function %s\n], Time::HiRes::time() - $ts, $demangled, $pretty_function);
}
my $mangled = $h_demangled_2_mangled->{$demangled};
$log .= sprintf qq[%f - cwrap: starting at line %d: %s; line=%d label=%s pretty_function=%s AKA %s mangled\n], Time::HiRes::time() - $ts, $i, pretty_asm($s_file_lines[$i -0]), $line, $label, $pretty_function, $mangled if($debug_search);
my $unique_dummy = sprintf qq[cwrap_data_verbosity_dummy_%u], $line;
if ($s_file_line =~ s~$unique_dummy~cwrap_data_$mangled~) {
# e.g. movq cwrap_data_verbosity_dummy_8@GOTPCREL(%rip), %rax
}
else {
cwrap_die(sprintf qq[%f ERROR: internal: cwrap: cannot find %s in assembler file referenced by line %d!\n], Time::HiRes::time() - $ts, $unique_dummy, $i);
}
} # foreach my $i
#
# re-write any labels with dots!
#
if (scalar keys %{$h_labels_to_rewrite} > 0) {
$log .= sprintf qq[%f - cwrap: rewriting %d dodgy dot labels\n], Time::HiRes::time() - $ts, scalar keys %{$h_labels_to_rewrite};
foreach my $mangled_name_with_dot (keys %{$h_labels_to_rewrite}) {
my $mangled_name = $h_labels_to_rewrite->{$mangled_name_with_dot};
$log .= sprintf qq[%f - cwrap: rewriting dodgy dot label %s to %s\n], Time::HiRes::time() - $ts, $mangled_name_with_dot, $mangled_name;
$s_file_line =~ s~$mangled_name_with_dot~$mangled_name~gs;
}
}
$s_file_line =~ s~\.string\s+"cwrap_data_verbosity_dummy_\d+"~~gm; # .string "cwrap_data_verbosity_dummy_10"
if ($s_file_line =~ m~(cwrap_data_verbosity_dummy_\d+)~s) {
cwrap_die(sprintf qq[%f ERROR: internal: cwrap: detected at least one unsubstituted temporary label: %s!\n], Time::HiRes::time() - $ts, $1);
}
#
# write out modified assembler file
#
my $s_file_out = sprintf qq[%s.2.s], $s_file;
$log .= sprintf qq[%f - cwrap: assembler file: name : > %s\n], Time::HiRes::time() - $ts, $s_file_out;
open(my $out, '>', $s_file_out) || cwrap_die(sprintf qq[%f ERROR: cwrap cannot open file for writing: %s; $1\n], Time::HiRes::time() - $ts, $s_file_out);
$s_file_line .= "\n";
syswrite($out, $s_file_line, length($s_file_line));
close $out;
} # read_modify_rewrite_assembler_file()
sub using_undefind_error_write_cwrap_c {
my ($output, $output_type) = @_; # output lines from nm or gxx command
my @output = split(m~\n~, $output);
$log .= sprintf qq[%f - cwrap: examining lines of %s output: %d\n], Time::HiRes::time() - $ts, $output_type, scalar @output;
if (0) { foreach my $line (@output) { $log .= sprintf qq[%f - cwrap: debug output: %s\n], Time::HiRes::time() - $ts, $line; } }
my $h;
if ($output_type eq 'nm') {
# come here to process output with undefineds from nm
foreach my $undefined (@output) {
chomp $undefined; # e.g. ../aux/paraglob/src/ahocorasick/libahocorasick.a:AhoCorasickPlus.cpp.o: U cwrap_data__ZNK9__gnu_cxx13new_allocatorIiE8max_sizeEv
next if ($undefined =~ m~cwrap_log_~); # do not generate cwrap_data structs for cwrap_log_*() functions
if ($undefined =~ m~^(.+?):\s+U\s+(.*)~) {
my ($file, $undefined_cwrap_data) = ($1, $2);
$h->{$undefined_cwrap_data} = $file if (not exists $h->{$undefined_cwrap_data});
}
else {
cwrap_die(sprintf qq[%f ERROR: internal: cwrap: do not understand nm output line: %s\n], Time::HiRes::time() - $ts, $undefined);
}
}
}
else {
# come here to process output with undefineds from gxx
my @undefined_errors = grep(m~undefined reference to .cwrap_data_~, @output); # e.g. cpp-example-1.cpp:5: undefined reference to `cwrap__Z8clean_upPi'
# first grab all the undefined error; note: gcc appears to spit them out in a random order!
foreach my $undefined_error (@undefined_errors) { # e.g. /usr/bin/ld: testCXXCompiler.cxx:(.text+0x1d): undefined reference to `cwrap_data_main'
next if ($undefined_error =~ m~cwrap_log_~);
chomp $undefined_error;
my ($source_file, $source_line, $missing_ref) = $undefined_error =~ m~([^/]+):([^\:]+): undefined reference to .(cwrap_[_A-Za-z0-9]+)~;
$h->{$missing_ref} = $source_file if (not exists $h->{$missing_ref});
}
}
$log .= sprintf qq[%f - cwrap: unique undefined cwrap_data_* symbols in nm output: %d\n], Time::HiRes::time() - $ts, scalar keys %{$h};
my @demangled_names; # e.g. int get_max<int>(int, int)
my @mangled_names; # e.g. _Z7get_maxIiET_S0_S0_
my @source_files;
foreach my $missing_ref (sort keys %{ $h }) { # sort because always want names in same order for test scripts
my $source_file = $h->{$missing_ref};
my ($mangled_name) = $missing_ref =~ m~cwrap_data_(.*)~;
push @source_files, $source_file;
push @mangled_names, $mangled_name; # e.g. _Z7get_maxIiET_S0_S0_
my $demangled_name = demangle_name($mangled_name);
push @demangled_names, $demangled_name; # e.g. int get_max<int>(int, int)
}
#todo: consider sorting the function names by demangled name instead of mangled name!
$log .= sprintf qq[%f - cwrap: writing %d missing cwrap structs to: %s\n], Time::HiRes::time() - $ts, scalar keys %{ $h }, $cwrap_c;
cwrap_die(sprintf qq[%f ERROR: internal: cwrap: missing cwrap structs should never be zero\n], Time::HiRes::time() - $ts) if (0 == scalar keys %{ $h });
open(my $out, '>', $cwrap_c) || cwrap_die(sprintf qq[%f ERROR: cwrap: cannot open file for writing: %s\n], Time::HiRes::time() - $ts, $cwrap_c);
printf $out <<EOF;
#ifndef _GNU_SOURCE
#define _GNU_SOURCE /* See feature_test_macros(7) */
#endif
#include <unistd.h>
#include <sys/syscall.h> /* for syscall(), SYS_gettid */
#include <signal.h> /* for raise() */
#include <stdlib.h> /* for exit() */
#include <string.h> /* for memcmp() */
#include <stdio.h>
#include <stdarg.h>
#include <sys/time.h>
#ifdef __cplusplus
extern "C" {
#endif
__attribute__ ((no_instrument_function)) void __cyg_profile_func_enter(void *func, void *callsite);
__attribute__ ((no_instrument_function)) void __cyg_profile_func_exit (void *func, void *callsite);
#define CWRAP_LOG_LINE_MAX (256)
#ifndef CWRAP_LOG_CURT
#define CWRAP_LOG_CURT (0)
#endif
#ifndef CWRAP_LOG_FILE
#define CWRAP_LOG_FILE (0)
#endif
#ifndef CWRAP_LOG_COR_ID
#define CWRAP_LOG_COR_ID (1)
#endif
#ifndef CWRAP_LOG_THREAD_ID
#define CWRAP_LOG_THREAD_ID (0)
#endif
#ifndef CWRAP_LOG_STACK_PTR
#define CWRAP_LOG_STACK_PTR (0)
#endif
#ifndef CWRAP_LOG_TIMESTAMP
#define CWRAP_LOG_TIMESTAMP (0)
#endif
#define COR_ID_MAX (1000)
typedef struct CWRAP_LOG_COR {
void * unique; // unique value representing last log line
int indent;
int line_result_pos;
int line_append_pos;
int line_pos;
char line_result[CWRAP_LOG_LINE_MAX];
char line_append[CWRAP_LOG_LINE_MAX];
char line[CWRAP_LOG_LINE_MAX];
} __attribute__((packed)) CWRAP_LOG_COR;
__thread int cor_id = 0;
__thread CWRAP_LOG_COR cwrap_log_cor[COR_ID_MAX] = {0}; // todo: make this dynamically grow to the necessary size; mremap() ?
char cwrap_log_spaces[] = " ";
int cwrap_log_verbosity = 1;
static __thread void * cwrap_log_sp_start = NULL;
static FILE * cwrap_log_file = NULL;
static int cwrap_log_fd;
static double cwrap_log_time = 0 ; // very first timestamp
static int cwrap_log_output_curt = CWRAP_LOG_CURT; // try to fold enter and leave lines if possible
static int cwrap_log_output_file = CWRAP_LOG_FILE; // output to file or stdout?
static int cwrap_log_output_cor_id = CWRAP_LOG_COR_ID;
static int cwrap_log_output_thread_id = CWRAP_LOG_THREAD_ID;
static int cwrap_log_output_stack_pointer = CWRAP_LOG_STACK_PTR;
static int cwrap_log_output_elapsed_time = CWRAP_LOG_TIMESTAMP;
extern void cwrap_log_push(int indent_direction, int no_append, int is_inside, const char * format, ...);
double cwrap_get_time_in_seconds(void)
{
struct timeval tv;
gettimeofday(&tv, NULL);
return (double)tv.tv_sec + 1.e-6 * (double)tv.tv_usec;
}
const char * cwrap_log_append_get(void)
{
const char * result = NULL;
if (cwrap_log_cor[cor_id].line_append_pos) {
cwrap_log_cor[cor_id].line_append_pos = 0;
result = &cwrap_log_cor[cor_id].line_append[0];
}
return result;
}
const char * cwrap_log_result_get(void)
{
const char * result = NULL;
if (cwrap_log_cor[cor_id].line_result_pos) {
cwrap_log_cor[cor_id].line_result_pos = 0;
result = &cwrap_log_cor[cor_id].line_result[0];
}
return result;
}
// todo: performance optimization: consider refactoring this code so that all sprintf() ingredients are queued and actual sprintf()s are executed in a separate thread?
void cwrap_log_flush(void)
{
if (cwrap_log_output_file) {
fprintf(cwrap_log_file, "%%s\\n", &cwrap_log_cor[cor_id].line[0]);
fflush(cwrap_log_file);
//fsync(cwrap_log_fd); // todo: fsync intermittantly?
}
else {
int pos = cwrap_log_cor[cor_id].line_pos - 1;
if ('\\n' == cwrap_log_cor[cor_id].line[pos]) { printf("%%s" , &cwrap_log_cor[cor_id].line[0]); }
else { printf("%%s\\n", &cwrap_log_cor[cor_id].line[0]); }
}
cwrap_log_cor[cor_id].line_pos = 0;
}
void cwrap_log_push_v(int indent_direction, int no_append, int is_inside, const char * format, va_list argument_list)
{
double time = cwrap_get_time_in_seconds();
if (no_append && (cwrap_log_cor[cor_id].line_pos > 0)) { // todo: create & check cor_id_last too?
const char * append = cwrap_log_append_get();
if (append) { if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += snprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, ") { // %%s", append); } }
else { if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += snprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, ") {" ); } }
cwrap_log_flush();
}
if (no_append && (cwrap_log_cor[cor_id].line_result_pos > 0) && (indent_direction >= 0)) {
const char * result = cwrap_log_result_get();
cwrap_log_push(0 /* no indent_direction */, 1 /* no append */, 1 /* is inside */, "return %%s", result);
cwrap_log_flush();
}
if (cwrap_log_output_file && (NULL == cwrap_log_file)) { // todo: make thread safe
cwrap_log_file = fopen("cwrap.out","w+");
cwrap_log_fd = fileno(cwrap_log_file);
}
if (0 == cwrap_log_time) {
cwrap_log_time = time;
}
double time_elapsed = time - cwrap_log_time;
void * cwrap_log_sp = &format;
cwrap_log_sp_start = cwrap_log_sp_start ? cwrap_log_sp_start : cwrap_log_sp;
if (no_append) {
if (cwrap_log_output_thread_id ) { if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += snprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, "T%%05ld " , syscall(SYS_gettid) ); } } // linux; cat /proc/sys/kernel/pid_max
if (cwrap_log_output_cor_id ) { if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += snprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, "C%%d " , cor_id ); } }
if (cwrap_log_output_stack_pointer) { if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += snprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, "SP%%+6ld ", (char *)cwrap_log_sp - (char *)cwrap_log_sp_start ); } }
if (cwrap_log_output_elapsed_time ) { if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += snprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, "%%fs " , time_elapsed ); } }
if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += snprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, "%%.*s" , 2 * cwrap_log_cor[cor_id].indent, &cwrap_log_spaces[0]); } // note: %% because of Perl
if (is_inside ) { if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += snprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, "- " ); } }
} // if (no_append)
if (cwrap_log_cor[cor_id].line_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_pos += vsnprintf(&cwrap_log_cor[cor_id].line[cwrap_log_cor[cor_id].line_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_pos, format , argument_list ); }
int pos = cwrap_log_cor[cor_id].line_pos - 1;
if ('\\n' == cwrap_log_cor[cor_id].line[pos]) { cwrap_log_cor[cor_id].line[pos] = 0; cwrap_log_cor[cor_id].line_pos --; } // chomp trailing \\n if present
cwrap_log_cor[cor_id].indent += indent_direction;
}
void cwrap_log_push(int indent_direction, int no_append, int is_inside, const char * format, ...)
{
va_list argument_list;
va_start(argument_list, format);
cwrap_log_push_v(indent_direction, no_append, is_inside, format, argument_list);
va_end(argument_list);
}
void cwrap_log_pop(int indent_direction, int no_append, int is_inside, const char * format, ...)
{
va_list argument_list;
va_start(argument_list, format);
cwrap_log_push_v(indent_direction, no_append, is_inside, format, argument_list);
cwrap_log_flush();
va_end(argument_list);
}
void cwrap_log(const char * format, ...)
{
va_list argument_list;
va_start(argument_list, format);
cwrap_log_cor[cor_id].unique = 0; // signal previous enters that leave folding should not occur
cwrap_log_push_v(0 /* no indent_direction */, 1 /* no append */, 1 /* is inside */, format, argument_list);
cwrap_log_flush();
va_end(argument_list);
}
void cwrap_log_verbatim(const char * format, ...)
{
va_list argument_list;
va_start(argument_list, format);
cwrap_log_cor[cor_id].unique = 0; // signal previous enters that leave folding should not occur
cwrap_log_push_v(0 /* no indent_direction */, 1 /* no append */, 0 /* is inside */, format, argument_list);
cwrap_log_flush();
va_end(argument_list);
}
void cwrap_log_append(const char * format, ...)
{
va_list argument_list;
va_start(argument_list, format);
if (cwrap_log_output_curt && (cwrap_log_cor[cor_id].line_pos > 0)) {
if (cwrap_log_cor[cor_id].line_append_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_append_pos += vsnprintf(&cwrap_log_cor[cor_id].line_append[cwrap_log_cor[cor_id].line_append_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_append_pos, format, argument_list); }
}
else {
cwrap_log_cor[cor_id].unique = 0; // signal previous enters that leave folding should not occur
cwrap_log_push_v(0 /* no indent_direction */, 1 /* no append */, 1 /* is inside */, format, argument_list);
cwrap_log_flush();
}
va_end(argument_list);
}
void cwrap_log_result(const char * format, ...)
{
va_list argument_list;
va_start(argument_list, format);
if (cwrap_log_output_curt) {
if (cwrap_log_cor[cor_id].line_result_pos < CWRAP_LOG_LINE_MAX) { cwrap_log_cor[cor_id].line_result_pos += vsnprintf(&cwrap_log_cor[cor_id].line_result[cwrap_log_cor[cor_id].line_result_pos], CWRAP_LOG_LINE_MAX - cwrap_log_cor[cor_id].line_result_pos, format, argument_list); }
int pos = cwrap_log_cor[cor_id].line_result_pos - 1;
if ('\\n' == cwrap_log_cor[cor_id].line_result[pos]) { cwrap_log_cor[cor_id].line_result[pos] = 0; cwrap_log_cor[cor_id].line_result_pos --; } // chomp trailing \\n if present
}
else {
cwrap_log_cor[cor_id].unique = 0; // signal previous enters that leave folding should not occur
cwrap_log_push (0 /* no indent_direction */, 1 /* no append */, 1 /* is inside */, "return ");
cwrap_log_push_v(0 /* no indent_direction */, 0 /* append */, 1 /* is inside */, format, argument_list);
cwrap_log_flush();
}
va_end(argument_list);
}
void cwrap_log_params(const char * format, ...)
{
va_list argument_list;
va_start(argument_list, format);
if (cwrap_log_output_curt && (cwrap_log_cor[cor_id].line_pos > 0)) {
cwrap_log_push_v(0 /* no indent_direction */, 0 /* append */, 0 /* is not inside */, format, argument_list);
}
else {
cwrap_log_cor[cor_id].unique = 0; // signal previous enters that leave folding should not occur
cwrap_log_push_v(0 /* no indent_direction */, 1 /* no append */, 1 /* is inside */, format, argument_list);
cwrap_log_flush();
}
va_end(argument_list);
}
#define CWRAP_MAGIC (0x12345678)
typedef struct CWRAP_DATA CWRAP_DATA;
struct CWRAP_DATA {
int verbosity; // must be 1st structure member!
int magic;
int calls;
int variation_x;
int of_y_variations;
int bytes___mangled_name;
int bytes_demangled_name;
const char * name; int len_name; // generic demangled name
const char * file; int len_file;
CWRAP_DATA * next;
} __attribute__((packed));
EOF
push @source_files, $cwrap_c;
push @mangled_names, "cwrap_log_verbosity_set_all";
push @demangled_names, "cwrap_log_verbosity_set_all";
push @source_files, $cwrap_c;
push @mangled_names, "cwrap_log_stats";
push @demangled_names, "cwrap_log_stats";
push @source_files, $cwrap_c;
push @mangled_names, "cwrap_log_verbosity_set";
push @demangled_names, "cwrap_log_verbosity_set";
my $default_function_verbosity = 9;
my $mangled_name_last = "NULL";
my $h_variation_x;
my $h_of_y_variations;
my $number___mangled_names = 0;
my $number_demangled_names = 0;
my $number___generic_names = 0;
my $bytes___mangled_names = 0;
my $bytes_demangled_names = 0;
my $bytes___generic_names = 0;
foreach my $i (0..$#mangled_names) {
my $mangled_name = $mangled_names[$i]; $number___mangled_names ++; $bytes___mangled_names += length( $mangled_name);
my $demangled_name = $demangled_names[$i]; $number_demangled_names ++; $bytes_demangled_names += length($demangled_name);
chomp $demangled_name;
my $compressed_demangled_name = compress_demangled_name($demangled_name);
if (not exists $h_of_y_variations->{$compressed_demangled_name}) {
$number___generic_names ++;
$bytes___generic_names += length($compressed_demangled_name);
}
$h_of_y_variations->{$compressed_demangled_name} ++;
$h_variation_x->{$mangled_name} = $h_of_y_variations->{$compressed_demangled_name};
}
$log .= sprintf qq[%f - cwrap: number___mangled_names=%d\n], Time::HiRes::time() - $ts, $number___mangled_names;
$log .= sprintf qq[%f - cwrap: number_demangled_names=%d\n], Time::HiRes::time() - $ts, $number_demangled_names;
$log .= sprintf qq[%f - cwrap: number___generic_names=%d\n], Time::HiRes::time() - $ts, $number___generic_names;
$log .= sprintf qq[%f - cwrap: bytes___mangled_names=%d\n], Time::HiRes::time() - $ts, $bytes___mangled_names;
$log .= sprintf qq[%f - cwrap: bytes_demangled_names=%d\n], Time::HiRes::time() - $ts, $bytes_demangled_names;
$log .= sprintf qq[%f - cwrap: bytes___generic_names=%d\n], Time::HiRes::time() - $ts, $bytes___generic_names;
foreach my $i (0..$#mangled_names) {
my $mangled_name = $mangled_names[$i];
my $demangled_name = $demangled_names[$i];
chomp $demangled_name;
my $compressed_demangled_name = compress_demangled_name($demangled_name);
$log .= sprintf qq[%f - cwrap: %-48s -> variation %d of %d for %s()\n], Time::HiRes::time() - $ts, $mangled_name, $h_variation_x->{$mangled_name}, $h_of_y_variations->{$compressed_demangled_name}, $compressed_demangled_name;
#for non-debug source_line might look like "(.text+0x1d)": cwrap_die(sprintf qq[%f ERROR: internal: cwrap: 0 == source_line from linker undefined error: %s\n], Time::HiRes::time() - $ts, $undefineds[$i]) if (0 == $source_line);
printf $out qq[CWRAP_DATA cwrap_data_%s = {%d, CWRAP_MAGIC, 0, %d, %d, %d, %d, "%s", %d, "%s", %d, %s};\n],
$mangled_name,
$default_function_verbosity,
$h_variation_x->{$mangled_name},
$h_of_y_variations->{$compressed_demangled_name},
length( $mangled_name),
length($demangled_name),
$compressed_demangled_name, length($compressed_demangled_name),
$source_files[$i] , length($source_files[$i] ),
$mangled_name_last;
$mangled_name_last = sprintf qq[&cwrap_data_%s], $mangled_name;
}
printf $out <<EOF;
int cwrap_default_function_verbosity = $default_function_verbosity;
CWRAP_DATA * cwrap_data_start = $mangled_name_last;
void cwrap_data_sanity_check(CWRAP_DATA * cwd) {
if (cwd->magic != CWRAP_MAGIC) {
printf("ERROR: internal: cwrap bad magic; expected 0x%%x, got 0x%%x exiting // cw=%%p sizeof(CWRAP_DATA)=%%ld\\n", CWRAP_MAGIC, cwd->magic, (void *)cwd, sizeof(CWRAP_DATA));
raise(SIGINT);
exit(1);
}
}
#define CWRAP_UNUSED_PARAMETER(param) (void)(param)
void __cyg_profile_func_enter(void *this_fn, void *call_site) {
CWRAP_UNUSED_PARAMETER(call_site);
CWRAP_DATA * cw = (CWRAP_DATA *) this_fn;
cwrap_data_sanity_check(cw);
//debug printf("debug: cwrap_log_verbosity=%%d ->name=%%s\\n", cwrap_log_verbosity, cw->name);
cwrap_log_cor[cor_id].unique = cw;
if (cw->calls <= 10000) cwrap_log_push(1, 1 /* no append */, 0 /* outside */, "+ %%s(", cw->name);
cw->calls ++;
}
// + foo(a=1) { // hint
// ^^^^^^ ^^^ <-- push+1
// ^^^ <-- param
// ^^^^^^^ <-- hint
// } = 1 // foo() #2
// ^^^ ^^^^^^^^^^^ <-- push-1
// ^^^^ <-- return
// + foo(a=1) {} = 1 // hint
// ^^^^^^ ^^^ <-- push+1
// ^^^ <-- param
// ^^^^^^^ <-- hint
// ^ <-- push-1
// ^^^^ <-- return
void __cyg_profile_func_exit(void *this_fn, void *call_site) {
CWRAP_UNUSED_PARAMETER(call_site);
CWRAP_DATA * cw = (CWRAP_DATA *) this_fn;
cwrap_data_sanity_check(cw);
if (cw->calls <= 10000) {
const char * append = cwrap_log_append_get();
const char * result = cwrap_log_result_get();
if (( cwrap_log_output_curt)
&& (cw == cwrap_log_cor[cor_id].unique)) { cwrap_log_pop(-1, 0 /* append */, 0 /* outside */, ") {}%%s%%s // " "#%%llu%%s%%s", NULL == result ? "" : " = ", NULL == result ? "" : result, cw->calls, NULL == append ? "" : " ", NULL == append ? "" : append); }
else { cwrap_log_pop(-1, 1 /* no append */, 0 /* outside */, "}%%s%%s // %%s() #%%llu%%s%%s", NULL == result ? "" : " = ", NULL == result ? "" : result, cw->name, cw->calls, NULL == append ? "" : " ", NULL == append ? "" : append); }
}
if (cwrap_log_cor[cor_id].indent < 0) {
printf("ERROR: internal: cwrap_log_indent[cor_id=%%d] < 0\\n", cor_id);
raise(SIGINT);
exit(1);
}
}
void cwrap_log_verbosity_set(int verbosity, const char * name) {
__cyg_profile_func_enter(&cwrap_data_cwrap_log_verbosity_set, NULL);
if(cwrap_log_verbosity >= cwrap_data_cwrap_log_verbosity_set.verbosity){ cwrap_log_params("verbosity=%%d, name=%%s", verbosity, name); }
int i = 0;
CWRAP_DATA * cwd = cwrap_data_start;
do {
cwrap_data_sanity_check(cwd);
//debug cwrap_log("i=%%d .verbosity=%%d .name=%%s", i, cwd->verbosity, &cwd->name[0]);
if (0 == memcmp(name, cwd->name, 3)) {
if(cwrap_log_verbosity >= cwrap_data_cwrap_log_verbosity_set.verbosity){ cwrap_log_append("setting verbosity to %%d (was %%d) for function %%s()", verbosity, cwd->verbosity, &cwd->name[0]); }
cwd->verbosity = verbosity;
}
i ++;
cwd = cwd->next;
} while (cwd);
__cyg_profile_func_exit(&cwrap_data_cwrap_log_verbosity_set, NULL);
}
void cwrap_log_stats(void) {
__cyg_profile_func_enter(&cwrap_data_cwrap_log_stats, NULL);
int i = 0;
int j = 0;
int k = 0;
CWRAP_DATA * cwd = cwrap_data_start;
do {
if (cwd->calls > 0) {
if(cwrap_log_verbosity >= cwrap_data_cwrap_log_stats.verbosity){ cwrap_log("%%d calls to %%d of %%d function variation for %%s() \\n", cwd->calls, cwd->variation_x, cwd->of_y_variations, &cwd->name[0]); }
i += cwd->calls;
j ++;
}
k ++;
cwd = cwd->next;
} while (cwd);
if(cwrap_log_verbosity >= cwrap_data_cwrap_log_stats.verbosity){ cwrap_log_append("%%d calls to %%d of %%d functions instrumented\\n", i, j, k); }
__cyg_profile_func_exit(&cwrap_data_cwrap_log_stats, NULL);
}
void cwrap_log_verbosity_set_all(int verbosity) {
__cyg_profile_func_enter(&cwrap_data_cwrap_log_verbosity_set_all, NULL);
if(cwrap_log_verbosity >= cwrap_data_cwrap_log_verbosity_set_all.verbosity){ cwrap_log_params("verbosity=%%d", verbosity); }
int i = 0;
CWRAP_DATA * cwd = cwrap_data_start;
do {
cwrap_data_sanity_check(cwd);
//debug cwrap_log("i=%%d .verbosity=%%d .name=%%s", i, cwd->verbosity, &cwd->name[0]);
cwd->verbosity = verbosity;
i ++;
cwd = cwd->next;
} while (cwd);
if(cwrap_log_verbosity >= cwrap_data_cwrap_log_verbosity_set_all.verbosity){ cwrap_log_append("set verbosity for %%d functions instrumented", i); }
__cyg_profile_func_exit(&cwrap_data_cwrap_log_verbosity_set_all, NULL);
}
// This function gets called *before* main() and hopefully *before* C++ initialization.
// It is completely silent unless verbosity is being switched on.
// The asm voodoo to make this work is described here [1].
// [1] https://stackoverflow.com/questions/2053029/how-exactly-does-attribute-constructor-work
void cwrap_log_init(void)
{
__asm__ (".section .init \\n call cwrap_log_init \\n .section .text\\n");
char * p_env_verb = getenv("CWRAP_LOG_VERBOSITY_SET_ALL");
char * p_env_stats = getenv("CWRAP_LOG_STATS");
char * p_env_curt = getenv("CWRAP_LOG_CURT");
char * p_env_file = getenv("CWRAP_LOG_FILE");
char * p_env_cor_id = getenv("CWRAP_LOG_COR_ID");
char * p_env_thread_id = getenv("CWRAP_LOG_THREAD_ID");
char * p_env_stack_ptr = getenv("CWRAP_LOG_STACK_PTR");
char * p_env_timestamp = getenv("CWRAP_LOG_TIMESTAMP");
int verbosity = p_env_verb ? atoi(p_env_verb ) : cwrap_default_function_verbosity;
int stats = p_env_stats ? atoi(p_env_stats ) : 0;
int curt = p_env_curt ? atoi(p_env_curt ) : CWRAP_LOG_CURT;
int file = p_env_file ? atoi(p_env_file ) : CWRAP_LOG_FILE;
int cor_id = p_env_cor_id ? atoi(p_env_cor_id ) : CWRAP_LOG_COR_ID;
int thread_id = p_env_thread_id ? atoi(p_env_thread_id) : CWRAP_LOG_THREAD_ID;
int stack_ptr = p_env_stack_ptr ? atoi(p_env_stack_ptr) : CWRAP_LOG_STACK_PTR;
int timestamp = p_env_timestamp ? atoi(p_env_timestamp) : CWRAP_LOG_TIMESTAMP;
if (verbosity != cwrap_default_function_verbosity) {
printf("cwrap_log_init() {} // CWRAP_LOG: _VERBOSITY_SET_ALL=%%d _STATS=%%d _CURT=%%d _FILE=%%d _COR_ID=%%d _THREAD_ID=%%d _STACK_PTR=%%d _TIMESTAMP=%%d\\n", verbosity, stats, curt, file, cor_id, thread_id, stack_ptr, timestamp);
cwrap_log_output_curt = curt ;
cwrap_log_output_file = file ;
cwrap_log_output_cor_id = cor_id ;
cwrap_log_output_thread_id = thread_id;
cwrap_log_output_stack_pointer = stack_ptr;
cwrap_log_output_elapsed_time = timestamp;
cwrap_data_cwrap_log_verbosity_set_all.verbosity = 1;
cwrap_log_verbosity_set_all(verbosity);
if (stats) {
atexit(cwrap_log_stats);
}
}
}
#ifdef __cplusplus
}
#endif
EOF
close $out;
} # using_undefind_error_write_cwrap_c()
sub create_cwrap_h() {
my $cwrap_file = "cwrap.h";
$log .= sprintf qq[%f - cwrap: writing missing cwrap header to: %s\n], Time::HiRes::time() - $ts, $cwrap_file;
open(my $out, '>', $cwrap_file) || cwrap_die(sprintf qq[%f ERROR: cwrap: cannot open file for writing: %s\n], Time::HiRes::time() - $ts, $cwrap_file);
printf $out <<EOF;
#ifdef __cplusplus
extern "C" {
#endif
#ifndef CWRAP_LOG_INIT_REF
#define CWRAP_LOG_INIT_REF
// help to force inclusion of cwrap_log_init() even if static library shenanigans during build process
// https://stackoverflow.com/questions/2991927/how-to-force-inclusion-of-an-object-file-in-a-static-library-when-linking-into-e
extern void cwrap_log_init(void);
__attribute__((weak)) void * p_cwrap_log_init = (void *) &cwrap_log_init;
#endif
#define CWRAP (1)
//#define COR_ID (1)
extern __thread int cor_id;
extern __thread int cwrap_log_indent[];
extern char cwrap_log_spaces[];
extern int cwrap_log_verbosity;
extern void cwrap_log(const char * format, ...);
extern void cwrap_log_verbatim(const char * format, ...);
extern void cwrap_log_push(int indent_direction, int no_append, const char * format, ...);
extern int cwrap_log_get_lines(void);
extern void cwrap_log_result(const char * format, ...);
extern void cwrap_log_append(const char * format, ...);
extern const char * cwrap_log_result_get(void);
extern const char * cwrap_log_append_get(void);
extern void cwrap_log_params(const char * format, ...);
extern void cwrap_log_verbosity_set(int verbosity, const char * name);
extern void cwrap_log_stats(void);
#ifdef __cplusplus
}
#endif
// The extra indirection is to ensure that the __LINE__ string comes through OK.
#define params_printf(...) _generic_printf(cwrap_log_params, __PRETTY_FUNCTION__, __COUNTER__, __VA_ARGS__)
#define result_printf(...) _generic_printf(cwrap_log_result, __PRETTY_FUNCTION__, __COUNTER__, __VA_ARGS__)
#define append_printf(...) _generic_printf(cwrap_log_append, __PRETTY_FUNCTION__, __COUNTER__, __VA_ARGS__)
#define debug_printf(...) _generic_printf(cwrap_log , __PRETTY_FUNCTION__, __COUNTER__, __VA_ARGS__)
#define _generic_printf(_function, _pretty_function, _counter, ...) __generic_printf(_function, _pretty_function, _counter, __VA_ARGS__)
#define __generic_printf(__function, __pretty_function, __counter, ...) __asm__(".pushsection __cwrap, \\\"S\\\", \@note; .int \" #__counter \"; .asciz \\\"%0\\\"; .popsection\\n\\t" : : "s" ( __pretty_function ) ); \\
extern int cwrap_data_verbosity_dummy_##__counter; \\
if(cwrap_log_verbosity >= cwrap_data_verbosity_dummy_##__counter /* get replaced in assembler file! */){ __function(__VA_ARGS__); }
EOF
# example non-fPIC assembler: .pushsection __cwrap, "S", \@note; .int 9; .asciz "\$__PRETTY_FUNCTION__.3184"; .popsection
# example non-fPIC assembler: ...
# example non-fPIC assembler: movl cwrap_log_verbosity\@GOTPCREL(%rip), %eax
# example non-fPIC assembler: cmpl %eax, 36+cwrap_log_verbosity_dummy\@GOTPCREL(%rip)
# example non-fPIC assembler: jle .L23
close EOF;
}
sub compress_demangled_name {
my ($demangled_name, $debug_expected) = @_;
my $debug_result;
my $demangled_name_orig = $demangled_name;
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~<[^<>]*>~!!~g) {} # remove all <..>
$debug_result .= sprintf qq[- compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
#while($demangled_name =~ s~\{[^\{\}]+\}~{}~) {} # remove all {..}
#$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug);
while($demangled_name =~ s~ const\&*~~g) {} # remove const&
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~lambda\([^\(\)]*\)\#\d+~lambda||~g) {} # remove all lambda(..)#n
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~\(\)~||~) {} # remove ()
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~\(([\*\&]+)\)~|*|~) {} # remove (*) or (*&)
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~\(anonymous namespace\)~|anonymous-namespace|~) {} # caf::(anonymous namespace)::fill_builtins()
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~\([^\(\)\*\&][^\(\)]*\)~||~) {} # remove (..) except not (*..) and not (&..)
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~lambda\|\|\#\d+~lambda||~g) {} # remove all lambda(..)#n due to nesting
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~!!~<>~g) {}
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~\|([^\|]*)\|~($1)~g) {}
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~unnamed type#\d+~unnamed-type~) {} # deal with unnamed type #1
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~^((.*?)<>|void)\s+~~) {} # std::tuple<> std::forward_as_tuple<>()
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
while($demangled_name =~ s~[^:\s]+\s+([^:\s]+::)~$1~) {} # std::vector<>& caf::default_sum_type_access<>::get<>() -> std::caf::default_sum_type_access<>::get<>()
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
$demangled_name =~ s~\(\)$~~; # remove single empty trailing () which normally contains function parameters
$debug_result .= sprintf qq[- test: compress_demangled_name(): %s\n\n], $demangled_name if ($debug_expected);
if ($debug_expected) {
printf qq[%s], $debug_result if ($demangled_name ne $debug_expected);
cmp_ok($demangled_name, 'eq', $debug_expected, sprintf qq[test: compressed %d bytes unique demangled name to expected %d bytes non-unique name: %s], length($demangled_name_orig), length($debug_expected), $debug_expected);
exit(1) if ($demangled_name ne $debug_expected);
}
return $demangled_name;
} # compress_demangled_name()
ONLY_REQUIRED_FOR_SUBS:;
1;
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment