From a1b3deb61164dc7420e4d0f350098f7e0ba1e8ab Mon Sep 17 00:00:00 2001 From: hariharandev1 Date: Sat, 7 Sep 2024 23:36:05 -0700 Subject: [PATCH 1/4] changes to support function tracing for shared libraries. --- .vscode/settings.json | 4 +- CMakeLists.txt | 2 + .../dftracer-config.cmake.build.in | 1 + .../dftracer-config.cmake.install.in | 1 + src/dftracer/core/dftracer_main.cpp | 6 ++ src/dftracer/finstrument/functions.cpp | 61 ++++++++++++++++++ src/dftracer/finstrument/functions.h | 62 +++++++++++++++++++ test/CMakeLists.txt | 10 ++- test/c/test.c | 3 + test/c/testlib.c | 1 + 10 files changed, 149 insertions(+), 2 deletions(-) create mode 100644 src/dftracer/finstrument/functions.cpp create mode 100644 src/dftracer/finstrument/functions.h create mode 100644 test/c/testlib.c diff --git a/.vscode/settings.json b/.vscode/settings.json index f85bcf9..b650320 100644 --- a/.vscode/settings.json +++ b/.vscode/settings.json @@ -91,6 +91,8 @@ "typeinfo": "cpp", "valarray": "cpp", "variant": "cpp", - "ranges": "cpp" + "ranges": "cpp", + "filesystem": "cpp", + "*.in": "cpp" } } \ No newline at end of file diff --git a/CMakeLists.txt b/CMakeLists.txt index 1595a05..5cd3ed2 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -256,6 +256,7 @@ set(DFTRACER_PRELOAD_PRIVATE_INCLUDE ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/df set(DFTRACER_CORE_SRC ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/brahma/posix.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/brahma/stdio.cpp + ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/finstrument/functions.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/writer/chrome_writer.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/utils/posix_internal.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/dftracer.cpp @@ -270,6 +271,7 @@ set(DFTRACER_CORE_PUBLIC_INCLUDE set(DFTRACER_CORE_PRIVATE_INCLUDE ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/utils/posix_internal.h ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/utils/utils.h + ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/finstrument/functions.h ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/brahma/posix.h ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/brahma/stdio.h ${CMAKE_CURRENT_SOURCE_DIR}/src/dftracer/core/dftracer_main.h diff --git a/cmake/configure_files/dftracer-config.cmake.build.in b/cmake/configure_files/dftracer-config.cmake.build.in index 20bd0ce..367740b 100644 --- a/cmake/configure_files/dftracer-config.cmake.build.in +++ b/cmake/configure_files/dftracer-config.cmake.build.in @@ -87,6 +87,7 @@ if (DFTRACER_INCLUDE_MPI) endif () endif() +set(DFTRACER_FUNCTION_FLAGS "-g" "-finstrument-functions" "-Wl,-E" "-fvisibility=default") check_required_components(dftracer) set(DFTRACER_LIBRARIES dftracer) \ No newline at end of file diff --git a/cmake/configure_files/dftracer-config.cmake.install.in b/cmake/configure_files/dftracer-config.cmake.install.in index 3aecaaa..a69e213 100644 --- a/cmake/configure_files/dftracer-config.cmake.install.in +++ b/cmake/configure_files/dftracer-config.cmake.install.in @@ -85,6 +85,7 @@ if (DFTRACER_INCLUDE_MPI) message(FATAL_ERROR "-- [DFTRACER] mpi is needed for ${PROJECT_NAME} build") endif () endif() +set(DFTRACER_FUNCTION_FLAGS "-g" "-finstrument-functions" "-Wl,-E" "-fvisibility=default") check_required_components(dftracer) diff --git a/src/dftracer/core/dftracer_main.cpp b/src/dftracer/core/dftracer_main.cpp index 786f465..8242a56 100644 --- a/src/dftracer/core/dftracer_main.cpp +++ b/src/dftracer/core/dftracer_main.cpp @@ -2,6 +2,7 @@ // Created by haridev on 10/8/23. // #include +#include template <> std::shared_ptr dftracer::Singleton::instance = nullptr; @@ -109,6 +110,10 @@ bool dftracer::DFTracerCore::finalize() { if (stdio_instance != nullptr) { stdio_instance->finalize(); } + auto function_instance = dftracer::Function::get_instance(); + if (function_instance != nullptr) { + function_instance->finalize(); + } } if (logger != nullptr) { logger->finalize(); @@ -234,6 +239,7 @@ void dftracer::DFTracerCore::initialize(bool _bind, const char *_log_file, brahma::STDIODFTracer::get_instance(conf->trace_all_files); } } + dftracer::Function::get_instance(); } } is_initialized = true; diff --git a/src/dftracer/finstrument/functions.cpp b/src/dftracer/finstrument/functions.cpp new file mode 100644 index 0000000..8aebe9f --- /dev/null +++ b/src/dftracer/finstrument/functions.cpp @@ -0,0 +1,61 @@ +#include +#include +std::shared_ptr dftracer::Function::instance = nullptr; + +thread_local std::unordered_map + dftracer::Function::map = + std::unordered_map(); +bool dftracer::Function::stop_trace = false; +int dftracer::Function::enter_event(ConstEventNameType name) { + if (stop_trace) return -1; + auto start = this->logger->get_time(); + map.insert_or_assign(name, start); + return 0; +} + +int dftracer::Function::exit_event(ConstEventNameType name, + TimeResolution &start) { + if (stop_trace) return -1; + auto tmap = map.find(name); + if (tmap != map.end()) { + start = tmap->second; + map.erase(tmap); + return 0; + } + return -1; +} + +void __cyg_profile_func_enter(void *func, void *caller) { + auto function = dftracer::Function::get_instance(); + Dl_info info; + if (!dladdr(func, &info)) return; + if (!info.dli_sname || !info.dli_fname) return; + if (!function->is_active()) return; + ConstEventNameType event_name = info.dli_sname; + DFTRACER_LOG_DEBUG("Calling function %s", event_name); + function->enter_event(event_name); +} + +void __cyg_profile_func_exit(void *func, void *caller) { + Dl_info info; + if (!dladdr(func, &info)) return; + if (!info.dli_sname || !info.dli_fname) return; + auto function = dftracer::Function::get_instance(); + if (!function->is_active()) return; + auto end_time = function->logger->get_time(); + ConstEventNameType event_name = info.dli_sname; + TimeResolution start_time; + int status = function->exit_event(event_name, start_time); + if (status == 0) { + std::unordered_map *metadata; + if (function->logger->include_metadata) { + metadata = new std::unordered_map(); + const char *so = info.dli_fname; + metadata->insert_or_assign("so", so); + } + function->logger->enter_event(); + function->logger->log(event_name, CATEGORY, start_time, + end_time - start_time, metadata); + function->logger->exit_event(); + } +} \ No newline at end of file diff --git a/src/dftracer/finstrument/functions.h b/src/dftracer/finstrument/functions.h new file mode 100644 index 0000000..4cb9510 --- /dev/null +++ b/src/dftracer/finstrument/functions.h @@ -0,0 +1,62 @@ +// +// Created by hariharan on 8/8/22. +// + +#ifndef DFTRACER_FUNCTION_H +#define DFTRACER_FUNCTION_H + +/* Internal Header */ +#include +#include +#include +#include +/* External Header */ +#include + +#include +#include +#include +#include + +static ConstEventNameType CATEGORY = "FUNC"; +extern "C" { +void __cyg_profile_func_enter(void *, void *) + __attribute__((no_instrument_function)); +void __cyg_profile_func_exit(void *, void *) + __attribute__((no_instrument_function)); +} +namespace dftracer { +class Function { + private: + static std::shared_ptr instance; + static bool stop_trace; + thread_local static std::unordered_map + map; + + public: + std::shared_ptr logger; + Function() { + DFTRACER_LOG_DEBUG("Function class intercepted", ""); + logger = DFT_LOGGER_INIT(); + } + + void finalize() { + DFTRACER_LOG_DEBUG("Finalizing Function", ""); + stop_trace = true; + } + ~Function() {} + static std::shared_ptr get_instance() { + DFTRACER_LOG_DEBUG("POSIX class get_instance", ""); + if (!stop_trace && instance == nullptr) { + instance = std::make_shared(); + } + return instance; + } + bool is_active() { return !stop_trace; } + int enter_event(ConstEventNameType name); + int exit_event(ConstEventNameType name, TimeResolution &start); +}; + +} // namespace dftracer + +#endif // DFTRACER_FUNCTION_H \ No newline at end of file diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index e34a60c..ff7ae6e 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -14,11 +14,19 @@ add_executable(test_cpp cpp/test.cpp) target_link_libraries(test_cpp ${PROJECT_NAME}) add_dependencies(test_cpp ${PROJECT_NAME}) add_dependencies(test_cpp ${PROJECT_NAME}_preload) +target_compile_options(test_cpp PRIVATE "-g") +target_compile_options(test_cpp PRIVATE "-finstrument-functions") +target_compile_options(test_cpp PRIVATE "-rdynamic") +add_library(testlib SHARED c/testlib.c) +target_compile_options(testlib PRIVATE "-g" "-finstrument-functions" "-Wl,-E" "-fvisibility=default") add_executable(test_c c/test.c) -target_link_libraries(test_c ${PROJECT_NAME}) +target_compile_options(test_c PRIVATE "-g" "-finstrument-functions" "-Wl,-E" "-fvisibility=default") +target_link_libraries(test_c ${PROJECT_NAME} testlib) add_dependencies(test_c ${PROJECT_NAME}) add_dependencies(test_c ${PROJECT_NAME}_preload) + + function(set_common_properties test_name) set_property(TEST ${test_name} APPEND PROPERTY ENVIRONMENT DFTRACER_LOG_LEVEL=DEBUG) set_property(TEST ${test_name} APPEND PROPERTY ENVIRONMENT DFTRACER_TRACE_COMPRESSION=0) diff --git a/test/c/test.c b/test/c/test.c index d39f323..6d82c8f 100644 --- a/test/c/test.c +++ b/test/c/test.c @@ -8,6 +8,8 @@ #include #include #include + +int bar(); void foo() { DFTRACER_C_FUNCTION_START(); DFTRACER_C_FUNCTION_UPDATE_INT("key", 0); @@ -16,6 +18,7 @@ void foo() { DFTRACER_C_REGION_START(CUSTOM); DFTRACER_C_REGION_UPDATE_INT(CUSTOM, "key", 0); DFTRACER_C_REGION_UPDATE_STR(CUSTOM, "key", "0"); + bar(); sleep(1); DFTRACER_C_REGION_START(CUSTOM_BLOCK); sleep(1); diff --git a/test/c/testlib.c b/test/c/testlib.c new file mode 100644 index 0000000..ebf881d --- /dev/null +++ b/test/c/testlib.c @@ -0,0 +1 @@ +int bar() { return 0; } \ No newline at end of file From 16bd7b0fdcf55518b638f0c0adb836f9087d0f24 Mon Sep 17 00:00:00 2001 From: hariharandev1 Date: Sun, 8 Sep 2024 00:02:22 -0700 Subject: [PATCH 2/4] support for function ptr for executables. 1. These addresses can be resolved during analysis. --- src/dftracer/finstrument/functions.cpp | 45 +++++++++++++++++--------- src/dftracer/finstrument/functions.h | 7 ++-- 2 files changed, 32 insertions(+), 20 deletions(-) diff --git a/src/dftracer/finstrument/functions.cpp b/src/dftracer/finstrument/functions.cpp index 8aebe9f..7e9fd08 100644 --- a/src/dftracer/finstrument/functions.cpp +++ b/src/dftracer/finstrument/functions.cpp @@ -2,24 +2,22 @@ #include std::shared_ptr dftracer::Function::instance = nullptr; -thread_local std::unordered_map - dftracer::Function::map = - std::unordered_map(); +thread_local std::unordered_map + dftracer::Function::map = std::unordered_map(); bool dftracer::Function::stop_trace = false; -int dftracer::Function::enter_event(ConstEventNameType name) { +int dftracer::Function::enter_event(std::string &name) { if (stop_trace) return -1; auto start = this->logger->get_time(); map.insert_or_assign(name, start); return 0; } -int dftracer::Function::exit_event(ConstEventNameType name, - TimeResolution &start) { +int dftracer::Function::exit_event(std::string &name, TimeResolution &start) { if (stop_trace) return -1; auto tmap = map.find(name); if (tmap != map.end()) { start = tmap->second; - map.erase(tmap); + map.erase(name); return 0; } return -1; @@ -27,23 +25,38 @@ int dftracer::Function::exit_event(ConstEventNameType name, void __cyg_profile_func_enter(void *func, void *caller) { auto function = dftracer::Function::get_instance(); + if (!function->is_active()) return; Dl_info info; if (!dladdr(func, &info)) return; - if (!info.dli_sname || !info.dli_fname) return; - if (!function->is_active()) return; - ConstEventNameType event_name = info.dli_sname; + if (!info.dli_fname) return; + std::string event_name; + if (!info.dli_sname) { + char name[256]; + sprintf(name, "%p", func); + event_name = name; + } else { + event_name = info.dli_sname; + } + DFTRACER_LOG_DEBUG("Calling function %s", event_name); function->enter_event(event_name); } void __cyg_profile_func_exit(void *func, void *caller) { - Dl_info info; - if (!dladdr(func, &info)) return; - if (!info.dli_sname || !info.dli_fname) return; auto function = dftracer::Function::get_instance(); - if (!function->is_active()) return; auto end_time = function->logger->get_time(); - ConstEventNameType event_name = info.dli_sname; + if (!function->is_active()) return; + Dl_info info; + if (!dladdr(func, &info)) return; + if (!info.dli_fname) return; + std::string event_name; + if (!info.dli_sname) { + char name[256]; + sprintf(name, "%p", func); + event_name = name; + } else { + event_name = info.dli_sname; + } TimeResolution start_time; int status = function->exit_event(event_name, start_time); if (status == 0) { @@ -54,7 +67,7 @@ void __cyg_profile_func_exit(void *func, void *caller) { metadata->insert_or_assign("so", so); } function->logger->enter_event(); - function->logger->log(event_name, CATEGORY, start_time, + function->logger->log(event_name.c_str(), CATEGORY, start_time, end_time - start_time, metadata); function->logger->exit_event(); } diff --git a/src/dftracer/finstrument/functions.h b/src/dftracer/finstrument/functions.h index 4cb9510..e55ba84 100644 --- a/src/dftracer/finstrument/functions.h +++ b/src/dftracer/finstrument/functions.h @@ -30,8 +30,7 @@ class Function { private: static std::shared_ptr instance; static bool stop_trace; - thread_local static std::unordered_map - map; + thread_local static std::unordered_map map; public: std::shared_ptr logger; @@ -53,8 +52,8 @@ class Function { return instance; } bool is_active() { return !stop_trace; } - int enter_event(ConstEventNameType name); - int exit_event(ConstEventNameType name, TimeResolution &start); + int enter_event(std::string &name); + int exit_event(std::string &name, TimeResolution &start); }; } // namespace dftracer From 74e7804f0c19a8a2cb73650f752bad1d964b685d Mon Sep 17 00:00:00 2001 From: hariharandev1 Date: Sun, 8 Sep 2024 00:11:46 -0700 Subject: [PATCH 3/4] Enable disabled workflow. --- src/dftracer/core/dftracer_main.cpp | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/dftracer/core/dftracer_main.cpp b/src/dftracer/core/dftracer_main.cpp index 8242a56..ecc810f 100644 --- a/src/dftracer/core/dftracer_main.cpp +++ b/src/dftracer/core/dftracer_main.cpp @@ -241,6 +241,8 @@ void dftracer::DFTracerCore::initialize(bool _bind, const char *_log_file, } dftracer::Function::get_instance(); } + } else { + dftracer::Function::get_instance()->finalize(); } is_initialized = true; } From c04fb84651bb3c651d724a24ed94cd6f9afe0565 Mon Sep 17 00:00:00 2001 From: hariharandev1 Date: Sun, 8 Sep 2024 00:19:53 -0700 Subject: [PATCH 4/4] added docs --- docs/api.rst | 13 +++++++++++++ test/CMakeLists.txt | 3 --- 2 files changed, 13 insertions(+), 3 deletions(-) diff --git a/docs/api.rst b/docs/api.rst index 1ab99b2..f7fffa4 100644 --- a/docs/api.rst +++ b/docs/api.rst @@ -261,6 +261,19 @@ The name passed to the function should be unique in every scope. DFTRACER_C_FUNCTION_END(); // END FUNCTION foo. } +---------------------------------------- +DFTracer C/C++ Function Profiling using GCC +---------------------------------------- + +GCC supports function level tracing using ``-finstrument-functions``. +DFTracer allows application to compile with ``-g -finstrument-functions -Wl,-E -fvisibility=default``. +If the applications are using cmake, they can find_package and then use the CMAKE Variable `DFTRACER_FUNCTION_FLAGS` for compile flags. +This can be applied globally or on a target. + +Internally DFTracer uses ``dladdr`` to resolve symbol names which work for shared libraries. +For executables or binaries, we store the address and the name which can be used to derive the function name at analysis time. +This can be done using ``nm -D`` or ``readelf -S`` utilities. + ------------------------- DFTracer Python APIs ------------------------- diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index ff7ae6e..cda7a47 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -14,9 +14,6 @@ add_executable(test_cpp cpp/test.cpp) target_link_libraries(test_cpp ${PROJECT_NAME}) add_dependencies(test_cpp ${PROJECT_NAME}) add_dependencies(test_cpp ${PROJECT_NAME}_preload) -target_compile_options(test_cpp PRIVATE "-g") -target_compile_options(test_cpp PRIVATE "-finstrument-functions") -target_compile_options(test_cpp PRIVATE "-rdynamic") add_library(testlib SHARED c/testlib.c) target_compile_options(testlib PRIVATE "-g" "-finstrument-functions" "-Wl,-E" "-fvisibility=default")