xref: /freebsd/contrib/kyua/utils/logging/operations_test.cpp (revision 911f0260390e18cf85f3dbf2c719b593efdc1e3c)
1 // Copyright 2011 The Kyua Authors.
2 // All rights reserved.
3 //
4 // Redistribution and use in source and binary forms, with or without
5 // modification, are permitted provided that the following conditions are
6 // met:
7 //
8 // * Redistributions of source code must retain the above copyright
9 //   notice, this list of conditions and the following disclaimer.
10 // * Redistributions in binary form must reproduce the above copyright
11 //   notice, this list of conditions and the following disclaimer in the
12 //   documentation and/or other materials provided with the distribution.
13 // * Neither the name of Google Inc. nor the names of its contributors
14 //   may be used to endorse or promote products derived from this software
15 //   without specific prior written permission.
16 //
17 // THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
18 // "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
19 // LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
20 // A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
21 // OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
22 // SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
23 // LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
24 // DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
25 // THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
26 // (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
27 // OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
28 
29 #include "utils/logging/operations.hpp"
30 
31 extern "C" {
32 #include <unistd.h>
33 }
34 
35 #include <fstream>
36 #include <string>
37 
38 #include <atf-c++.hpp>
39 
40 #include "utils/datetime.hpp"
41 #include "utils/format/macros.hpp"
42 #include "utils/fs/operations.hpp"
43 #include "utils/fs/path.hpp"
44 
45 namespace datetime = utils::datetime;
46 namespace fs = utils::fs;
47 namespace logging = utils::logging;
48 
49 
50 ATF_TEST_CASE_WITHOUT_HEAD(generate_log_name__before_log);
51 ATF_TEST_CASE_BODY(generate_log_name__before_log)
52 {
53     datetime::set_mock_now(2011, 2, 21, 18, 10, 0, 0);
54     ATF_REQUIRE_EQ(fs::path("/some/dir/foobar.20110221-181000.log"),
55                    logging::generate_log_name(fs::path("/some/dir"), "foobar"));
56 
57     datetime::set_mock_now(2011, 2, 21, 18, 10, 1, 987654);
58     logging::log(logging::level_info, "file", 123, "A message");
59 
60     datetime::set_mock_now(2011, 2, 21, 18, 10, 2, 123);
61     ATF_REQUIRE_EQ(fs::path("/some/dir/foobar.20110221-181000.log"),
62                    logging::generate_log_name(fs::path("/some/dir"), "foobar"));
63 }
64 
65 
66 ATF_TEST_CASE_WITHOUT_HEAD(generate_log_name__after_log);
67 ATF_TEST_CASE_BODY(generate_log_name__after_log)
68 {
69     datetime::set_mock_now(2011, 2, 21, 18, 15, 0, 0);
70     logging::log(logging::level_info, "file", 123, "A message");
71     datetime::set_mock_now(2011, 2, 21, 18, 15, 1, 987654);
72     logging::log(logging::level_info, "file", 123, "A message");
73 
74     datetime::set_mock_now(2011, 2, 21, 18, 15, 2, 123);
75     ATF_REQUIRE_EQ(fs::path("/some/dir/foobar.20110221-181500.log"),
76                    logging::generate_log_name(fs::path("/some/dir"), "foobar"));
77 
78     datetime::set_mock_now(2011, 2, 21, 18, 15, 3, 1);
79     logging::log(logging::level_info, "file", 123, "A message");
80 
81     datetime::set_mock_now(2011, 2, 21, 18, 15, 4, 91);
82     ATF_REQUIRE_EQ(fs::path("/some/dir/foobar.20110221-181500.log"),
83                    logging::generate_log_name(fs::path("/some/dir"), "foobar"));
84 }
85 
86 
87 ATF_TEST_CASE_WITHOUT_HEAD(log);
88 ATF_TEST_CASE_BODY(log)
89 {
90     logging::set_inmemory();
91 
92     datetime::set_mock_now(2011, 2, 21, 18, 10, 0, 0);
93     logging::log(logging::level_debug, "f1", 1, "Debug message");
94 
95     datetime::set_mock_now(2011, 2, 21, 18, 10, 1, 987654);
96     logging::log(logging::level_error, "f2", 2, "Error message");
97 
98     logging::set_persistency("debug", fs::path("test.log"));
99 
100     datetime::set_mock_now(2011, 2, 21, 18, 10, 2, 123);
101     logging::log(logging::level_info, "f3", 3, "Info message");
102 
103     datetime::set_mock_now(2011, 2, 21, 18, 10, 3, 456);
104     logging::log(logging::level_warning, "f4", 4, "Warning message");
105 
106     std::ifstream input("test.log");
107     ATF_REQUIRE(input);
108 
109     const pid_t pid = ::getpid();
110 
111     std::string line;
112     ATF_REQUIRE(std::getline(input, line).good());
113     ATF_REQUIRE_EQ(
114         (F("20110221-181000 D %s f1:1: Debug message") % pid).str(), line);
115     ATF_REQUIRE(std::getline(input, line).good());
116     ATF_REQUIRE_EQ(
117         (F("20110221-181001 E %s f2:2: Error message") % pid).str(), line);
118     ATF_REQUIRE(std::getline(input, line).good());
119     ATF_REQUIRE_EQ(
120         (F("20110221-181002 I %s f3:3: Info message") % pid).str(), line);
121     ATF_REQUIRE(std::getline(input, line).good());
122     ATF_REQUIRE_EQ(
123         (F("20110221-181003 W %s f4:4: Warning message") % pid).str(), line);
124 }
125 
126 
127 ATF_TEST_CASE_WITHOUT_HEAD(set_inmemory__reset);
128 ATF_TEST_CASE_BODY(set_inmemory__reset)
129 {
130     logging::set_persistency("debug", fs::path("test.log"));
131 
132     datetime::set_mock_now(2011, 2, 21, 18, 20, 0, 654321);
133     logging::log(logging::level_debug, "file", 123, "Debug message");
134     logging::set_inmemory();
135     logging::log(logging::level_debug, "file", 123, "Debug message 2");
136 
137     std::ifstream input("test.log");
138     ATF_REQUIRE(input);
139 
140     const pid_t pid = ::getpid();
141 
142     std::string line;
143     ATF_REQUIRE(std::getline(input, line).good());
144     ATF_REQUIRE_EQ(
145         (F("20110221-182000 D %s file:123: Debug message") % pid).str(), line);
146 }
147 
148 
149 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__no_backlog);
150 ATF_TEST_CASE_BODY(set_persistency__no_backlog)
151 {
152     logging::set_persistency("debug", fs::path("test.log"));
153 
154     datetime::set_mock_now(2011, 2, 21, 18, 20, 0, 654321);
155     logging::log(logging::level_debug, "file", 123, "Debug message");
156 
157     std::ifstream input("test.log");
158     ATF_REQUIRE(input);
159 
160     const pid_t pid = ::getpid();
161 
162     std::string line;
163     ATF_REQUIRE(std::getline(input, line).good());
164     ATF_REQUIRE_EQ(
165         (F("20110221-182000 D %s file:123: Debug message") % pid).str(), line);
166 }
167 
168 
169 /// Creates a log for testing purposes, buffering messages on start.
170 ///
171 /// \param level The level of the desired log.
172 /// \param path The output file.
173 static void
174 create_log(const std::string& level, const std::string& path)
175 {
176     logging::set_inmemory();
177 
178     datetime::set_mock_now(2011, 3, 19, 11, 40, 0, 100);
179     logging::log(logging::level_debug, "file1", 11, "Debug 1");
180 
181     datetime::set_mock_now(2011, 3, 19, 11, 40, 1, 200);
182     logging::log(logging::level_error, "file2", 22, "Error 1");
183 
184     datetime::set_mock_now(2011, 3, 19, 11, 40, 2, 300);
185     logging::log(logging::level_info, "file3", 33, "Info 1");
186 
187     datetime::set_mock_now(2011, 3, 19, 11, 40, 3, 400);
188     logging::log(logging::level_warning, "file4", 44, "Warning 1");
189 
190     logging::set_persistency(level, fs::path(path));
191 
192     datetime::set_mock_now(2011, 3, 19, 11, 40, 4, 500);
193     logging::log(logging::level_debug, "file1", 11, "Debug 2");
194 
195     datetime::set_mock_now(2011, 3, 19, 11, 40, 5, 600);
196     logging::log(logging::level_error, "file2", 22, "Error 2");
197 
198     datetime::set_mock_now(2011, 3, 19, 11, 40, 6, 700);
199     logging::log(logging::level_info, "file3", 33, "Info 2");
200 
201     datetime::set_mock_now(2011, 3, 19, 11, 40, 7, 800);
202     logging::log(logging::level_warning, "file4", 44, "Warning 2");
203 }
204 
205 
206 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__debug);
207 ATF_TEST_CASE_BODY(set_persistency__some_backlog__debug)
208 {
209     create_log("debug", "test.log");
210 
211     std::ifstream input("test.log");
212     ATF_REQUIRE(input);
213 
214     const pid_t pid = ::getpid();
215 
216     std::string line;
217     ATF_REQUIRE(std::getline(input, line).good());
218     ATF_REQUIRE_EQ(
219         (F("20110319-114000 D %s file1:11: Debug 1") % pid).str(), line);
220     ATF_REQUIRE(std::getline(input, line).good());
221     ATF_REQUIRE_EQ(
222         (F("20110319-114001 E %s file2:22: Error 1") % pid).str(), line);
223     ATF_REQUIRE(std::getline(input, line).good());
224     ATF_REQUIRE_EQ(
225         (F("20110319-114002 I %s file3:33: Info 1") % pid).str(), line);
226     ATF_REQUIRE(std::getline(input, line).good());
227     ATF_REQUIRE_EQ(
228         (F("20110319-114003 W %s file4:44: Warning 1") % pid).str(), line);
229     ATF_REQUIRE(std::getline(input, line).good());
230     ATF_REQUIRE_EQ(
231         (F("20110319-114004 D %s file1:11: Debug 2") % pid).str(), line);
232     ATF_REQUIRE(std::getline(input, line).good());
233     ATF_REQUIRE_EQ(
234         (F("20110319-114005 E %s file2:22: Error 2") % pid).str(), line);
235     ATF_REQUIRE(std::getline(input, line).good());
236     ATF_REQUIRE_EQ(
237         (F("20110319-114006 I %s file3:33: Info 2") % pid).str(), line);
238     ATF_REQUIRE(std::getline(input, line).good());
239     ATF_REQUIRE_EQ(
240         (F("20110319-114007 W %s file4:44: Warning 2") % pid).str(), line);
241 }
242 
243 
244 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__error);
245 ATF_TEST_CASE_BODY(set_persistency__some_backlog__error)
246 {
247     create_log("error", "test.log");
248 
249     std::ifstream input("test.log");
250     ATF_REQUIRE(input);
251 
252     const pid_t pid = ::getpid();
253 
254     std::string line;
255     ATF_REQUIRE(std::getline(input, line).good());
256     ATF_REQUIRE_EQ(
257         (F("20110319-114001 E %s file2:22: Error 1") % pid).str(), line);
258     ATF_REQUIRE(std::getline(input, line).good());
259     ATF_REQUIRE_EQ(
260         (F("20110319-114005 E %s file2:22: Error 2") % pid).str(), line);
261 }
262 
263 
264 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__info);
265 ATF_TEST_CASE_BODY(set_persistency__some_backlog__info)
266 {
267     create_log("info", "test.log");
268 
269     std::ifstream input("test.log");
270     ATF_REQUIRE(input);
271 
272     const pid_t pid = ::getpid();
273 
274     std::string line;
275     ATF_REQUIRE(std::getline(input, line).good());
276     ATF_REQUIRE_EQ(
277         (F("20110319-114001 E %s file2:22: Error 1") % pid).str(), line);
278     ATF_REQUIRE(std::getline(input, line).good());
279     ATF_REQUIRE_EQ(
280         (F("20110319-114002 I %s file3:33: Info 1") % pid).str(), line);
281     ATF_REQUIRE(std::getline(input, line).good());
282     ATF_REQUIRE_EQ(
283         (F("20110319-114003 W %s file4:44: Warning 1") % pid).str(), line);
284     ATF_REQUIRE(std::getline(input, line).good());
285     ATF_REQUIRE_EQ(
286         (F("20110319-114005 E %s file2:22: Error 2") % pid).str(), line);
287     ATF_REQUIRE(std::getline(input, line).good());
288     ATF_REQUIRE_EQ(
289         (F("20110319-114006 I %s file3:33: Info 2") % pid).str(), line);
290     ATF_REQUIRE(std::getline(input, line).good());
291     ATF_REQUIRE_EQ(
292         (F("20110319-114007 W %s file4:44: Warning 2") % pid).str(), line);
293 }
294 
295 
296 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__warning);
297 ATF_TEST_CASE_BODY(set_persistency__some_backlog__warning)
298 {
299     create_log("warning", "test.log");
300 
301     std::ifstream input("test.log");
302     ATF_REQUIRE(input);
303 
304     const pid_t pid = ::getpid();
305 
306     std::string line;
307     ATF_REQUIRE(std::getline(input, line).good());
308     ATF_REQUIRE_EQ(
309         (F("20110319-114001 E %s file2:22: Error 1") % pid).str(), line);
310     ATF_REQUIRE(std::getline(input, line).good());
311     ATF_REQUIRE_EQ(
312         (F("20110319-114003 W %s file4:44: Warning 1") % pid).str(), line);
313     ATF_REQUIRE(std::getline(input, line).good());
314     ATF_REQUIRE_EQ(
315         (F("20110319-114005 E %s file2:22: Error 2") % pid).str(), line);
316     ATF_REQUIRE(std::getline(input, line).good());
317     ATF_REQUIRE_EQ(
318         (F("20110319-114007 W %s file4:44: Warning 2") % pid).str(), line);
319 }
320 
321 
322 ATF_TEST_CASE(set_persistency__fail);
323 ATF_TEST_CASE_HEAD(set_persistency__fail)
324 {
325     set_md_var("require.user", "unprivileged");
326 }
327 ATF_TEST_CASE_BODY(set_persistency__fail)
328 {
329     ATF_REQUIRE_THROW_RE(std::range_error, "'foobar'",
330                          logging::set_persistency("foobar", fs::path("log")));
331 
332     fs::mkdir(fs::path("dir"), 0644);
333     ATF_REQUIRE_THROW_RE(std::runtime_error, "dir/fail.log",
334                          logging::set_persistency("debug",
335                                                   fs::path("dir/fail.log")));
336 }
337 
338 
339 ATF_INIT_TEST_CASES(tcs)
340 {
341     ATF_ADD_TEST_CASE(tcs, generate_log_name__before_log);
342     ATF_ADD_TEST_CASE(tcs, generate_log_name__after_log);
343 
344     ATF_ADD_TEST_CASE(tcs, log);
345 
346     ATF_ADD_TEST_CASE(tcs, set_inmemory__reset);
347 
348     ATF_ADD_TEST_CASE(tcs, set_persistency__no_backlog);
349     ATF_ADD_TEST_CASE(tcs, set_persistency__some_backlog__debug);
350     ATF_ADD_TEST_CASE(tcs, set_persistency__some_backlog__error);
351     ATF_ADD_TEST_CASE(tcs, set_persistency__some_backlog__info);
352     ATF_ADD_TEST_CASE(tcs, set_persistency__some_backlog__warning);
353     ATF_ADD_TEST_CASE(tcs, set_persistency__fail);
354 }
355