utils/logging/operations_test.cpp

   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 }