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 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_persistency__no_backlog); 128 ATF_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. 151 static void 152 create_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 184 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__debug); 185 ATF_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 222 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__error); 223 ATF_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 242 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__info); 243 ATF_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 274 ATF_TEST_CASE_WITHOUT_HEAD(set_persistency__some_backlog__warning); 275 ATF_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 300 ATF_TEST_CASE(set_persistency__fail); 301 ATF_TEST_CASE_HEAD(set_persistency__fail) 302 { 303 set_md_var("require.user", "unprivileged"); 304 } 305 ATF_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 317 ATF_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