1// Copyright 2011 Google Inc.
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
31extern "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
45namespace datetime = utils::datetime;
46namespace fs = utils::fs;
47namespace logging = utils::logging;
48
49
50ATF_TEST_CASE_WITHOUT_HEAD(generate_log_name__before_log);
51ATF_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
66ATF_TEST_CASE_WITHOUT_HEAD(generate_log_name__after_log);
67ATF_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
87ATF_TEST_CASE_WITHOUT_HEAD(log);
88ATF_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
127ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__no_backlog);
128ATF_TEST_CASE_BODY(set_persistency__no_backlog)
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
135    std::ifstream input("test.log");
136    ATF_REQUIRE(input);
137
138    const pid_t pid = ::getpid();
139
140    std::string line;
141    ATF_REQUIRE(std::getline(input, line).good());
142    ATF_REQUIRE_EQ(
143        (F("20110221-182000 D %s file:123: Debug message") % pid).str(), line);
144}
145
146
147/// Creates a log for testing purposes, buffering messages on start.
148///
149/// \param level The level of the desired log.
150/// \param path The output file.
151static void
152create_log(const std::string& level, const std::string& path)
153{
154    logging::set_inmemory();
155
156    datetime::set_mock_now(2011, 3, 19, 11, 40, 0, 100);
157    logging::log(logging::level_debug, "file1", 11, "Debug 1");
158
159    datetime::set_mock_now(2011, 3, 19, 11, 40, 1, 200);
160    logging::log(logging::level_error, "file2", 22, "Error 1");
161
162    datetime::set_mock_now(2011, 3, 19, 11, 40, 2, 300);
163    logging::log(logging::level_info, "file3", 33, "Info 1");
164
165    datetime::set_mock_now(2011, 3, 19, 11, 40, 3, 400);
166    logging::log(logging::level_warning, "file4", 44, "Warning 1");
167
168    logging::set_persistency(level, fs::path(path));
169
170    datetime::set_mock_now(2011, 3, 19, 11, 40, 4, 500);
171    logging::log(logging::level_debug, "file1", 11, "Debug 2");
172
173    datetime::set_mock_now(2011, 3, 19, 11, 40, 5, 600);
174    logging::log(logging::level_error, "file2", 22, "Error 2");
175
176    datetime::set_mock_now(2011, 3, 19, 11, 40, 6, 700);
177    logging::log(logging::level_info, "file3", 33, "Info 2");
178
179    datetime::set_mock_now(2011, 3, 19, 11, 40, 7, 800);
180    logging::log(logging::level_warning, "file4", 44, "Warning 2");
181}
182
183
184ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__debug);
185ATF_TEST_CASE_BODY(set_persistency__some_backlog__debug)
186{
187    create_log("debug", "test.log");
188
189    std::ifstream input("test.log");
190    ATF_REQUIRE(input);
191
192    const pid_t pid = ::getpid();
193
194    std::string line;
195    ATF_REQUIRE(std::getline(input, line).good());
196    ATF_REQUIRE_EQ(
197        (F("20110319-114000 D %s file1:11: Debug 1") % pid).str(), line);
198    ATF_REQUIRE(std::getline(input, line).good());
199    ATF_REQUIRE_EQ(
200        (F("20110319-114001 E %s file2:22: Error 1") % pid).str(), line);
201    ATF_REQUIRE(std::getline(input, line).good());
202    ATF_REQUIRE_EQ(
203        (F("20110319-114002 I %s file3:33: Info 1") % pid).str(), line);
204    ATF_REQUIRE(std::getline(input, line).good());
205    ATF_REQUIRE_EQ(
206        (F("20110319-114003 W %s file4:44: Warning 1") % pid).str(), line);
207    ATF_REQUIRE(std::getline(input, line).good());
208    ATF_REQUIRE_EQ(
209        (F("20110319-114004 D %s file1:11: Debug 2") % pid).str(), line);
210    ATF_REQUIRE(std::getline(input, line).good());
211    ATF_REQUIRE_EQ(
212        (F("20110319-114005 E %s file2:22: Error 2") % pid).str(), line);
213    ATF_REQUIRE(std::getline(input, line).good());
214    ATF_REQUIRE_EQ(
215        (F("20110319-114006 I %s file3:33: Info 2") % pid).str(), line);
216    ATF_REQUIRE(std::getline(input, line).good());
217    ATF_REQUIRE_EQ(
218        (F("20110319-114007 W %s file4:44: Warning 2") % pid).str(), line);
219}
220
221
222ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__error);
223ATF_TEST_CASE_BODY(set_persistency__some_backlog__error)
224{
225    create_log("error", "test.log");
226
227    std::ifstream input("test.log");
228    ATF_REQUIRE(input);
229
230    const pid_t pid = ::getpid();
231
232    std::string line;
233    ATF_REQUIRE(std::getline(input, line).good());
234    ATF_REQUIRE_EQ(
235        (F("20110319-114001 E %s file2:22: Error 1") % pid).str(), line);
236    ATF_REQUIRE(std::getline(input, line).good());
237    ATF_REQUIRE_EQ(
238        (F("20110319-114005 E %s file2:22: Error 2") % pid).str(), line);
239}
240
241
242ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__info);
243ATF_TEST_CASE_BODY(set_persistency__some_backlog__info)
244{
245    create_log("info", "test.log");
246
247    std::ifstream input("test.log");
248    ATF_REQUIRE(input);
249
250    const pid_t pid = ::getpid();
251
252    std::string line;
253    ATF_REQUIRE(std::getline(input, line).good());
254    ATF_REQUIRE_EQ(
255        (F("20110319-114001 E %s file2:22: Error 1") % pid).str(), line);
256    ATF_REQUIRE(std::getline(input, line).good());
257    ATF_REQUIRE_EQ(
258        (F("20110319-114002 I %s file3:33: Info 1") % pid).str(), line);
259    ATF_REQUIRE(std::getline(input, line).good());
260    ATF_REQUIRE_EQ(
261        (F("20110319-114003 W %s file4:44: Warning 1") % pid).str(), line);
262    ATF_REQUIRE(std::getline(input, line).good());
263    ATF_REQUIRE_EQ(
264        (F("20110319-114005 E %s file2:22: Error 2") % pid).str(), line);
265    ATF_REQUIRE(std::getline(input, line).good());
266    ATF_REQUIRE_EQ(
267        (F("20110319-114006 I %s file3:33: Info 2") % pid).str(), line);
268    ATF_REQUIRE(std::getline(input, line).good());
269    ATF_REQUIRE_EQ(
270        (F("20110319-114007 W %s file4:44: Warning 2") % pid).str(), line);
271}
272
273
274ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__warning);
275ATF_TEST_CASE_BODY(set_persistency__some_backlog__warning)
276{
277    create_log("warning", "test.log");
278
279    std::ifstream input("test.log");
280    ATF_REQUIRE(input);
281
282    const pid_t pid = ::getpid();
283
284    std::string line;
285    ATF_REQUIRE(std::getline(input, line).good());
286    ATF_REQUIRE_EQ(
287        (F("20110319-114001 E %s file2:22: Error 1") % pid).str(), line);
288    ATF_REQUIRE(std::getline(input, line).good());
289    ATF_REQUIRE_EQ(
290        (F("20110319-114003 W %s file4:44: Warning 1") % pid).str(), line);
291    ATF_REQUIRE(std::getline(input, line).good());
292    ATF_REQUIRE_EQ(
293        (F("20110319-114005 E %s file2:22: Error 2") % pid).str(), line);
294    ATF_REQUIRE(std::getline(input, line).good());
295    ATF_REQUIRE_EQ(
296        (F("20110319-114007 W %s file4:44: Warning 2") % pid).str(), line);
297}
298
299
300ATF_TEST_CASE(set_persistency__fail);
301ATF_TEST_CASE_HEAD(set_persistency__fail)
302{
303    set_md_var("require.user", "unprivileged");
304}
305ATF_TEST_CASE_BODY(set_persistency__fail)
306{
307    ATF_REQUIRE_THROW_RE(std::range_error, "'foobar'",
308                         logging::set_persistency("foobar", fs::path("log")));
309
310    fs::mkdir(fs::path("dir"), 0644);
311    ATF_REQUIRE_THROW_RE(std::runtime_error, "dir/fail.log",
312                         logging::set_persistency("debug",
313                                                  fs::path("dir/fail.log")));
314}
315
316
317ATF_INIT_TEST_CASES(tcs)
318{
319    ATF_ADD_TEST_CASE(tcs, generate_log_name__before_log);
320    ATF_ADD_TEST_CASE(tcs, generate_log_name__after_log);
321
322    ATF_ADD_TEST_CASE(tcs, log);
323
324    ATF_ADD_TEST_CASE(tcs, set_persistency__no_backlog);
325    ATF_ADD_TEST_CASE(tcs, set_persistency__some_backlog__debug);
326    ATF_ADD_TEST_CASE(tcs, set_persistency__some_backlog__error);
327    ATF_ADD_TEST_CASE(tcs, set_persistency__some_backlog__info);
328    ATF_ADD_TEST_CASE(tcs, set_persistency__some_backlog__warning);
329    ATF_ADD_TEST_CASE(tcs, set_persistency__fail);
330}
331