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