diff --git a/SerialPrograms/Source/ML/Inference/ML_PaddleOCRPipeline.cpp b/SerialPrograms/Source/ML/Inference/ML_PaddleOCRPipeline.cpp index ab9ab35fb7..066d79e626 100644 --- a/SerialPrograms/Source/ML/Inference/ML_PaddleOCRPipeline.cpp +++ b/SerialPrograms/Source/ML/Inference/ML_PaddleOCRPipeline.cpp @@ -87,6 +87,7 @@ PaddleOCRPipeline::PaddleOCRPipeline( , m_det_path(std::move(det_path)) { load_dictionary(Filesystem::Path(dict_path)); + std::cerr << "[ORT-DIAG] PaddleOCRPipeline ctor finished: " << rec_path << std::endl; } PaddleOCRDetector& PaddleOCRPipeline::detector(){ @@ -381,6 +382,10 @@ std::string PaddleOCRPipeline::recognize_line(const cv::Mat& cropped_image){ const char* input_names[] = {m_input_name.c_str()}; const char* output_names[] = {m_output_name.c_str()}; + static int diag_run_count = 0; + if (++diag_run_count <= 20){ + std::cerr << "[ORT-DIAG] recognize_line: about to call session->Run() (call " << diag_run_count << ")" << std::endl; + } try{ if (debugging){ m_logger.log("[OCR-DEBUG] Calling m_rec_session.Run() now..."); diff --git a/SerialPrograms/Source/ML/Models/ML_ONNXRuntimeHelpers.cpp b/SerialPrograms/Source/ML/Models/ML_ONNXRuntimeHelpers.cpp index d0dac9d2a8..620173c414 100644 --- a/SerialPrograms/Source/ML/Models/ML_ONNXRuntimeHelpers.cpp +++ b/SerialPrograms/Source/ML/Models/ML_ONNXRuntimeHelpers.cpp @@ -167,9 +167,11 @@ Ort::Session create_session( const std::string& model_cache_path, bool try_gpu ){ + std::cerr << "[ORT-DIAG] create_session(" << model_path << ", try_gpu=" << (try_gpu ? 1 : 0) << ")" << std::endl; bool write_flag_file = true; std::string file_hash; std::tie(write_flag_file, file_hash) = clean_up_old_model_cache(model_cache_path, model_path); + std::cerr << "[ORT-DIAG] clean_up_old_model_cache done, write_flag_file=" << write_flag_file << std::endl; auto onnx_path = str_to_onnx_str(model_path); @@ -205,7 +207,9 @@ Ort::Session create_session( Ort::SessionOptions cpu_options = create_session_options(model_cache_path, false); cpu_options.DisablePerSessionThreads(); + std::cerr << "[ORT-DIAG] calling Ort::Session constructor (CPU, per-session threads disabled)..." << std::endl; Ort::Session session{global_ort_env(), onnx_path.c_str(), cpu_options}; + std::cerr << "[ORT-DIAG] Ort::Session constructor returned: " << model_path << std::endl; logger.log("Ort::Session created"); return session; } diff --git a/SerialPrograms/Source/ML/Models/ML_OrtEnv.cpp b/SerialPrograms/Source/ML/Models/ML_OrtEnv.cpp index c69ace4a39..e16195442e 100644 --- a/SerialPrograms/Source/ML/Models/ML_OrtEnv.cpp +++ b/SerialPrograms/Source/ML/Models/ML_OrtEnv.cpp @@ -4,6 +4,8 @@ * */ +#include +#include #include "Common/Cpp/Exceptions.h" #include "Common/Cpp/PrettyPrint.h" #include "CommonFramework/Logging/Logger.h" @@ -19,11 +21,15 @@ Ort::ThreadingOptions make_ort_threading_options(){ { int threads = (int)PerformanceOptions::instance().ONNX_OPTIONS.MAX_INTRA_OP_THREADS; global_logger_tagged().log("Setting ONNX Intra-Op Threads: " + tostr_u_commas(threads)); + std::cerr << "[ORT-DIAG] ONNX Runtime " << Ort::GetVersionString() + << ", hardware_concurrency() = " << std::thread::hardware_concurrency() + << ", SetGlobalIntraOpNumThreads(" << threads << ")" << std::endl; ret.SetGlobalIntraOpNumThreads(threads); } { int threads = (int)PerformanceOptions::instance().ONNX_OPTIONS.MAX_INTER_OP_THREADS; global_logger_tagged().log("Setting ONNX Inter-Op Threads: " + tostr_u_commas(threads)); + std::cerr << "[ORT-DIAG] SetGlobalInterOpNumThreads(" << threads << ")" << std::endl; ret.SetGlobalInterOpNumThreads(threads); } ret.SetGlobalSpinControl(0); @@ -31,6 +37,7 @@ Ort::ThreadingOptions make_ort_threading_options(){ // them, and they are very slow on Intel CPUs. ONNX Runtime only supports this on x86; // see Common/Cpp/Hardware/FloatingPointMode.h. ret.SetGlobalDenormalAsZero(); + std::cerr << "[ORT-DIAG] SetGlobalSpinControl(0), SetGlobalDenormalAsZero()" << std::endl; return ret; } @@ -42,9 +49,10 @@ Ort::Env& global_ort_env(){ #endif static Ort::Env env( make_ort_threading_options(), - ORT_LOGGING_LEVEL_WARNING, + ORT_LOGGING_LEVEL_INFO, // [ORT-DIAG] was WARNING "Global_ThreadPool_Env" ); + std::cerr << "[ORT-DIAG] Ort::Env created" << std::endl; return env; } diff --git a/SerialPrograms/Source/Tests/CommandLineTests.cpp b/SerialPrograms/Source/Tests/CommandLineTests.cpp index a723fef213..ab6fe321f0 100644 --- a/SerialPrograms/Source/Tests/CommandLineTests.cpp +++ b/SerialPrograms/Source/Tests/CommandLineTests.cpp @@ -7,23 +7,91 @@ #include #include "CommonFramework/Logging/Logger.h" +#include "CommonTools/OCR/OCR_PaddleOCR.h" #include "ComputerPrograms/ComputerPrograms_UnitTestRunner.h" #include "CommandLineTests.h" +#if defined(__APPLE__) || defined(__linux__) +#include +#include +#include +#endif + using std::cout; using std::endl; namespace PokemonAutomation{ +#if defined(__APPLE__) || defined(__linux__) +// On a fatal signal, dump a native backtrace of the crashing thread straight to stderr +// (fd 2, unbuffered) so it survives in the CI log even though stdout's buffer is lost when +// the process segfaults. Then restore the default disposition and re-raise, so the OS still +// writes its crash report (.ips on macOS) and the exit code still reflects the crash. +static void crash_backtrace_handler(int sig){ + // Re-entrancy guard: if we crash while handling a signal, just die. + static volatile sig_atomic_t in_handler = 0; + if (in_handler){ + _exit(128 + sig); + } + in_handler = 1; + + const char msg[] = "\n[PA-CRASH] Fatal signal, backtrace of the crashing thread:\n"; + if (write(2, msg, sizeof(msg) - 1) < 0){ + // Nothing more we can do. + } + + void* frames[128]; + int n = backtrace(frames, 128); + backtrace_symbols_fd(frames, n, 2); // writes one symbolized frame per line to fd 2 + + // Let the OS do its normal crash handling (crash report + exit code). + signal(sig, SIG_DFL); + raise(sig); +} + +static void install_crash_backtrace_handlers(){ + static const int sigs[] = { SIGSEGV, SIGBUS, SIGABRT, SIGILL, SIGFPE }; + for (int sig : sigs){ + signal(sig, crash_backtrace_handler); + } +} +#else +static void install_crash_backtrace_handlers(){} +#endif + int run_command_line_tests(bool augment_color_distortions){ + install_crash_backtrace_handlers(); + // [ORT-DIAG] Keep stdout line-buffered in CI: when piped, stdio defaults to full + // buffering, so the last few KB of test output (and where the crash happened) is lost + // in the buffer when the process dies. + // 8192 bytes: 0 means "implementation-defined" and MSVC's ucrt can end up with a + // zero-size buffer, which corrupts the next stdout write (observed 0xC0000409 on the + // Windows CI runner). + setvbuf(stdout, nullptr, _IOLBF, 8192); cout << "Running parallel unit tests..." << endl; - ComputerPrograms::CommandLineUnitTestRunner runner(global_logger_command_line()); - if (runner.run(augment_color_distortions)){ - return 1; + + // [ORT-DIAG] The Mac Intel crash is probabilistic (~60% of CI runs) and happens at + // PaddleOCR's ONNX session creation, which normally happens only once per process + // (the sessions are cached). To raise the odds of reproducing it in CI, run the full + // suite several times, clearing the PaddleOCR cache between runs so the sessions are + // re-created each time. + constexpr int k_repeat_runs = 3; + for (int run_index = 1; run_index <= k_repeat_runs; ++run_index){ + std::cerr << "[ORT-DIAG] Test suite run " << run_index << " of " << k_repeat_runs << std::endl; + if (run_index > 1){ + OCR::clear_paddle_ocr_cache(); // Force PaddleOCR to re-create its ONNX sessions. + } + ComputerPrograms::CommandLineUnitTestRunner runner(global_logger_command_line()); + if (runner.run(augment_color_distortions)){ + std::cerr << "[ORT-DIAG] Test suite run " << run_index << " reported failures; stopping." + << std::endl; + return 1; + } } + cout << "Running parallel unit tests... Done!" << endl; return 0; }