1/*
2 * Licensed to the Apache Software Foundation (ASF) under one
3 * or more contributor license agreements. See the NOTICE file
4 * distributed with this work for additional information
5 * regarding copyright ownership. The ASF licenses this file
6 * to you under the Apache License, Version 2.0 (the
7 * "License"); you may not use this file except in compliance
8 * with the License. You may obtain a copy of the License at
9 *
10 * http://www.apache.org/licenses/LICENSE-2.0
11 *
12 * Unless required by applicable law or agreed to in writing,
13 * software distributed under the License is distributed on an
14 * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
15 * KIND, either express or implied. See the License for the
16 * specific language governing permissions and limitations
17 * under the License.
18 */
19#include <tvm/runtime/logging.h>
20
21#include <stdexcept>
22#include <string>
23
24#if TVM_LOG_STACK_TRACE
25#if TVM_USE_LIBBACKTRACE
26
27#include <backtrace.h>
28#include <cxxabi.h>
29
30#include <iomanip>
31#include <iostream>
32#include <sstream>
33#include <unordered_map>
34#include <vector>
35
36#if TVM_BACKTRACE_ON_SEGFAULT
37#include <signal.h>
38
39#include <csignal>
40#include <cstring>
41#endif
42
43namespace tvm {
44namespace runtime {
45namespace {
46
47struct BacktraceInfo {
48 std::vector<std::string> lines;
49 size_t max_size;
50 std::string error_message;
51};
52
53void BacktraceCreateErrorCallback(void* data, const char* msg, int errnum) {
54 std::cerr << "Could not initialize backtrace state: " << msg << std::endl;
55}
56
57backtrace_state* BacktraceCreate() {
58 return backtrace_create_state(nullptr, 1, BacktraceCreateErrorCallback, nullptr);
59}
60
61static backtrace_state* _bt_state = BacktraceCreate();
62
63std::string DemangleName(std::string name) {
64 int status = 0;
65 size_t length = name.size();
66 std::unique_ptr<char, void (*)(void* __ptr)> demangled_name = {
67 abi::__cxa_demangle(name.c_str(), nullptr, &length, &status), &std::free};
68 if (demangled_name && status == 0 && length > 0) {
69 return demangled_name.get();
70 } else {
71 return name;
72 }
73}
74
75void BacktraceErrorCallback(void* data, const char* msg, int errnum) {
76 // do nothing
77}
78
79void BacktraceSyminfoCallback(void* data, uintptr_t pc, const char* symname, uintptr_t symval,
80 uintptr_t symsize) {
81 auto str = reinterpret_cast<std::string*>(data);
82
83 if (symname != nullptr) {
84 std::string tmp(symname, symsize);
85 *str = DemangleName(tmp.c_str());
86 } else {
87 std::ostringstream s;
88 s << "0x" << std::setfill('0') << std::setw(sizeof(uintptr_t) * 2) << std::hex << pc;
89 *str = s.str();
90 }
91}
92
93int BacktraceFullCallback(void* data, uintptr_t pc, const char* filename, int lineno,
94 const char* symbol) {
95 auto stack_trace = reinterpret_cast<BacktraceInfo*>(data);
96 std::stringstream s;
97
98 std::unique_ptr<std::string> symbol_str = std::make_unique<std::string>("<unknown>");
99 if (symbol != nullptr) {
100 *symbol_str = DemangleName(symbol);
101 } else {
102 // see if syminfo gives anything
103 backtrace_syminfo(_bt_state, pc, BacktraceSyminfoCallback, BacktraceErrorCallback,
104 symbol_str.get());
105 }
106 s << *symbol_str;
107
108 if (filename != nullptr) {
109 s << std::endl << " at " << filename;
110 if (lineno != 0) {
111 s << ":" << lineno;
112 }
113 }
114 // Skip tvm::backtrace and tvm::LogFatal::~LogFatal at the beginning of the trace as they don't
115 // add anything useful to the backtrace.
116 if (!(stack_trace->lines.size() == 0 &&
117 (symbol_str->find("tvm::runtime::Backtrace", 0) == 0 ||
118 symbol_str->find("tvm::runtime::detail::LogFatal", 0) == 0))) {
119 stack_trace->lines.push_back(s.str());
120 }
121 // TVMFuncCall denotes the API boundary so we stop there. Exceptions should be caught there.
122 if (*symbol_str == "TVMFuncCall" || stack_trace->lines.size() >= stack_trace->max_size) {
123 return 1;
124 }
125 return 0;
126}
127
128#if TVM_BACKTRACE_ON_SEGFAULT
129void backtrace_handler(int sig) {
130 // Technically we shouldn't do any allocation in a signal handler, but
131 // Backtrace may allocate. What's the worst it could do? We're already
132 // crashing.
133 std::cerr << "!!!!!!! TVM encountered a Segfault !!!!!!!\n" << Backtrace() << std::endl;
134
135 // Re-raise signal with default handler
136 struct sigaction act;
137 std::memset(&act, 0, sizeof(struct sigaction));
138 act.sa_flags = SA_RESETHAND;
139 act.sa_handler = SIG_DFL;
140 sigaction(sig, &act, nullptr);
141 raise(sig);
142}
143
144__attribute__((constructor)) void install_signal_handler(void) {
145 // this may override already installed signal handlers
146 std::signal(SIGSEGV, backtrace_handler);
147}
148#endif
149} // namespace
150
151std::string Backtrace() {
152 BacktraceInfo bt;
153
154 // Limit backtrace length based on TVM_BACKTRACE_LIMIT env variable
155 auto user_limit_s = getenv("TVM_BACKTRACE_LIMIT");
156 const auto default_limit = 500;
157
158 if (user_limit_s == nullptr) {
159 bt.max_size = default_limit;
160 } else {
161 // Parse out the user-set backtrace limit
162 try {
163 bt.max_size = std::stoi(user_limit_s);
164 } catch (const std::invalid_argument& e) {
165 bt.max_size = default_limit;
166 }
167 }
168
169 if (_bt_state == nullptr) {
170 return "";
171 }
172 // libbacktrace eats memory if run on multiple threads at the same time, so we guard against it
173 static std::mutex m;
174 std::lock_guard<std::mutex> lock(m);
175 backtrace_full(_bt_state, 0, BacktraceFullCallback, BacktraceErrorCallback, &bt);
176
177 std::ostringstream s;
178 s << "Stack trace:\n";
179 for (size_t i = 0; i < bt.lines.size(); i++) {
180 s << " " << i << ": " << bt.lines[i] << "\n";
181 }
182
183 return s.str();
184}
185} // namespace runtime
186} // namespace tvm
187
188#else
189
190#include <dmlc/logging.h>
191
192namespace tvm {
193namespace runtime {
194// Fallback to the dmlc implementation when backtrace is not available.
195std::string Backtrace() { return dmlc::StackTrace(); }
196} // namespace runtime
197} // namespace tvm
198
199#endif // TVM_USE_LIBBACKTRACE
200#else
201
202namespace tvm {
203namespace runtime {
204// stacktrace logging is completely disabled
205std::string Backtrace() { return ""; }
206} // namespace runtime
207} // namespace tvm
208#endif // TVM_LOG_STACK_TRACE
209
210#if (TVM_LOG_CUSTOMIZE == 0)
211namespace tvm {
212namespace runtime {
213namespace detail {
214
215const char* ::tvm::runtime::detail::LogMessage::level_strings_[] = {
216 ": Debug: ", // TVM_LOG_LEVEL_DEBUG
217 ": ", // TVM_LOG_LEVEL_INFO
218 ": Warning: ", // TVM_LOG_LEVEL_WARNING
219 ": Error: ", // TVM_LOG_LEVEL_ERROR
220};
221
222namespace {
223constexpr const char* kSrcPrefix = "/src/";
224// Note: Better would be std::char_traits<const char>::length(kSrcPrefix) but it is not
225// a constexpr on all compilation targets.
226constexpr const size_t kSrcPrefixLength = 5;
227constexpr const char* kDefaultKeyword = "DEFAULT";
228} // namespace
229
230namespace {
231/*! \brief Convert __FILE__ to a vlog_level_map_ key, which strips any prefix ending iwth src/ */
232std::string FileToVLogMapKey(const std::string& filename) {
233 // Canonicalize the filename.
234 // TODO(mbs): Not Windows friendly.
235 size_t last_src = filename.rfind(kSrcPrefix, std::string::npos, kSrcPrefixLength);
236 if (last_src == std::string::npos) {
237 std::string no_slash_src{kSrcPrefix + 1};
238 if (filename.substr(0, no_slash_src.size()) == no_slash_src) {
239 return filename.substr(no_slash_src.size());
240 }
241 }
242 // Strip anything before the /src/ prefix, on the assumption that will yield the
243 // TVM project relative filename. If no such prefix fallback to filename without
244 // canonicalization.
245 return (last_src == std::string::npos) ? filename : filename.substr(last_src + kSrcPrefixLength);
246}
247} // namespace
248
249/* static */
250TvmLogDebugSettings TvmLogDebugSettings::ParseSpec(const char* opt_spec) {
251 TvmLogDebugSettings settings;
252 if (opt_spec == nullptr) {
253 // DLOG and VLOG disabled.
254 return settings;
255 }
256 std::string spec(opt_spec);
257 if (spec.empty() || spec == "0") {
258 // DLOG and VLOG disabled.
259 return settings;
260 }
261 settings.dlog_enabled_ = true;
262 if (spec == "1") {
263 // Legacy specification for enabling just DLOG.
264 return settings;
265 }
266 std::istringstream spec_stream(spec);
267 auto tell_pos = [&](const std::string& last_read) {
268 int pos = spec_stream.tellg();
269 if (pos == -1) {
270 LOG(INFO) << "override pos: " << last_read;
271 // when pos == -1, failbit was set due to std::getline reaching EOF without seeing delimiter.
272 pos = spec.size() - last_read.size();
273 }
274 return pos;
275 };
276 while (spec_stream) {
277 std::string name;
278 if (!std::getline(spec_stream, name, '=')) {
279 // Reached end.
280 break;
281 }
282 if (name.empty()) {
283 LOG(FATAL) << "TVM_LOG_DEBUG ill-formed at position " << tell_pos(name) << ": empty filename";
284 }
285
286 name = FileToVLogMapKey(name);
287
288 std::string level;
289 if (!std::getline(spec_stream, level, ',')) {
290 LOG(FATAL) << "TVM_LOG_DEBUG ill-formed at position " << tell_pos(level)
291 << ": expecting \"=<level>\" after \"" << name << "\"";
292 return settings;
293 }
294 if (level.empty()) {
295 LOG(FATAL) << "TVM_LOG_DEBUG ill-formed at position " << tell_pos(level)
296 << ": empty level after \"" << name << "\"";
297 return settings;
298 }
299 // Parse level, default to 0 if ill-formed which we don't detect.
300 char* end_of_level = nullptr;
301 int level_val = static_cast<int>(strtol(level.c_str(), &end_of_level, 10));
302 if (end_of_level != level.c_str() + level.size()) {
303 LOG(FATAL) << "TVM_LOG_DEBUG ill-formed at position " << tell_pos(level)
304 << ": invalid level: \"" << level << "\"";
305 return settings;
306 }
307 LOG(INFO) << "TVM_LOG_DEBUG enables VLOG statements in '" << name << "' up to level " << level;
308 settings.vlog_level_map_.emplace(name, level_val);
309 }
310 return settings;
311}
312
313bool TvmLogDebugSettings::VerboseEnabledImpl(const std::string& filename, int level) const {
314 // Check for exact match.
315 auto itr = vlog_level_map_.find(FileToVLogMapKey(filename));
316 if (itr != vlog_level_map_.end()) {
317 return level <= itr->second;
318 }
319 // Check for default.
320 itr = vlog_level_map_.find(kDefaultKeyword);
321 if (itr != vlog_level_map_.end()) {
322 return level <= itr->second;
323 }
324 return false;
325}
326
327LogFatal::Entry& LogFatal::GetEntry() {
328 static thread_local LogFatal::Entry result;
329 return result;
330}
331
332std::string VLogContext::str() const {
333 std::stringstream result;
334 for (const auto* entry : context_stack_) {
335 ICHECK_NOTNULL(entry);
336 result << entry->str();
337 result << ": ";
338 }
339 return result.str();
340}
341
342} // namespace detail
343} // namespace runtime
344} // namespace tvm
345#endif // TVM_LOG_CUSTOMIZE
346