1#include <c10/util/Backtrace.h>
2#include <c10/util/Flags.h>
3#include <c10/util/Logging.h>
4#ifdef FBCODE_CAFFE2
5#include <folly/synchronization/SanitizeThread.h>
6#endif
7
8#include <algorithm>
9#include <cstdlib>
10#include <cstring>
11#include <iostream>
12#include <numeric>
13
14// Common code that we use regardless of whether we use glog or not.
15
16C10_DEFINE_bool(
17 caffe2_use_fatal_for_enforce,
18 false,
19 "If set true, when CAFFE_ENFORCE is not met, abort instead "
20 "of throwing an exception.");
21
22namespace c10 {
23
24namespace {
25// NOLINTNEXTLINE(modernize-redundant-void-arg)
26std::function<string(void)>* GetFetchStackTrace() {
27 static std::function<string(void)> func = []() {
28 return get_backtrace(/*frames_to_skip=*/1);
29 };
30 return &func;
31};
32} // namespace
33
34void SetStackTraceFetcher(std::function<string(void)> fetcher) {
35 *GetFetchStackTrace() = std::move(fetcher);
36}
37
38void ThrowEnforceNotMet(
39 const char* file,
40 const int line,
41 const char* condition,
42 const std::string& msg,
43 const void* caller) {
44 c10::Error e(file, line, condition, msg, (*GetFetchStackTrace())(), caller);
45 if (FLAGS_caffe2_use_fatal_for_enforce) {
46 LOG(FATAL) << e.msg();
47 }
48 throw e;
49}
50
51void ThrowEnforceNotMet(
52 const char* file,
53 const int line,
54 const char* condition,
55 const char* msg,
56 const void* caller) {
57 ThrowEnforceNotMet(file, line, condition, std::string(msg), caller);
58}
59
60void ThrowEnforceFiniteNotMet(
61 const char* file,
62 const int line,
63 const char* condition,
64 const std::string& msg,
65 const void* caller) {
66 throw c10::EnforceFiniteError(
67 file, line, condition, msg, (*GetFetchStackTrace())(), caller);
68}
69
70void ThrowEnforceFiniteNotMet(
71 const char* file,
72 const int line,
73 const char* condition,
74 const char* msg,
75 const void* caller) {
76 ThrowEnforceFiniteNotMet(file, line, condition, std::string(msg), caller);
77}
78// PyTorch-style error message
79// (This must be defined here for access to GetFetchStackTrace)
80Error::Error(SourceLocation source_location, std::string msg)
81 : Error(
82 std::move(msg),
83 str("Exception raised from ",
84 source_location,
85 " (most recent call first):\n",
86 (*GetFetchStackTrace())())) {}
87
88using APIUsageLoggerType = std::function<void(const std::string&)>;
89using DDPUsageLoggerType = std::function<void(const DDPLoggingData&)>;
90
91namespace {
92bool IsAPIUsageDebugMode() {
93 const char* val = getenv("PYTORCH_API_USAGE_STDERR");
94 return val && *val; // any non-empty value
95}
96
97void APIUsageDebug(const string& event) {
98 // use stderr to avoid messing with glog
99 std::cerr << "PYTORCH_API_USAGE " << event << std::endl;
100}
101
102APIUsageLoggerType* GetAPIUsageLogger() {
103 static APIUsageLoggerType func =
104 IsAPIUsageDebugMode() ? &APIUsageDebug : [](const string&) {};
105 return &func;
106};
107
108DDPUsageLoggerType* GetDDPUsageLogger() {
109 static DDPUsageLoggerType func = [](const DDPLoggingData&) {};
110 return &func;
111};
112} // namespace
113
114void SetAPIUsageLogger(std::function<void(const std::string&)> logger) {
115 TORCH_CHECK(logger);
116 *GetAPIUsageLogger() = std::move(logger);
117}
118
119void SetPyTorchDDPUsageLogger(
120 std::function<void(const DDPLoggingData&)> logger) {
121 TORCH_CHECK(logger);
122 *GetDDPUsageLogger() = std::move(logger);
123}
124
125void LogAPIUsage(const std::string& event) try {
126 if (auto logger = GetAPIUsageLogger())
127 (*logger)(event);
128} catch (std::bad_function_call&) {
129 // static destructor race
130}
131
132void LogPyTorchDDPUsage(const DDPLoggingData& ddpData) try {
133 if (auto logger = GetDDPUsageLogger())
134 (*logger)(ddpData);
135} catch (std::bad_function_call&) {
136 // static destructor race
137}
138
139namespace detail {
140bool LogAPIUsageFakeReturn(const std::string& event) try {
141 if (auto logger = GetAPIUsageLogger())
142 (*logger)(event);
143 return true;
144} catch (std::bad_function_call&) {
145 // static destructor race
146 return true;
147}
148
149namespace {
150
151void setLogLevelFlagFromEnv();
152
153} // namespace
154} // namespace detail
155} // namespace c10
156
157#if defined(C10_USE_GFLAGS) && defined(C10_USE_GLOG)
158// When GLOG depends on GFLAGS, these variables are being defined in GLOG
159// directly via the GFLAGS definition, so we will use DECLARE_* to declare
160// them, and use them in Caffe2.
161// GLOG's minloglevel
162DECLARE_int32(minloglevel);
163// GLOG's verbose log value.
164DECLARE_int32(v);
165// GLOG's logtostderr value
166DECLARE_bool(logtostderr);
167#endif // defined(C10_USE_GFLAGS) && defined(C10_USE_GLOG)
168
169#if !defined(C10_USE_GLOG)
170// This backward compatibility flags are in order to deal with cases where
171// Caffe2 are not built with glog, but some init flags still pass in these
172// flags. They may go away in the future.
173C10_DEFINE_int32(minloglevel, 0, "Equivalent to glog minloglevel");
174C10_DEFINE_int32(v, 0, "Equivalent to glog verbose");
175C10_DEFINE_bool(logtostderr, false, "Equivalent to glog logtostderr");
176#endif // !defined(c10_USE_GLOG)
177
178#ifdef C10_USE_GLOG
179
180// Provide easy access to the above variables, regardless whether GLOG is
181// dependent on GFLAGS or not. Note that the namespace (fLI, fLB) is actually
182// consistent between GLOG and GFLAGS, so we can do the below declaration
183// consistently.
184namespace c10 {
185using fLB::FLAGS_logtostderr;
186using fLI::FLAGS_minloglevel;
187using fLI::FLAGS_v;
188} // namespace c10
189
190C10_DEFINE_int(
191 caffe2_log_level,
192 google::GLOG_WARNING,
193 "The minimum log level that caffe2 will output.");
194
195// Google glog's api does not have an external function that allows one to check
196// if glog is initialized or not. It does have an internal function - so we are
197// declaring it here. This is a hack but has been used by a bunch of others too
198// (e.g. Torch).
199namespace google {
200namespace glog_internal_namespace_ {
201bool IsGoogleLoggingInitialized();
202} // namespace glog_internal_namespace_
203} // namespace google
204
205namespace c10 {
206namespace {
207
208void initGoogleLogging(char const* name) {
209#if !defined(_MSC_VER)
210 // This trick can only be used on UNIX platforms
211 if (!::google::glog_internal_namespace_::IsGoogleLoggingInitialized())
212#endif
213 {
214 ::google::InitGoogleLogging(name);
215#if !defined(_MSC_VER)
216 // This is never defined on Windows
217 ::google::InstallFailureSignalHandler();
218#endif
219 }
220}
221
222} // namespace
223
224void initLogging() {
225 detail::setLogLevelFlagFromEnv();
226
227 UpdateLoggingLevelsFromFlags();
228}
229
230bool InitCaffeLogging(int* argc, char** argv) {
231 if (*argc == 0) {
232 return true;
233 }
234
235 initGoogleLogging(argv[0]);
236
237 UpdateLoggingLevelsFromFlags();
238
239 return true;
240}
241
242void UpdateLoggingLevelsFromFlags() {
243#ifdef FBCODE_CAFFE2
244 // TODO(T82645998): Fix data race exposed by TSAN.
245 folly::annotate_ignore_thread_sanitizer_guard g(__FILE__, __LINE__);
246#endif
247 // If caffe2_log_level is set and is lower than the min log level by glog,
248 // we will transfer the caffe2_log_level setting to glog to override that.
249 FLAGS_minloglevel = std::min(FLAGS_caffe2_log_level, FLAGS_minloglevel);
250 // If caffe2_log_level is explicitly set, let's also turn on logtostderr.
251 if (FLAGS_caffe2_log_level < google::GLOG_WARNING) {
252 FLAGS_logtostderr = 1;
253 }
254 // Also, transfer the caffe2_log_level verbose setting to glog.
255 if (FLAGS_caffe2_log_level < 0) {
256 FLAGS_v = std::min(FLAGS_v, -FLAGS_caffe2_log_level);
257 }
258}
259
260void ShowLogInfoToStderr() {
261 FLAGS_logtostderr = 1;
262 FLAGS_minloglevel = std::min(FLAGS_minloglevel, google::GLOG_INFO);
263}
264} // namespace c10
265
266#else // !C10_USE_GLOG
267
268#ifdef ANDROID
269#include <android/log.h>
270#endif // ANDROID
271
272C10_DEFINE_int(
273 caffe2_log_level,
274 c10::GLOG_WARNING,
275 "The minimum log level that caffe2 will output.");
276
277namespace c10 {
278
279void initLogging() {
280 detail::setLogLevelFlagFromEnv();
281}
282
283bool InitCaffeLogging(int* argc, char** argv) {
284 // When doing InitCaffeLogging, we will assume that caffe's flag parser has
285 // already finished.
286 if (*argc == 0)
287 return true;
288 if (!c10::CommandLineFlagsHasBeenParsed()) {
289 std::cerr << "InitCaffeLogging() has to be called after "
290 "c10::ParseCommandLineFlags. Modify your program to make sure "
291 "of this."
292 << std::endl;
293 return false;
294 }
295 if (FLAGS_caffe2_log_level > GLOG_FATAL) {
296 std::cerr << "The log level of Caffe2 has to be no larger than GLOG_FATAL("
297 << GLOG_FATAL << "). Capping it to GLOG_FATAL." << std::endl;
298 FLAGS_caffe2_log_level = GLOG_FATAL;
299 }
300 return true;
301}
302
303void UpdateLoggingLevelsFromFlags() {}
304
305void ShowLogInfoToStderr() {
306 FLAGS_caffe2_log_level = GLOG_INFO;
307}
308
309MessageLogger::MessageLogger(const char* file, int line, int severity)
310 : severity_(severity) {
311 if (severity_ < FLAGS_caffe2_log_level) {
312 // Nothing needs to be logged.
313 return;
314 }
315#ifdef ANDROID
316 tag_ = "native";
317#else // !ANDROID
318 tag_ = "";
319#endif // ANDROID
320 /*
321 time_t rawtime;
322 struct tm * timeinfo;
323 time(&rawtime);
324 timeinfo = localtime(&rawtime);
325 std::chrono::nanoseconds ns =
326 std::chrono::duration_cast<std::chrono::nanoseconds>(
327 std::chrono::high_resolution_clock::now().time_since_epoch());
328 */
329 stream_ << "["
330 << CAFFE2_SEVERITY_PREFIX[std::min(4, GLOG_FATAL - severity_)]
331 //<< (timeinfo->tm_mon + 1) * 100 + timeinfo->tm_mday
332 //<< std::setfill('0')
333 //<< " " << std::setw(2) << timeinfo->tm_hour
334 //<< ":" << std::setw(2) << timeinfo->tm_min
335 //<< ":" << std::setw(2) << timeinfo->tm_sec
336 //<< "." << std::setw(9) << ns.count() % 1000000000
337 << " " << c10::detail::StripBasename(std::string(file)) << ":" << line
338 << "] ";
339}
340
341// Output the contents of the stream to the proper channel on destruction.
342MessageLogger::~MessageLogger() {
343 if (severity_ < FLAGS_caffe2_log_level) {
344 // Nothing needs to be logged.
345 return;
346 }
347 stream_ << "\n";
348#ifdef ANDROID
349 static const int android_log_levels[] = {
350 ANDROID_LOG_FATAL, // LOG_FATAL
351 ANDROID_LOG_ERROR, // LOG_ERROR
352 ANDROID_LOG_WARN, // LOG_WARNING
353 ANDROID_LOG_INFO, // LOG_INFO
354 ANDROID_LOG_DEBUG, // VLOG(1)
355 ANDROID_LOG_VERBOSE, // VLOG(2) .. VLOG(N)
356 };
357 int android_level_index = GLOG_FATAL - std::min(GLOG_FATAL, severity_);
358 int level = android_log_levels[std::min(android_level_index, 5)];
359 // Output the log string the Android log at the appropriate level.
360 __android_log_print(level, tag_, "%s", stream_.str().c_str());
361 // Indicate termination if needed.
362 if (severity_ == GLOG_FATAL) {
363 __android_log_print(ANDROID_LOG_FATAL, tag_, "terminating.\n");
364 }
365#else // !ANDROID
366 if (severity_ >= FLAGS_caffe2_log_level) {
367 // If not building on Android, log all output to std::cerr.
368 std::cerr << stream_.str();
369 // Simulating the glog default behavior: if the severity is above INFO,
370 // we flush the stream so that the output appears immediately on std::cerr.
371 // This is expected in some of our tests.
372 if (severity_ > GLOG_INFO) {
373 std::cerr << std::flush;
374 }
375 }
376#endif // ANDROID
377 if (severity_ == GLOG_FATAL) {
378 DealWithFatal();
379 }
380}
381
382} // namespace c10
383
384#endif // !C10_USE_GLOG
385
386namespace c10 {
387namespace detail {
388namespace {
389
390void setLogLevelFlagFromEnv() {
391 const char* level_str = std::getenv("TORCH_CPP_LOG_LEVEL");
392
393 // Not set, fallback to the default level (i.e. WARNING).
394 std::string level{level_str != nullptr ? level_str : ""};
395 if (level.empty()) {
396 return;
397 }
398
399 std::transform(
400 level.begin(), level.end(), level.begin(), [](unsigned char c) {
401 return toupper(c);
402 });
403
404 if (level == "0" || level == "INFO") {
405 FLAGS_caffe2_log_level = 0;
406
407 return;
408 }
409 if (level == "1" || level == "WARNING") {
410 FLAGS_caffe2_log_level = 1;
411
412 return;
413 }
414 if (level == "2" || level == "ERROR") {
415 FLAGS_caffe2_log_level = 2;
416
417 return;
418 }
419 if (level == "3" || level == "FATAL") {
420 FLAGS_caffe2_log_level = 3;
421
422 return;
423 }
424
425 std::cerr
426 << "`TORCH_CPP_LOG_LEVEL` environment variable cannot be parsed. Valid values are "
427 "`INFO`, `WARNING`, `ERROR`, and `FATAL` or their numerical equivalents `0`, `1`, "
428 "`2`, and `3`."
429 << std::endl;
430}
431
432} // namespace
433} // namespace detail
434} // namespace c10
435