Line data Source code
1 : /*
2 : * Copyright (c) 2006-2019 Made to Order Software Corp. All Rights Reserved
3 : *
4 : * https://snapwebsites.org/project/snaplogger
5 : * contact@m2osw.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 2 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 along
18 : * with this program; if not, write to the Free Software Foundation, Inc.,
19 : * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
20 : */
21 :
22 : // self
23 : //
24 : #include "main.h"
25 :
26 :
27 : // snaplogger lib
28 : //
29 : #include <snaplogger/buffer_appender.h>
30 : #include <snaplogger/exception.h>
31 : #include <snaplogger/format.h>
32 : #include <snaplogger/logger.h>
33 : #include <snaplogger/map_diagnostic.h>
34 : #include <snaplogger/message.h>
35 : #include <snaplogger/severity.h>
36 : #include <snaplogger/version.h>
37 :
38 :
39 : // C lib
40 : //
41 : #include <unistd.h>
42 :
43 :
44 :
45 4 : CATCH_TEST_CASE("not_a_message", "[message]")
46 : {
47 4 : CATCH_START_SECTION("Call send_message() with wrong ostream")
48 : {
49 1 : CATCH_REQUIRE_THROWS_MATCHES(
50 : snaplogger::send_message(std::cout)
51 : , snaplogger::not_a_message
52 : , Catch::Matchers::ExceptionMessage(
53 : "the 'out' parameter to the send_message() function is expected to be a snaplogger::message object."));
54 : }
55 : CATCH_END_SECTION()
56 :
57 4 : CATCH_START_SECTION("Print snaplogger::secure to wrong ostream")
58 : {
59 2 : std::stringstream buffer;
60 1 : std::streambuf * old(std::cout.rdbuf(buffer.rdbuf()));
61 1 : std::cout << snaplogger::secure << std::endl;
62 1 : CATCH_REQUIRE(buffer.str() == "(section:secure)\n");
63 1 : std::cout.rdbuf(old);
64 : }
65 : CATCH_END_SECTION()
66 2 : }
67 :
68 :
69 :
70 4 : CATCH_TEST_CASE("message_capture", "[message]")
71 : {
72 4 : CATCH_START_SECTION("Message Buffering")
73 : {
74 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "message-logging");
75 :
76 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
77 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
78 :
79 1 : CATCH_REQUIRE(buffer->get_type() == "buffer");
80 :
81 1 : advgetopt::options_environment opt_env;
82 1 : opt_env.f_project_name = "test-logger";
83 2 : advgetopt::getopt opts(opt_env);
84 1 : buffer->set_config(opts);
85 :
86 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${message}"));
87 1 : buffer->set_format(f);
88 :
89 1 : l->add_appender(buffer);
90 :
91 1 : SNAP_LOG_ERROR << "Logging this error" << SNAP_LOG_SEND;
92 1 : CATCH_REQUIRE(buffer->str() == "Logging this error\n");
93 :
94 : // test the other str() function too
95 : //
96 1 : buffer->str("Start: ");
97 :
98 : // show that the "\n" does not get duplicated
99 : //
100 1 : SNAP_LOG_ERROR << "Error with newline\n" << SNAP_LOG_SEND;
101 1 : CATCH_REQUIRE(buffer->str() == "Start: Error with newline\n");
102 1 : buffer->clear();
103 :
104 : // show that the "\r\n" gets replaced by "\n"
105 : //
106 1 : SNAP_LOG_ERROR << "Error with CRLF\r\n" << SNAP_LOG_SEND;
107 1 : CATCH_REQUIRE(buffer->str() == "Error with CRLF\n");
108 1 : buffer->clear();
109 :
110 : // severity too low, no change to buffer
111 : //
112 1 : SNAP_LOG_DEBUG << "Debug Message " << M_PI << " which does not make it at all...\n" << SNAP_LOG_SEND;
113 1 : CATCH_REQUIRE(buffer->empty());
114 :
115 1 : l->reset();
116 : }
117 : CATCH_END_SECTION()
118 :
119 4 : CATCH_START_SECTION("JSON Buffering")
120 : {
121 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "json-logging");
122 :
123 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
124 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("json-buffer"));
125 :
126 1 : CATCH_REQUIRE(buffer->get_type() == "buffer");
127 :
128 1 : advgetopt::options_environment opt_env;
129 1 : opt_env.f_project_name = "json-logger";
130 2 : advgetopt::getopt opts(opt_env);
131 1 : buffer->set_config(opts);
132 :
133 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>(
134 : "{\"version\":1,"
135 2 : "\"message\":\"${message:escape='\\\r\n\t\"'}\"}"));
136 1 : buffer->set_format(f);
137 :
138 1 : l->add_appender(buffer);
139 :
140 1 : SNAP_LOG_ERROR << "A JSON error message" << SNAP_LOG_SEND;
141 1 : CATCH_REQUIRE(buffer->str() == "{\"version\":1,\"message\":\"A JSON error message\"}\n");
142 1 : buffer->clear();
143 :
144 : // show that the "\n" does not get duplicated
145 : //
146 1 : SNAP_LOG_ERROR << "See what happens with a \"quoted string\" within the message\n" << SNAP_LOG_SEND;
147 1 : CATCH_REQUIRE(buffer->str() == "{\"version\":1,\"message\":\"See what happens with a \\\"quoted string\\\" within the message\"}\n");
148 1 : buffer->clear();
149 :
150 1 : l->reset();
151 : }
152 : CATCH_END_SECTION()
153 2 : }
154 :
155 :
156 3 : CATCH_TEST_CASE("message_copy", "[message]")
157 : {
158 2 : CATCH_START_SECTION("Copy Message")
159 : {
160 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "message-copying");
161 :
162 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
163 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
164 :
165 1 : CATCH_REQUIRE(buffer->get_type() == "buffer");
166 :
167 1 : advgetopt::options_environment opt_env;
168 1 : opt_env.f_project_name = "test-logger";
169 2 : advgetopt::getopt opts(opt_env);
170 1 : buffer->set_config(opts);
171 :
172 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${message}"));
173 1 : buffer->set_format(f);
174 :
175 1 : l->add_appender(buffer);
176 :
177 1 : int const line_number = __LINE__;
178 : snaplogger::message::pointer_t msg(std::make_shared<snaplogger::message>
179 2 : (::snaplogger::severity_t::SEVERITY_ERROR, __FILE__, __func__, line_number));
180 :
181 1 : CATCH_REQUIRE(msg->get_filename() == __FILE__);
182 1 : CATCH_REQUIRE(msg->get_function() == __func__);
183 1 : CATCH_REQUIRE(msg->get_line() == line_number);
184 :
185 1 : msg->set_filename("logger.cpp");
186 1 : msg->set_function("magical");
187 1 : msg->set_line(701);
188 :
189 1 : CATCH_REQUIRE(msg->get_filename() == "logger.cpp");
190 1 : CATCH_REQUIRE(msg->get_function() == "magical");
191 1 : CATCH_REQUIRE(msg->get_line() == 701);
192 :
193 1 : *msg << "Logging an error.";
194 :
195 1 : CATCH_REQUIRE(msg->str() == "Logging an error.");
196 :
197 2 : snaplogger::message::pointer_t copy(std::make_shared<snaplogger::message>(*msg, *msg));
198 :
199 1 : CATCH_REQUIRE(msg->str() == "Logging an error.");
200 1 : CATCH_REQUIRE(copy->str() == "Logging an error.");
201 :
202 : // no destructor called, the output is still empty
203 : //
204 1 : CATCH_REQUIRE(buffer->empty());
205 :
206 1 : copy.reset();
207 :
208 : // msg not lost
209 : //
210 1 : CATCH_REQUIRE(msg->str() == "Logging an error.");
211 :
212 : // destructor against copy does not trigger send_message()
213 : //
214 1 : CATCH_REQUIRE(buffer->empty());
215 :
216 1 : snaplogger::send_message(*msg);
217 :
218 : // now we get the message as expected!
219 : //
220 : // (note that internally we can skip receiving the message on the
221 : // original, but not as a client... we may want to have the ability
222 : // to cancel a message, though.)
223 : //
224 1 : CATCH_REQUIRE(buffer->str() == "Logging an error.\n");
225 :
226 1 : msg.reset();
227 :
228 1 : CATCH_REQUIRE(buffer->str() == "Logging an error.\n");
229 :
230 1 : l->reset();
231 : }
232 : CATCH_END_SECTION()
233 1 : }
234 :
235 :
236 4 : CATCH_TEST_CASE("message_severity", "[message][severity]")
237 : {
238 4 : CATCH_START_SECTION("Appender vs Message severity")
239 : {
240 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "message-severity");
241 :
242 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
243 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
244 :
245 1 : advgetopt::options_environment opt_env;
246 1 : opt_env.f_project_name = "test-logger";
247 2 : advgetopt::getopt opts(opt_env);
248 1 : buffer->set_config(opts);
249 :
250 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${message}"));
251 1 : buffer->set_format(f);
252 :
253 1 : l->add_appender(buffer);
254 :
255 1 : int const min_severity(static_cast<int>(snaplogger::severity_t::SEVERITY_MIN));
256 1 : int const max_severity(static_cast<int>(snaplogger::severity_t::SEVERITY_MAX));
257 257 : for(int i(min_severity); i <= max_severity; ++i)
258 : {
259 256 : buffer->set_severity(static_cast<snaplogger::severity_t>(i));
260 65792 : for(int j(min_severity); j <= max_severity; ++j)
261 : {
262 : snaplogger::send_message(
263 : ::snaplogger::message(
264 : static_cast<::snaplogger::severity_t>(j)
265 : , __FILE__
266 : , __func__
267 : , __LINE__
268 65536 : ) << "The message itself");
269 :
270 65536 : if(j >= i
271 32896 : && i != static_cast<int>(snaplogger::severity_t::SEVERITY_OFF)
272 32895 : && j != static_cast<int>(snaplogger::severity_t::SEVERITY_OFF))
273 : {
274 32640 : CATCH_REQUIRE(buffer->str() == "The message itself\n");
275 : }
276 : else
277 : {
278 32896 : CATCH_REQUIRE(buffer->empty());
279 : }
280 65536 : buffer->clear();
281 : }
282 : }
283 :
284 1 : l->reset();
285 : }
286 : CATCH_END_SECTION()
287 :
288 4 : CATCH_START_SECTION("Changing message severity (takes about 3.5min)")
289 : {
290 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "message-copying");
291 :
292 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
293 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
294 :
295 1 : advgetopt::options_environment opt_env;
296 1 : opt_env.f_project_name = "test-logger";
297 2 : advgetopt::getopt opts(opt_env);
298 1 : buffer->set_config(opts);
299 :
300 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${message}"));
301 1 : buffer->set_format(f);
302 :
303 1 : l->add_appender(buffer);
304 :
305 1 : int const min_severity(static_cast<int>(snaplogger::severity_t::SEVERITY_MIN));
306 1 : int const max_severity(static_cast<int>(snaplogger::severity_t::SEVERITY_MAX));
307 30 : for(int i(min_severity); i <= max_severity; i += 1 + (rand() & 15))
308 : {
309 29 : buffer->set_severity(static_cast<snaplogger::severity_t>(i));
310 911 : for(int j(min_severity); j <= max_severity; j += 1 + (rand() & 15))
311 : {
312 27914 : for(int k(min_severity); k <= max_severity; k += 1 + (rand() & 15))
313 : {
314 : ::snaplogger::message::pointer_t msg(std::make_shared<::snaplogger::message>(
315 : static_cast<::snaplogger::severity_t>(j)
316 : , __FILE__
317 : , __func__
318 : , __LINE__
319 54064 : ));
320 27032 : *msg << "Start of message";
321 27032 : msg->set_severity(static_cast<::snaplogger::severity_t>(k));
322 27032 : *msg << " -- end of message";
323 27032 : snaplogger::send_message(*msg);
324 : //std::cerr << "checking with " << i << ", " << j << ", " << k << "\n";
325 :
326 27032 : if(j >= i
327 12322 : && k >= i
328 8184 : && i != static_cast<int>(snaplogger::severity_t::SEVERITY_OFF)
329 8184 : && j != static_cast<int>(snaplogger::severity_t::SEVERITY_OFF))
330 : //&& k != static_cast<int>(snaplogger::severity_t::SEVERITY_OFF))
331 : {
332 8160 : if(j >= i)
333 : {
334 8160 : CATCH_REQUIRE(buffer->str() == "Start of message -- end of message\n");
335 : }
336 : else
337 : {
338 0 : CATCH_REQUIRE(buffer->str() == "Start of message\n");
339 8160 : }
340 : }
341 : else
342 : {
343 18872 : CATCH_REQUIRE(buffer->empty());
344 : }
345 27032 : buffer->clear();
346 : }
347 : }
348 : }
349 :
350 1 : l->reset();
351 : }
352 : CATCH_END_SECTION()
353 2 : }
354 :
355 :
356 6 : CATCH_TEST_CASE("message_format", "[message][format]")
357 : {
358 8 : CATCH_START_SECTION("Message is Recursive")
359 : {
360 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "basic-format");
361 :
362 : // these two are not called in this test
363 : //
364 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROJECT_NAME, "test-logger");
365 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_VERSION, "5.32.1024");
366 :
367 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
368 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
369 :
370 1 : advgetopt::options_environment opt_env;
371 1 : opt_env.f_project_name = "test-logger";
372 1 : opt_env.f_version = "5.32.1024";
373 2 : advgetopt::getopt opts(opt_env);
374 1 : buffer->set_config(opts);
375 :
376 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${project_name} ${message} v${version}"));
377 1 : buffer->set_format(f);
378 :
379 1 : l->add_appender(buffer);
380 :
381 : SNAP_LOG_WARNING
382 2 : << "Message Project Name = ${project_name} and Version = ${version} -- uses \"recursive\""
383 1 : << SNAP_LOG_SEND;
384 :
385 1 : CATCH_REQUIRE(buffer->str() ==
386 : "test-logger Message Project Name = test-logger and"
387 : " Version = 5.32.1024 -- uses \"recursive\" v5.32.1024"
388 : "\n");
389 :
390 1 : l->reset();
391 : }
392 : CATCH_END_SECTION()
393 :
394 8 : CATCH_START_SECTION("${message} itself is not recursive")
395 : {
396 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "prevent-infinite-loop");
397 :
398 : // these two are not called in this test
399 : //
400 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROJECT_NAME, "test-logger");
401 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_VERSION, "5.32.1024");
402 :
403 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
404 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
405 :
406 1 : advgetopt::options_environment opt_env;
407 1 : opt_env.f_project_name = "test-logger";
408 1 : opt_env.f_version = "5.32.1024";
409 2 : advgetopt::getopt opts(opt_env);
410 1 : buffer->set_config(opts);
411 :
412 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${project_name} ${message} v${version}"));
413 1 : buffer->set_format(f);
414 :
415 1 : l->add_appender(buffer);
416 :
417 : SNAP_LOG_WARNING
418 2 : << "Message ${message} says: Project Name = ${project_name} and Version = ${version} -- uses \"recursive\""
419 1 : << SNAP_LOG_SEND;
420 :
421 1 : CATCH_REQUIRE(buffer->str() ==
422 : "test-logger Message says: Project Name = test-logger and"
423 : " Version = 5.32.1024 -- uses \"recursive\" v5.32.1024"
424 : "\n");
425 :
426 1 : l->reset();
427 : }
428 : CATCH_END_SECTION()
429 :
430 8 : CATCH_START_SECTION("${pid} uses the get_environment() function")
431 : {
432 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "get-environment");
433 :
434 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
435 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
436 :
437 1 : advgetopt::options_environment opt_env;
438 2 : advgetopt::getopt opts(opt_env);
439 1 : buffer->set_config(opts);
440 :
441 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${message}"));
442 1 : buffer->set_format(f);
443 :
444 1 : l->add_appender(buffer);
445 :
446 : SNAP_LOG_WARNING
447 2 : << "Test PID = ${pid} == ${pid:running}"
448 1 : << SNAP_LOG_SEND;
449 :
450 1 : CATCH_REQUIRE(buffer->str() ==
451 : "Test PID = " + std::to_string(getpid())
452 : + " == " + std::to_string(getpid())
453 : + "\n");
454 :
455 1 : l->reset();
456 : }
457 : CATCH_END_SECTION()
458 :
459 8 : CATCH_START_SECTION("Verify year")
460 : {
461 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "get-environment");
462 :
463 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
464 1 : CATCH_REQUIRE(l->get_appender("test-buffer") == nullptr);
465 :
466 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
467 :
468 1 : advgetopt::options_environment opt_env;
469 2 : advgetopt::getopt opts(opt_env);
470 1 : buffer->set_config(opts);
471 :
472 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${message}"));
473 1 : buffer->set_format(f);
474 :
475 1 : l->add_appender(buffer);
476 :
477 1 : CATCH_REQUIRE(l->get_appender("test-buffer") == buffer);
478 :
479 : // we create a message so we can check the timestamp in our test
480 : //
481 : snaplogger::message::pointer_t msg(std::make_shared<snaplogger::message>
482 2 : (::snaplogger::severity_t::SEVERITY_ERROR, __FILE__, __func__, __LINE__));
483 1 : *msg << "Created message on YYYY = ${date:year}, MM = ${date:month}, DD = ${date:day}";
484 :
485 1 : timespec const stamp(msg->get_timestamp());
486 :
487 1 : snaplogger::send_message(*msg);
488 :
489 : tm t;
490 1 : gmtime_r(&stamp.tv_sec, &t);
491 : char year[16];
492 : char month[16];
493 : char day[16];
494 1 : strftime(year, 16, "%Y", &t);
495 1 : strftime(month, 16, "%m", &t);
496 1 : strftime(day, 16, "%d", &t);
497 :
498 1 : CATCH_REQUIRE(buffer->str() ==
499 : std::string("Created message on YYYY = ")
500 : + year
501 : + ", MM = "
502 : + std::to_string(std::atoi(month)) // remove the leading '0' if necessary
503 : + ", DD = "
504 : + std::to_string(std::atoi(day)) // remove the leading '0' if necessary
505 : + "\n");
506 :
507 1 : l->reset();
508 : }
509 : CATCH_END_SECTION()
510 4 : }
511 :
512 :
513 3 : CATCH_TEST_CASE("message_component_filter", "[message][component]")
514 : {
515 2 : CATCH_START_SECTION("Filter Message with Component")
516 : {
517 1 : snaplogger::set_diagnostic(snaplogger::DIAG_KEY_PROGNAME, "component-filter");
518 :
519 2 : snaplogger::logger::pointer_t l(snaplogger::logger::get_instance());
520 2 : snaplogger::buffer_appender::pointer_t buffer(std::make_shared<snaplogger::buffer_appender>("test-buffer"));
521 :
522 1 : advgetopt::options_environment opt_env;
523 2 : advgetopt::getopt opts(opt_env);
524 1 : buffer->set_config(opts);
525 :
526 2 : snaplogger::format::pointer_t f(std::make_shared<snaplogger::format>("${message}"));
527 1 : buffer->set_format(f);
528 :
529 1 : l->add_appender(buffer);
530 :
531 : SNAP_LOG_WARNING
532 2 : << snaplogger::secure // mark as a secure message
533 1 : << "This message is secure but not the buffer"
534 1 : << SNAP_LOG_SEND;
535 :
536 1 : CATCH_REQUIRE(buffer->empty());
537 :
538 : SNAP_LOG_WARNING
539 2 : << "Test number: "
540 1 : << 2
541 1 : << " with buffer still unsecure..."
542 1 : << SNAP_LOG_SEND_SECURELY; // mark at the end
543 :
544 1 : CATCH_REQUIRE(buffer->empty());
545 :
546 : // mark the buffer as a secure buffer now
547 : //
548 1 : buffer->add_component(snaplogger::g_secure_component);
549 :
550 : SNAP_LOG_WARNING
551 2 : << snaplogger::secure // mark as a secure message
552 1 : << "This message is secure and so is the buffer"
553 1 : << SNAP_LOG_SEND;
554 :
555 1 : CATCH_REQUIRE(buffer->str() == "This message is secure and so is the buffer\n");
556 :
557 1 : buffer->clear();
558 :
559 : SNAP_LOG_WARNING
560 2 : << "Test number: "
561 1 : << 4
562 1 : << " with secure buffer..."
563 1 : << SNAP_LOG_SEND_SECURELY; // mark at the end
564 :
565 1 : CATCH_REQUIRE(buffer->str() == "Test number: 4 with secure buffer...\n");
566 :
567 1 : l->reset();
568 : }
569 : CATCH_END_SECTION()
570 7 : }
571 :
572 :
573 :
574 : // vim: ts=4 sw=4 et
|