13 * accompanied this code).
14 *
15 * You should have received a copy of the GNU General Public License version
16 * 2 along with this work; if not, write to the Free Software Foundation,
17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18 *
19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20 * or visit www.oracle.com if you need additional information or have any
21 * questions.
22 *
23 */
24
25 #include "precompiled.hpp"
26
27 /////////////// Unit tests ///////////////
28
29 #ifndef PRODUCT
30
31 #include "logging/log.hpp"
32 #include "logging/logConfiguration.hpp"
33 #include "logging/logOutput.hpp"
34 #include "memory/resourceArea.hpp"
35
36 void Test_log_length() {
37 remove("loglengthoutput.txt");
38
39 // Write long message to output file
40 ResourceMark rm;
41 LogHandle(logging) log;
42 bool success = LogConfiguration::parse_log_arguments("loglengthoutput.txt", "logging=trace",
43 NULL, NULL, log.error_stream());
44 assert(success, "test unable to configure logging");
45 log.trace("01:1234567890-"
46 "02:1234567890-"
47 "03:1234567890-"
48 "04:1234567890-"
49 "05:1234567890-"
50 "06:1234567890-"
51 "07:1234567890-"
52 "08:1234567890-"
53 "09:1234567890-"
54 "10:1234567890-"
55 "11:1234567890-"
66 "22:1234567890-"
67 "23:1234567890-"
68 "24:1234567890-"
69 "25:1234567890-"
70 "26:1234567890-"
71 "27:1234567890-"
72 "28:1234567890-"
73 "29:1234567890-"
74 "30:1234567890-"
75 "31:1234567890-"
76 "32:1234567890-"
77 "33:1234567890-"
78 "34:1234567890-"
79 "35:1234567890-"
80 "36:1234567890-"
81 "37:1234567890-");
82 LogConfiguration::parse_log_arguments("loglengthoutput.txt", "all=off",
83 NULL, NULL, log.error_stream());
84
85 // Look for end of message in output file
86 FILE* fp = fopen("loglengthoutput.txt", "r");
87 assert(fp, "File read error");
88 char output[600];
89 if (fgets(output, 600, fp) != NULL) {
90 assert(strstr(output, "37:1234567890-"), "logging print size error");
91 }
92 fclose(fp);
93 remove("loglengthoutput.txt");
94 }
95
96 #define assert_str_eq(s1, s2) \
97 assert(strcmp(s1, s2) == 0, "Expected '%s' to equal '%s'", s1, s2)
98
99 #define assert_char_in(c, s) \
100 assert(strchr(s, c) != NULL, "Expected '%s' to contain character '%c'", s, c)
101
102 #define assert_char_not_in(c, s) \
103 assert(strchr(s, c) == NULL, "Expected '%s' to *not* contain character '%c'", s, c)
104
105 void Test_configure_stdout() {
106 ResourceMark rm;
107 LogHandle(logging) log;
108 LogOutput* stdoutput = LogOutput::Stdout;
109
110 // Save current stdout config and clear it
111 char* saved_config = os::strdup_check_oom(stdoutput->config_string());
112 LogConfiguration::parse_log_arguments("stdout", "all=off", NULL, NULL, log.error_stream());
119 // Enable 'gc=debug' (no wildcard), verifying no other tags are enabled
120 LogConfiguration::configure_stdout(LogLevel::Debug, true, LOG_TAGS(gc));
121 // No '+' character means only single tags are enabled, and no combinations
122 assert_char_not_in('+', stdoutput->config_string());
123 assert(log_is_enabled(Debug, gc), "logging was not properly enabled");
124
125 // Enable 'gc*=trace' (with wildcard), verifying at least one tag combination is enabled (gc+...)
126 LogConfiguration::configure_stdout(LogLevel::Trace, false, LOG_TAGS(gc));
127 assert_char_in('+', stdoutput->config_string());
128 assert(log_is_enabled(Trace, gc), "logging was not properly enabled");
129
130 // Disable 'gc*' and 'logging', verifying all logging is properly disabled
131 LogConfiguration::configure_stdout(LogLevel::Off, false, LOG_TAGS(gc));
132 LogConfiguration::configure_stdout(LogLevel::Off, true, LOG_TAGS(logging));
133 assert_str_eq("all=off", stdoutput->config_string());
134
135 // Restore saved configuration
136 LogConfiguration::parse_log_arguments("stdout", saved_config, NULL, NULL, log.error_stream());
137 os::free(saved_config);
138 }
139 #endif // PRODUCT
|
13 * accompanied this code).
14 *
15 * You should have received a copy of the GNU General Public License version
16 * 2 along with this work; if not, write to the Free Software Foundation,
17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18 *
19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20 * or visit www.oracle.com if you need additional information or have any
21 * questions.
22 *
23 */
24
25 #include "precompiled.hpp"
26
27 /////////////// Unit tests ///////////////
28
29 #ifndef PRODUCT
30
31 #include "logging/log.hpp"
32 #include "logging/logConfiguration.hpp"
33 #include "logging/logMessage.hpp"
34 #include "logging/logMessageBuffer.hpp"
35 #include "logging/logOutput.hpp"
36 #include "memory/resourceArea.hpp"
37
38 static bool file_contains_substrings_in_order(const char* filename, const char* substrs[]) {
39 FILE* fp = fopen(filename, "r");
40 assert(fp, "File read error");
41 char buffer[1024];
42 for (int i = 0; substrs[i] != NULL; i++) {
43 assert(sizeof(buffer) > strlen(substrs[i]), "insufficient buffer");
44 bool found = false;
45 while (fgets(buffer, sizeof(buffer), fp) != NULL) {
46 if (strstr(buffer, substrs[i]) != NULL) {
47 found = true;
48 break;
49 }
50 }
51 if (!found) {
52 return false;
53 }
54 }
55 fclose(fp);
56 return true;
57 }
58
59 static bool file_contains_substring(const char* filename, const char* substr) {
60 const char* strs[] = {substr, NULL};
61 return file_contains_substrings_in_order(filename, strs);
62 }
63
64 void Test_log_length() {
65 remove("loglengthoutput.txt");
66
67 // Write long message to output file
68 ResourceMark rm;
69 LogHandle(logging) log;
70 bool success = LogConfiguration::parse_log_arguments("loglengthoutput.txt", "logging=trace",
71 NULL, NULL, log.error_stream());
72 assert(success, "test unable to configure logging");
73 log.trace("01:1234567890-"
74 "02:1234567890-"
75 "03:1234567890-"
76 "04:1234567890-"
77 "05:1234567890-"
78 "06:1234567890-"
79 "07:1234567890-"
80 "08:1234567890-"
81 "09:1234567890-"
82 "10:1234567890-"
83 "11:1234567890-"
94 "22:1234567890-"
95 "23:1234567890-"
96 "24:1234567890-"
97 "25:1234567890-"
98 "26:1234567890-"
99 "27:1234567890-"
100 "28:1234567890-"
101 "29:1234567890-"
102 "30:1234567890-"
103 "31:1234567890-"
104 "32:1234567890-"
105 "33:1234567890-"
106 "34:1234567890-"
107 "35:1234567890-"
108 "36:1234567890-"
109 "37:1234567890-");
110 LogConfiguration::parse_log_arguments("loglengthoutput.txt", "all=off",
111 NULL, NULL, log.error_stream());
112
113 // Look for end of message in output file
114 assert(file_contains_substring("loglengthoutput.txt", "37:1234567890-"), "logging print size error");
115 remove("loglengthoutput.txt");
116 }
117
118 #define assert_str_eq(s1, s2) \
119 assert(strcmp(s1, s2) == 0, "Expected '%s' to equal '%s'", s1, s2)
120
121 #define assert_char_in(c, s) \
122 assert(strchr(s, c) != NULL, "Expected '%s' to contain character '%c'", s, c)
123
124 #define assert_char_not_in(c, s) \
125 assert(strchr(s, c) == NULL, "Expected '%s' to *not* contain character '%c'", s, c)
126
127 void Test_configure_stdout() {
128 ResourceMark rm;
129 LogHandle(logging) log;
130 LogOutput* stdoutput = LogOutput::Stdout;
131
132 // Save current stdout config and clear it
133 char* saved_config = os::strdup_check_oom(stdoutput->config_string());
134 LogConfiguration::parse_log_arguments("stdout", "all=off", NULL, NULL, log.error_stream());
141 // Enable 'gc=debug' (no wildcard), verifying no other tags are enabled
142 LogConfiguration::configure_stdout(LogLevel::Debug, true, LOG_TAGS(gc));
143 // No '+' character means only single tags are enabled, and no combinations
144 assert_char_not_in('+', stdoutput->config_string());
145 assert(log_is_enabled(Debug, gc), "logging was not properly enabled");
146
147 // Enable 'gc*=trace' (with wildcard), verifying at least one tag combination is enabled (gc+...)
148 LogConfiguration::configure_stdout(LogLevel::Trace, false, LOG_TAGS(gc));
149 assert_char_in('+', stdoutput->config_string());
150 assert(log_is_enabled(Trace, gc), "logging was not properly enabled");
151
152 // Disable 'gc*' and 'logging', verifying all logging is properly disabled
153 LogConfiguration::configure_stdout(LogLevel::Off, false, LOG_TAGS(gc));
154 LogConfiguration::configure_stdout(LogLevel::Off, true, LOG_TAGS(logging));
155 assert_str_eq("all=off", stdoutput->config_string());
156
157 // Restore saved configuration
158 LogConfiguration::parse_log_arguments("stdout", saved_config, NULL, NULL, log.error_stream());
159 os::free(saved_config);
160 }
161
162 class LogMessageTest {
163 private:
164 static LogHandle(logging) _log;
165 static const char* _level_filename[];
166
167 static void test_level_inclusion();
168 static void test_long_message();
169 static void test_message_with_many_lines();
170 static void test_line_order();
171 static void test_prefixing();
172 static void test_scoped_messages();
173
174 public:
175 static void test();
176 };
177
178 const char* LogMessageTest::_level_filename[] = {
179 NULL, // LogLevel::Off
180 #define LOG_LEVEL(name, printname) "multiline-" #printname ".log",
181 LOG_LEVEL_LIST
182 #undef LOG_LEVEL
183 };
184
185 void Test_multiline_logging() {
186 LogMessageTest::test();
187 }
188
189 void LogMessageTest::test() {
190 ResourceMark rm;
191
192 for (int i = 0; i < LogLevel::Count; i++) {
193 char buf[32];
194 // Attempt to remove possibly pre-existing log files
195 remove(_level_filename[i]);
196
197 jio_snprintf(buf, sizeof(buf), "logging=%s", LogLevel::name(static_cast<LogLevelType>(i)));
198 bool success = LogConfiguration::parse_log_arguments(_level_filename[i], buf,
199 NULL, NULL, _log.error_stream());
200 assert(success, "unable to configure logging to file '%s'", _level_filename[i]);
201 }
202
203 test_level_inclusion();
204 test_line_order();
205 test_long_message();
206 test_message_with_many_lines();
207 test_prefixing();
208 test_scoped_messages();
209
210 // Stop logging to the files and remove them.
211 for (int i = 0; i < LogLevel::Count; i++) {
212 LogConfiguration::parse_log_arguments(_level_filename[i], "all=off", NULL, NULL, _log.error_stream());
213 remove(_level_filename[i]);
214 }
215 }
216
217 // Verify that messages with multiple levels are written
218 // to outputs configured for all the corresponding levels
219 void LogMessageTest::test_level_inclusion() {
220 const size_t message_count = 10;
221 LogMessageBuffer msg[message_count];
222
223 struct {
224 int message_number;
225 LogLevelType level;
226 } lines[] = {
227 { 0, LogLevel::Error },
228 { 1, LogLevel::Info },
229 { 2, LogLevel::Info }, { 2, LogLevel::Debug },
230 { 3, LogLevel::Info }, { 3, LogLevel::Warning },
231 { 4, LogLevel::Debug }, { 4, LogLevel::Warning },
232 { 5, LogLevel::Trace }, { 5, LogLevel::Debug },
233 { 6, LogLevel::Warning }, { 6, LogLevel::Error },
234 { 7, LogLevel::Trace }, { 7, LogLevel::Info }, { 7, LogLevel::Debug },
235 { 8, LogLevel::Trace }, { 8, LogLevel::Debug }, { 8, LogLevel::Info },
236 { 8, LogLevel::Warning }, { 8, LogLevel::Error},
237 { 9, LogLevel::Trace }
238 };
239
240 // Fill in messages with the above lines
241 for (size_t i = 0; i < ARRAY_SIZE(lines); i++) {
242 switch (lines[i].level) {
243 #define LOG_LEVEL(name, printname) \
244 case LogLevel::name: \
245 msg[lines[i].message_number].printname("msg[%d]: " #printname, lines[i].message_number); \
246 break;
247 LOG_LEVEL_LIST
248 #undef LOG_LEVEL
249 }
250 }
251
252 for (size_t i = 0; i < message_count; i++) {
253 _log.write(msg[i]);
254 }
255
256 // Verify that lines are written to the expected log files
257 for (size_t i = 0; i < ARRAY_SIZE(lines); i++) {
258 char expected[256];
259 jio_snprintf(expected, sizeof(expected), "msg[%d]: %s",
260 lines[i].message_number, LogLevel::name(lines[i].level));
261 for (int level = lines[i].level; level > 0; level--) {
262 assert(file_contains_substring(_level_filename[level], expected),
263 "line #" SIZE_FORMAT " missing from log file '%s'", i, _level_filename[level]);
264 }
265 for (int level = lines[i].level + 1; level < LogLevel::Count; level++) {
266 assert(!file_contains_substring(_level_filename[level], expected),
267 "line #" SIZE_FORMAT " erroneously included in log file '%s'", i, _level_filename[level]);
268 }
269 }
270 }
271
272 // Verify that messages are logged in the order they are added to the log message
273 void LogMessageTest::test_line_order() {
274 LogMessageBuffer msg;
275 msg.info("info line").error("error line").trace("trace line")
276 .error("another error").warning("warning line").debug("debug line");
277 _log.write(msg);
278
279 const char* expected[] = { "info line", "error line", "trace line",
280 "another error", "warning line", "debug line", NULL };
281 assert(file_contains_substrings_in_order(_level_filename[LogLevel::Trace], expected),
282 "output missing or in incorrect order");
283 }
284
285 void LogMessageTest::test_long_message() {
286 // Write 10K bytes worth of log data
287 LogMessageBuffer msg;
288 const size_t size = 10 * K;
289 const char* start_marker = "#start#";
290 const char* end_marker = "#the end#";
291 char* data = NEW_C_HEAP_ARRAY(char, size, mtLogging);
292
293 // fill buffer with start_marker...some data...end_marker
294 sprintf(data, "%s", start_marker);
295 for (size_t i = strlen(start_marker); i < size; i++) {
296 data[i] = '0' + (i % 10);
297 }
298 sprintf(data + size - strlen(end_marker) - 1, "%s", end_marker);
299
300 msg.trace("%s", data); // Adds a newline, making the message exactly 10K in length.
301 _log.write(msg);
302
303 const char* expected[] = { start_marker, "0123456789", end_marker, NULL };
304 assert(file_contains_substrings_in_order(_level_filename[LogLevel::Trace], expected),
305 "unable to print long line");
306 FREE_C_HEAP_ARRAY(char, data);
307 }
308
309 void LogMessageTest::test_message_with_many_lines() {
310 const size_t lines = 100;
311 const size_t line_length = 16;
312
313 LogMessageBuffer msg;
314 for (size_t i = 0; i < lines; i++) {
315 msg.info("Line #" SIZE_FORMAT, i);
316 }
317 _log.write(msg);
318
319 char expected_lines_data[lines][line_length];
320 const char* expected_lines[lines + 1];
321 for (size_t i = 0; i < lines; i++) {
322 jio_snprintf(&expected_lines_data[i][0], line_length, "Line #" SIZE_FORMAT, i);
323 expected_lines[i] = expected_lines_data[i];
324 }
325 expected_lines[lines] = NULL;
326
327 assert(file_contains_substrings_in_order(_level_filename[LogLevel::Trace], expected_lines),
328 "couldn't find all lines in multiline message");
329 }
330
331 static size_t dummy_prefixer(char* buf, size_t len) {
332 static int i = 0;
333 const char* prefix = "some prefix: ";
334 const size_t prefix_len = strlen(prefix);
335 if (len < prefix_len) {
336 return prefix_len;
337 }
338 jio_snprintf(buf, len, "%s", prefix);
339 return prefix_len;
340 }
341
342 void LogMessageTest::test_prefixing() {
343 LogMessageBuffer msg;
344 msg.set_prefix(dummy_prefixer);
345 for (int i = 0; i < 3; i++) {
346 msg.info("test %d", i);
347 }
348 msg.set_prefix(NULL);
349 msg.info("test 3");
350 _log.write(msg);
351
352 const char* expected[] = {
353 "] some prefix: test 0",
354 "] some prefix: test 1",
355 "] some prefix: test 2",
356 "] test 3",
357 NULL
358 };
359 assert(file_contains_substrings_in_order(_level_filename[LogLevel::Trace], expected), "error in prefixed output");
360 }
361
362 void LogMessageTest::test_scoped_messages() {
363 {
364 LogMessage(logging) msg;
365 msg.info("scoped info");
366 }
367 assert(file_contains_substring(_level_filename[LogLevel::Info], "scoped info"),
368 "missing output from scoped log message");
369 }
370
371 #endif // PRODUCT
|