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 | |
43 | namespace tvm { |
44 | namespace runtime { |
45 | namespace { |
46 | |
47 | struct BacktraceInfo { |
48 | std::vector<std::string> lines; |
49 | size_t max_size; |
50 | std::string error_message; |
51 | }; |
52 | |
53 | void BacktraceCreateErrorCallback(void* data, const char* msg, int errnum) { |
54 | std::cerr << "Could not initialize backtrace state: " << msg << std::endl; |
55 | } |
56 | |
57 | backtrace_state* BacktraceCreate() { |
58 | return backtrace_create_state(nullptr, 1, BacktraceCreateErrorCallback, nullptr); |
59 | } |
60 | |
61 | static backtrace_state* _bt_state = BacktraceCreate(); |
62 | |
63 | std::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 | |
75 | void BacktraceErrorCallback(void* data, const char* msg, int errnum) { |
76 | // do nothing |
77 | } |
78 | |
79 | void 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 | |
93 | int 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 |
129 | void 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 | |
151 | std::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 | |
192 | namespace tvm { |
193 | namespace runtime { |
194 | // Fallback to the dmlc implementation when backtrace is not available. |
195 | std::string Backtrace() { return dmlc::StackTrace(); } |
196 | } // namespace runtime |
197 | } // namespace tvm |
198 | |
199 | #endif // TVM_USE_LIBBACKTRACE |
200 | #else |
201 | |
202 | namespace tvm { |
203 | namespace runtime { |
204 | // stacktrace logging is completely disabled |
205 | std::string Backtrace() { return "" ; } |
206 | } // namespace runtime |
207 | } // namespace tvm |
208 | #endif // TVM_LOG_STACK_TRACE |
209 | |
210 | #if (TVM_LOG_CUSTOMIZE == 0) |
211 | namespace tvm { |
212 | namespace runtime { |
213 | namespace detail { |
214 | |
215 | const 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 | |
222 | namespace { |
223 | constexpr 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. |
226 | constexpr const size_t kSrcPrefixLength = 5; |
227 | constexpr const char* kDefaultKeyword = "DEFAULT" ; |
228 | } // namespace |
229 | |
230 | namespace { |
231 | /*! \brief Convert __FILE__ to a vlog_level_map_ key, which strips any prefix ending iwth src/ */ |
232 | std::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 */ |
250 | TvmLogDebugSettings 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 | |
313 | bool 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 | |
327 | LogFatal::Entry& LogFatal::GetEntry() { |
328 | static thread_local LogFatal::Entry result; |
329 | return result; |
330 | } |
331 | |
332 | std::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 | |