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