/** * Copyright (C) 2019-present MongoDB, Inc. * * This program is free software: you can redistribute it and/or modify * it under the terms of the Server Side Public License, version 1, * as published by MongoDB, Inc. * * This program is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the * Server Side Public License for more details. * * You should have received a copy of the Server Side Public License * along with this program. If not, see * . * * As a special exception, the copyright holders give permission to link the * code of portions of this program with the OpenSSL library under certain * conditions as described in each individual source file and distribute * linked combinations including the program with the OpenSSL library. You * must comply with the Server Side Public License in all respects for * all of the code used other than as permitted herein. If you modify file(s) * with this exception, you may extend this exception to your version of the * file(s), but you are not obligated to do so. If you do not wish to do so, * delete this exception statement from your version. If you delete this * exception statement from all source files in the program, then also delete * it in the license file. */ #define MONGO_LOGV2_DEFAULT_COMPONENT ::mongo::logv2::LogComponent::kDefault #include "mongo/platform/basic.h" #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include "mongo/bson/bsonobjbuilder.h" #include "mongo/bson/json.h" #include "mongo/config.h" #include "mongo/logv2/log.h" #include "mongo/platform/mutex.h" #include "mongo/stdx/condition_variable.h" #include "mongo/stdx/thread.h" #include "mongo/unittest/unittest.h" #include "mongo/util/debug_util.h" #include "mongo/util/hex.h" #include "mongo/util/stacktrace.h" /** `sigaltstack` was introduced in glibc-2.12 in 2010. */ #if !defined(_WIN32) #define HAVE_SIGALTSTACK #endif #ifdef __linux__ #include #include #include #endif // __linux__ namespace mongo { namespace stack_trace_test_detail { /** Needs to have linkage so we can test metadata. */ void testFunctionWithLinkage() { printf("..."); } struct RecursionParam { std::uint64_t n; std::function f; }; MONGO_COMPILER_NOINLINE int recurseWithLinkage(RecursionParam& p, std::uint64_t i = 0) { if (i == p.n) { p.f(); } else { recurseWithLinkage(p, i + 1); } return 0; } } // namespace stack_trace_test_detail namespace { using namespace fmt::literals; using namespace std::literals::chrono_literals; constexpr bool kSuperVerbose = 0; // Devel instrumentation #if defined(_WIN32) constexpr bool kIsWindows = true; #else constexpr bool kIsWindows = false; #endif class LogAdapter { public: std::string toString() const { // LAME std::ostringstream os; os << *this; return os.str(); } friend std::ostream& operator<<(std::ostream& os, const LogAdapter& x) { x.doPrint(os); return os; } private: virtual void doPrint(std::ostream& os) const = 0; }; template class LogVec : public LogAdapter { public: explicit LogVec(const T& v, StringData sep = ","_sd) : v(v), sep(sep) {} private: void doPrint(std::ostream& os) const override { os << std::hex; os << "{"; StringData s; for (auto&& e : v) { os << s << e; s = sep; } os << "}"; os << std::dec; } const T& v; StringData sep = ","_sd; }; uintptr_t fromHex(const std::string& s) { return static_cast(std::stoull(s, nullptr, 16)); } // Break down a printStackTrace output for a contrived call tree and sanity-check it. TEST(StackTrace, PosixFormat) { if (kIsWindows) { return; } std::string trace; stack_trace_test_detail::RecursionParam param{3, [&] { StringStackTraceSink sink{trace}; printStackTrace(sink); }}; stack_trace_test_detail::recurseWithLinkage(param, 3); if (kSuperVerbose) { LOGV2_OPTIONS( 24153, {logv2::LogTruncation::Disabled}, "trace:{{{trace}}}", "trace"_attr = trace); } // Expect log to be a "BACKTRACE:" 1-line record, followed by some "Frame:" lines. // Each "Frame:" line holds a full json object, but we only examine its "a" field here. std::string jsonLine; std::vector humanAddrs; pcrecpp::StringPiece in{trace}; static const pcrecpp::RE jsonLineRE(R"re(BACKTRACE: (\{.*\})\n?)re"); ASSERT_TRUE(jsonLineRE.Consume(&in, &jsonLine)) << "\"" << in.as_string() << "\""; while (true) { std::string frameLine; static const pcrecpp::RE frameRE(R"re( Frame: (\{.*\})\n?)re"); if (!frameRE.Consume(&in, &frameLine)) break; BSONObj frameObj = fromjson(frameLine); // throwy humanAddrs.push_back(fromHex(frameObj["a"].String())); } ASSERT_TRUE(in.empty()) << "must be consumed fully: \"" << in.as_string() << "\""; BSONObj jsonObj = fromjson(jsonLine); // throwy ASSERT_TRUE(jsonObj.hasField("backtrace")); ASSERT_TRUE(jsonObj.hasField("processInfo")); ASSERT_TRUE(jsonObj["processInfo"].Obj().hasField("somap")); struct SoMapEntry { uintptr_t base; std::string path; }; std::map soMap; for (const auto& so : jsonObj["processInfo"]["somap"].Array()) { auto soObj = so.Obj(); SoMapEntry ent{}; ent.base = fromHex(soObj["b"].String()); if (soObj.hasField("path")) { ent.path = soObj["path"].String(); } soMap[ent.base] = ent; } // Sanity check: make sure all BACKTRACE addrs are represented in the Frame section. std::vector btAddrs; for (const auto& btElem : jsonObj["backtrace"].embeddedObject()) { btAddrs.push_back(fromHex(btElem.embeddedObject()["a"].String())); } // Mac OS backtrace returns extra frames in "backtrace". ASSERT_TRUE(std::search(btAddrs.begin(), btAddrs.end(), humanAddrs.begin(), humanAddrs.end()) == btAddrs.begin()) << LogVec(btAddrs) << " vs " << LogVec(humanAddrs); } std::vector splitLines(std::string in) { std::vector lines; while (true) { auto pos = in.find("\n"); if (pos == std::string::npos) { break; } else { lines.push_back(in.substr(0, pos)); in = in.substr(pos + 1); } } if (!in.empty()) { lines.push_back(in); } return lines; } TEST(StackTrace, WindowsFormat) { if (!kIsWindows) { return; } std::string trace = [&] { std::string s; stack_trace_test_detail::RecursionParam param{3, [&] { StringStackTraceSink sink{s}; printStackTrace(sink); }}; stack_trace_test_detail::recurseWithLinkage(param); return s; }(); std::vector lines = splitLines(trace); std::string jsonLine; ASSERT_TRUE(pcrecpp::RE(R"re(BACKTRACE: (\{.*\}))re").FullMatch(lines[0], &jsonLine)); std::vector humanAddrs; for (size_t i = 1; i < lines.size(); ++i) { static const pcrecpp::RE re(R"re( Frame: (?:\{"a":"(.*?)",.*\}))re"); uintptr_t addr; ASSERT_TRUE(re.FullMatch(lines[i], pcrecpp::Hex(&addr))) << lines[i]; humanAddrs.push_back(addr); } BSONObj jsonObj = fromjson(jsonLine); // throwy ASSERT_TRUE(jsonObj.hasField("backtrace")) << tojson(jsonObj); std::vector btAddrs; for (const auto& btElem : jsonObj["backtrace"].Obj()) { btAddrs.push_back(fromHex(btElem.Obj()["a"].String())); } ASSERT_TRUE(std::search(btAddrs.begin(), btAddrs.end(), humanAddrs.begin(), humanAddrs.end()) == btAddrs.begin()) << LogVec(btAddrs) << " vs " << LogVec(humanAddrs); } std::string traceString() { std::ostringstream os; printStackTrace(os); return os.str(); } /** Emit a stack trace before main() runs, for use in the EarlyTraceSanity test. */ std::string earlyTrace = traceString(); /** * Verify that the JSON object emitted as part of a stack trace contains a "processInfo" * field, and that it, in turn, contains the fields expected by mongosymb.py. Verify in * particular that a stack trace emitted before main() and before the MONGO_INITIALIZERS * have run will be valid according to mongosymb.py. */ TEST(StackTrace, EarlyTraceSanity) { if (kIsWindows) { return; } const std::string trace = traceString(); const std::string substrings[] = { R"("processInfo":)", R"("gitVersion":)", R"("compiledModules":)", R"("uname":)", R"("somap":)", }; for (const auto& sub : substrings) { ASSERT_STRING_CONTAINS(earlyTrace, sub); } for (const auto& sub : substrings) { ASSERT_STRING_CONTAINS(trace, sub); } } #ifndef _WIN32 // `MetadataGenerator::load` should fill its meta member with something reasonable. // Only testing with functions which we expect the dynamic linker to know about, so // they must have external linkage. TEST(StackTrace, MetadataGenerator) { StackTraceAddressMetadataGenerator gen; struct { void* ptr; std::string fileSub; std::string symbolSub; } const tests[] = { { reinterpret_cast(&stack_trace_test_detail::testFunctionWithLinkage), "stacktrace_test", "testFunctionWithLinkage", }, { // printf's file tricky (surprises under ASAN, Mac, ...), // but we should at least get a symbol name containing "printf" out of it. reinterpret_cast(&std::printf), {}, "printf", }, }; for (const auto& test : tests) { const auto& meta = gen.load(test.ptr); if (kSuperVerbose) { OstreamStackTraceSink sink{std::cout}; meta.printTo(sink); } ASSERT_EQUALS(meta.address(), reinterpret_cast(test.ptr)); if (!test.fileSub.empty()) { ASSERT_TRUE(meta.file()); ASSERT_STRING_CONTAINS(meta.file().name(), test.fileSub); } if (!test.symbolSub.empty()) { ASSERT_TRUE(meta.symbol()); ASSERT_STRING_CONTAINS(meta.symbol().name(), test.symbolSub); } } } TEST(StackTrace, MetadataGeneratorFunctionMeasure) { // Measure the size of a C++ function as a test of metadata retrieval. // Load increasing addresses until the metadata's symbol name changes. StackTraceAddressMetadataGenerator gen; void* fp = reinterpret_cast(&stack_trace_test_detail::testFunctionWithLinkage); const auto& meta = gen.load(fp); if (!meta.symbol()) return; // No symbol for `fp`. forget it. std::string savedSymbol{meta.symbol().name()}; uintptr_t fBase = meta.symbol().base(); ASSERT_EQ(fBase, reinterpret_cast(fp)) << "function pointer should match its symbol base"; size_t fSize = 0; for (; true; ++fSize) { auto& m = gen.load(reinterpret_cast(fBase + fSize)); if (!m.symbol() || m.symbol().name() != savedSymbol) break; } // Place some reasonable expectation on the size of the tiny test function. ASSERT_GT(fSize, 0); ASSERT_LT(fSize, 512); } #endif // _WIN32 #ifdef HAVE_SIGALTSTACK class StackTraceSigAltStackTest : public unittest::Test { public: using unittest::Test::Test; template static std::string ostr(const T& v) { std::ostringstream os; os << v; return os.str(); } static void handlerPreamble(int sig) { LOGV2(23387, "tid:{ostr_stdx_this_thread_get_id}, caught signal {sig}!\n", "ostr_stdx_this_thread_get_id"_attr = ostr(stdx::this_thread::get_id()), "sig"_attr = sig); char storage; LOGV2(23388, "local var:{reinterpret_cast_uint64_t_storage}", "reinterpret_cast_uint64_t_storage"_attr = reinterpret_cast(&storage)); } static void tryHandler(void (*handler)(int, siginfo_t*, void*)) { constexpr int sig = SIGUSR1; constexpr size_t kStackSize = size_t{1} << 20; // 1 MiB auto buf = std::make_unique>(); constexpr unsigned char kSentinel = 0xda; std::fill(buf->begin(), buf->end(), kSentinel); LOGV2(24157, "sigaltstack buf: [{size}] @{data}", "size"_attr = integerToHex(buf->size()), "data"_attr = integerToHex(reinterpret_cast(buf->data()))); stdx::thread thr([&] { LOGV2(23389, "tid:{ostr_stdx_this_thread_get_id} running\n", "ostr_stdx_this_thread_get_id"_attr = ostr(stdx::this_thread::get_id())); { stack_t ss; ss.ss_sp = buf->data(); ss.ss_size = buf->size(); ss.ss_flags = 0; if (int r = sigaltstack(&ss, nullptr); r < 0) { perror("sigaltstack"); } } { struct sigaction sa = {}; sa.sa_sigaction = handler; sa.sa_mask = {}; sa.sa_flags = SA_SIGINFO | SA_ONSTACK; if (int r = sigaction(sig, &sa, nullptr); r < 0) { perror("sigaction"); } } raise(sig); { stack_t ss; ss.ss_sp = 0; ss.ss_size = 0; ss.ss_flags = SS_DISABLE; if (int r = sigaltstack(&ss, nullptr); r < 0) { perror("sigaltstack"); } } }); thr.join(); size_t used = std::distance( std::find_if(buf->begin(), buf->end(), [](unsigned char x) { return x != kSentinel; }), buf->end()); LOGV2(23390, "stack used: {used} bytes\n", "used"_attr = used); } }; TEST_F(StackTraceSigAltStackTest, Minimal) { tryHandler([](int sig, siginfo_t*, void*) { handlerPreamble(sig); }); } TEST_F(StackTraceSigAltStackTest, Print) { tryHandler([](int sig, siginfo_t*, void*) { handlerPreamble(sig); printStackTrace(); }); } TEST_F(StackTraceSigAltStackTest, Backtrace) { tryHandler([](int sig, siginfo_t*, void*) { handlerPreamble(sig); std::array addrs; rawBacktrace(addrs.data(), addrs.size()); }); } #endif // HAVE_SIGALTSTACK class JsonTest : public unittest::Test { public: using unittest::Test::Test; using Hex = stack_trace_detail::Hex; using Dec = stack_trace_detail::Dec; }; TEST_F(JsonTest, Hex) { ASSERT_EQ(StringData(Hex(static_cast(0))), "0"); ASSERT_EQ(StringData(Hex(0xffff)), "FFFF"); ASSERT_EQ(Hex(0xfff0), "FFF0"); ASSERT_EQ(Hex(0x8000'0000'0000'0000), "8000000000000000"); ASSERT_EQ(Hex::fromHex("FFFF"), 0xffff); ASSERT_EQ(Hex::fromHex("0"), 0); ASSERT_EQ(Hex::fromHex("FFFFFFFFFFFFFFFF"), 0xffff'ffff'ffff'ffff); std::string s; StringStackTraceSink sink{s}; sink << Hex(0xffff); ASSERT_EQ(s, R"(FFFF)"); } #if defined(MONGO_STACKTRACE_CAN_DUMP_ALL_THREADS) class PrintAllThreadStacksTest : public unittest::Test { public: struct WatchInt { int v = 0; Mutex* m; stdx::condition_variable cond; void incr(int i) { stdx::unique_lock lock{*m}; v += i; cond.notify_all(); } void wait(int target) { stdx::unique_lock lock{*m}; cond.wait(lock, [&] { return v == target; }); } }; struct Worker { stdx::thread thread; int tid; bool blocks = false; }; void spawnWorker(bool blocksSignal = false) { pending.incr(1); auto& ref = workers.emplace_back(); ref.thread = stdx::thread([&, blocksSignal] { ref.tid = syscall(SYS_gettid); ref.blocks = blocksSignal; if (blocksSignal) { sigset_t mask; sigemptyset(&mask); sigaddset(&mask, SIGUSR2); pthread_sigmask(SIG_BLOCK, &mask, nullptr); } pending.incr(-1); endAll.wait(1); }); pending.wait(0); } void reapWorkers() { endAll.incr(1); for (auto& w : workers) w.thread.join(); } void doPrintAllThreadStacks(size_t numThreads) { for (size_t i = 0; i < numThreads; ++i) spawnWorker(); std::string dumped; StringStackTraceSink sink{dumped}; printAllThreadStacks(sink); if (kSuperVerbose) LOGV2_OPTIONS( 24156, {logv2::LogTruncation::Disabled}, "{dumped}", "dumped"_attr = dumped); reapWorkers(); std::set seenTids; // Make some assertions about `dumped`. BSONObj jsonObj = fromjson(dumped); auto allInfoElement = jsonObj.getObjectField("threadInfo"); for (const auto& ti : allInfoElement) { const BSONObj& obj = ti.Obj(); seenTids.insert(obj.getIntField("tid")); ASSERT(obj.hasElement("backtrace")); } for (auto&& w : workers) ASSERT(seenTids.find(w.tid) != seenTids.end()) << "missing tid:" << w.tid; } Mutex mutex; WatchInt endAll{0, &mutex}; WatchInt pending{0, &mutex}; std::deque workers; }; TEST_F(PrintAllThreadStacksTest, WithDeadThreads) { for (int i = 0; i < 2; ++i) spawnWorker(true); for (int i = 0; i < 2; ++i) spawnWorker(false); std::string dumped; stdx::thread dumper([&] { StringStackTraceSink sink{dumped}; printAllThreadStacks(sink); }); // Give tracer some time to signal all the threads. // We know the threads with the signal blocked will not respond. // The dumper thread will poll until those are dead. // There's no API to monitor its progress, so sleep a hefty chunk of time. sleep(2); reapWorkers(); dumper.join(); BSONObj jsonObj = fromjson(dumped); std::map tidDumps; // All are references into jsonObj. std::set mustSee; for (const auto& w : workers) mustSee.insert(w.tid); for (const auto& el : jsonObj.getObjectField("missedThreadIds")) mustSee.erase(el.Int()); auto allInfoElement = jsonObj.getObjectField("threadInfo"); for (const auto& ti : allInfoElement) { const BSONObj& obj = ti.Obj(); int tid = obj.getIntField("tid"); mustSee.erase(tid); auto witer = std::find_if(workers.begin(), workers.end(), [&](auto&& w) { return w.tid == tid; }); if (witer == workers.end()) continue; bool missingBacktrace = !obj.hasElement("backtrace"); ASSERT_EQ(witer->blocks, missingBacktrace); } ASSERT(mustSee.empty()) << format(FMT_STRING("tids missing from report: {}"), fmt::join(mustSee, ",")); } TEST_F(PrintAllThreadStacksTest, Go_2_Threads) { doPrintAllThreadStacks(2); } TEST_F(PrintAllThreadStacksTest, Go_20_Threads) { doPrintAllThreadStacks(20); } TEST_F(PrintAllThreadStacksTest, Go_200_Threads) { doPrintAllThreadStacks(200); } #endif // defined(MONGO_STACKTRACE_CAN_DUMP_ALL_THREADS) #if defined(MONGO_CONFIG_USE_LIBUNWIND) || defined(MONGO_CONFIG_HAVE_EXECINFO_BACKTRACE) /** * Try to backtrace from a stack containing a libc function. To do this * we need a libc function that makes a user-provided callback, like qsort. */ TEST(StackTrace, BacktraceThroughLibc) { struct Result { void notify() { if (called) return; called = true; arrSize = rawBacktrace(arr.data(), arr.size()); } bool called = 0; std::array arr; size_t arrSize; }; static Result capture; std::array arr{{}}; qsort(arr.data(), arr.size(), sizeof(arr[0]), [](const void* a, const void* b) { // Order them by position in the array. capture.notify(); return static_cast(static_cast(a) < static_cast(b)); }); LOGV2(23391, "caught [{capture_arrSize}]:", "capture_arrSize"_attr = capture.arrSize); for (size_t i = 0; i < capture.arrSize; ++i) { LOGV2(23392, " [{i}] {reinterpret_cast_uint64_t_capture_arr_i}", "i"_attr = i, "reinterpret_cast_uint64_t_capture_arr_i"_attr = reinterpret_cast(capture.arr[i])); } } #endif // mongo stacktrace backend } // namespace } // namespace mongo