2018-12-31 20:04:05 +01:00
|
|
|
//
|
2021-01-01 13:57:46 +01:00
|
|
|
// Copyright Aliaksei Levin (levlam@telegram.org), Arseny Smirnov (arseny30@gmail.com) 2014-2021
|
2018-12-31 20:04:05 +01:00
|
|
|
//
|
|
|
|
// Distributed under the Boost Software License, Version 1.0. (See accompanying
|
|
|
|
// file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt)
|
|
|
|
//
|
|
|
|
#include "td/utils/logging.h"
|
|
|
|
|
2020-10-11 13:45:22 +02:00
|
|
|
#include "td/utils/ExitGuard.h"
|
2018-12-31 20:04:05 +01:00
|
|
|
#include "td/utils/port/Clocks.h"
|
2018-08-17 15:41:51 +02:00
|
|
|
#include "td/utils/port/StdStreams.h"
|
2018-12-31 20:04:05 +01:00
|
|
|
#include "td/utils/port/thread_local.h"
|
|
|
|
#include "td/utils/Slice.h"
|
|
|
|
#include "td/utils/Time.h"
|
|
|
|
|
|
|
|
#include <atomic>
|
|
|
|
#include <cstdlib>
|
2020-06-26 01:24:13 +02:00
|
|
|
#include <limits>
|
2020-06-24 13:47:36 +02:00
|
|
|
#include <mutex>
|
2018-12-31 20:04:05 +01:00
|
|
|
|
|
|
|
#if TD_ANDROID
|
|
|
|
#include <android/log.h>
|
|
|
|
#define ALOG_TAG "DLTD"
|
|
|
|
#elif TD_TIZEN
|
|
|
|
#include <dlog.h>
|
|
|
|
#define DLOG_TAG "DLTD"
|
|
|
|
#elif TD_EMSCRIPTEN
|
|
|
|
#include <emscripten.h>
|
|
|
|
#endif
|
|
|
|
|
|
|
|
namespace td {
|
|
|
|
|
2018-08-13 19:15:09 +02:00
|
|
|
LogOptions log_options;
|
|
|
|
|
2021-05-17 17:49:09 +02:00
|
|
|
static std::atomic<int> max_callback_verbosity_level = 0;
|
|
|
|
static std::atomic<OnLogMessageCallback> on_log_message_callback = nullptr;
|
|
|
|
|
|
|
|
void set_log_message_callback(int max_verbosity_level, OnLogMessageCallback callback) {
|
|
|
|
max_callback_verbosity_level = max_verbosity_level;
|
|
|
|
on_log_message_callback = callback;
|
|
|
|
}
|
|
|
|
|
2021-05-17 15:18:19 +02:00
|
|
|
void LogInterface::append(int log_level, CSlice slice) {
|
|
|
|
do_append(log_level, slice);
|
2021-05-17 17:49:09 +02:00
|
|
|
if (log_level <= max_callback_verbosity_level.load(std::memory_order_relaxed)) {
|
|
|
|
auto callback = on_log_message_callback.load(std::memory_order_relaxed);
|
|
|
|
if (callback != nullptr) {
|
|
|
|
callback(log_level, slice);
|
|
|
|
}
|
|
|
|
}
|
2021-05-17 15:18:19 +02:00
|
|
|
if (log_level == VERBOSITY_NAME(FATAL)) {
|
|
|
|
process_fatal_error(slice);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2018-12-31 20:04:05 +01:00
|
|
|
TD_THREAD_LOCAL const char *Logger::tag_ = nullptr;
|
|
|
|
TD_THREAD_LOCAL const char *Logger::tag2_ = nullptr;
|
|
|
|
|
2018-08-13 19:15:09 +02:00
|
|
|
Logger::Logger(LogInterface &log, const LogOptions &options, int log_level, Slice file_name, int line_num,
|
|
|
|
Slice comment)
|
|
|
|
: Logger(log, options, log_level) {
|
2020-06-17 04:51:36 +02:00
|
|
|
if (log_level == VERBOSITY_NAME(PLAIN) && &options == &log_options) {
|
|
|
|
return;
|
|
|
|
}
|
2018-08-13 19:15:09 +02:00
|
|
|
if (!options_.add_info) {
|
2018-12-31 20:04:05 +01:00
|
|
|
return;
|
|
|
|
}
|
2020-10-11 13:45:22 +02:00
|
|
|
if (ExitGuard::is_exited()) {
|
|
|
|
return;
|
|
|
|
}
|
2018-12-31 20:04:05 +01:00
|
|
|
|
2018-08-13 19:15:09 +02:00
|
|
|
// log level
|
2018-06-05 01:34:51 +02:00
|
|
|
sb_ << '[';
|
2020-08-04 00:07:49 +02:00
|
|
|
if (static_cast<unsigned int>(log_level) < 10) {
|
|
|
|
sb_ << ' ' << static_cast<char>('0' + log_level);
|
|
|
|
} else {
|
|
|
|
sb_ << log_level;
|
2018-02-11 15:07:16 +01:00
|
|
|
}
|
2020-08-04 00:07:49 +02:00
|
|
|
sb_ << ']';
|
2018-08-13 19:15:09 +02:00
|
|
|
|
|
|
|
// thread id
|
|
|
|
auto thread_id = get_thread_id();
|
|
|
|
sb_ << "[t";
|
2020-08-04 00:07:49 +02:00
|
|
|
if (static_cast<unsigned int>(thread_id) < 10) {
|
|
|
|
sb_ << ' ' << static_cast<char>('0' + thread_id);
|
|
|
|
} else {
|
|
|
|
sb_ << thread_id;
|
2018-12-31 20:04:05 +01:00
|
|
|
}
|
2020-08-04 00:07:49 +02:00
|
|
|
sb_ << ']';
|
2018-08-13 19:15:09 +02:00
|
|
|
|
|
|
|
// timestamp
|
2020-08-03 22:38:28 +02:00
|
|
|
auto time = Clocks::system();
|
2020-08-04 00:39:52 +02:00
|
|
|
auto unix_time = static_cast<uint32>(time);
|
|
|
|
auto nanoseconds = static_cast<uint32>((time - unix_time) * 1e9);
|
2020-08-03 22:38:28 +02:00
|
|
|
sb_ << '[' << unix_time << '.';
|
2020-08-04 00:39:52 +02:00
|
|
|
uint32 limit = 100000000;
|
2020-08-03 22:38:28 +02:00
|
|
|
while (nanoseconds < limit && limit > 1) {
|
|
|
|
sb_ << '0';
|
|
|
|
limit /= 10;
|
|
|
|
}
|
|
|
|
sb_ << nanoseconds << ']';
|
2018-08-13 19:15:09 +02:00
|
|
|
|
|
|
|
// file : line
|
|
|
|
if (!file_name.empty()) {
|
|
|
|
auto last_slash_ = static_cast<int32>(file_name.size()) - 1;
|
|
|
|
while (last_slash_ >= 0 && file_name[last_slash_] != '/' && file_name[last_slash_] != '\\') {
|
|
|
|
last_slash_--;
|
|
|
|
}
|
|
|
|
file_name = file_name.substr(last_slash_ + 1);
|
2020-08-04 00:39:52 +02:00
|
|
|
sb_ << '[' << file_name << ':' << static_cast<unsigned int>(line_num) << ']';
|
2018-08-13 19:15:09 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
// context from tag_
|
2018-12-31 20:04:05 +01:00
|
|
|
if (tag_ != nullptr && *tag_) {
|
2018-06-05 01:34:51 +02:00
|
|
|
sb_ << "[#" << Slice(tag_) << ']';
|
2018-12-31 20:04:05 +01:00
|
|
|
}
|
2018-08-13 19:15:09 +02:00
|
|
|
|
|
|
|
// context from tag2_
|
2018-12-31 20:04:05 +01:00
|
|
|
if (tag2_ != nullptr && *tag2_) {
|
2018-06-05 01:34:51 +02:00
|
|
|
sb_ << "[!" << Slice(tag2_) << ']';
|
2018-12-31 20:04:05 +01:00
|
|
|
}
|
2018-08-13 19:15:09 +02:00
|
|
|
|
|
|
|
// comment (e.g. condition in LOG_IF)
|
2018-12-31 20:04:05 +01:00
|
|
|
if (!comment.empty()) {
|
2018-06-05 01:34:51 +02:00
|
|
|
sb_ << "[&" << comment << ']';
|
2018-12-31 20:04:05 +01:00
|
|
|
}
|
2018-08-13 19:15:09 +02:00
|
|
|
|
2018-06-05 01:34:51 +02:00
|
|
|
sb_ << '\t';
|
2018-12-31 20:04:05 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
Logger::~Logger() {
|
2020-10-11 13:45:22 +02:00
|
|
|
if (ExitGuard::is_exited()) {
|
|
|
|
return;
|
|
|
|
}
|
2018-08-13 19:15:09 +02:00
|
|
|
if (options_.fix_newlines) {
|
2018-12-31 20:04:05 +01:00
|
|
|
sb_ << '\n';
|
|
|
|
auto slice = as_cslice();
|
|
|
|
if (slice.back() != '\n') {
|
|
|
|
slice.back() = '\n';
|
|
|
|
}
|
2018-08-13 19:15:09 +02:00
|
|
|
while (slice.size() > 1 && slice[slice.size() - 2] == '\n') {
|
2018-09-07 02:41:21 +02:00
|
|
|
slice.back() = '\0';
|
2018-08-13 19:15:09 +02:00
|
|
|
slice = MutableCSlice(slice.begin(), slice.begin() + slice.size() - 1);
|
|
|
|
}
|
2021-05-17 15:18:19 +02:00
|
|
|
log_.append(log_level_, slice);
|
2018-08-13 19:15:09 +02:00
|
|
|
} else {
|
2021-05-17 15:18:19 +02:00
|
|
|
log_.append(log_level_, as_cslice());
|
2018-12-31 20:04:05 +01:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
TsCerr::TsCerr() {
|
|
|
|
enterCritical();
|
|
|
|
}
|
|
|
|
TsCerr::~TsCerr() {
|
|
|
|
exitCritical();
|
|
|
|
}
|
|
|
|
TsCerr &TsCerr::operator<<(Slice slice) {
|
2018-08-13 19:15:09 +02:00
|
|
|
auto &fd = Stderr();
|
2018-12-31 20:04:05 +01:00
|
|
|
if (fd.empty()) {
|
|
|
|
return *this;
|
|
|
|
}
|
|
|
|
double end_time = 0;
|
|
|
|
while (!slice.empty()) {
|
|
|
|
auto res = fd.write(slice);
|
|
|
|
if (res.is_error()) {
|
|
|
|
if (res.error().code() == EPIPE) {
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
// Resource temporary unavailable
|
|
|
|
if (end_time == 0) {
|
|
|
|
end_time = Time::now() + 0.01;
|
|
|
|
} else if (Time::now() > end_time) {
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
continue;
|
|
|
|
}
|
|
|
|
slice.remove_prefix(res.ok());
|
|
|
|
}
|
|
|
|
return *this;
|
|
|
|
}
|
|
|
|
|
|
|
|
void TsCerr::enterCritical() {
|
2020-10-11 13:45:22 +02:00
|
|
|
while (lock_.test_and_set(std::memory_order_acquire) && !ExitGuard::is_exited()) {
|
2018-12-31 20:04:05 +01:00
|
|
|
// spin
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
void TsCerr::exitCritical() {
|
|
|
|
lock_.clear(std::memory_order_release);
|
|
|
|
}
|
|
|
|
TsCerr::Lock TsCerr::lock_ = ATOMIC_FLAG_INIT;
|
|
|
|
|
2020-10-11 13:45:22 +02:00
|
|
|
void TsLog::enter_critical() {
|
|
|
|
while (lock_.test_and_set(std::memory_order_acquire) && !ExitGuard::is_exited()) {
|
|
|
|
// spin
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
void TsLog::exit_critical() {
|
|
|
|
lock_.clear(std::memory_order_release);
|
|
|
|
}
|
|
|
|
|
2018-12-31 20:04:05 +01:00
|
|
|
class DefaultLog : public LogInterface {
|
2021-05-17 15:18:19 +02:00
|
|
|
void do_append(int log_level, CSlice slice) final {
|
2018-12-31 20:04:05 +01:00
|
|
|
#if TD_ANDROID
|
|
|
|
switch (log_level) {
|
|
|
|
case VERBOSITY_NAME(FATAL):
|
|
|
|
__android_log_write(ANDROID_LOG_FATAL, ALOG_TAG, slice.c_str());
|
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(ERROR):
|
|
|
|
__android_log_write(ANDROID_LOG_ERROR, ALOG_TAG, slice.c_str());
|
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(WARNING):
|
|
|
|
__android_log_write(ANDROID_LOG_WARN, ALOG_TAG, slice.c_str());
|
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(INFO):
|
|
|
|
__android_log_write(ANDROID_LOG_INFO, ALOG_TAG, slice.c_str());
|
|
|
|
break;
|
|
|
|
default:
|
|
|
|
__android_log_write(ANDROID_LOG_DEBUG, ALOG_TAG, slice.c_str());
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
#elif TD_TIZEN
|
|
|
|
switch (log_level) {
|
|
|
|
case VERBOSITY_NAME(FATAL):
|
2020-12-23 17:38:58 +01:00
|
|
|
dlog_print(DLOG_ERROR, DLOG_TAG, "%s", slice.c_str());
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(ERROR):
|
2020-12-23 17:38:58 +01:00
|
|
|
dlog_print(DLOG_ERROR, DLOG_TAG, "%s", slice.c_str());
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(WARNING):
|
2020-12-23 17:38:58 +01:00
|
|
|
dlog_print(DLOG_WARN, DLOG_TAG, "%s", slice.c_str());
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(INFO):
|
2020-12-23 17:38:58 +01:00
|
|
|
dlog_print(DLOG_INFO, DLOG_TAG, "%s", slice.c_str());
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
default:
|
2020-12-23 17:38:58 +01:00
|
|
|
dlog_print(DLOG_DEBUG, DLOG_TAG, "%s", slice.c_str());
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
}
|
|
|
|
#elif TD_EMSCRIPTEN
|
|
|
|
switch (log_level) {
|
|
|
|
case VERBOSITY_NAME(FATAL):
|
|
|
|
emscripten_log(
|
|
|
|
EM_LOG_ERROR | EM_LOG_CONSOLE | EM_LOG_C_STACK | EM_LOG_JS_STACK | EM_LOG_DEMANGLE | EM_LOG_FUNC_PARAMS,
|
|
|
|
"%s", slice.c_str());
|
2018-03-06 12:43:46 +01:00
|
|
|
EM_ASM(throw(UTF8ToString($0)), slice.c_str());
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(ERROR):
|
|
|
|
emscripten_log(EM_LOG_ERROR | EM_LOG_CONSOLE, "%s", slice.c_str());
|
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(WARNING):
|
|
|
|
emscripten_log(EM_LOG_WARN | EM_LOG_CONSOLE, "%s", slice.c_str());
|
|
|
|
break;
|
|
|
|
default:
|
|
|
|
emscripten_log(EM_LOG_CONSOLE, "%s", slice.c_str());
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
#elif !TD_WINDOWS
|
|
|
|
Slice color;
|
|
|
|
switch (log_level) {
|
|
|
|
case VERBOSITY_NAME(FATAL):
|
|
|
|
case VERBOSITY_NAME(ERROR):
|
2019-02-13 00:29:52 +01:00
|
|
|
color = Slice(TC_RED);
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(WARNING):
|
2019-02-13 00:29:52 +01:00
|
|
|
color = Slice(TC_YELLOW);
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
case VERBOSITY_NAME(INFO):
|
2019-02-13 00:29:52 +01:00
|
|
|
color = Slice(TC_CYAN);
|
2018-12-31 20:04:05 +01:00
|
|
|
break;
|
|
|
|
}
|
2019-07-06 13:29:15 +02:00
|
|
|
if (!slice.empty() && slice.back() == '\n') {
|
2019-07-21 20:07:07 +02:00
|
|
|
TsCerr() << color << slice.substr(0, slice.size() - 1) << TC_EMPTY "\n";
|
2019-07-06 13:29:15 +02:00
|
|
|
} else {
|
|
|
|
TsCerr() << color << slice << TC_EMPTY;
|
|
|
|
}
|
2018-12-31 20:04:05 +01:00
|
|
|
#else
|
|
|
|
// TODO: color
|
|
|
|
TsCerr() << slice;
|
|
|
|
#endif
|
|
|
|
}
|
|
|
|
};
|
|
|
|
static DefaultLog default_log;
|
|
|
|
|
|
|
|
LogInterface *const default_log_interface = &default_log;
|
|
|
|
LogInterface *log_interface = default_log_interface;
|
2018-01-24 16:45:57 +01:00
|
|
|
|
|
|
|
static OnFatalErrorCallback on_fatal_error_callback = nullptr;
|
|
|
|
|
|
|
|
void set_log_fatal_error_callback(OnFatalErrorCallback callback) {
|
|
|
|
on_fatal_error_callback = callback;
|
|
|
|
}
|
|
|
|
|
|
|
|
void process_fatal_error(CSlice message) {
|
|
|
|
auto callback = on_fatal_error_callback;
|
|
|
|
if (callback) {
|
|
|
|
callback(message);
|
|
|
|
}
|
|
|
|
std::abort();
|
|
|
|
}
|
2018-12-31 20:04:05 +01:00
|
|
|
|
2020-06-24 13:47:36 +02:00
|
|
|
namespace {
|
|
|
|
std::mutex sdl_mutex;
|
|
|
|
int sdl_cnt = 0;
|
|
|
|
int sdl_verbosity = 0;
|
|
|
|
} // namespace
|
2020-06-26 01:24:13 +02:00
|
|
|
|
2020-06-24 13:47:36 +02:00
|
|
|
ScopedDisableLog::ScopedDisableLog() {
|
|
|
|
std::unique_lock<std::mutex> guard(sdl_mutex);
|
|
|
|
if (sdl_cnt == 0) {
|
|
|
|
sdl_verbosity = set_verbosity_level(std::numeric_limits<int>::min());
|
|
|
|
}
|
|
|
|
sdl_cnt++;
|
|
|
|
}
|
|
|
|
|
|
|
|
ScopedDisableLog::~ScopedDisableLog() {
|
|
|
|
std::unique_lock<std::mutex> guard(sdl_mutex);
|
|
|
|
sdl_cnt--;
|
|
|
|
if (sdl_cnt == 0) {
|
|
|
|
set_verbosity_level(sdl_verbosity);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2020-10-11 13:45:22 +02:00
|
|
|
static ExitGuard exit_guard;
|
|
|
|
|
2018-12-31 20:04:05 +01:00
|
|
|
} // namespace td
|