Line data Source code
1 : // Copyright (c) 2013-2021 Made to Order Software Corp. All Rights Reserved
2 : //
3 : // https://snapwebsites.org/project/snaplogger
4 : // contact@m2osw.com
5 : //
6 : // This program is free software; you can redistribute it and/or modify
7 : // it under the terms of the GNU General Public License as published by
8 : // the Free Software Foundation; either version 2 of the License, or
9 : // (at your option) any later version.
10 : //
11 : // This program is distributed in the hope that it will be useful,
12 : // but WITHOUT ANY WARRANTY; without even the implied warranty of
13 : // MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
14 : // GNU General Public License for more details.
15 : //
16 : // You should have received a copy of the GNU General Public License along
17 : // with this program; if not, write to the Free Software Foundation, Inc.,
18 : // 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
19 :
20 : /** \file
21 : * \brief Appenders are used to append data to somewhere.
22 : *
23 : * This file declares the base appender class.
24 : */
25 :
26 : // self
27 : //
28 : #include "snaplogger/private_logger.h"
29 :
30 : #include "snaplogger/console_appender.h"
31 : #include "snaplogger/exception.h"
32 : #include "snaplogger/file_appender.h"
33 : #include "snaplogger/guard.h"
34 : #include "snaplogger/logger.h"
35 : #include "snaplogger/syslog_appender.h"
36 :
37 :
38 : // cppthread lib
39 : //
40 : #include <cppthread/log.h>
41 : #include <cppthread/runner.h>
42 :
43 :
44 : // last include
45 : //
46 : #include <snapdev/poison.h>
47 :
48 :
49 :
50 : namespace snaplogger
51 : {
52 :
53 :
54 : namespace
55 : {
56 :
57 :
58 :
59 2 : void getopt_logs(cppthread::log_level_t l, std::string const & m)
60 : {
61 2 : severity_t sev(severity_t::SEVERITY_ERROR);
62 2 : switch(l)
63 : {
64 0 : case cppthread::log_level_t::debug:
65 0 : sev = severity_t::SEVERITY_DEBUG;
66 0 : break;
67 :
68 2 : case cppthread::log_level_t::info:
69 2 : sev = severity_t::SEVERITY_INFORMATION;
70 2 : break;
71 :
72 0 : case cppthread::log_level_t::warning:
73 0 : sev = severity_t::SEVERITY_WARNING;
74 0 : break;
75 :
76 0 : case cppthread::log_level_t::fatal:
77 0 : sev = severity_t::SEVERITY_FATAL;
78 0 : break;
79 :
80 : //case cppthread::log_level_t::error:
81 0 : default:
82 : // anything else, keep SEVERITY_ERROR
83 0 : break;
84 :
85 : }
86 :
87 4 : message msg(sev, __FILE__, __func__, __LINE__);
88 :
89 : // we do not use the g_... names in case they were not yet allocated
90 : //
91 2 : msg.add_component(get_component(COMPONENT_NORMAL));
92 2 : msg.add_component(get_component(COMPONENT_CPPTHREAD));
93 :
94 2 : msg << m;
95 :
96 : // this call cannot create a loop, if the creation of the logger
97 : // generates an cppthread log, then the second call will generate
98 : // an exception (see get_instance() in snaplogger/logger.cpp)
99 : //
100 4 : logger::pointer_t lg(logger::get_instance());
101 :
102 2 : lg->log_message(msg);
103 2 : }
104 :
105 :
106 :
107 : }
108 : // no name namespace
109 :
110 :
111 : namespace detail
112 : {
113 :
114 :
115 :
116 :
117 1 : class asynchronous_logger
118 : : public cppthread::runner
119 : {
120 : public:
121 1 : asynchronous_logger(message_fifo_t::pointer_t fifo)
122 1 : : runner("logger asynchronous thread")
123 2 : , f_logger(logger::get_instance())
124 3 : , f_fifo(fifo)
125 : {
126 1 : }
127 :
128 2 : virtual void run()
129 : {
130 : // loop until the FIFO is marked as being done
131 : //
132 : for(;;)
133 : {
134 3 : message::pointer_t msg;
135 2 : if(!f_fifo->pop_front(msg, -1))
136 : {
137 1 : break;
138 : }
139 2 : logger::pointer_t l(f_logger.lock());
140 1 : if(l != nullptr)
141 : {
142 1 : l->process_message(*msg);
143 : }
144 1 : }
145 1 : }
146 :
147 : private:
148 : logger::weak_pointer_t f_logger = logger::pointer_t();
149 : message_fifo_t::pointer_t f_fifo = message_fifo_t::pointer_t();
150 : };
151 :
152 :
153 :
154 : }
155 : // detail namespace
156 :
157 :
158 :
159 2 : private_logger::private_logger()
160 : {
161 : // if a call arrives really early, this is defined in the logger
162 : //
163 2 : f_normal_component = get_component(COMPONENT_NORMAL);
164 :
165 2 : cppthread::set_log_callback(getopt_logs);
166 2 : }
167 :
168 :
169 6 : private_logger::~private_logger()
170 : {
171 2 : delete_thread();
172 4 : }
173 :
174 :
175 2 : void private_logger::shutdown()
176 : {
177 2 : delete_thread();
178 2 : }
179 :
180 :
181 8 : void private_logger::register_appender_factory(appender_factory::pointer_t factory)
182 : {
183 8 : if(factory == nullptr)
184 : {
185 : throw logger_logic_error( // LCOV_EXCL_LINE
186 : "register_appender_factory() called with a nullptr."); // LCOV_EXCL_LINE
187 : }
188 :
189 16 : guard g;
190 :
191 8 : if(f_appender_factories.find(factory->get_type()) != f_appender_factories.end())
192 : {
193 : throw duplicate_error( // LCOV_EXCL_LINE
194 : "trying to register appender type \"" // LCOV_EXCL_LINE
195 : + factory->get_type() // LCOV_EXCL_LINE
196 : + "\" twice won't work."); // LCOV_EXCL_LINE
197 : }
198 :
199 8 : f_appender_factories[factory->get_type()] = factory;
200 8 : }
201 :
202 :
203 2 : appender::pointer_t private_logger::create_appender(std::string const & type, std::string const & name)
204 : {
205 4 : guard g;
206 :
207 2 : auto it(f_appender_factories.find(type));
208 2 : if(it != f_appender_factories.end())
209 : {
210 1 : return it->second->create(name);
211 : }
212 :
213 1 : return appender::pointer_t();
214 : }
215 :
216 :
217 : /** \brief Get a component by name.
218 : *
219 : * All components are stored in the f_components set managed by the
220 : * private_logger object instance. This way each component is unique.
221 : *
222 : * This function searches the list of existing components. If one with
223 : * the same name already exists, then that one is picked and returned.
224 : * If it doesn't exist yet, then a new component is created and that
225 : * new component's pointer is saved in the f_components list and
226 : * returned.
227 : *
228 : * The name of the components must be composed of letters (a-z),
229 : * underscores (_), and digits (0-9). Any other character is considered
230 : * invalid. The function will force uppercase characters (A-Z) to lowercase
231 : * and dashes (-) to underscores (_). Finally, a component name can't start
232 : * with a digit (0-9).
233 : *
234 : * \exception invalid_parameter
235 : * This function raises an invalid_parameter exception when it find an
236 : * invalid character in the input name.
237 : *
238 : * \param[in] name The name of the component to retrieve.
239 : *
240 : * \return The pointer to the component named \p name.
241 : */
242 58 : component::pointer_t private_logger::get_component(std::string const & name)
243 : {
244 116 : guard g;
245 :
246 116 : std::string n;
247 58 : n.reserve(name.length());
248 494 : for(char const * s(name.c_str()); *s != '\0'; ++s)
249 : {
250 436 : if(*s >= 'a' && *s <= 'z')
251 : {
252 414 : n += *s;
253 : }
254 22 : else if(*s >= 'A' && *s <= 'Z')
255 : {
256 : // force to lowercase
257 : //
258 0 : n += *s | 0x20;
259 : }
260 22 : else if(*s == '-' || *s == '_')
261 : {
262 0 : n += '_';
263 : }
264 22 : else if(*s >= '0' && *s <= '9')
265 : {
266 22 : if(n.empty())
267 : {
268 : throw invalid_parameter(
269 : "a component name cannot start with a digits ("
270 0 : + name
271 0 : + ")");
272 : }
273 22 : n += *s;
274 : }
275 : else
276 : {
277 : throw invalid_parameter(
278 : "a component name cannot include a '"
279 0 : + *s
280 0 : + ("' character ("
281 0 : + name
282 0 : + ")"));
283 : }
284 : }
285 :
286 58 : auto it(f_components.find(n));
287 58 : if(it != f_components.end())
288 : {
289 36 : return it->second;
290 : }
291 :
292 : // the component constructor is only accessible to the private_logger
293 : // so we can't do a make_shared<>()
294 : //
295 : //auto comp(std::make_shared<component>(n));
296 :
297 22 : f_components[n].reset(new component(n));
298 :
299 22 : return f_components[n];
300 : }
301 :
302 :
303 20 : format::pointer_t private_logger::get_default_format()
304 : {
305 40 : guard g;
306 :
307 20 : if(f_default_format == nullptr)
308 : {
309 2 : f_default_format = std::make_shared<format>(
310 : //"${env:name=HOME:padding='-':align=center:exact_width=6} "
311 : "${date} ${time} ${hostname}"
312 : " ${progname}[${pid}]: ${severity}:"
313 : " ${message:escape:max_width=1000}"
314 : " (in function \"${function}()\")"
315 : " (${basename}:${line})"
316 1 : );
317 : }
318 :
319 40 : return f_default_format;
320 : }
321 :
322 :
323 97893 : environment::pointer_t private_logger::create_environment()
324 : {
325 97893 : pid_t const tid(cppthread::gettid());
326 :
327 195786 : guard g;
328 :
329 97893 : auto it(f_environment.find(tid));
330 97893 : if(it == f_environment.end())
331 : {
332 4 : auto result(std::make_shared<environment>(tid));
333 2 : f_environment[tid] = result;
334 2 : return result;
335 : }
336 :
337 97891 : return it->second;
338 : }
339 :
340 :
341 : /** \brief Add a severity.
342 : *
343 : * This function adds a severity to the private logger object.
344 : *
345 : * Remember that a severity can be given aliases so this function may
346 : * add quite a few entries, not just one.
347 : *
348 : * To add an alias after creation, make sure to use the add_alias() instead.
349 : * This makes sure you link the same severity to several names.
350 : *
351 : * \warning
352 : * You should not be calling this function directly. Please see the
353 : * direct snaplogger::add_severity() function instead.
354 : *
355 : * \exception duplicate_error
356 : * The function verifies that the new severity is not a duplicate of
357 : * an existing system severity. The verification process checks the
358 : * severity by severity level and by name. You can, however, have
359 : * _duplicates_ of user defined severity levels. However, the last
360 : * user defined severity of a given name & level sticks, the others
361 : * get deleted.
362 : *
363 : * \param[in] sev The severity object to be added.
364 : */
365 25 : void private_logger::add_severity(severity::pointer_t sev)
366 : {
367 50 : guard g;
368 :
369 25 : auto it(f_severity_by_severity.find(sev->get_severity()));
370 25 : if(it != f_severity_by_severity.end())
371 : {
372 2 : if(it->second->is_system())
373 : {
374 : throw duplicate_error("a system severity ("
375 4 : + std::to_string(static_cast<long>(it->first))
376 6 : + ") cannot be replaced (same severity level: "
377 8 : + std::to_string(static_cast<long>(sev->get_severity()))
378 6 : + ").");
379 : }
380 : }
381 :
382 60 : for(auto const & n : sev->get_all_names())
383 : {
384 37 : auto s(f_severity_by_name.find(n));
385 37 : if(s != f_severity_by_name.end())
386 : {
387 2 : if(s->second->is_system())
388 : {
389 : // note that any severity can be partially edited, just not
390 : // added more than once
391 : //
392 : throw duplicate_error("a system severity ("
393 4 : + n
394 6 : + ") cannot be replaced (same name).");
395 : }
396 : }
397 : }
398 :
399 21 : sev->mark_as_registered();
400 :
401 21 : f_severity_by_severity[sev->get_severity()] = sev;
402 :
403 56 : for(auto const & n : sev->get_all_names())
404 : {
405 35 : f_severity_by_name[n] = sev;
406 : }
407 21 : }
408 :
409 :
410 : /** \brief Add yet another alias.
411 : *
412 : * This function is used when the system aliases get assigned additional
413 : * aliases. The add_severity() was already called with system definitions,
414 : * so this is the only way to add additional aliases to them trhough the .ini
415 : * files.
416 : *
417 : * \param[in] sev A pointer to the severity to be added.
418 : * \param[in] name The name of the alias.
419 : */
420 2 : void private_logger::add_alias(severity::pointer_t sev, std::string const & name)
421 : {
422 4 : guard g;
423 :
424 2 : auto it(f_severity_by_severity.find(sev->get_severity()));
425 2 : if(it == f_severity_by_severity.end())
426 : {
427 : throw duplicate_error("to register an alias the corresponding main severity must already be registered. We could not find a severity with level "
428 0 : + std::to_string(static_cast<long>(sev->get_severity()))
429 0 : + ".");
430 : }
431 :
432 2 : auto s(f_severity_by_name.find(name));
433 2 : if(s != f_severity_by_name.end())
434 : {
435 0 : if(s->second->is_system())
436 : {
437 : // note that any severity can be partially edited, just not
438 : // added more than once
439 : //
440 : throw duplicate_error("a system severity ("
441 0 : + name
442 0 : + ") cannot be replaced (same name).");
443 : }
444 : }
445 :
446 2 : f_severity_by_name[name] = sev;
447 2 : }
448 :
449 :
450 30 : severity::pointer_t private_logger::get_severity(std::string const & name) const
451 : {
452 60 : guard g;
453 :
454 60 : std::string n(name);
455 30 : std::transform(n.begin(), n.end(), n.begin(), std::towlower);
456 30 : auto it(f_severity_by_name.find(n));
457 30 : if(it == f_severity_by_name.end())
458 : {
459 5 : return severity::pointer_t();
460 : }
461 :
462 25 : return it->second;
463 : }
464 :
465 :
466 43 : severity::pointer_t private_logger::get_severity(severity_t sev) const
467 : {
468 86 : guard g;
469 :
470 43 : auto it(f_severity_by_severity.find(sev));
471 43 : if(it == f_severity_by_severity.end())
472 : {
473 2 : return severity::pointer_t();
474 : }
475 :
476 41 : return it->second;
477 : }
478 :
479 :
480 0 : severity::pointer_t private_logger::get_default_severity() const
481 : {
482 0 : return f_default_severity;
483 : }
484 :
485 :
486 1 : void private_logger::set_default_severity(severity::pointer_t sev)
487 : {
488 1 : f_default_severity = sev;
489 1 : }
490 :
491 :
492 : /** \brief Get the list of currently defined severities.
493 : *
494 : * This function gets the list of all the severities sorted by name.
495 : *
496 : * Note that some severities are given multiple names (i.e. "info" and
497 : * "information"). In that case, both names will appear in this list.
498 : * If you want to avoid such duplicates, use the get_severities_by_severity().
499 : *
500 : * \note
501 : * The function return the map by copy so that way it works in a
502 : * multithreaded environment. However, the pointer is a set of pointers
503 : * to severities. Those pointers are not duplicated.
504 : *
505 : * \return A copy of the current severity list.
506 : *
507 : * \sa get_severities_by_name()
508 : */
509 0 : severity_by_name_t private_logger::get_severities_by_name() const
510 : {
511 : // this call is required in case the severities were not yet defined
512 : //
513 0 : snapdev::NOT_USED(snaplogger::get_severity("error")); // TODO: assuming that "error" won't change
514 :
515 0 : guard g;
516 :
517 0 : return f_severity_by_name;
518 : }
519 :
520 :
521 0 : severity_by_severity_t private_logger::get_severities_by_severity() const
522 : {
523 : // this call is required in case the severities were not yet defined
524 : //
525 0 : snapdev::NOT_USED(snaplogger::get_severity("error")); // TODO: assuming that "error" won't change
526 :
527 0 : guard g;
528 :
529 0 : return f_severity_by_severity;
530 : }
531 :
532 :
533 28 : void private_logger::set_diagnostic(std::string const & key, std::string const & diagnostic)
534 : {
535 56 : guard g;
536 :
537 28 : f_map_diagnostics[key] = diagnostic;
538 28 : }
539 :
540 :
541 1 : void private_logger::unset_diagnostic(std::string const & key)
542 : {
543 2 : guard g;
544 :
545 1 : auto it(f_map_diagnostics.find(key));
546 1 : if(it != f_map_diagnostics.end())
547 : {
548 1 : f_map_diagnostics.erase(it);
549 : }
550 1 : }
551 :
552 :
553 46 : map_diagnostics_t private_logger::get_map_diagnostics()
554 : {
555 92 : guard g;
556 :
557 92 : return f_map_diagnostics;
558 : }
559 :
560 :
561 0 : void private_logger::set_maximum_trace_diagnostics(size_t max)
562 : {
563 0 : f_maximum_trace_diagnostics = max;
564 0 : }
565 :
566 :
567 0 : size_t private_logger::get_maximum_trace_diagnostics() const
568 : {
569 0 : return f_maximum_trace_diagnostics;
570 : }
571 :
572 :
573 0 : void private_logger::add_trace_diagnostic(std::string const & diagnostic)
574 : {
575 0 : guard g;
576 :
577 0 : f_trace_diagnostics.push_back(diagnostic);
578 0 : if(f_trace_diagnostics.size() > f_maximum_trace_diagnostics)
579 : {
580 0 : f_trace_diagnostics.pop_front();
581 : }
582 0 : }
583 :
584 :
585 0 : void private_logger::clear_trace_diagnostics()
586 : {
587 0 : guard g;
588 :
589 0 : f_trace_diagnostics.clear();
590 0 : }
591 :
592 :
593 0 : trace_diagnostics_t private_logger::get_trace_diagnostics()
594 : {
595 0 : guard g;
596 :
597 0 : return f_trace_diagnostics;
598 : }
599 :
600 :
601 3 : void private_logger::push_nested_diagnostic(std::string const & diagnostic)
602 : {
603 6 : guard g;
604 :
605 3 : f_nested_diagnostics.push_back(diagnostic);
606 3 : }
607 :
608 :
609 3 : void private_logger::pop_nested_diagnostic()
610 : {
611 6 : guard g;
612 :
613 3 : f_nested_diagnostics.pop_back();
614 3 : }
615 :
616 :
617 8 : string_vector_t private_logger::get_nested_diagnostics() const
618 : {
619 16 : guard g;
620 :
621 16 : return f_nested_diagnostics;
622 : }
623 :
624 :
625 63 : void private_logger::register_variable_factory(variable_factory::pointer_t factory)
626 : {
627 126 : guard g;
628 :
629 63 : auto it(f_variable_factories.find(factory->get_type()));
630 63 : if(it != f_variable_factories.end())
631 : {
632 : throw duplicate_error(
633 : "trying to add two variable factories of type \""
634 2 : + factory->get_type()
635 3 : + "\".");
636 : }
637 :
638 62 : f_variable_factories[factory->get_type()] = factory;
639 62 : }
640 :
641 :
642 230 : variable::pointer_t private_logger::get_variable(std::string const & type)
643 : {
644 460 : guard g;
645 :
646 230 : if(f_variable_factories.empty())
647 : {
648 : throw invalid_variable("No variable factories were registered yet; you can't create a variable with type \"" // LCOV_EXCL_LINE
649 : + type // LCOV_EXCL_LINE
650 : + "\" at this point."); // LCOV_EXCL_LINE
651 : }
652 :
653 230 : auto it(f_variable_factories.find(type));
654 230 : if(it == f_variable_factories.end())
655 : {
656 : // TBD: should we instead return a null var.?
657 : throw invalid_variable("You can't create variable with type \""
658 2 : + type
659 3 : + "\", no such variable type was registered.");
660 : }
661 :
662 458 : return it->second->create_variable();
663 : }
664 :
665 :
666 49015 : bool private_logger::has_functions() const
667 : {
668 98030 : guard g;
669 :
670 98030 : return !f_functions.empty();
671 : }
672 :
673 :
674 23 : void private_logger::register_function(function::pointer_t func)
675 : {
676 46 : guard g;
677 :
678 23 : auto it(f_functions.find(func->get_name()));
679 23 : if(it != f_functions.end())
680 : {
681 : throw duplicate_error(
682 : "trying to add two functions named \""
683 2 : + func->get_name()
684 3 : + "\".");
685 : }
686 22 : f_functions[func->get_name()] = func;
687 22 : }
688 :
689 :
690 152 : function::pointer_t private_logger::get_function(std::string const & name) const
691 : {
692 304 : guard g;
693 :
694 152 : auto it(f_functions.find(name));
695 152 : if(it != f_functions.end())
696 : {
697 109 : return it->second;
698 : }
699 :
700 43 : return function::pointer_t();
701 : }
702 :
703 :
704 1 : void private_logger::create_thread()
705 : {
706 2 : guard g;
707 :
708 : try
709 : {
710 1 : f_fifo = std::make_shared<message_fifo_t>();
711 1 : f_asynchronous_logger = std::make_shared<detail::asynchronous_logger>(f_fifo);
712 1 : f_thread = std::make_shared<cppthread::thread>("asynchronous logger thread", f_asynchronous_logger.get());
713 1 : f_thread->start();
714 : }
715 : catch(...) // LCOV_EXCL_LINE
716 : {
717 : if(f_fifo != nullptr) // LCOV_EXCL_LINE
718 : {
719 : f_fifo->done(false); // LCOV_EXCL_LINE
720 : }
721 :
722 : f_thread.reset(); // LCOV_EXCL_LINE
723 : f_asynchronous_logger.reset(); // LCOV_EXCL_LINE
724 : f_fifo.reset(); // LCOV_EXCL_LINE
725 : throw; // LCOV_EXCL_LINE
726 : }
727 1 : }
728 :
729 :
730 5 : void private_logger::delete_thread()
731 : {
732 : // WARNING: we can't call fifo::done() while our guard is locked
733 : // we also have to make sure it's not a null pointer
734 : //
735 10 : message_fifo_t::pointer_t fifo = message_fifo_t::pointer_t();
736 10 : asynchronous_logger_pointer_t asynchronous_logger = asynchronous_logger_pointer_t();
737 10 : cppthread::thread::pointer_t thread = cppthread::thread::pointer_t();
738 :
739 : {
740 10 : guard g;
741 :
742 5 : swap(thread, f_thread);
743 5 : swap(asynchronous_logger, f_asynchronous_logger);
744 5 : swap(fifo, f_fifo);
745 : }
746 :
747 5 : if(fifo != nullptr)
748 : {
749 1 : fifo->done(false);
750 : }
751 :
752 : try
753 : {
754 5 : thread.reset();
755 : }
756 : catch(std::exception const & e)
757 : {
758 : // in most cases this one happens when quitting when one of your
759 : // functions attempts to get an instance of the logger, which is
760 : // forbidden once you return from your main() function
761 : //
762 : std::cerr << "got exception \""
763 : << e.what()
764 : << "\" while deleting the asynchronous thread."
765 : << std::endl;
766 : }
767 5 : }
768 :
769 :
770 1 : void private_logger::send_message_to_thread(message::pointer_t msg)
771 : {
772 : {
773 2 : guard g;
774 :
775 1 : if(f_fifo == nullptr)
776 : {
777 1 : create_thread();
778 : }
779 : }
780 :
781 1 : f_fifo->push_back(msg);
782 1 : }
783 :
784 :
785 :
786 :
787 98410 : private_logger::pointer_t get_private_logger()
788 : {
789 98410 : return std::dynamic_pointer_cast<private_logger>(logger::get_instance());
790 : }
791 :
792 :
793 49088 : private_logger::pointer_t get_private_logger(message const & msg)
794 : {
795 49088 : return std::dynamic_pointer_cast<private_logger>(msg.get_logger());
796 : }
797 :
798 :
799 :
800 6 : } // snaplogger namespace
801 : // vim: ts=4 sw=4 et
|