compiler-rt/test/xray/TestCases/Posix/fdr-mode.cpp

   1 // RUN: %clangxx_xray -g -std=c++11 %s -o %t
   2 // RUN: rm -f fdr-logging-test-*
   3 // RUN: rm -f fdr-unwrite-test-*
   4 // RUN: XRAY_OPTIONS="patch_premain=false xray_logfile_base=fdr-logging-test- \
   5 // RUN:     xray_mode=xray-fdr verbosity=1" \
   6 // RUN: XRAY_FDR_OPTIONS="func_duration_threshold_us=0" \
   7 // RUN:     %run %t 2>&1 | FileCheck %s
   8 // RUN: XRAY_OPTIONS="patch_premain=false \
   9 // RUN:     xray_logfile_base=fdr-unwrite-test- xray_mode=xray-fdr \
  10 // RUN:     verbosity=1" \
  11 // RUN: XRAY_FDR_OPTIONS="func_duration_threshold_us=5000" \
  12 // RUN:     %run %t 2>&1 | FileCheck %s
  13 // RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
  14 // RUN:     "`ls fdr-logging-test-* | head -1`" \
  15 // RUN:     | FileCheck %s --check-prefix=TRACE
  16 // RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
  17 // RUN:     "`ls fdr-unwrite-test-* | head -1`" \
  18 // RUN:     | FileCheck %s --check-prefix=UNWRITE
  19 // RUN: rm fdr-logging-test-*
  20 // RUN: rm fdr-unwrite-test-*
  21 // UNSUPPORTED: target=powerpc64le-{{.*}}
  22 /// TODO: FDR logging arg1 handler(__xray_ArgLoggerEntry) hasn't implemented yet on LoongArch
  23 // UNSUPPORTED: target=loongarch64{{.*}}
  24 // REQUIRES: built-in-llvm-tree
  25
  26 #include "xray/xray_log_interface.h"
  27 #include <cassert>
  28 #include <chrono>
  29 #include <cstdio>
  30 #include <iostream>
  31 #include <stdlib.h>
  32 #include <thread>
  33 #include <time.h>
  34
  35 thread_local uint64_t var = 0;
  36 [[clang::xray_always_instrument]] void __attribute__((noinline)) fC() { ++var; }
  37
  38 [[clang::xray_always_instrument]] void __attribute__((noinline)) fB() { fC(); }
  39
  40 [[clang::xray_always_instrument]] void __attribute__((noinline)) fA() { fB(); }
  41
  42 [[clang::xray_always_instrument, clang::xray_log_args(1)]]
  43 void __attribute__((noinline)) fArg(int) { }
  44
  45 int main(int argc, char *argv[]) {
  46   std::cout << "Logging before init." << std::endl;
  47   // CHECK: Logging before init.
  48   assert(__xray_log_select_mode("xray-fdr") ==
  49          XRayLogRegisterStatus::XRAY_REGISTRATION_OK);
  50   auto status =
  51       __xray_log_init_mode("xray-fdr", "buffer_size=16384:buffer_max=10");
  52   assert(status == XRayLogInitStatus::XRAY_LOG_INITIALIZED);
  53   std::cout << "Init status " << status << std::endl;
  54   // CHECK: Init status {{.*}}
  55   std::cout << "Patching..." << std::endl;
  56   // CHECK: Patching...
  57   __xray_patch();
  58   fA();
  59   fC();
  60   fB();
  61   fA();
  62   fC();
  63   std::thread other_thread([]() {
  64     fC();
  65     fB();
  66     fA();
  67     fArg(1);
  68   });
  69   other_thread.join();
  70   std::cout << "Joined" << std::endl;
  71   // CHECK: Joined
  72   std::cout << "Finalize status " << __xray_log_finalize() << std::endl;
  73   // CHECK: Finalize status {{.*}}
  74   fC();
  75   std::cout << "Main execution var = " << var << std::endl;
  76   // CHECK: Main execution var = 6
  77   std::cout << "Flush status " << __xray_log_flushLog() << std::endl;
  78   // CHECK: Flush status {{.*}}
  79   __xray_unpatch();
  80   return 0;
  81 }
  82
  83 // Check that we're able to see two threads, each entering and exiting fA().
  84 // TRACE-DAG: - { type: 0, func-id: [[FIDA:[0-9]+]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}}, data: '' }
  85 // TRACE:     - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}}, data: '' }
  86 // TRACE-DAG: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}}, data: '' }
  87 // TRACE:     - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}}, data: '' }
  88 //
  89 // Do the same as above for fC()
  90 // TRACE-DAG: - { type: 0, func-id: [[FIDC:[0-9]+]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}}, data: '' }
  91 // TRACE:     - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}}, data: '' }
  92 // TRACE-DAG: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}}, data: '' }
  93 // TRACE:     - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}}, data: '' }
  94
  95 // Do the same as above for fB()
  96 // TRACE-DAG: - { type: 0, func-id: [[FIDB:[0-9]+]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}}, data: '' }
  97 // TRACE:     - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}}, data: '' }
  98 // TRACE-DAG: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS]], kind: function-enter, tsc: {{[0-9]+}}, data: '' }
  99 // TRACE:     - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}}, data: '' }
 100
 101 // TRACE-DAG: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-enter-arg, tsc: {{[0-9]+}}, data: '' }
 102 // TRACE-DAG: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-exit, tsc: {{[0-9]+}}, data: '' }
 103
 104 // Assert that when unwriting is enabled with a high threshold time, all the function records are erased. A CPU switch could erroneously fail this test, but
 105 // is unlikely given the test program.
 106 // Even with a high threshold, arg1 logging is never unwritten.
 107 // UNWRITE: header:
 108 // UNWRITE: records:
 109 // UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], process: [[PROCESS:[0-9]+]], kind: function-enter-arg, tsc: {{[0-9]+}}, data: '' }
 110 // UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], process: [[PROCESS]], kind: function-exit, tsc: {{[0-9]+}}, data: '' }
 111 // UNWRITE-NOT: function-enter
 112 // UNWRITE-NOT: function-{{exit|tail-exit}}