| 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(Mode: "xray-fdr" , Config: "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}} |
| 113 | |