logger.cpp (27618B)
1 #include "libshit/logger.hpp" 2 3 #if LIBSHIT_OS_IS_WINDOWS 4 # define WIN32_LEAN_AND_MEAN 5 # define NOMINMAX 6 # include <windows.h> 7 # include <io.h> 8 # undef ERROR 9 #endif 10 11 #include "libshit/abomination.hpp" 12 #include "libshit/doctest.hpp" 13 #include "libshit/function.hpp" 14 #include "libshit/lua/function_call.hpp" 15 #include "libshit/memory_utils.hpp" 16 #include "libshit/nonowning_string.hpp" 17 #include "libshit/options.hpp" 18 #include "libshit/string_utils.hpp" 19 #include "libshit/synchronized.hpp" 20 #include "libshit/utils.hpp" 21 22 #if LIBSHIT_WITH_LUA 23 # include "libshit/logger.lua.h" 24 #endif 25 26 #include <boost/tokenizer.hpp> 27 #include <tracy/Tracy.hpp> 28 29 #include <algorithm> 30 #include <atomic> 31 #include <charconv> 32 #include <cstdint> 33 #include <cstring> 34 #include <iostream> 35 #include <iterator> 36 #include <map> 37 #include <new> 38 #include <string> 39 #include <vector> 40 41 #if !LIBSHIT_OS_IS_WINDOWS 42 # include <sys/time.h> 43 # include <time.h> // localtime_r is not c++, we (probably) need time.h 44 #endif 45 46 namespace Libshit::Logger 47 { 48 TEST_SUITE_BEGIN("Libshit::Logger"); 49 using namespace Detail; 50 51 OptionGroup& GetOptionGroup() 52 { 53 static OptionGroup grp{OptionParser::GetGlobal(), "Logging options"}; 54 return grp; 55 } 56 57 std::ostream* nullptr_ostream; 58 59 struct Detail::GlobalSync 60 { 61 std::size_t max_name = 16; 62 std::size_t max_file = 42; 63 64 bool show_fun = false; 65 bool win_colors = false; 66 bool ansi_colors = false; 67 bool ansi_colors_forced = false; 68 bool _256_colors = true; 69 bool print_time = false; 70 71 std::ostream* os = &std::clog; 72 std::ofstream of; 73 }; 74 75 struct Detail::GlobalLevel 76 { 77 int global_level = -1; 78 std::vector<std::pair<const char*, int>> level_map; 79 // direct access data/size for checker function below 80 const std::pair<const char*, int>* levels = nullptr; 81 std::size_t level_size = 0; 82 std::vector<std::unique_ptr<char[]>> strings; 83 }; 84 85 namespace 86 { 87 struct Global 88 { 89 Global() 90 { 91 #if LIBSHIT_OS_IS_WINDOWS 92 const bool tty = _isatty(2); 93 #elif LIBSHIT_OS_IS_VITA 94 const bool tty = false; 95 #else 96 const bool tty = isatty(STDERR_FILENO); 97 #endif 98 // otherwise clog is actually unbuffered... 99 // buf can be nullptr on linux (and posix?), but crashes on windows... 100 setvbuf(stderr, stderr_buf, tty ? _IOLBF : _IOFBF, 4096); 101 102 auto& s = sync.UnsafeGetObject(); // single threaded here 103 auto x = Abomination::getenv("TERM"); 104 s._256_colors = x && std::strstr(x, "256color"); 105 106 s.win_colors = LIBSHIT_OS_IS_WINDOWS && tty; 107 s.ansi_colors = !LIBSHIT_OS_IS_WINDOWS && tty && 108 (x ? std::strcmp(x, "dummy") != 0 : false); 109 } 110 111 char stderr_buf[4096]; 112 std::atomic<bool> force_flush = false; 113 114 Synchronized<GlobalSync, std::shared_mutex> sync{ 115 LIBSHIT_SYNCHRONIZED_NAME("Libshit::Logger::Global::Sync")}; 116 117 Synchronized<GlobalLevel, std::shared_mutex> level{ 118 LIBSHIT_SYNCHRONIZED_NAME("Libshit::Logger::Global::Level")}; 119 }; 120 } 121 122 // BIG FUGLY HACK: under clang windows, this GlobalInitializer is 123 // constructed/destructed multiple times (on the same address!) 124 static unsigned global_refcount; 125 static std::aligned_storage_t<sizeof(Global), alignof(Global)> global_storage; 126 static Global& GetGlobal() noexcept 127 { return *reinterpret_cast<Global*>(&global_storage); } 128 129 namespace Detail 130 { 131 GlobalInitializer::GlobalInitializer() 132 { 133 if (global_refcount++ != 0) return; 134 new (&global_storage) Global; 135 } 136 GlobalInitializer::~GlobalInitializer() noexcept 137 { 138 if (--global_refcount != 0) return; 139 reinterpret_cast<Global*>(&global_storage)->~Global(); 140 } 141 } 142 143 bool HasAnsiColor() { return GetGlobal().sync.SharedLock()->ansi_colors; } 144 bool HasWinColor() { return GetGlobal().sync.SharedLock()->win_colors; } 145 bool HasShowFun() { return GetGlobal().sync.SharedLock()->show_fun; } 146 void ForceFlush() { GetGlobal().sync.Lock()->os->flush(); } 147 148 // --------------------------------------------------------------------------- 149 // Options 150 151 static int ParseLevel(StringView str) 152 { 153 if (!Ascii::CaseCmp(str, "none"_ns)) 154 return NONE; 155 if (!Ascii::CaseCmp(str, "err"_ns) || !Ascii::CaseCmp(str, "error"_ns)) 156 return ERROR; 157 else if (!Ascii::CaseCmp(str, "warn"_ns) || !Ascii::CaseCmp(str, "warning"_ns)) 158 return WARNING; 159 else if (!Ascii::CaseCmp(str, "info"_ns)) 160 return INFO; 161 else 162 { 163 int l; 164 auto res = std::from_chars(str.begin(), str.end(), l); 165 if (res.ec != std::errc() || res.ptr != str.end()) 166 throw InvalidParam{Cat({"Invalid log level ", str})}; 167 return l; 168 } 169 } 170 171 TEST_CASE("ParseLevel") 172 { 173 CHECK(ParseLevel("0") == 0); 174 CHECK(ParseLevel("2") == 2); 175 CHECK(ParseLevel("-5") == -5); 176 CHECK(ParseLevel("none") == Level::NONE); 177 CHECK(ParseLevel("error") == Level::ERROR); 178 CHECK(ParseLevel("err") == Level::ERROR); 179 CHECK(ParseLevel("warning") == Level::WARNING); 180 CHECK(ParseLevel("warn") == Level::WARNING); 181 CHECK(ParseLevel("info") == Level::INFO); 182 CHECK_THROWS(ParseLevel("foo")); 183 CHECK_THROWS(ParseLevel("1a")); 184 } 185 186 static void SetLogLevel(GlobalLevel& l, StringView name, int level) 187 { 188 auto it = std::find_if( 189 l.level_map.begin(), l.level_map.end(), 190 [&](const auto& i) { return i.first == name; }); 191 if (it == l.level_map.end()) 192 { 193 auto& str = l.strings.emplace_back(); 194 str = MakeUnique<char[]>(name.size() + 1, uninitialized); 195 memcpy(str.get(), name.data(), name.size()); 196 str[name.size()] = '\0'; 197 l.level_map.emplace_back(str.get(), level); 198 199 l.levels = l.level_map.data(); 200 l.level_size = l.level_map.size(); 201 } 202 else 203 it->second = level; 204 } 205 206 TEST_CASE("SetLogLevel") 207 { 208 TestRedirect rd{std::clog}; 209 { 210 auto l = GetGlobal().level.Lock(); 211 REQUIRE(l->level_map.empty()); 212 REQUIRE(l->level_size == 0); 213 REQUIRE(l->levels == nullptr); 214 REQUIRE(l->strings.empty()); 215 216 SetLogLevel(*l, "foo", 1); 217 SetLogLevel(*l, "bar", 0); 218 SetLogLevel(*l, "foo", 3); 219 SetLogLevel(*l, "asd", -1); 220 221 REQUIRE(l->strings.size() == 3); 222 CHECK_STREQ(l->strings[0].get(), "foo"); 223 CHECK_STREQ(l->strings[1].get(), "bar"); 224 CHECK_STREQ(l->strings[2].get(), "asd"); 225 CHECK(l->level_map == decltype(l->level_map){ 226 {l->strings[0].get(), 3}, {l->strings[1].get(), 0}, 227 {l->strings[2].get(), -1}}); 228 REQUIRE(l->level_size == 3); 229 using L = std::pair<const char*, int>; 230 CHECK(l->levels[0] == L{l->strings[0].get(), 3}); 231 CHECK(l->levels[1] == L{l->strings[1].get(), 0}); 232 CHECK(l->levels[2] == L{l->strings[2].get(), -1}); 233 } 234 235 CHECK(GetLogLevel("foo") == 3); 236 CHECK(GetLogLevel("asd") == -1); 237 CHECK(GetLogLevel("nosuch") == -1); 238 SetGlobalLogLevel(13); 239 CHECK(GetLogLevel("foo") == 3); 240 CHECK(GetLogLevel("asd") == -1); 241 CHECK(GetLogLevel("nosuch") == 13); 242 } 243 244 static Option level_opt{ 245 GetOptionGroup(), "log-level", 'l', 1, 246 "[MODULE=LEVEL,[...]][DEFAULT_LEVEL]", 247 "Sets logging level for the specified modules, or the global default\n\t" 248 "Valid levels: none, err, warn, info, 0..4 (debug levels" 249 #if !LIBSHIT_IS_DBG_LOG_ENABLED 250 " - non-debug build, most of them will be missing" 251 #endif 252 ")\n\tDefault level: info", 253 [](auto& parser, auto&& args) 254 { 255 boost::char_separator<char> sep{","}; 256 auto arg = args.front(); 257 boost::tokenizer<boost::char_separator<char>, const char*> 258 tokens{arg, arg+strlen(arg), sep}; 259 auto l = GetGlobal().level.Lock(); 260 for (const auto& tok : tokens) 261 { 262 auto p = tok.find_first_of('='); 263 if (p == std::string::npos) 264 l->global_level = ParseLevel(tok); 265 else 266 { 267 auto lvl = ParseLevel(StringView{tok}.substr(p + 1)); 268 SetLogLevel(*l, tok.substr(0, p), lvl); 269 } 270 } 271 }}; 272 273 static Option show_fun_opt{ 274 GetOptionGroup(), "log-show-functions", 0, nullptr, 275 "Show function signatures in log when available", 276 [](auto&, auto&&) { GetGlobal().sync.Lock()->show_fun = true; }}; 277 278 static void EnableAnsiColors( 279 OptionParser& parser, std::vector<const char*>&&) noexcept 280 { 281 auto g = GetGlobal().sync.Lock(); 282 #if LIBSHIT_OS_IS_WINDOWS 283 # ifndef ENABLE_VIRTUAL_TERMINAL_PROCESSING 284 # define ENABLE_VIRTUAL_TERMINAL_PROCESSING 4 285 # endif 286 // This should enable ANSI sequence processing on win10+. Completely 287 // untested as I don't use that spyware. 288 auto h = GetStdHandle(STD_OUTPUT_HANDLE); 289 if (h != INVALID_HANDLE_VALUE) 290 { 291 DWORD mode = 0; 292 if (GetConsoleMode(h, &mode)) 293 SetConsoleMode(h, mode | ENABLE_VIRTUAL_TERMINAL_PROCESSING); 294 } 295 #endif 296 g->win_colors = false; 297 g->ansi_colors = true; 298 g->ansi_colors_forced = true; 299 } 300 301 static Option ansi_colors_opt{ 302 GetOptionGroup(), "log-ansi-colors", 0, nullptr, 303 "Force output colorization with ANSI escape sequences", 304 FUNC<EnableAnsiColors>}; 305 static Option no_colors_opt{ 306 GetOptionGroup(), "log-no-colors", 0, nullptr, 307 "Disable output colorization", 308 [](auto&, auto&&) 309 { 310 auto g = GetGlobal().sync.Lock(); 311 g->win_colors = false; 312 g->ansi_colors = false; 313 g->ansi_colors_forced = false; 314 }}; 315 static Option print_time_opt{ 316 GetOptionGroup(), "log-print-time", 0, nullptr, 317 "Print timestamps before log messages", 318 [](auto&, auto&&) { GetGlobal().sync.Lock()->print_time = true; }}; 319 static Option force_flush_opt{ 320 GetOptionGroup(), "log-force-flush", 0, nullptr, 321 "Force flushing log messages (default when logging to a tty)", 322 [](auto&, auto&&) 323 { GetGlobal().force_flush.store(true, std::memory_order_relaxed); }}; 324 325 bool IsRedirected() 326 { return GetGlobal().sync.SharedLock()->os != &std::clog; } 327 void RedirectToFile(const char* fname) 328 { 329 auto g = GetGlobal().sync.Lock(); 330 Abomination::Open(g->of, fname); 331 g->os = &g->of; 332 g->win_colors = false; // win colors only works with stderr! 333 // no ansi colors, unless the user explicitly enabled it 334 if (!g->ansi_colors_forced) g->ansi_colors = false; 335 // todo: make it possible to disable this 336 g->print_time = true; 337 } 338 static Option file_opt{ 339 GetOptionGroup(), "log-to-file", 1, "FILE", 340 "Redirect log output to file", 341 [](auto& parser, auto&& args) { RedirectToFile(args[0]); }}; 342 343 344 // --------------------------------------------------------------------------- 345 346 TestRedirect::TestRedirect(std::ostream& os, bool ansi_colors) 347 : sync{std::make_unique<GlobalSync>()}, 348 level{std::make_unique<GlobalLevel>()} 349 { 350 sync->os = &os; 351 sync->ansi_colors = ansi_colors; 352 353 // should be noexcept below 354 std::swap(*GetGlobal().sync.Lock(), *sync); 355 std::swap(*GetGlobal().level.Lock(), *level); 356 } 357 358 TestRedirect::~TestRedirect() noexcept 359 { 360 *GetGlobal().sync.Lock() = Move(*sync); 361 *GetGlobal().level.Lock() = Move(*level); 362 } 363 364 void SetGlobalLogLevel(int level) noexcept 365 { GetGlobal().level.Lock()->global_level = level; } 366 void SetLogLevel(StringView name, int level) 367 { SetLogLevel(*GetGlobal().level.Lock(), name, level); } 368 369 // --------------------------------------------------------------------------- 370 371 static constexpr std::uint8_t RAND_COLORS[] = { 372 1,2,3,4,5,6,7, 8,9,10,11,12,13,14,15, 373 374 // (16..231).select{|i| i-=16; b=i%6; i/=6; g=i%6; i/=6; i+g+b>6} 375 33, 38, 39, 43, 44, 45, 48, 49, 50, 51, 63, 68, 69, 73, 74, 75, 78, 79, 80, 376 81, 83, 84, 85, 86, 87, 93, 98, 99, 103, 104, 105, 108, 109, 110, 111, 113, 377 114, 115, 116, 117, 118, 119, 120, 121, 122, 123, 128, 129, 133, 134, 135, 378 138, 139, 140, 141, 143, 144, 145, 146, 147, 148, 149, 150, 151, 152, 153, 379 154, 155, 156, 157, 158, 159, 163, 164, 165, 168, 169, 170, 171, 173, 174, 380 175, 176, 177, 178, 179, 180, 181, 182, 183, 184, 185, 186, 187, 188, 189, 381 190, 191, 192, 193, 194, 195, 198, 199, 200, 201, 203, 204, 205, 206, 207, 382 208, 209, 210, 211, 212, 213, 214, 215, 216, 217, 218, 219, 220, 221, 222, 383 223, 224, 225, 226, 227, 228, 229, 230, 231 384 }; 385 static constexpr const std::size_t NON256COL_NUM = 15; 386 387 #if LIBSHIT_OS_IS_WINDOWS 388 static std::uint8_t WIN_COLOR_MAP[] = { 389 #define C(r,g,b,i) \ 390 (((r) ? FOREGROUND_RED : 0) | ((g) ? FOREGROUND_GREEN : 0) | \ 391 ((b) ? FOREGROUND_BLUE : 0) | ((i) ? FOREGROUND_INTENSITY : 0)) 392 C(0,0,0,0), C(1,0,0,0), C(0,1,0,0), C(1,1,0,0), C(0,0,1,0), C(1,0,1,0), 393 C(0,1,1,0), C(1,1,1,0), 394 395 C(0,0,0,1), C(1,0,0,1), C(0,1,0,1), C(1,1,0,1), C(0,0,1,1), C(1,0,1,1), 396 C(0,1,1,1), C(1,1,1,1), 397 #undef C 398 }; 399 #endif 400 401 // 32-bit FNV-1a hash http://www.isthe.com/chongo/tech/comp/fnv/index.html 402 static std::uint32_t Hash(StringView sv) 403 { 404 std::uint32_t res = 0x811c9dc5; 405 for (unsigned char c : sv) 406 res = (res ^ c) * 0x01000193; 407 return res; 408 } 409 410 static void IntToStrPadded(std::string& out, unsigned i, std::size_t to_pad, 411 char pad_char = '0') 412 { 413 char buf[128]; 414 auto res = std::to_chars(std::begin(buf), std::end(buf), i); 415 auto len = res.ptr - buf; 416 if (to_pad > len) out.append(to_pad-len, pad_char); 417 out.append(buf, len); 418 } 419 420 TEST_CASE("IntToStrPadded") 421 { 422 std::string s; 423 IntToStrPadded(s, 123, 0); 424 CHECK(s == "123"); 425 s.clear(); 426 IntToStrPadded(s, 12, 4, 'x'); 427 CHECK(s == "xx12"); 428 } 429 430 static void PrintTime(std::string& out) 431 { 432 #define F(i, n) IntToStrPadded(out, i, n) 433 434 #if LIBSHIT_OS_IS_WINDOWS 435 SYSTEMTIME tim; 436 GetLocalTime(&tim); 437 F(tim.wYear, 0); out += '-'; F(tim.wMonth, 2); out += '-'; F(tim.wDay, 2); 438 out += ' '; F(tim.wHour, 2); out += ':'; F(tim.wMinute, 2); out += ':'; 439 F(tim.wSecond, 2); out += '.'; F(tim.wMilliseconds, 3); 440 #else 441 struct timeval tv; 442 if (gettimeofday(&tv, nullptr) < 0) return; 443 char buf[128]; 444 struct tm tmp; 445 if (strftime(buf, 128, "%F %H:%M:%S.", localtime_r(&tv.tv_sec, &tmp)) == 0) 446 return; 447 out.append(buf); F(tv.tv_usec, 6); 448 #endif 449 450 out += ' '; 451 #undef F 452 } 453 454 template <typename Cb> 455 static void ProcessAnsi(std::ostream& os, StringView str, Cb cb) 456 { 457 enum class State { INIT, ESC, CSI } state = State::INIT; 458 const char* csi_start = nullptr; // shut up clang, not uninitialized 459 for (const char& c : str) 460 switch (state) 461 { 462 case State::INIT: 463 if (c == 033) state = State::ESC; else os.put(c); break; 464 case State::ESC: 465 if (c == '[') 466 { 467 state = State::CSI; 468 csi_start = &c+1; 469 } 470 else 471 state = State::INIT; 472 break; 473 case State::CSI: 474 if (c >= 0x40 && c <= 0x7e) 475 { 476 cb({csi_start, &c}, c); 477 state = State::INIT; 478 } 479 break; 480 } 481 } 482 483 void StripFormat(std::ostream& os, StringView str) 484 { ProcessAnsi(os, str, [](StringView, char){}); } 485 486 TEST_CASE("StripFormat") 487 { 488 std::stringstream ss; 489 StripFormat(ss, "abc\ndef123"); 490 CHECK(ss.str() == "abc\ndef123"); 491 492 ss.str(""); 493 StripFormat(ss, "a\033[1;32mfoo\033[0mbar"); 494 CHECK(ss.str() == "afoobar"); 495 496 // movement commands and everything ignored 497 ss.str(""); 498 StripFormat(ss, "x\033[;5Hy"); 499 CHECK(ss.str() == "xy"); 500 } 501 502 namespace 503 { 504 struct LogBuffer final : public std::streambuf 505 { 506 std::streamsize xsputn(const char* msg, std::streamsize n) override 507 { 508 auto g = GetGlobal().sync.Lock(); 509 auto old_n = n; 510 while (n) 511 { 512 if (buf.empty()) WriteBegin(*g); 513 auto end = std::find(msg, msg+n, '\n'); 514 if (end == msg+n) 515 { 516 g.Reset(); 517 buf.append(msg, msg+n); 518 return old_n; 519 } 520 521 buf.append(msg, end-msg); 522 WriteEnd(); 523 TracyMessageC(buf.data(), buf.size(), GetTracyColor()); 524 525 if (g->ansi_colors) 526 g->os->write(buf.data(), buf.size()); 527 #if LIBSHIT_OS_IS_WINDOWS 528 else if (g->win_colors) 529 WinFormat(*g->os); 530 #endif 531 else 532 StripFormat(*g->os, buf); 533 buf.clear(); 534 535 ++end; // skip \n -- WriteEnd wrote it 536 n -= end-msg; 537 msg = end; 538 } 539 return old_n; 540 } 541 542 #if LIBSHIT_OS_IS_WINDOWS 543 void WinFormat(std::ostream& os) 544 { 545 assert(&os == &std::clog); // can't use LIBSHIT_ASSERT here as it logs 546 547 constexpr const auto reset = 548 FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_BLUE; 549 constexpr const auto color_mask = reset; 550 auto win_attrib = reset; 551 auto fun = [&](StringView csi, char cmd) 552 { 553 if (cmd != 'm') return; 554 os.flush(); 555 auto h = GetStdHandle(STD_ERROR_HANDLE); 556 557 if (csi.empty()) 558 { 559 SetConsoleTextAttribute(h, reset); 560 return; 561 } 562 563 enum class State { NORMAL, FG0, FG1 } state = State::NORMAL; 564 std::size_t p = 0; 565 for (auto i = csi.find_first_of(';'); p != StringView::npos; 566 i == StringView::npos ? p = i : 567 (p = i+1, i = csi.find_first_of(';', p))) 568 { 569 unsigned sgr; 570 auto sub = csi.substr(p, i-p); 571 auto res = std::from_chars(sub.begin(), sub.end(), sgr); 572 if (res.ec != std::errc() || res.ptr != sub.end()) continue; 573 switch (state) 574 { 575 case State::NORMAL: 576 switch (sgr) 577 { 578 case 0: win_attrib = reset; break; 579 case 1: win_attrib |= FOREGROUND_INTENSITY; break; 580 case 22: win_attrib &= ~FOREGROUND_INTENSITY; break; 581 case 38: state = State::FG0; break; 582 } 583 584 if (sgr >= 30 && sgr <= 37) 585 win_attrib = (win_attrib & ~color_mask) | WIN_COLOR_MAP[sgr-30]; 586 break; 587 588 case State::FG0: 589 state = sgr == 5 ? State::FG1 : State::NORMAL; break; 590 591 case State::FG1: 592 if (sgr < std::size(WIN_COLOR_MAP)) win_attrib = WIN_COLOR_MAP[sgr]; 593 state = State::NORMAL; 594 break; 595 } 596 } 597 SetConsoleTextAttribute(h, win_attrib); 598 }; 599 ProcessAnsi(os, buf, fun); 600 } 601 #endif 602 603 int_type overflow(int_type ch) override 604 { 605 if (ch != traits_type::eof()) 606 { 607 char c = ch; 608 LogBuffer::xsputn(&c, 1); 609 } 610 return 0; 611 } 612 613 int sync() override 614 { 615 auto& g = GetGlobal(); 616 if (g.force_flush.load(std::memory_order_relaxed)) 617 g.sync.Lock()->os->flush(); 618 return 0; 619 } 620 621 std::uint32_t GetTracyColor() const 622 { 623 switch (level) 624 { 625 case ERROR: return 0xff0000; 626 case WARNING: return 0xffff00; 627 case INFO: return 0x00ff00; 628 default: return 0; 629 } 630 } 631 632 void WriteBegin(GlobalSync& g) 633 { 634 if (g.print_time) PrintTime(buf); 635 636 auto print_col = [&]() 637 { 638 switch (level) 639 { 640 case ERROR: buf.append("\033[0;1;31m"); break; 641 case WARNING: buf.append("\033[0;1;33m"); break; 642 case INFO: buf.append("\033[0;1;32m"); break; 643 default: buf.append("\033[0;1m"); break; 644 } 645 }; 646 print_col(); 647 648 switch (level) 649 { 650 case ERROR: buf.append("ERROR"); break; 651 case WARNING: buf.append("WARN "); break; 652 case INFO: buf.append("info "); break; 653 default: 654 buf.append("dbg"); 655 IntToStrPadded(buf, level, 2, ' '); 656 break; 657 } 658 659 buf += '['; 660 g.max_name = std::max(g.max_name, name.size()); 661 662 { 663 auto i = Hash(name); 664 if (!g.win_colors && g._256_colors) 665 i %= std::size(RAND_COLORS); 666 else 667 i %= NON256COL_NUM; 668 buf.append("\033[22;38;5;"); 669 IntToStrPadded(buf, RAND_COLORS[i], 1); 670 buf += 'm'; 671 } 672 673 buf.append(g.max_name - name.size(), ' ').append(name); 674 print_col(); 675 buf.append("]\033[22m"); 676 677 if (!file.empty()) 678 { 679 g.max_file = std::max(g.max_file, file.size()); 680 buf.append(g.max_file + 1 - file.size(), ' '); 681 if (auto p = file.rfind('/'); p != StringView::npos) 682 buf.append(file.substr(0, p+1)).append("\033[1m"). 683 append(file.substr(p+1)); 684 else 685 buf.append(file); 686 buf.append("\033[22m:"); 687 IntToStrPadded(buf, line, 3, ' '); 688 } 689 if (g.show_fun && !fun.empty()) buf.append(": ").append(fun); 690 buf.append(": "); 691 } 692 693 void WriteEnd() 694 { 695 buf.append("\033[0m\n"); 696 } 697 698 std::string buf; 699 StringView name; 700 int level; 701 StringView file; 702 unsigned line; 703 StringView fun; 704 }; 705 } 706 707 int GetLogLevel(const char* name) 708 { 709 auto gs = GetGlobal().level.SharedLock(); 710 auto& g = *gs; // help debug builds... 711 if (auto n = g.level_size) 712 for (auto l = g.levels; n--; ++l) 713 if (strcmp(l->first, name) == 0) 714 return l->second; 715 return g.global_level; 716 } 717 718 namespace Detail 719 { 720 struct PerThread 721 { 722 LogBuffer filter; 723 std::ostream log_os{&filter}; 724 }; 725 726 PerThreadInitializer::PerThreadInitializer() { pimpl = new PerThread; } 727 PerThreadInitializer::~PerThreadInitializer() noexcept 728 { delete pimpl; pimpl = nullptr; } 729 } 730 731 std::ostream& Log( 732 const char* name, int level, const char* file, unsigned line, 733 const char* fun) 734 { 735 auto p = per_thread_initializer.pimpl; 736 // I don't know whether this is a bug or not, but apparently the tread local 737 // can be destroyed while later dtors might still log. Hopefully this will 738 // only happen on the main thread in rare cases, so the leak is not that 739 // serious. 740 if (p == nullptr) 741 p = per_thread_initializer.pimpl = new PerThread; 742 743 p->filter.name = name; 744 p->filter.level = level; 745 p->filter.file = file; 746 p->filter.line = line; 747 p->filter.fun = fun; 748 return p->log_os; 749 } 750 751 // default max_name=16, max_file=42 752 #define NAME_PAD " name" 753 #define FILE_PAD " filename" 754 TEST_CASE("Log") 755 { 756 std::stringstream ss; 757 TestRedirect ts{ss}; 758 Log("name", Level::WARNING, "filename", 123, "func") << "test" << std::endl; 759 CHECK(ss.str() == "WARN [" NAME_PAD "] " FILE_PAD ":123: test\n"_ns); 760 761 ss.str(""); 762 GetGlobal().sync.Lock()->show_fun = true; 763 Log("name", Level::INFO, "filename", 123, "func") << "test" << std::endl; 764 CHECK(ss.str() == "info [" NAME_PAD "] " FILE_PAD ":123: func: test\n"_ns); 765 766 ss.str(""); 767 Log("name", Level::ERROR, nullptr, 0, nullptr) << "missing" << std::endl; 768 CHECK(ss.str() == "ERROR[" NAME_PAD "]: missing\n"_ns); 769 770 ss.str(""); 771 Log("name", 2, "filename", 3, nullptr) << "multi\nline" << std::endl; 772 CHECK(ss.str() == "dbg 2[" NAME_PAD "] " FILE_PAD ": 3: multi\n" 773 "dbg 2[" NAME_PAD "] " FILE_PAD ": 3: line\n"_ns); 774 775 ss.str(""); 776 LIBSHIT_LOG("random", Level::ERROR) << "foo" << std::endl; 777 CHECK(ss.str() != ""); 778 779 ss.str(""); 780 LIBSHIT_LOG("random", 3) << "foo" << std::endl; 781 CHECK(ss.str() == ""); 782 } 783 784 #define LOG_COLOR_TEST(name, name_col, _256) \ 785 TEST_CASE("Log color " name) \ 786 { \ 787 std::stringstream ss; \ 788 TestRedirect ts{ss, true}; \ 789 GetGlobal().sync.Lock()->show_fun = true; \ 790 GetGlobal().sync.Lock()->_256_colors = _256; \ 791 Log("name", Level::ERROR, "filename", 5, "func") << "testerror" << std::endl; \ 792 CHECK(ss.str() == "\033[0;1;31mERROR[" name_col "\033[0;1;31m]\033[22m " \ 793 FILE_PAD "\033[22m: 5: func: testerror\033[0m\n"_ns); \ 794 \ 795 ss.str(""); \ 796 Log("name", Level::WARNING, "filename", 13, nullptr) << "xyz" << std::endl; \ 797 CHECK(ss.str() == "\033[0;1;33mWARN [" name_col "\033[0;1;33m]\033[22m " \ 798 FILE_PAD "\033[22m: 13: xyz\033[0m\n"_ns); \ 799 \ 800 ss.str(""); \ 801 Log("name", Level::WARNING, "file/name", 77, nullptr) << "xyz" << std::endl; \ 802 CHECK(ss.str() == "\033[0;1;33mWARN [" name_col "\033[0;1;33m]\033[22m " \ 803 " file/\033[1mname" \ 804 "\033[22m: 77: xyz\033[0m\n"_ns); \ 805 \ 806 ss.str(""); \ 807 Log("name", Level::INFO, nullptr, 0, nullptr) << "bar\nbaz" << std::endl; \ 808 CHECK(ss.str() == \ 809 "\033[0;1;32minfo [" name_col "\033[0;1;32m]\033[22m: bar\033[0m\n" \ 810 "\033[0;1;32minfo [" name_col "\033[0;1;32m]\033[22m: baz\033[0m\n"_ns); \ 811 \ 812 ss.str(""); \ 813 Log("name", 0, "filename", 1234, nullptr) << "dbg!" << std::endl; \ 814 CHECK(ss.str() == "\033[0;1mdbg 0[" name_col "\033[0;1m]\033[22m " \ 815 FILE_PAD "\033[22m:1234: dbg!\033[0m\n"_ns); \ 816 } 817 818 LOG_COLOR_TEST("256", "\033[22;38;5;204m" NAME_PAD, true) 819 LOG_COLOR_TEST("16", "\033[22;38;5;3m" NAME_PAD, false) 820 821 #undef NAME_COL 822 #undef NAME_PAD 823 #undef FILE_PAD 824 825 #if LIBSHIT_WITH_LUA 826 static void LuaLog( 827 Lua::StateRef vm, const char* name, int level, Lua::Skip msg) 828 { 829 (void) msg; 830 const char* file = nullptr; 831 unsigned line = 0; 832 const char* fun = nullptr; 833 834 lua_Debug dbg; 835 if (lua_getstack(vm, 1, &dbg) && lua_getinfo(vm, "Sln", &dbg)) 836 { 837 file = dbg.short_src; 838 line = dbg.currentline; 839 fun = dbg.name; 840 } 841 842 auto& os = Log(name, level, file, line, fun); 843 844 std::size_t len; 845 auto str = luaL_tolstring(vm, 3, &len); // +1 846 os.write(str, len); 847 lua_pop(vm, 1); // 0 848 849 os << std::flush; 850 } 851 852 static Lua::State::Register reg{[](Lua::StateRef vm) 853 { 854 lua_createtable(vm, 0, 2); // +1 855 856 vm.PushFunction<&CheckLog>(); // +2 857 lua_setfield(vm, -2, "check_log"); // +1 858 859 vm.PushFunction<&LuaLog>(); // +2 860 lua_setfield(vm, -2, "raw_log"); // +1 861 862 vm.Push(Level::ERROR); // +2 863 lua_setfield(vm, -2, "ERROR"); // +1 864 865 vm.Push(Level::WARNING); // +2 866 lua_setfield(vm, -2, "WARNING"); // +1 867 868 vm.Push(Level::INFO); // +2 869 lua_setfield(vm, -2, "INFO"); // +1 870 871 lua_pushglobaltable(vm); // +2 872 vm.SetRecTable("libshit.log", -2); // +1 873 lua_pop(vm, 1); // 0 874 875 LIBSHIT_LUA_RUNBC(vm, logger, 0); 876 }}; 877 #endif 878 879 TEST_SUITE_END(); 880 }