LCOV - code coverage report
Current view: top level - src - logger.cpp (source / functions) Hit Total Coverage
Test: jami-coverage-filtered.info Lines: 139 203 68.5 %
Date: 2024-12-21 08:56:24 Functions: 31 50 62.0 %

          Line data    Source code
       1             : /*
       2             :  *  Copyright (C) 2004-2024 Savoir-faire Linux Inc.
       3             :  *
       4             :  *  This program is free software: you can redistribute it and/or modify
       5             :  *  it under the terms of the GNU General Public License as published by
       6             :  *  the Free Software Foundation, either version 3 of the License, or
       7             :  *  (at your option) any later version.
       8             :  *
       9             :  *  This program is distributed in the hope that it will be useful,
      10             :  *  but WITHOUT ANY WARRANTY; without even the implied warranty of
      11             :  *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
      12             :  *  GNU General Public License for more details.
      13             :  *
      14             :  *  You should have received a copy of the GNU General Public License
      15             :  *  along with this program. If not, see <https://www.gnu.org/licenses/>.
      16             :  */
      17             : 
      18             : #include <cstdio>
      19             : #include <cstring>
      20             : #include <cerrno>
      21             : #include <ctime>
      22             : #include <ciso646> // fix windows compiler bug
      23             : 
      24             : #include "client/ring_signal.h"
      25             : 
      26             : #include <fmt/core.h>
      27             : #include <fmt/format.h>
      28             : #include <fmt/compile.h>
      29             : 
      30             : #ifdef _MSC_VER
      31             : #include <sys_time.h>
      32             : #else
      33             : #include <sys/time.h>
      34             : #endif
      35             : 
      36             : #include <atomic>
      37             : #include <condition_variable>
      38             : #include <functional>
      39             : #include <fstream>
      40             : #include <string>
      41             : #include <ios>
      42             : #include <mutex>
      43             : #include <thread>
      44             : #include <array>
      45             : 
      46             : #include "fileutils.h"
      47             : #include "logger.h"
      48             : 
      49             : #ifdef __linux__
      50             : #include <unistd.h>
      51             : #include <syslog.h>
      52             : #include <sys/syscall.h>
      53             : #endif // __linux__
      54             : 
      55             : #ifdef __ANDROID__
      56             : #ifndef APP_NAME
      57             : #define APP_NAME "libjami"
      58             : #endif /* APP_NAME */
      59             : #endif
      60             : 
      61             : #define END_COLOR     "\033[0m"
      62             : 
      63             : #ifndef _WIN32
      64             : #define RED    "\033[22;31m"
      65             : #define YELLOW "\033[01;33m"
      66             : #define CYAN   "\033[22;36m"
      67             : #else
      68             : #define FOREGROUND_WHITE 0x000f
      69             : #define RED              FOREGROUND_RED + 0x0008
      70             : #define YELLOW           FOREGROUND_RED + FOREGROUND_GREEN + 0x0008
      71             : #define CYAN             FOREGROUND_BLUE + FOREGROUND_GREEN + 0x0008
      72             : #define LIGHT_GREEN      FOREGROUND_GREEN + 0x0008
      73             : #endif // _WIN32
      74             : 
      75             : #define LOGFILE "jami"
      76             : 
      77             : namespace jami {
      78             : 
      79             : static constexpr auto ENDL = '\n';
      80             : 
      81             : #ifndef __GLIBC__
      82             : static const char*
      83             : check_error(int result, char* buffer)
      84             : {
      85             :     switch (result) {
      86             :     case 0:
      87             :         return buffer;
      88             : 
      89             :     case ERANGE: /* should never happen */
      90             :         return "unknown (too big to display)";
      91             : 
      92             :     default:
      93             :         return "unknown (invalid error number)";
      94             :     }
      95             : }
      96             : 
      97             : static const char*
      98             : check_error(char* result, char*)
      99             : {
     100             :     return result;
     101             : }
     102             : #endif
     103             : 
     104             : void
     105           0 : strErr()
     106             : {
     107             : #ifdef __GLIBC__
     108           0 :     JAMI_ERR("%m");
     109             : #else
     110             :     char buf[1000];
     111             :     JAMI_ERR("%s", check_error(strerror_r(errno, buf, sizeof(buf)), buf));
     112             : #endif
     113           0 : }
     114             : 
     115             : // extract the last component of a pathname (extract a filename from its dirname)
     116             : static const char*
     117      539705 : stripDirName(const char* path)
     118             : {
     119      539705 :     if (path) {
     120      434189 :         const char* occur = strrchr(path, DIR_SEPARATOR_CH);
     121      434189 :         return occur ? occur + 1 : path;
     122      105516 :     } else return nullptr;
     123             : }
     124             : 
     125             : std::string
     126      322572 : formatHeader(const char* const file, int line)
     127             : {
     128             : #ifdef __linux__
     129      322572 :     auto tid = syscall(__NR_gettid) & 0xffff;
     130             : #else
     131             :     auto tid = std::this_thread::get_id();
     132             : #endif // __linux__
     133             : 
     134             :     unsigned int secs, milli;
     135             :     struct timeval tv;
     136      322758 :     if (!gettimeofday(&tv, NULL)) {
     137      322750 :         secs = tv.tv_sec;
     138      322750 :         milli = tv.tv_usec / 1000; // suppose that milli < 1000
     139             :     } else {
     140           0 :         secs = time(NULL);
     141           0 :         milli = 0;
     142             :     }
     143             : 
     144      322750 :     if (file) {
     145      217089 :         return fmt::format(FMT_COMPILE("[{: >3d}.{:0<3d}|{: >4}|{: <24s}:{: <4d}] "),
     146             :                            secs,
     147             :                            milli,
     148             :                            tid,
     149      434121 :                            stripDirName(file),
     150      216964 :                            line);
     151             :     } else {
     152      316718 :         return fmt::format(FMT_COMPILE("[{: >3d}.{:0<3d}|{: >4}] "), secs, milli, tid);
     153             :     }
     154             : }
     155             : 
     156             : std::string
     157       67004 : formatPrintfArgs(const char* format, va_list ap)
     158             : {
     159       67004 :     std::string ret;
     160             :     /* A good guess of what we might encounter. */
     161             :     static constexpr size_t default_buf_size = 80;
     162             : 
     163       67005 :     ret.resize(default_buf_size);
     164             : 
     165             :     /* Necessary if we don't have enough space in buf. */
     166             :     va_list cp;
     167       67013 :     va_copy(cp, ap);
     168             : 
     169       67013 :     int size = vsnprintf(ret.data(), ret.size(), format, ap);
     170             : 
     171             :     /* Not enough space?  Well try again. */
     172       67012 :     if ((size_t) size >= ret.size()) {
     173       12455 :         ret.resize(size + 1);
     174       12455 :         vsnprintf((char*) ret.data(), ret.size(), format, cp);
     175             :     }
     176             : 
     177       67016 :     ret.resize(size);
     178             : 
     179       67014 :     va_end(cp);
     180             : 
     181      134028 :     return ret;
     182           0 : }
     183             : 
     184             : struct Logger::Msg
     185             : {
     186             :     Msg() = delete;
     187             : 
     188      255639 :     Msg(int level, const char* file, int line, bool linefeed, std::string&& message)
     189      255639 :         : file_(stripDirName(file))
     190      255660 :         , line_(line)
     191      255660 :         , payload_(std::move(message))
     192      255646 :         , level_(level)
     193      255646 :         , linefeed_(linefeed)
     194      255646 :     {}
     195             : 
     196       67006 :     Msg(int level, const char* file, int line, bool linefeed, const char* fmt, va_list ap)
     197       67006 :         : file_(stripDirName(file))
     198       67009 :         , line_(line)
     199       67009 :         , payload_(formatPrintfArgs(fmt, ap))
     200       67013 :         , level_(level)
     201       67013 :         , linefeed_(linefeed)
     202       67013 :     {}
     203             : 
     204           0 :     Msg(Msg&& other)
     205           0 :     {
     206           0 :         file_ = other.file_;
     207           0 :         line_ = other.line_;
     208           0 :         payload_ = std::move(other.payload_);
     209           0 :         level_ = other.level_;
     210           0 :         linefeed_ = other.linefeed_;
     211           0 :     }
     212             : 
     213      322540 :     inline std::string header() const {
     214      322540 :         return formatHeader(file_, line_);
     215             :     }
     216             : 
     217             :     const char* file_;
     218             :     unsigned line_;
     219             :     std::string payload_;
     220             :     int level_;
     221             :     bool linefeed_;
     222             : };
     223             : 
     224             : class Logger::Handler
     225             : {
     226             : public:
     227           0 :     virtual ~Handler() = default;
     228             : 
     229             :     virtual void consume(Msg& msg) = 0;
     230             : 
     231         924 :     void enable(bool en) { enabled_.store(en, std::memory_order_relaxed); }
     232     1356512 :     bool isEnable() { return enabled_.load(std::memory_order_relaxed); }
     233             : 
     234             : private:
     235             :     std::atomic_bool enabled_ {false};
     236             : };
     237             : 
     238             : class ConsoleLog : public Logger::Handler
     239             : {
     240             : public:
     241      389986 :     static ConsoleLog& instance()
     242             :     {
     243             :         // Intentional memory leak:
     244             :         // Some thread can still be logging even during static destructors.
     245      389986 :         static ConsoleLog* self = new ConsoleLog();
     246      389949 :         return *self;
     247             :     }
     248             : 
     249             : #ifdef _WIN32
     250             :     void printLogImpl(Logger::Msg& msg, bool with_color)
     251             :     {
     252             :         // If we are using Visual Studio, we can use OutputDebugString to print
     253             :         // to the "Output" window. Otherwise, we just use fputs to stderr.
     254             :         static std::function<void(const char* str)> fputsFunc = [](const char* str) {
     255             :             fputs(str, stderr);
     256             :         };
     257             :         static std::function<void(const char* str)> outputDebugStringFunc = [](const char* str) {
     258             :             OutputDebugStringA(str);
     259             :         };
     260             :         static std::function<void()> putcFunc = []() {
     261             :             putc(ENDL, stderr);
     262             :         };
     263             :         // These next two functions will be used to print the message and line ending.
     264             :         static auto printFunc = IsDebuggerPresent() ? outputDebugStringFunc : fputsFunc;
     265             :         static auto endlFunc = IsDebuggerPresent() ? []() { OutputDebugStringA("\n"); } : putcFunc;
     266             : 
     267             :         WORD saved_attributes;
     268             :         static HANDLE hConsole = GetStdHandle(STD_OUTPUT_HANDLE);
     269             :         auto header = msg.header();
     270             :         if (with_color) {
     271             :             static WORD color_header = CYAN;
     272             :             WORD color_prefix = LIGHT_GREEN;
     273             :             CONSOLE_SCREEN_BUFFER_INFO consoleInfo;
     274             : 
     275             :             switch (msg.level_) {
     276             :             case LOG_ERR:
     277             :                 color_prefix = RED;
     278             :                 break;
     279             : 
     280             :             case LOG_WARNING:
     281             :                 color_prefix = YELLOW;
     282             :                 break;
     283             :             }
     284             : 
     285             :             GetConsoleScreenBufferInfo(hConsole, &consoleInfo);
     286             :             saved_attributes = consoleInfo.wAttributes;
     287             :             SetConsoleTextAttribute(hConsole, color_header);
     288             : 
     289             :             printFunc(header.c_str());
     290             : 
     291             :             SetConsoleTextAttribute(hConsole, saved_attributes);
     292             :             SetConsoleTextAttribute(hConsole, color_prefix);
     293             :         } else {
     294             :             printFunc(header.c_str());
     295             :         }
     296             : 
     297             :         printFunc(msg.payload_.c_str());
     298             : 
     299             :         if (msg.linefeed_) {
     300             :             endlFunc();
     301             :         }
     302             : 
     303             :         if (with_color) {
     304             :             SetConsoleTextAttribute(hConsole, saved_attributes);
     305             :         }
     306             :     }
     307             : #else
     308      322539 :     void printLogImpl(const Logger::Msg& msg, bool with_color)
     309             :     {
     310      322539 :         auto header = msg.header();
     311      322461 :         if (with_color) {
     312      322463 :             const char* color_header = CYAN;
     313      322463 :             const char* color_prefix = "";
     314             : 
     315      322463 :             switch (msg.level_) {
     316        5880 :             case LOG_ERR:
     317        5880 :                 color_prefix = RED;
     318        5880 :                 break;
     319             : 
     320       38668 :             case LOG_WARNING:
     321       38668 :                 color_prefix = YELLOW;
     322       38668 :                 break;
     323             :             }
     324             : 
     325      322463 :             fputs(color_header, stderr);
     326      322773 :             fwrite(header.c_str(), 1, header.size(), stderr);
     327      322774 :             fputs(END_COLOR, stderr);
     328      322774 :             fputs(color_prefix, stderr);
     329             :         } else {
     330           0 :             fwrite(header.c_str(), 1, header.size(), stderr);
     331             :         }
     332             : 
     333      322772 :         fputs(msg.payload_.c_str(), stderr);
     334             : 
     335      322774 :         if (with_color) {
     336      322774 :             fputs(END_COLOR, stderr);
     337             :         }
     338      322774 :         if (msg.linefeed_) {
     339      322748 :             putc(ENDL, stderr);
     340             :         }
     341      322774 :     }
     342             : #endif /* _WIN32 */
     343             : 
     344      322548 :     void consume(Logger::Msg& msg) override
     345             :     {
     346          76 :         static bool with_color = !(getenv("NO_COLOR") || getenv("NO_COLORS") || getenv("NO_COLOUR")
     347      322624 :                                    || getenv("NO_COLOURS"));
     348             : 
     349      322548 :         printLogImpl(msg, with_color);
     350      322772 :     }
     351             : };
     352             : 
     353             : void
     354         308 : Logger::setConsoleLog(bool en)
     355             : {
     356         308 :     ConsoleLog::instance().enable(en);
     357             : #ifdef _WIN32
     358             :     static WORD original_attributes;
     359             :     if (en) {
     360             :         if (AttachConsole(ATTACH_PARENT_PROCESS) || AllocConsole()) {
     361             :             FILE *fpstdout = stdout, *fpstderr = stderr;
     362             :             freopen_s(&fpstdout, "CONOUT$", "w", stdout);
     363             :             freopen_s(&fpstderr, "CONOUT$", "w", stderr);
     364             :             // Save the original state of the console window(in case AttachConsole worked).
     365             :             CONSOLE_SCREEN_BUFFER_INFO consoleInfo;
     366             :             GetConsoleScreenBufferInfo(GetStdHandle(STD_OUTPUT_HANDLE), &consoleInfo);
     367             :             original_attributes = consoleInfo.wAttributes;
     368             :             SetConsoleCP(CP_UTF8);
     369             :             SetConsoleMode(GetStdHandle(STD_OUTPUT_HANDLE),
     370             :                            ENABLE_QUICK_EDIT_MODE | ENABLE_EXTENDED_FLAGS);
     371             :         }
     372             :     } else {
     373             :         // Restore the original state of the console window in case we attached.
     374             :         SetConsoleTextAttribute(GetStdHandle(STD_OUTPUT_HANDLE), original_attributes);
     375             :         FreeConsole();
     376             :     }
     377             : #endif
     378         308 : }
     379             : 
     380             : class SysLog : public Logger::Handler
     381             : {
     382             : public:
     383      323149 :     static SysLog& instance()
     384             :     {
     385             :         // Intentional memory leak:
     386             :         // Some thread can still be logging even during static destructors.
     387      323149 :         static SysLog* self = new SysLog();
     388      323149 :         return *self;
     389             :     }
     390             : 
     391          39 :     SysLog()
     392          39 :     {
     393             : #ifdef _WIN32
     394             :         ::openlog(LOGFILE, WINLOG_PID, WINLOG_MAIL);
     395             : #else
     396             : #ifndef __ANDROID__
     397          39 :         ::openlog(LOGFILE, LOG_NDELAY, LOG_USER);
     398             : #endif
     399             : #endif /* _WIN32 */
     400          39 :     }
     401             : 
     402      322772 :     void consume(Logger::Msg& msg) override
     403             :     {
     404             : #ifdef __ANDROID__
     405             :         __android_log_write(msg.level_, msg.file_, msg.payload_.c_str());
     406             : #else
     407      322772 :         ::syslog(msg.level_, "%.*s", (int) msg.payload_.size(), msg.payload_.data());
     408             : #endif
     409      322773 :     }
     410             : };
     411             : 
     412             : void
     413         308 : Logger::setSysLog(bool en)
     414             : {
     415         308 :     SysLog::instance().enable(en);
     416         308 : }
     417             : 
     418             : class MonitorLog : public Logger::Handler
     419             : {
     420             : public:
     421      322843 :     static MonitorLog& instance()
     422             :     {
     423             :         // Intentional memory leak
     424             :         // Some thread can still be logging even during static destructors.
     425      322843 :         static MonitorLog* self = new MonitorLog();
     426      322843 :         return *self;
     427             :     }
     428             : 
     429           0 :     void consume(Logger::Msg& msg) override
     430             :     {
     431           0 :         auto message = msg.header() + msg.payload_;
     432           0 :         emitSignal<libjami::ConfigurationSignal::MessageSend>(message);
     433           0 :     }
     434             : };
     435             : 
     436             : void
     437           0 : Logger::setMonitorLog(bool en)
     438             : {
     439           0 :     MonitorLog::instance().enable(en);
     440           0 : }
     441             : 
     442             : class FileLog : public Logger::Handler
     443             : {
     444             : public:
     445      323151 :     static FileLog& instance()
     446             :     {
     447             :         // Intentional memory leak:
     448             :         // Some thread can still be logging even during static destructors.
     449      323151 :         static FileLog* self = new FileLog();
     450      323151 :         return *self;
     451             :     }
     452             : 
     453         308 :     void setFile(const std::string& path)
     454             :     {
     455         308 :         if (thread_.joinable()) {
     456           0 :             notify([this] { enable(false); });
     457           0 :             thread_.join();
     458             :         }
     459             : 
     460         308 :         std::ofstream file;
     461         308 :         if (not path.empty()) {
     462           0 :             file.open(path, std::ofstream::out | std::ofstream::app);
     463           0 :             enable(true);
     464             :         } else {
     465         308 :             enable(false);
     466         308 :             return;
     467             :         }
     468             : 
     469           0 :         thread_ = std::thread([this, file = std::move(file)]() mutable {
     470           0 :             std::vector<Logger::Msg> pendingQ_;
     471           0 :             while (isEnable()) {
     472             :                 {
     473           0 :                     std::unique_lock lk(mtx_);
     474           0 :                     cv_.wait(lk, [&] { return not isEnable() or not currentQ_.empty(); });
     475           0 :                     if (not isEnable())
     476           0 :                         break;
     477             : 
     478           0 :                     std::swap(currentQ_, pendingQ_);
     479           0 :                 }
     480             : 
     481           0 :                 do_consume(file, pendingQ_);
     482           0 :                 pendingQ_.clear();
     483             :             }
     484           0 :             file.close();
     485           0 :         });
     486         308 :     }
     487             : 
     488           0 :     ~FileLog()
     489           0 :     {
     490           0 :         notify([=] { enable(false); });
     491           0 :         if (thread_.joinable())
     492           0 :             thread_.join();
     493           0 :     }
     494             : 
     495           0 :     void consume(Logger::Msg& msg) override
     496             :     {
     497           0 :         notify([&, this] { currentQ_.emplace_back(std::move(msg)); });
     498           0 :     }
     499             : 
     500             : private:
     501             :     template<typename T>
     502           0 :     void notify(T func)
     503             :     {
     504           0 :         std::lock_guard lk(mtx_);
     505           0 :         func();
     506           0 :         cv_.notify_one();
     507           0 :     }
     508             : 
     509           0 :     void do_consume(std::ofstream& file, const std::vector<Logger::Msg>& messages)
     510             :     {
     511           0 :         for (const auto& msg : messages) {
     512           0 :             file << msg.header() << msg.payload_;
     513           0 :             if (msg.linefeed_)
     514           0 :                 file << ENDL;
     515             :         }
     516           0 :         file.flush();
     517           0 :     }
     518             : 
     519             :     std::vector<Logger::Msg> currentQ_;
     520             :     std::mutex mtx_;
     521             :     std::condition_variable cv_;
     522             :     std::thread thread_;
     523             : };
     524             : 
     525             : void
     526           0 : Logger::setFileLog(const std::string& path)
     527             : {
     528           0 :     FileLog::instance().setFile(path);
     529           0 : }
     530             : 
     531             : LIBJAMI_PUBLIC void
     532       67073 : Logger::log(int level, const char* file, int line, bool linefeed, const char* fmt, ...)
     533             : {
     534             :     va_list ap;
     535             : 
     536       67073 :     va_start(ap, fmt);
     537             : 
     538       67073 :     vlog(level, file, line, linefeed, fmt, ap);
     539             : 
     540       67078 :     va_end(ap);
     541       67078 : }
     542             : 
     543             : template<typename T>
     544             : void
     545     1290931 : log_to_if_enabled(T& handler, Logger::Msg& msg)
     546             : {
     547     1290931 :     if (handler.isEnable()) {
     548      645349 :         handler.consume(msg);
     549             :     }
     550     1291125 : }
     551             : 
     552             : static std::atomic_bool debugEnabled_ {false};
     553             : 
     554             : void
     555         308 : Logger::setDebugMode(bool enable)
     556             : {
     557         308 :     debugEnabled_.store(enable, std::memory_order_relaxed);
     558         308 : }
     559             : 
     560             : bool
     561       83182 : Logger::debugEnabled()
     562             : {
     563       83182 :     return debugEnabled_.load(std::memory_order_relaxed);
     564             : }
     565             : 
     566             : void
     567       67072 : Logger::vlog(int level, const char* file, int line, bool linefeed, const char* fmt, va_list ap)
     568             : {
     569       67072 :     if (level < LOG_WARNING and not debugEnabled_.load(std::memory_order_relaxed)) {
     570          61 :         return;
     571             :     }
     572             : 
     573       67134 :     if (not(ConsoleLog::instance().isEnable() or SysLog::instance().isEnable()
     574          61 :             or MonitorLog::instance().isEnable() or FileLog::instance().isEnable())) {
     575          61 :         return;
     576             :     }
     577             : 
     578             :     /* Timestamp is generated here. */
     579       67008 :     Msg msg(level, file, line, linefeed, fmt, ap);
     580             : 
     581       67014 :     log_to_if_enabled(ConsoleLog::instance(), msg);
     582       67017 :     log_to_if_enabled(SysLog::instance(), msg);
     583       67017 :     log_to_if_enabled(MonitorLog::instance(), msg);
     584       67017 :     log_to_if_enabled(FileLog::instance(), msg); // Takes ownership of msg if enabled
     585       67017 : }
     586             : 
     587             : void
     588      255679 : Logger::write(int level, const char* file, int line, std::string&& message)
     589             : {
     590             :     /* Timestamp is generated here. */
     591      255679 :     Msg msg(level, file, line, true, std::move(message));
     592             : 
     593      255640 :     log_to_if_enabled(ConsoleLog::instance(), msg);
     594      255765 :     log_to_if_enabled(SysLog::instance(), msg);
     595      255765 :     log_to_if_enabled(MonitorLog::instance(), msg);
     596      255765 :     log_to_if_enabled(FileLog::instance(), msg); // Takes ownership of msg if enabled
     597      255765 : }
     598             : 
     599             : void
     600         308 : Logger::fini()
     601             : {
     602             :     // Force close on file and join thread
     603         308 :     FileLog::instance().setFile({});
     604             : 
     605             : #ifdef _WIN32
     606             :     Logger::setConsoleLog(false);
     607             : #endif /* _WIN32 */
     608         308 : }
     609             : 
     610             : } // namespace jami

Generated by: LCOV version 1.14