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 814889 : stripDirName(const char* path)
118 : {
119 814889 : if (path) {
120 709344 : const char* occur = strrchr(path, DIR_SEPARATOR_CH);
121 709344 : return occur ? occur + 1 : path;
122 105545 : } else return nullptr;
123 : }
124 :
125 : std::string
126 460174 : formatHeader(const char* const file, int line)
127 : {
128 : #ifdef __linux__
129 460174 : 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 460515 : if (!gettimeofday(&tv, NULL)) {
137 460512 : secs = tv.tv_sec;
138 460512 : milli = tv.tv_usec / 1000; // suppose that milli < 1000
139 : } else {
140 0 : secs = time(NULL);
141 0 : milli = 0;
142 : }
143 :
144 460512 : if (file) {
145 354738 : return fmt::format(FMT_COMPILE("[{: >3d}.{:0<3d}|{: >4}|{: <24s}:{: <4d}] "),
146 : secs,
147 : milli,
148 : tid,
149 709068 : stripDirName(file),
150 354267 : line);
151 : } else {
152 316891 : return fmt::format(FMT_COMPILE("[{: >3d}.{:0<3d}|{: >4}] "), secs, milli, tid);
153 : }
154 : }
155 :
156 : std::string
157 69236 : formatPrintfArgs(const char* format, va_list ap)
158 : {
159 69236 : std::string ret;
160 : /* A good guess of what we might encounter. */
161 : static constexpr size_t default_buf_size = 80;
162 :
163 69238 : ret.resize(default_buf_size);
164 :
165 : /* Necessary if we don't have enough space in buf. */
166 : va_list cp;
167 69247 : va_copy(cp, ap);
168 :
169 69247 : int size = vsnprintf(ret.data(), ret.size(), format, ap);
170 :
171 : /* Not enough space? Well try again. */
172 69243 : if ((size_t) size >= ret.size()) {
173 14397 : ret.resize(size + 1);
174 14397 : vsnprintf((char*) ret.data(), ret.size(), format, cp);
175 : }
176 :
177 69247 : ret.resize(size);
178 :
179 69241 : va_end(cp);
180 :
181 138482 : return ret;
182 0 : }
183 :
184 : struct Logger::Msg
185 : {
186 : Msg() = delete;
187 :
188 391079 : Msg(int level, const char* file, int line, bool linefeed, std::string&& message)
189 391079 : : file_(stripDirName(file))
190 391084 : , line_(line)
191 391084 : , payload_(std::move(message))
192 391087 : , level_(level)
193 391087 : , linefeed_(linefeed)
194 391087 : {}
195 :
196 69230 : Msg(int level, const char* file, int line, bool linefeed, const char* fmt, va_list ap)
197 69230 : : file_(stripDirName(file))
198 69236 : , line_(line)
199 69236 : , payload_(formatPrintfArgs(fmt, ap))
200 69241 : , level_(level)
201 69241 : , linefeed_(linefeed)
202 69241 : {}
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 460157 : inline std::string header() const {
214 460157 : 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 1908349 : 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 529847 : static ConsoleLog& instance()
242 : {
243 : // Intentional memory leak:
244 : // Some thread can still be logging even during static destructors.
245 529847 : static ConsoleLog* self = new ConsoleLog();
246 529842 : 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 460172 : void printLogImpl(const Logger::Msg& msg, bool with_color)
309 : {
310 460172 : auto header = msg.header();
311 459812 : if (with_color) {
312 459817 : const char* color_header = CYAN;
313 459817 : const char* color_prefix = "";
314 :
315 459817 : switch (msg.level_) {
316 5870 : case LOG_ERR:
317 5870 : color_prefix = RED;
318 5870 : break;
319 :
320 39995 : case LOG_WARNING:
321 39995 : color_prefix = YELLOW;
322 39995 : break;
323 : }
324 :
325 459817 : fputs(color_header, stderr);
326 460545 : fwrite(header.c_str(), 1, header.size(), stderr);
327 460546 : fputs(END_COLOR, stderr);
328 460547 : fputs(color_prefix, stderr);
329 : } else {
330 0 : fwrite(header.c_str(), 1, header.size(), stderr);
331 : }
332 :
333 460545 : fputs(msg.payload_.c_str(), stderr);
334 :
335 460547 : if (with_color) {
336 460547 : fputs(END_COLOR, stderr);
337 : }
338 460544 : if (msg.linefeed_) {
339 460530 : putc(ENDL, stderr);
340 : }
341 460545 : }
342 : #endif /* _WIN32 */
343 :
344 460163 : void consume(Logger::Msg& msg) override
345 : {
346 76 : static bool with_color = !(getenv("NO_COLOR") || getenv("NO_COLORS") || getenv("NO_COLOUR")
347 460239 : || getenv("NO_COLOURS"));
348 :
349 460163 : printLogImpl(msg, with_color);
350 460542 : }
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 460920 : static SysLog& instance()
384 : {
385 : // Intentional memory leak:
386 : // Some thread can still be logging even during static destructors.
387 460920 : static SysLog* self = new SysLog();
388 460921 : 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 460545 : 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 460545 : ::syslog(msg.level_, "%.*s", (int) msg.payload_.size(), msg.payload_.data());
408 : #endif
409 460547 : }
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 460616 : static MonitorLog& instance()
422 : {
423 : // Intentional memory leak
424 : // Some thread can still be logging even during static destructors.
425 460616 : static MonitorLog* self = new MonitorLog();
426 460616 : 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 460924 : static FileLog& instance()
446 : {
447 : // Intentional memory leak:
448 : // Some thread can still be logging even during static destructors.
449 460924 : static FileLog* self = new FileLog();
450 460924 : 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 69304 : Logger::log(int level, const char* file, int line, bool linefeed, const char* fmt, ...)
533 : {
534 : va_list ap;
535 :
536 69304 : va_start(ap, fmt);
537 :
538 69304 : vlog(level, file, line, linefeed, fmt, ap);
539 :
540 69310 : va_end(ap);
541 69310 : }
542 :
543 : template<typename T>
544 : void
545 1841900 : log_to_if_enabled(T& handler, Logger::Msg& msg)
546 : {
547 1841900 : if (handler.isEnable()) {
548 920736 : handler.consume(msg);
549 : }
550 1842214 : }
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 212131 : Logger::debugEnabled()
562 : {
563 212131 : return debugEnabled_.load(std::memory_order_relaxed);
564 : }
565 :
566 : void
567 69302 : Logger::vlog(int level, const char* file, int line, bool linefeed, const char* fmt, va_list ap)
568 : {
569 69302 : if (level < LOG_WARNING and not debugEnabled_.load(std::memory_order_relaxed)) {
570 61 : return;
571 : }
572 :
573 69360 : 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 69227 : Msg msg(level, file, line, linefeed, fmt, ap);
580 :
581 69241 : log_to_if_enabled(ConsoleLog::instance(), msg);
582 69249 : log_to_if_enabled(SysLog::instance(), msg);
583 69249 : log_to_if_enabled(MonitorLog::instance(), msg);
584 69249 : log_to_if_enabled(FileLog::instance(), msg); // Takes ownership of msg if enabled
585 69249 : }
586 :
587 : void
588 391111 : Logger::write(int level, const char* file, int line, std::string&& message)
589 : {
590 : /* Timestamp is generated here. */
591 391111 : Msg msg(level, file, line, true, std::move(message));
592 :
593 391074 : log_to_if_enabled(ConsoleLog::instance(), msg);
594 391303 : log_to_if_enabled(SysLog::instance(), msg);
595 391306 : log_to_if_enabled(MonitorLog::instance(), msg);
596 391306 : log_to_if_enabled(FileLog::instance(), msg); // Takes ownership of msg if enabled
597 391305 : }
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
|