Line data Source code
1 : // Copyright (c) 2013-2022 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 3 : private_logger::~private_logger()
170 : {
171 1 : delete_thread();
172 2 : }
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 0 : appender_factory_t private_logger::appender_factory_list() const
204 : {
205 0 : return f_appender_factories;
206 : }
207 :
208 :
209 2 : appender::pointer_t private_logger::create_appender(std::string const & type, std::string const & name)
210 : {
211 4 : guard g;
212 :
213 2 : auto it(f_appender_factories.find(type));
214 2 : if(it != f_appender_factories.end())
215 : {
216 1 : return it->second->create(name);
217 : }
218 :
219 1 : return appender::pointer_t();
220 : }
221 :
222 :
223 : /** \brief Get a component by name.
224 : *
225 : * All components are stored in the f_components set managed by the
226 : * private_logger object instance. This way each component is unique.
227 : *
228 : * This function searches the list of existing components. If one with
229 : * the same name already exists, then that one is picked and returned.
230 : * If it doesn't exist yet, then a new component is created and that
231 : * new component's pointer is saved in the f_components list and
232 : * returned.
233 : *
234 : * The name of the components must be composed of letters (a-z),
235 : * underscores (_), and digits (0-9). Any other character is considered
236 : * invalid. The function will force uppercase characters (A-Z) to lowercase
237 : * and dashes (-) to underscores (_). Finally, a component name can't start
238 : * with a digit (0-9).
239 : *
240 : * \exception invalid_parameter
241 : * This function raises an invalid_parameter exception when it find an
242 : * invalid character in the input name.
243 : *
244 : * \param[in] name The name of the component to retrieve.
245 : *
246 : * \return The pointer to the component named \p name.
247 : */
248 63 : component::pointer_t private_logger::get_component(std::string const & name)
249 : {
250 126 : guard g;
251 :
252 126 : std::string n;
253 63 : n.reserve(name.length());
254 547 : for(char const * s(name.c_str()); *s != '\0'; ++s)
255 : {
256 484 : if(*s >= 'a' && *s <= 'z')
257 : {
258 460 : n += *s;
259 : }
260 24 : else if(*s >= 'A' && *s <= 'Z')
261 : {
262 : // force to lowercase
263 : //
264 0 : n += *s | 0x20;
265 : }
266 24 : else if(*s == '-' || *s == '_')
267 : {
268 2 : n += '_';
269 : }
270 22 : else if(*s >= '0' && *s <= '9')
271 : {
272 22 : if(n.empty())
273 : {
274 : throw invalid_parameter(
275 : "a component name cannot start with a digits ("
276 0 : + name
277 0 : + ")");
278 : }
279 22 : n += *s;
280 : }
281 : else
282 : {
283 : throw invalid_parameter(
284 : "a component name cannot include a '"
285 0 : + *s
286 0 : + ("' character ("
287 0 : + name
288 0 : + ")"));
289 : }
290 : }
291 :
292 63 : auto it(f_components.find(n));
293 63 : if(it != f_components.end())
294 : {
295 39 : return it->second;
296 : }
297 :
298 : // the component constructor is only accessible to the private_logger
299 : // so we can't do a make_shared<>()
300 : //
301 : //auto comp(std::make_shared<component>(n));
302 :
303 24 : f_components[n].reset(new component(n));
304 :
305 24 : return f_components[n];
306 : }
307 :
308 :
309 23 : format::pointer_t private_logger::get_default_format()
310 : {
311 46 : guard g;
312 :
313 23 : if(f_default_format == nullptr)
314 : {
315 2 : f_default_format = std::make_shared<format>(
316 : //"${env:name=HOME:padding='-':align=center:exact_width=6} "
317 : "${date} ${time} ${hostname}"
318 : " ${progname}[${pid}]: ${severity}:"
319 : " ${message:escape:max_width=1000}"
320 : " (in function \"${function}()\")"
321 : " (${basename}:${line})"
322 1 : );
323 : }
324 :
325 46 : return f_default_format;
326 : }
327 :
328 :
329 99165 : environment::pointer_t private_logger::create_environment()
330 : {
331 99165 : pid_t const tid(cppthread::gettid());
332 :
333 198330 : guard g;
334 :
335 99165 : auto it(f_environment.find(tid));
336 99165 : if(it == f_environment.end())
337 : {
338 4 : auto result(std::make_shared<environment>(tid));
339 2 : f_environment[tid] = result;
340 2 : return result;
341 : }
342 :
343 99163 : return it->second;
344 : }
345 :
346 :
347 : /** \brief Add a severity.
348 : *
349 : * This function adds a severity to the private logger object.
350 : *
351 : * Remember that a severity can be given aliases so this function may
352 : * add quite a few entries, not just one.
353 : *
354 : * To add an alias after creation, make sure to use the add_alias() instead.
355 : * This makes sure you link the same severity to several names.
356 : *
357 : * \warning
358 : * You should not be calling this function directly. Please see the
359 : * direct snaplogger::add_severity() function instead.
360 : *
361 : * \exception duplicate_error
362 : * The function verifies that the new severity is not a duplicate of
363 : * an existing system severity. The verification process checks the
364 : * severity by severity level and by name. You can, however, have
365 : * _duplicates_ of user defined severity levels. However, the last
366 : * user defined severity of a given name & level sticks, the others
367 : * get deleted.
368 : *
369 : * \param[in] sev The severity object to be added.
370 : */
371 30 : void private_logger::add_severity(severity::pointer_t sev)
372 : {
373 60 : guard g;
374 :
375 30 : auto it(f_severity_by_severity.find(sev->get_severity()));
376 30 : if(it != f_severity_by_severity.end())
377 : {
378 2 : if(it->second->is_system())
379 : {
380 : throw duplicate_error("a system severity ("
381 4 : + std::to_string(static_cast<long>(it->first))
382 6 : + ") cannot be replaced (same severity level: "
383 8 : + std::to_string(static_cast<long>(sev->get_severity()))
384 6 : + ").");
385 : }
386 : }
387 :
388 72 : for(auto const & n : sev->get_all_names())
389 : {
390 44 : auto s(f_severity_by_name.find(n));
391 44 : if(s != f_severity_by_name.end())
392 : {
393 2 : if(s->second->is_system())
394 : {
395 : // note that any severity can be partially edited, just not
396 : // added more than once
397 : //
398 : throw duplicate_error("a system severity ("
399 4 : + n
400 6 : + ") cannot be replaced (same name).");
401 : }
402 : }
403 : }
404 :
405 26 : sev->mark_as_registered();
406 :
407 26 : f_severity_by_severity[sev->get_severity()] = sev;
408 :
409 68 : for(auto const & n : sev->get_all_names())
410 : {
411 42 : f_severity_by_name[n] = sev;
412 : }
413 26 : }
414 :
415 :
416 : /** \brief Add yet another alias.
417 : *
418 : * This function is used when the system aliases get assigned additional
419 : * aliases. The add_severity() was already called with system definitions,
420 : * so this is the only way to add additional aliases to them trhough the .ini
421 : * files.
422 : *
423 : * \param[in] sev A pointer to the severity to be added.
424 : * \param[in] name The name of the alias.
425 : */
426 1 : void private_logger::add_alias(severity::pointer_t sev, std::string const & name)
427 : {
428 2 : guard g;
429 :
430 1 : auto it(f_severity_by_severity.find(sev->get_severity()));
431 1 : if(it == f_severity_by_severity.end())
432 : {
433 : throw duplicate_error("to register an alias the corresponding main severity must already be registered. We could not find a severity with level "
434 0 : + std::to_string(static_cast<long>(sev->get_severity()))
435 0 : + ".");
436 : }
437 :
438 1 : auto s(f_severity_by_name.find(name));
439 1 : if(s != f_severity_by_name.end())
440 : {
441 0 : if(s->second->is_system())
442 : {
443 : // note that any severity can be partially edited, just not
444 : // added more than once
445 : //
446 : throw duplicate_error("a system severity ("
447 0 : + name
448 0 : + ") cannot be replaced (same name).");
449 : }
450 : }
451 :
452 1 : f_severity_by_name[name] = sev;
453 1 : }
454 :
455 :
456 12 : severity::pointer_t private_logger::get_severity(std::string const & name) const
457 : {
458 24 : guard g;
459 :
460 24 : std::string n(name);
461 12 : std::transform(n.begin(), n.end(), n.begin(), std::towlower);
462 12 : auto it(f_severity_by_name.find(n));
463 12 : if(it == f_severity_by_name.end())
464 : {
465 5 : return severity::pointer_t();
466 : }
467 :
468 7 : return it->second;
469 : }
470 :
471 :
472 39 : severity::pointer_t private_logger::get_severity(severity_t sev) const
473 : {
474 78 : guard g;
475 :
476 39 : auto it(f_severity_by_severity.find(sev));
477 39 : if(it == f_severity_by_severity.end())
478 : {
479 2 : return severity::pointer_t();
480 : }
481 :
482 37 : return it->second;
483 : }
484 :
485 :
486 0 : severity::pointer_t private_logger::get_default_severity() const
487 : {
488 0 : return f_default_severity;
489 : }
490 :
491 :
492 0 : void private_logger::set_default_severity(severity::pointer_t sev)
493 : {
494 0 : f_default_severity = sev;
495 0 : }
496 :
497 :
498 : /** \brief Get the list of currently defined severities.
499 : *
500 : * This function gets the list of all the severities sorted by name.
501 : *
502 : * Note that some severities are given multiple names (i.e. "info" and
503 : * "information"). In that case, both names will appear in this list.
504 : * If you want to avoid such duplicates, use the get_severities_by_severity().
505 : *
506 : * \note
507 : * The function return the map by copy so that way it works in a
508 : * multithreaded environment. However, the pointer is a set of pointers
509 : * to severities. Those pointers are not duplicated.
510 : *
511 : * \return A copy of the current severity list.
512 : *
513 : * \sa get_severities_by_name()
514 : */
515 0 : severity_by_name_t private_logger::get_severities_by_name() const
516 : {
517 : // this call is required in case the severities were not yet defined
518 : //
519 0 : snapdev::NOT_USED(snaplogger::get_severity("error")); // TODO: assuming that "error" won't change
520 :
521 0 : guard g;
522 :
523 0 : return f_severity_by_name;
524 : }
525 :
526 :
527 0 : severity_by_severity_t private_logger::get_severities_by_severity() const
528 : {
529 : // this call is required in case the severities were not yet defined
530 : //
531 0 : snapdev::NOT_USED(snaplogger::get_severity("error")); // TODO: assuming that "error" won't change
532 :
533 0 : guard g;
534 :
535 0 : return f_severity_by_severity;
536 : }
537 :
538 :
539 33 : void private_logger::set_diagnostic(std::string const & key, std::string const & diagnostic)
540 : {
541 66 : guard g;
542 :
543 33 : f_map_diagnostics[key] = diagnostic;
544 33 : }
545 :
546 :
547 1 : void private_logger::unset_diagnostic(std::string const & key)
548 : {
549 2 : guard g;
550 :
551 1 : auto it(f_map_diagnostics.find(key));
552 1 : if(it != f_map_diagnostics.end())
553 : {
554 1 : f_map_diagnostics.erase(it);
555 : }
556 1 : }
557 :
558 :
559 35 : map_diagnostics_t private_logger::get_map_diagnostics()
560 : {
561 70 : guard g;
562 :
563 70 : return f_map_diagnostics;
564 : }
565 :
566 :
567 0 : void private_logger::set_maximum_trace_diagnostics(size_t max)
568 : {
569 0 : f_maximum_trace_diagnostics = max;
570 0 : }
571 :
572 :
573 0 : size_t private_logger::get_maximum_trace_diagnostics() const
574 : {
575 0 : return f_maximum_trace_diagnostics;
576 : }
577 :
578 :
579 0 : void private_logger::add_trace_diagnostic(std::string const & diagnostic)
580 : {
581 0 : guard g;
582 :
583 0 : f_trace_diagnostics.push_back(diagnostic);
584 0 : if(f_trace_diagnostics.size() > f_maximum_trace_diagnostics)
585 : {
586 0 : f_trace_diagnostics.pop_front();
587 : }
588 0 : }
589 :
590 :
591 0 : void private_logger::clear_trace_diagnostics()
592 : {
593 0 : guard g;
594 :
595 0 : f_trace_diagnostics.clear();
596 0 : }
597 :
598 :
599 0 : trace_diagnostics_t private_logger::get_trace_diagnostics()
600 : {
601 0 : guard g;
602 :
603 0 : return f_trace_diagnostics;
604 : }
605 :
606 :
607 3 : void private_logger::push_nested_diagnostic(std::string const & diagnostic)
608 : {
609 6 : guard g;
610 :
611 3 : f_nested_diagnostics.push_back(diagnostic);
612 3 : }
613 :
614 :
615 3 : void private_logger::pop_nested_diagnostic()
616 : {
617 6 : guard g;
618 :
619 3 : f_nested_diagnostics.pop_back();
620 3 : }
621 :
622 :
623 4 : string_vector_t private_logger::get_nested_diagnostics() const
624 : {
625 8 : guard g;
626 :
627 8 : return f_nested_diagnostics;
628 : }
629 :
630 :
631 65 : void private_logger::register_variable_factory(variable_factory::pointer_t factory)
632 : {
633 130 : guard g;
634 :
635 65 : auto it(f_variable_factories.find(factory->get_type()));
636 65 : if(it != f_variable_factories.end())
637 : {
638 : throw duplicate_error(
639 : "trying to add two variable factories of type \""
640 2 : + factory->get_type()
641 3 : + "\".");
642 : }
643 :
644 64 : f_variable_factories[factory->get_type()] = factory;
645 64 : }
646 :
647 :
648 221 : variable::pointer_t private_logger::get_variable(std::string const & type)
649 : {
650 442 : guard g;
651 :
652 221 : if(f_variable_factories.empty())
653 : {
654 : throw invalid_variable("No variable factories were registered yet; you can't create a variable with type \"" // LCOV_EXCL_LINE
655 : + type // LCOV_EXCL_LINE
656 : + "\" at this point."); // LCOV_EXCL_LINE
657 : }
658 :
659 221 : auto it(f_variable_factories.find(type));
660 221 : if(it == f_variable_factories.end())
661 : {
662 : // TBD: should we instead return a null var.?
663 : throw invalid_variable("You can't create variable with type \""
664 2 : + type
665 3 : + "\", no such variable type was registered.");
666 : }
667 :
668 440 : return it->second->create_variable();
669 : }
670 :
671 :
672 48661 : bool private_logger::has_functions() const
673 : {
674 97322 : guard g;
675 :
676 97322 : return !f_functions.empty();
677 : }
678 :
679 :
680 23 : void private_logger::register_function(function::pointer_t func)
681 : {
682 46 : guard g;
683 :
684 23 : auto it(f_functions.find(func->get_name()));
685 23 : if(it != f_functions.end())
686 : {
687 : throw duplicate_error(
688 : "trying to add two functions named \""
689 2 : + func->get_name()
690 3 : + "\".");
691 : }
692 22 : f_functions[func->get_name()] = func;
693 22 : }
694 :
695 :
696 149 : function::pointer_t private_logger::get_function(std::string const & name) const
697 : {
698 298 : guard g;
699 :
700 149 : auto it(f_functions.find(name));
701 149 : if(it != f_functions.end())
702 : {
703 109 : return it->second;
704 : }
705 :
706 40 : return function::pointer_t();
707 : }
708 :
709 :
710 1 : void private_logger::create_thread()
711 : {
712 2 : guard g;
713 :
714 : try
715 : {
716 1 : f_fifo = std::make_shared<message_fifo_t>();
717 1 : f_asynchronous_logger = std::make_shared<detail::asynchronous_logger>(f_fifo);
718 1 : f_thread = std::make_shared<cppthread::thread>("asynchronous logger thread", f_asynchronous_logger.get());
719 1 : f_thread->start();
720 : }
721 : catch(...) // LCOV_EXCL_LINE
722 : {
723 : if(f_fifo != nullptr) // LCOV_EXCL_LINE
724 : {
725 : f_fifo->done(false); // LCOV_EXCL_LINE
726 : }
727 :
728 : f_thread.reset(); // LCOV_EXCL_LINE
729 : f_asynchronous_logger.reset(); // LCOV_EXCL_LINE
730 : f_fifo.reset(); // LCOV_EXCL_LINE
731 : throw; // LCOV_EXCL_LINE
732 : }
733 1 : }
734 :
735 :
736 4 : void private_logger::delete_thread()
737 : {
738 : // WARNING: we can't call fifo::done() while our guard is locked
739 : // we also have to make sure it's not a null pointer
740 : //
741 8 : message_fifo_t::pointer_t fifo = message_fifo_t::pointer_t();
742 8 : asynchronous_logger_pointer_t asynchronous_logger = asynchronous_logger_pointer_t();
743 8 : cppthread::thread::pointer_t thread = cppthread::thread::pointer_t();
744 :
745 : {
746 8 : guard g;
747 :
748 4 : swap(thread, f_thread);
749 4 : swap(asynchronous_logger, f_asynchronous_logger);
750 4 : swap(fifo, f_fifo);
751 : }
752 :
753 4 : if(fifo != nullptr)
754 : {
755 1 : fifo->done(false);
756 : }
757 :
758 : try
759 : {
760 4 : thread.reset();
761 : }
762 : catch(std::exception const & e)
763 : {
764 : // in most cases this one happens when quitting when one of your
765 : // functions attempts to get an instance of the logger, which is
766 : // forbidden once you return from your main() function
767 : //
768 : std::cerr << "got exception \""
769 : << e.what()
770 : << "\" while deleting the asynchronous thread."
771 : << std::endl;
772 : }
773 4 : }
774 :
775 :
776 1 : void private_logger::send_message_to_thread(message::pointer_t msg)
777 : {
778 : {
779 2 : guard g;
780 :
781 1 : if(f_fifo == nullptr)
782 : {
783 1 : create_thread();
784 : }
785 : }
786 :
787 1 : f_fifo->push_back(msg);
788 1 : }
789 :
790 :
791 :
792 :
793 99674 : private_logger::pointer_t get_private_logger()
794 : {
795 99674 : return std::dynamic_pointer_cast<private_logger>(logger::get_instance());
796 : }
797 :
798 :
799 48716 : private_logger::pointer_t get_private_logger(message const & msg)
800 : {
801 48716 : return std::dynamic_pointer_cast<private_logger>(msg.get_logger());
802 : }
803 :
804 :
805 :
806 6 : } // snaplogger namespace
807 : // vim: ts=4 sw=4 et
|