[llvm-dev] XRAY_OPTIONS variable does not enable FDR mode and log flushing
Henry Zhu via llvm-dev
llvm-dev at lists.llvm.org
Mon Jun 11 14:49:09 PDT 2018
Hello,
Setting the xray_mode to xray-fdr in XRAY_OPTIONS does not enable FDR mode.
Under Flight Data Recorder Mode in the docs (https://llvm.org/docs/XRay.html),
it mentions that “ To use FDR mode on your application, you may set the
xray_mode variable to xray-fdr in the XRAY_OPTIONS environment variable.”
I will demonstrate below with output generated from setting the flag
I am running Ubuntu 16.04.1 on a x86_64 machine and am using clang 7.0.
henry at OptiPlex-9010:~$ uname -a
Linux OptiPlex-9010 4.13.0-43-generic #48~16.04.1-Ubuntu SMP Thu May 17
12:56:46 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
The test file I will be using is arg1-arg0-logging.cc from the
TestCases/Posix directory. I will include the file as an attachment as well.
Steps taken:
henry at OptiPlex-9010:~/build_xray/llvm-instrumented-build/bin$ ./clang++
-fxray-instrument -std=c++11 arg1-arg0-logging.cc
Running with xray-fdr mode enabled:
henry at OptiPlex-9010:~/build_xray/llvm-instrumented-build/bin$
XRAY_OPTIONS="patch_premain=true verbosity=1 xray_mode=xray-fdr" ./a.out
hello, arg0!
hello, arg1!
Running with basic-mode enabled:
henry at OptiPlex-9010:~/build_xray/llvm-instrumented-build/bin$
XRAY_OPTIONS="patch_premain=true verbosity=1 xray_mode=xray-basic" ./a.out
==13229==XRay: Log file in 'xray-log.a.out.dpsGGd'
hello, arg0!
hello, arg1!
==13229==Skipping buffer for TID: 13229; Fd = 3; Offset = 0
==13229==Cleaned up log for TID: 13229
As shown above, setting the xray_mode=xray-fdr does not initialize or
produce any logs. The documentation states that setting this variable would
enable fdr mode, but nothing from the output indicates that.
Instead, I enabled xray-fdr programmatically, but it does not produce a
trace even when the program terminates. I have to call __xray_log_finalize
and __xray_log_flushLog() to produce a trace. Shouldn’t XRay in FDR mode
produce a trace when the program terminates like basic mode does?
The test file I will be using is fdr-mode.cc from the TestCases/Posix
directory. I will also modify the test case and its new name is
fdr-mode-no-flush.cc. I have included the files as attachments as well.
fdr-mode-no-flush.cc (I have removed the lines to __xray_log_finalize and
xray_log_flushLog():
// RUN: %clangxx_xray -g -std=c++11 %s -o %t
// RUN: rm fdr-logging-test-* || true
// RUN: rm fdr-unwrite-test-* || true
// RUN: XRAY_OPTIONS="patch_premain=false
xray_logfile_base=fdr-logging-test- \
// RUN: xray_mode=xray-fdr verbosity=1" \
// RUN: XRAY_FDR_OPTIONS="func_duration_threshold_us=0" \
// RUN: %run %t 2>&1 | FileCheck %s
// RUN: XRAY_OPTIONS="patch_premain=false \
// RUN: xray_logfile_base=fdr-unwrite-test- xray_mode=xray-fdr \
// RUN: verbosity=1" \
// RUN: XRAY_FDR_OPTIONS="func_duration_threshold_us=5000" \
// RUN: %run %t 2>&1 | FileCheck %s
// RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
// RUN: "`ls fdr-logging-test-* | head -1`" \
// RUN: | FileCheck %s --check-prefix=TRACE
// RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
// RUN: "`ls fdr-unwrite-test-* | head -1`" \
// RUN: | FileCheck %s --check-prefix=UNWRITE
// RUN: rm fdr-logging-test-*
// RUN: rm fdr-unwrite-test-*
// FIXME: Make llvm-xray work on non-x86_64 as well.
// REQUIRES: x86_64-target-arch
// REQUIRES: built-in-llvm-tree
#include "xray/xray_log_interface.h"
#include <cassert>
#include <chrono>
#include <cstdio>
#include <iostream>
#include <stdlib.h>
#include <thread>
#include <time.h>
thread_local uint64_t var = 0;
[[clang::xray_always_instrument]] void __attribute__((noinline)) fC() {
++var; }
[[clang::xray_always_instrument]] void __attribute__((noinline)) fB() {
fC(); }
[[clang::xray_always_instrument]] void __attribute__((noinline)) fA() {
fB(); }
[[clang::xray_always_instrument, clang::xray_log_args(1)]]
void __attribute__((noinline)) fArg(int) { }
int main(int argc, char *argv[]) {
using namespace __xray;
std::cout << "Logging before init." << std::endl;
// CHECK: Logging before init.
assert(__xray_log_select_mode("xray-fdr") ==
XRayLogRegisterStatus::XRAY_REGISTRATION_OK);
auto status =
__xray_log_init_mode("xray-fdr", "buffer_size=16384:buffer_max=10");
assert(status == XRayLogInitStatus::XRAY_LOG_INITIALIZED);
std::cout << "Init status " << status << std::endl;
// CHECK: Init status {{.*}}
std::cout << "Patching..." << std::endl;
// CHECK: Patching...
__xray_patch();
fA();
fC();
fB();
fA();
fC();
std::thread other_thread([]() {
fC();
fB();
fA();
fArg(1);
});
other_thread.join();
std::cout << "Joined" << std::endl;
// CHECK: Joined
fC();
std::cout << "Main execution var = " << var << std::endl;
// CHECK: Main execution var = 6
__xray_unpatch();
return 0;
}
// Check that we're able to see two threads, each entering and exiting fA().
// TRACE-DAG: - { type: 0, func-id: [[FIDA:[0-9]+]], function: {{.*fA.*}},
cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc:
{{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu:
{{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc:
{{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu:
{{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu:
{{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc:
{{[0-9]+}} }
//
// Do the same as above for fC()
// TRACE-DAG: - { type: 0, func-id: [[FIDC:[0-9]+]], function: {{.*fC.*}},
cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc:
{{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu:
{{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc:
{{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu:
{{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu:
{{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc:
{{[0-9]+}} }
// Do the same as above for fB()
// TRACE-DAG: - { type: 0, func-id: [[FIDB:[0-9]+]], function: {{.*fB.*}},
cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc:
{{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu:
{{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc:
{{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu:
{{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu:
{{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc:
{{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDARG:[0-9]+]], function:
'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2]], kind:
function-enter-arg, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu:
{{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
// 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
// is unlikely given the test program.
// Even with a high threshold, arg1 logging is never unwritten.
// UNWRITE: header:
// UNWRITE: records:
// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG:[0-9]+]], function:
'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind:
function-enter-arg, tsc: {{[0-9]+}} }
// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)',
cpu: {{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
// UNWRITE-NOT: function-enter
// UNWRITE-NOT: function-{{exit|tail-exit}}
Compiling:
henry at OptiPlex-9010:~/build_xray/llvm-instrumented-build/bin$ ./clang++
-fxray-instrument -std=c++11 fdr-mode-no-flush.cc
henry at OptiPlex-9010:~/build_xray/llvm-instrumented-build/bin$
XRAY_OPTIONS="patch_premain=true verbosity=1 xray_mode=xray-fdr" ./a.out
Logging before init.
==13595==Initializing FDR mode with options: buffer_size=16384:buffer_max=10
==13595==XRay FDR init successful.
Init status 2
Patching...
Joined
Main execution var = 6
XRay reports that fdr-mode is initialized, but when the program is finished
executing, the logs are not flushed to a trace file. I would expect
fdr-mode to flush like basic-mode does when before a program terminates,
but it does not do so unless __xray_log_finalize and __xray_log_flushLog
are called before program termination.
fdr-mode.cc(same as the TestCase/Posix/fdr-mode.cc):
Compiling:
henry at OptiPlex-9010:~/build_xray/llvm-instrumented-build/bin$ ./clang++
-fxray-instrument -std=c++11 fdr-mode.cc
henry at OptiPlex-9010:~/build_xray/llvm-instrumented-build/bin$
XRAY_OPTIONS="patch_premain=true verbosity=1 xray_mode=xray-fdr" ./a.out
Logging before init.
==13609==Initializing FDR mode with options: buffer_size=16384:buffer_max=10
==13609==XRay FDR init successful.
Init status 2
Patching...
Joined
Finalize status 4
Main execution var = 6
==13609==XRay: Log file in 'xray-log.a.out.Fef0vA'
Flush status 2
Now, the log is generated. It seems a bit odd to me that setting
xray_mode=xray-fdr does not enable fdr mode as stated in the documentation.
In addition, one has to manually configure the program to initialize
fdr-mode and flush its buffers before program termination. Is there a
reason for fdr mode to be setup this way? Is it possible to enable fdr mode
and flushing to logs by setting xray_mode=xray-fdr?
Thanks,
Henry
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.llvm.org/pipermail/llvm-dev/attachments/20180611/8cc8b07a/attachment-0001.html>
-------------- next part --------------
// Allow having both the no-arg and arg1 logging implementation live together,
// and be called in the correct cases.
//
// RUN: rm arg0-arg1-logging-* || true
// RUN: %clangxx_xray -std=c++11 %s -o %t
// RUN: XRAY_OPTIONS="patch_premain=true verbosity=1 xray_logfile_base=arg0-arg1-logging-" %run %t
//
// TODO: Support these in ARM and PPC
// XFAIL: arm || aarch64 || mips
// UNSUPPORTED: powerpc64le
#include "xray/xray_interface.h"
#include <cassert>
#include <cstdio>
using namespace std;
bool arg0loggercalled = false;
void arg0logger(int32_t, XRayEntryType) { arg0loggercalled = true; }
[[clang::xray_always_instrument]] void arg0fn() { printf("hello, arg0!\n"); }
bool arg1loggercalled = false;
void arg1logger(int32_t, XRayEntryType, uint64_t) { arg1loggercalled = true; }
[[ clang::xray_always_instrument, clang::xray_log_args(1) ]] void
arg1fn(uint64_t arg1) {
printf("hello, arg1!\n");
}
int main(int argc, char *argv[]) {
__xray_set_handler(arg0logger);
__xray_set_handler_arg1(arg1logger);
arg0fn();
arg1fn(0xcafef00d);
__xray_remove_handler_arg1();
__xray_remove_handler();
assert(arg0loggercalled && arg1loggercalled);
}
-------------- next part --------------
// RUN: %clangxx_xray -g -std=c++11 %s -o %t
// RUN: rm fdr-logging-test-* || true
// RUN: rm fdr-unwrite-test-* || true
// RUN: XRAY_OPTIONS="patch_premain=false xray_logfile_base=fdr-logging-test- \
// RUN: xray_mode=xray-fdr verbosity=1" \
// RUN: XRAY_FDR_OPTIONS="func_duration_threshold_us=0" \
// RUN: %run %t 2>&1 | FileCheck %s
// RUN: XRAY_OPTIONS="patch_premain=false \
// RUN: xray_logfile_base=fdr-unwrite-test- xray_mode=xray-fdr \
// RUN: verbosity=1" \
// RUN: XRAY_FDR_OPTIONS="func_duration_threshold_us=5000" \
// RUN: %run %t 2>&1 | FileCheck %s
// RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
// RUN: "`ls fdr-logging-test-* | head -1`" \
// RUN: | FileCheck %s --check-prefix=TRACE
// RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
// RUN: "`ls fdr-unwrite-test-* | head -1`" \
// RUN: | FileCheck %s --check-prefix=UNWRITE
// RUN: rm fdr-logging-test-*
// RUN: rm fdr-unwrite-test-*
// FIXME: Make llvm-xray work on non-x86_64 as well.
// REQUIRES: x86_64-target-arch
// REQUIRES: built-in-llvm-tree
#include "xray/xray_log_interface.h"
#include <cassert>
#include <chrono>
#include <cstdio>
#include <iostream>
#include <stdlib.h>
#include <thread>
#include <time.h>
thread_local uint64_t var = 0;
[[clang::xray_always_instrument]] void __attribute__((noinline)) fC() { ++var; }
[[clang::xray_always_instrument]] void __attribute__((noinline)) fB() { fC(); }
[[clang::xray_always_instrument]] void __attribute__((noinline)) fA() { fB(); }
[[clang::xray_always_instrument, clang::xray_log_args(1)]]
void __attribute__((noinline)) fArg(int) { }
int main(int argc, char *argv[]) {
using namespace __xray;
std::cout << "Logging before init." << std::endl;
// CHECK: Logging before init.
assert(__xray_log_select_mode("xray-fdr") ==
XRayLogRegisterStatus::XRAY_REGISTRATION_OK);
auto status =
__xray_log_init_mode("xray-fdr", "buffer_size=16384:buffer_max=10");
assert(status == XRayLogInitStatus::XRAY_LOG_INITIALIZED);
std::cout << "Init status " << status << std::endl;
// CHECK: Init status {{.*}}
std::cout << "Patching..." << std::endl;
// CHECK: Patching...
__xray_patch();
fA();
fC();
fB();
fA();
fC();
std::thread other_thread([]() {
fC();
fB();
fA();
fArg(1);
});
other_thread.join();
std::cout << "Joined" << std::endl;
// CHECK: Joined
std::cout << "Finalize status " << __xray_log_finalize() << std::endl;
// CHECK: Finalize status {{.*}}
fC();
std::cout << "Main execution var = " << var << std::endl;
// CHECK: Main execution var = 6
std::cout << "Flush status " << __xray_log_flushLog() << std::endl;
// CHECK: Flush status {{.*}}
__xray_unpatch();
return 0;
}
// Check that we're able to see two threads, each entering and exiting fA().
// TRACE-DAG: - { type: 0, func-id: [[FIDA:[0-9]+]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
//
// Do the same as above for fC()
// TRACE-DAG: - { type: 0, func-id: [[FIDC:[0-9]+]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// Do the same as above for fB()
// TRACE-DAG: - { type: 0, func-id: [[FIDB:[0-9]+]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2]], kind: function-enter-arg, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
// 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
// is unlikely given the test program.
// Even with a high threshold, arg1 logging is never unwritten.
// UNWRITE: header:
// UNWRITE: records:
// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter-arg, tsc: {{[0-9]+}} }
// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
// UNWRITE-NOT: function-enter
// UNWRITE-NOT: function-{{exit|tail-exit}}
-------------- next part --------------
// RUN: %clangxx_xray -g -std=c++11 %s -o %t
// RUN: rm fdr-logging-test-* || true
// RUN: rm fdr-unwrite-test-* || true
// RUN: XRAY_OPTIONS="patch_premain=false xray_logfile_base=fdr-logging-test- \
// RUN: xray_mode=xray-fdr verbosity=1" \
// RUN: XRAY_FDR_OPTIONS="func_duration_threshold_us=0" \
// RUN: %run %t 2>&1 | FileCheck %s
// RUN: XRAY_OPTIONS="patch_premain=false \
// RUN: xray_logfile_base=fdr-unwrite-test- xray_mode=xray-fdr \
// RUN: verbosity=1" \
// RUN: XRAY_FDR_OPTIONS="func_duration_threshold_us=5000" \
// RUN: %run %t 2>&1 | FileCheck %s
// RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
// RUN: "`ls fdr-logging-test-* | head -1`" \
// RUN: | FileCheck %s --check-prefix=TRACE
// RUN: %llvm_xray convert --symbolize --output-format=yaml -instr_map=%t \
// RUN: "`ls fdr-unwrite-test-* | head -1`" \
// RUN: | FileCheck %s --check-prefix=UNWRITE
// RUN: rm fdr-logging-test-*
// RUN: rm fdr-unwrite-test-*
// FIXME: Make llvm-xray work on non-x86_64 as well.
// REQUIRES: x86_64-target-arch
// REQUIRES: built-in-llvm-tree
#include "xray/xray_log_interface.h"
#include <cassert>
#include <chrono>
#include <cstdio>
#include <iostream>
#include <stdlib.h>
#include <thread>
#include <time.h>
thread_local uint64_t var = 0;
[[clang::xray_always_instrument]] void __attribute__((noinline)) fC() { ++var; }
[[clang::xray_always_instrument]] void __attribute__((noinline)) fB() { fC(); }
[[clang::xray_always_instrument]] void __attribute__((noinline)) fA() { fB(); }
[[clang::xray_always_instrument, clang::xray_log_args(1)]]
void __attribute__((noinline)) fArg(int) { }
int main(int argc, char *argv[]) {
using namespace __xray;
std::cout << "Logging before init." << std::endl;
// CHECK: Logging before init.
assert(__xray_log_select_mode("xray-fdr") ==
XRayLogRegisterStatus::XRAY_REGISTRATION_OK);
auto status =
__xray_log_init_mode("xray-fdr", "buffer_size=16384:buffer_max=10");
assert(status == XRayLogInitStatus::XRAY_LOG_INITIALIZED);
std::cout << "Init status " << status << std::endl;
// CHECK: Init status {{.*}}
std::cout << "Patching..." << std::endl;
// CHECK: Patching...
__xray_patch();
fA();
fC();
fB();
fA();
fC();
std::thread other_thread([]() {
fC();
fB();
fA();
fArg(1);
});
other_thread.join();
std::cout << "Joined" << std::endl;
// CHECK: Joined
fC();
std::cout << "Main execution var = " << var << std::endl;
// CHECK: Main execution var = 6
__xray_unpatch();
return 0;
}
// Check that we're able to see two threads, each entering and exiting fA().
// TRACE-DAG: - { type: 0, func-id: [[FIDA:[0-9]+]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDA]], function: {{.*fA.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
//
// Do the same as above for fC()
// TRACE-DAG: - { type: 0, func-id: [[FIDC:[0-9]+]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDC]], function: {{.*fC.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// Do the same as above for fB()
// TRACE-DAG: - { type: 0, func-id: [[FIDB:[0-9]+]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD1]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
// TRACE: - { type: 0, func-id: [[FIDB]], function: {{.*fB.*}}, cpu: {{.*}}, thread: [[THREAD2]], kind: function-{{exit|tail-exit}}, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2]], kind: function-enter-arg, tsc: {{[0-9]+}} }
// TRACE-DAG: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
// 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
// is unlikely given the test program.
// Even with a high threshold, arg1 logging is never unwritten.
// UNWRITE: header:
// UNWRITE: records:
// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG:[0-9]+]], function: 'fArg(int)', args: [ 1 ], cpu: {{.*}}, thread: [[THREAD2:[0-9]+]], kind: function-enter-arg, tsc: {{[0-9]+}} }
// UNWRITE-NEXT: - { type: 0, func-id: [[FIDARG]], function: 'fArg(int)', cpu: {{.*}}, thread: [[THREAD2]], kind: function-exit, tsc: {{[0-9]+}} }
// UNWRITE-NOT: function-enter
// UNWRITE-NOT: function-{{exit|tail-exit}}
More information about the llvm-dev
mailing list