forked from degauden/Elements
-
Notifications
You must be signed in to change notification settings - Fork 2
Expand file tree
/
Copy pathLogging_test.cpp
More file actions
377 lines (321 loc) · 12.7 KB
/
Copy pathLogging_test.cpp
File metadata and controls
377 lines (321 loc) · 12.7 KB
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
/**
* @file Logging_test.cpp
* @date January 14, 2014
* @author Nikolaos Apostolakos
*
* @copyright 2012-2020 Euclid Science Ground Segment
*
* This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General
* Public License as published by the Free Software Foundation; either version 3.0 of the License, or (at your option)
* any later version.
*
* This library is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied
* warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU Lesser General Public License for more
* details.
*
* You should have received a copy of the GNU Lesser General Public License along with this library; if not, write to
* the Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
*
*/
#include "ElementsKernel/Logging.h"
#include <ctime> // for time
#include <filesystem> // for exists
#include <fstream> // IWYU pragma: keep
#include <iomanip> // for operator<<, setprecision, _Setprecision
#include <iostream> // for cerr, cout
#include <random> // for minstd_rand
#include <sstream> // for basic_istream, basic_ostream, operator<<, basic_ostream::operator<<, stringstream, basic_ios::rdbuf, ifstream, endl, ostream, basic_ios::clear, streambuf
#include <string> // for basic_string, char_traits, string, allocator, getline, operator+, operator<<
#include <tuple> // for tuple, tie, ignore, make_tuple
#include <vector> // for vector
#include <boost/algorithm/string.hpp> // for ends_with, trim, trim_left
#include <boost/test/unit_test.hpp>
#include "ElementsKernel/MathConstants.h" // for pi
#include "ElementsKernel/Temporary.h" // for TempDir
using Elements::Logging;
using std::ignore;
using std::string;
using std::stringstream;
using std::tie;
using std::tuple;
using std::vector;
using std::filesystem::exists;
// A class which takes over the given stream and keeps track of the log messages
// sent to it. It recovers the given stream in its previous state during destruction.
class LogMessageTracker {
public:
explicit LogMessageTracker(std::ostream& stream) : m_stream(stream), m_old{stream.rdbuf(m_messages.rdbuf())} {}
~LogMessageTracker() {
m_stream.rdbuf(m_old);
}
void reset() {
m_messages.str("");
m_messages.clear();
}
vector<tuple<string, string, string, string>> getMessages() {
using boost::algorithm::trim;
using boost::algorithm::trim_left;
vector<tuple<string, string, string, string>> messages;
for (string line; std::getline(m_messages, line);) {
string timestamp = line.substr(0, line.find(' '));
line = line.substr(line.find(' ') + 1);
string message = line.substr(line.find(':') + 1);
trim_left(message);
line = line.substr(0, line.find(':'));
trim(line);
string logLevelString = line.substr(line.rfind(' '));
trim(logLevelString);
// Logging::Level logLevel = levelMap[logLevelString];
string name = line.substr(0, line.rfind(' '));
trim(name);
messages.emplace_back(timestamp, logLevelString, name, message);
}
return messages;
}
private:
stringstream m_messages;
std::ostream& m_stream;
std::streambuf* m_old;
};
struct ElementsLogging_Fixture {
Logging m_logger = Logging::getLogger("TestLogger");
Elements::TempDir m_tmpdir;
// This tracker will record all messages written in the stderr. The Elements
// logging system guarantees that the messages will appear there.
LogMessageTracker m_tracker{std::cerr};
std::minstd_rand m_simple_rand;
ElementsLogging_Fixture() {
Logging::setLevel("INFO");
Logging::setLogFile("");
m_simple_rand.seed(std::time(nullptr));
}
~ElementsLogging_Fixture() = default;
};
//-----------------------------------------------------------------------------
BOOST_AUTO_TEST_SUITE(ElementsLogging_test)
//-----------------------------------------------------------------------------
// Test that the names are set correctly
//-----------------------------------------------------------------------------
BOOST_FIXTURE_TEST_CASE(loggerNames_test, ElementsLogging_Fixture) {
using std::tie;
// Given
const auto logger2 = Logging::getLogger("TestLogger2");
// When
m_logger.info("From logger 1");
logger2.info("From logger 2");
// Then
const auto messages = m_tracker.getMessages();
BOOST_CHECK_EQUAL(messages.size(), 2);
string name1;
tie(ignore, ignore, name1, ignore) = messages[0];
BOOST_CHECK_EQUAL(name1, "TestLogger");
string name2;
tie(ignore, ignore, name2, ignore) = messages[1];
BOOST_CHECK_EQUAL(name2, "TestLogger2");
}
//-----------------------------------------------------------------------------
// Test that the message text and level is correct
//-----------------------------------------------------------------------------
BOOST_FIXTURE_TEST_CASE(messageTextAndLevel_test, ElementsLogging_Fixture) {
// Given
Logging::setLevel("DEBUG");
// When
m_logger.debug("Debug message");
m_logger.info("Info message");
m_logger.warn("Warn message");
m_logger.error("Error message");
m_logger.fatal("Fatal message");
m_logger.debug("Debug message with %d value", 15);
m_logger.info("Info message with %d value", 15);
m_logger.warn("Warn message with %d value", 15);
m_logger.error("Error message with %d value", 15);
m_logger.fatal("Fatal message with %d value", 15);
m_logger.debug() << "Debug message with " << 15 << " value";
m_logger.info() << "Info message with " << 15 << " value";
m_logger.warn() << "Warn message with " << 15 << " value";
m_logger.error() << "Error message with " << 15 << " value";
m_logger.fatal() << "Fatal message with " << 15 << " value";
m_logger.info() << "This is the logged Pi: " << 5 << " " << std::setprecision(12) << Elements::Units::pi;
std::cout << "Pi:" << std::setprecision(9) << Elements::Units::pi << std::endl;
// Then
const auto messages = m_tracker.getMessages();
BOOST_CHECK_EQUAL(messages.size(), 16);
string logLevel;
string message;
tie(ignore, logLevel, ignore, message) = messages[0];
BOOST_CHECK_EQUAL(logLevel, "DEBUG");
BOOST_CHECK_EQUAL(message, "Debug message");
tie(ignore, logLevel, ignore, message) = messages[1];
BOOST_CHECK_EQUAL(logLevel, "INFO");
BOOST_CHECK_EQUAL(message, "Info message");
tie(ignore, logLevel, ignore, message) = messages[2];
BOOST_CHECK_EQUAL(logLevel, "WARN");
BOOST_CHECK_EQUAL(message, "Warn message");
tie(ignore, logLevel, ignore, message) = messages[3];
BOOST_CHECK_EQUAL(logLevel, "ERROR");
BOOST_CHECK_EQUAL(message, "Error message");
tie(ignore, logLevel, ignore, message) = messages[4];
BOOST_CHECK_EQUAL(logLevel, "FATAL");
BOOST_CHECK_EQUAL(message, "Fatal message");
tie(ignore, logLevel, ignore, message) = messages[5];
BOOST_CHECK_EQUAL(logLevel, "DEBUG");
BOOST_CHECK_EQUAL(message, "Debug message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[6];
BOOST_CHECK_EQUAL(logLevel, "INFO");
BOOST_CHECK_EQUAL(message, "Info message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[7];
BOOST_CHECK_EQUAL(logLevel, "WARN");
BOOST_CHECK_EQUAL(message, "Warn message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[8];
BOOST_CHECK_EQUAL(logLevel, "ERROR");
BOOST_CHECK_EQUAL(message, "Error message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[9];
BOOST_CHECK_EQUAL(logLevel, "FATAL");
BOOST_CHECK_EQUAL(message, "Fatal message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[10];
BOOST_CHECK_EQUAL(logLevel, "DEBUG");
BOOST_CHECK_EQUAL(message, "Debug message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[11];
BOOST_CHECK_EQUAL(logLevel, "INFO");
BOOST_CHECK_EQUAL(message, "Info message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[12];
BOOST_CHECK_EQUAL(logLevel, "WARN");
BOOST_CHECK_EQUAL(message, "Warn message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[13];
BOOST_CHECK_EQUAL(logLevel, "ERROR");
BOOST_CHECK_EQUAL(message, "Error message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[14];
BOOST_CHECK_EQUAL(logLevel, "FATAL");
BOOST_CHECK_EQUAL(message, "Fatal message with 15 value");
tie(ignore, logLevel, ignore, message) = messages[15];
BOOST_CHECK_EQUAL(logLevel, "INFO");
BOOST_CHECK_EQUAL(message, "This is the logged Pi: 5 3.14159265359");
}
//-----------------------------------------------------------------------------
// Test the setLevel method
//-----------------------------------------------------------------------------
BOOST_FIXTURE_TEST_CASE(setLevel_test, ElementsLogging_Fixture) {
// Given
Logging::setLevel("DEBUG");
// When
m_logger.debug("Debug message");
m_logger.info("Info message");
m_logger.warn("Warn message");
m_logger.error("Error message");
m_logger.fatal("Fatal message");
// Then
auto messages = m_tracker.getMessages();
BOOST_CHECK_EQUAL(messages.size(), 5);
// Given
m_tracker.reset();
Logging::setLevel("INFO");
// When
m_logger.debug("Debug message");
m_logger.info("Info message");
m_logger.warn("Warn message");
m_logger.error("Error message");
m_logger.fatal("Fatal message");
// Then
messages = m_tracker.getMessages();
BOOST_CHECK_EQUAL(messages.size(), 4);
// Given
m_tracker.reset();
Logging::setLevel("WARN");
// When
m_logger.debug("Debug message");
m_logger.info("Info message");
m_logger.warn("Warn message");
m_logger.error("Error message");
m_logger.fatal("Fatal message");
// Then
messages = m_tracker.getMessages();
BOOST_CHECK_EQUAL(messages.size(), 3);
// Given
m_tracker.reset();
Logging::setLevel("ERROR");
// When
m_logger.debug("Debug message");
m_logger.info("Info message");
m_logger.warn("Warn message");
m_logger.error("Error message");
m_logger.fatal("Fatal message");
// Then
messages = m_tracker.getMessages();
BOOST_CHECK_EQUAL(messages.size(), 2);
// Given
m_tracker.reset();
Logging::setLevel("FATAL");
// When
m_logger.debug("Debug message");
m_logger.info("Info message");
m_logger.warn("Warn message");
m_logger.error("Error message");
m_logger.fatal("Fatal message");
// Then
messages = m_tracker.getMessages();
BOOST_CHECK_EQUAL(messages.size(), 1);
}
//-----------------------------------------------------------------------------
// Test logging in a file works correctly
//-----------------------------------------------------------------------------
BOOST_FIXTURE_TEST_CASE(setLogFile_test, ElementsLogging_Fixture) {
using boost::algorithm::ends_with;
// Given
stringstream logFileName{};
logFileName << m_tmpdir.path().string() + "/" << std::time(nullptr) << m_simple_rand() << ".log";
Logging::setLogFile(logFileName.str());
// When
m_logger.error("First message");
m_logger.info("Second message");
// Then
BOOST_CHECK(exists(logFileName.str()));
std::ifstream logFile{logFileName.str()};
vector<string> lines{};
string line;
while (std::getline(logFile, line)) {
lines.emplace_back(line);
}
logFile.close();
BOOST_CHECK_EQUAL(lines.size(), 2);
BOOST_CHECK(ends_with(lines[0], "First message"));
BOOST_CHECK(ends_with(lines[1], "Second message"));
}
//-----------------------------------------------------------------------------
// Test logging is happening in a single file at a time
//-----------------------------------------------------------------------------
BOOST_FIXTURE_TEST_CASE(singleLogFile_test, ElementsLogging_Fixture) {
using boost::algorithm::ends_with;
// Given
stringstream logFileName1{};
logFileName1 << m_tmpdir.path().string() + "/" << std::time(nullptr) << m_simple_rand() << ".log";
stringstream logFileName2{};
logFileName2 << m_tmpdir.path().string() + "/" << std::time(nullptr) << m_simple_rand() << ".log";
// When
Logging::setLogFile(logFileName1.str());
m_logger.error("First message");
Logging::setLogFile(logFileName2.str());
m_logger.info("Second message");
m_logger.info("Third message");
// Then
BOOST_CHECK(exists(logFileName1.str()));
std::ifstream logFile1{logFileName1.str()};
vector<string> lines{};
string line;
while (std::getline(logFile1, line)) {
lines.emplace_back(line);
}
logFile1.close();
BOOST_CHECK_EQUAL(lines.size(), 1);
BOOST_CHECK(ends_with(lines[0], "First message"));
BOOST_CHECK(exists(logFileName2.str()));
std::ifstream logFile2{logFileName2.str()};
lines = vector<string>{};
while (std::getline(logFile2, line)) {
lines.emplace_back(line);
}
logFile2.close();
BOOST_CHECK_EQUAL(lines.size(), 2);
BOOST_CHECK(ends_with(lines[0], "Second message"));
BOOST_CHECK(ends_with(lines[1], "Third message"));
}
BOOST_AUTO_TEST_SUITE_END()