1 /*
   2  * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.
   8  *
   9  * This code is distributed in the hope that it will be useful, but WITHOUT
  10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  12  * version 2 for more details (a copy is included in the LICENSE file that
  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 "gc/shared/gcTraceTime.inline.hpp"
  32 #include "logging/log.hpp"
  33 #include "logging/logConfiguration.hpp"
  34 #include "logging/logFileOutput.hpp"
  35 #include "logging/logMessage.hpp"
  36 #include "logging/logMessageBuffer.hpp"
  37 #include "logging/logOutput.hpp"
  38 #include "logging/logTagLevelExpression.hpp"
  39 #include "logging/logTagSet.hpp"
  40 #include "logging/logTagSetDescriptions.hpp"
  41 #include "logging/logStream.inline.hpp"
  42 #include "memory/resourceArea.hpp"
  43 
  44 #define assert_str_eq(s1, s2) \
  45   assert(strcmp(s1, s2) == 0, "Expected '%s' to equal '%s'", s1, s2)
  46 
  47 #define assert_char_in(c, s) \
  48   assert(strchr(s, c) != NULL, "Expected '%s' to contain character '%c'", s, c)
  49 
  50 #define assert_char_not_in(c, s) \
  51   assert(strchr(s, c) == NULL, "Expected '%s' to *not* contain character '%c'", s, c)
  52 
  53 void Test_log_tag_combinations_limit() {
  54   assert(LogTagLevelExpression::MaxCombinations > LogTagSet::ntagsets(),
  55       "Combination limit (" SIZE_FORMAT ") not sufficient "
  56       "for configuring all available tag sets (" SIZE_FORMAT ")",
  57       LogTagLevelExpression::MaxCombinations, LogTagSet::ntagsets());
  58 }
  59 
  60 // Read a complete line from fp and return it as a resource allocated string.
  61 // Returns NULL on EOF.
  62 static char* read_line(FILE* fp) {
  63   assert(fp != NULL, "bad fp");
  64   int buflen = 512;
  65   char* buf = NEW_RESOURCE_ARRAY(char, buflen);
  66   long pos = ftell(fp);
  67 
  68   char* ret = fgets(buf, buflen, fp);
  69   while (ret != NULL && buf[strlen(buf) - 1] != '\n' && !feof(fp)) {
  70     // retry with a larger buffer
  71     buf = REALLOC_RESOURCE_ARRAY(char, buf, buflen, buflen * 2);
  72     buflen *= 2;
  73     // rewind to beginning of line
  74     fseek(fp, pos, SEEK_SET);
  75     // retry read with new buffer
  76     ret = fgets(buf, buflen, fp);
  77   }
  78   return ret;
  79 }
  80 
  81 static bool file_contains_substrings_in_order(const char* filename, const char* substrs[]) {
  82   FILE* fp = fopen(filename, "r");
  83   assert(fp != NULL, "error opening file %s: %s", filename, strerror(errno));
  84 
  85   size_t idx = 0;
  86   while (substrs[idx] != NULL) {
  87     ResourceMark rm;
  88     char* line = read_line(fp);
  89     if (line == NULL) {
  90       break;
  91     }
  92     for (char* match = strstr(line, substrs[idx]); match != NULL;) {
  93       size_t match_len = strlen(substrs[idx]);
  94       idx++;
  95       if (substrs[idx] == NULL) {
  96         break;
  97       }
  98       match = strstr(match + match_len, substrs[idx]);
  99     }
 100   }
 101 
 102   fclose(fp);
 103   return substrs[idx] == NULL;
 104 }
 105 
 106 static bool file_contains_substring(const char* filename, const char* substr) {
 107   const char* strs[] = {substr, NULL};
 108   return file_contains_substrings_in_order(filename, strs);
 109 }
 110 
 111 static size_t number_of_lines_with_substring_in_file(const char* filename,
 112                                                      const char* substr) {
 113   FILE* fp = fopen(filename, "r");
 114   assert(fp != NULL, "error opening file %s: %s", filename, strerror(errno));
 115 
 116   size_t ret = 0;
 117   for (;;) {
 118     ResourceMark rm;
 119     char* line = read_line(fp);
 120     if (line == NULL) {
 121       break;
 122     }
 123     if (strstr(line, substr) != NULL) {
 124       ret++;
 125     }
 126   }
 127 
 128   fclose(fp);
 129   return ret;
 130 }
 131 
 132 static bool file_exists(const char* filename) {
 133   struct stat st;
 134   return os::stat(filename, &st) == 0;
 135 }
 136 
 137 static void delete_file(const char* filename) {
 138   if (!file_exists(filename)) {
 139     return;
 140   }
 141   int ret = remove(filename);
 142   assert(ret == 0, "failed to remove file '%s': %s", filename, strerror(errno));
 143 }
 144 
 145 static void create_directory(const char* name) {
 146   assert(!file_exists(name), "can't create directory: %s already exists", name);
 147   bool failed;
 148 #ifdef _WINDOWS
 149   failed = !CreateDirectory(name, NULL);
 150 #else
 151   failed = mkdir(name, 0777);
 152 #endif
 153   assert(!failed, "failed to create directory %s", name);
 154 }
 155 
 156 class TestLogFile {
 157  private:
 158   char file_name[256];
 159 
 160   void set_name(const char* test_name) {
 161     const char* tmpdir = os::get_temp_directory();
 162     int pos = jio_snprintf(file_name, sizeof(file_name), "%s%svmtest.%s.%d.log", tmpdir, os::file_separator(), test_name, os::current_process_id());
 163     assert(pos > 0, "too small log file name buffer");
 164     assert((size_t)pos < sizeof(file_name), "too small log file name buffer");
 165   }
 166 
 167  public:
 168   TestLogFile(const char* test_name) {
 169     set_name(test_name);
 170     remove(name());
 171   }
 172 
 173   ~TestLogFile() {
 174     remove(name());
 175   }
 176 
 177   const char* name() {
 178     return file_name;
 179   }
 180 };
 181 
 182 class TestLogSavedConfig {
 183  private:
 184   char* _saved_config;
 185   char* _new_output;
 186   Log(logging) _log;
 187  public:
 188   TestLogSavedConfig(const char* apply_output = NULL, const char* apply_setting = NULL) : _new_output(0) {
 189     ResourceMark rm;
 190     _saved_config = os::strdup_check_oom(LogOutput::Stdout->config_string());
 191     bool success = LogConfiguration::parse_log_arguments("stdout", "all=off", NULL, NULL, _log.error_stream());
 192     assert(success, "test unable to turn all off");
 193 
 194     if (apply_output) {
 195       _new_output = os::strdup_check_oom(apply_output);
 196       bool success = LogConfiguration::parse_log_arguments(_new_output, apply_setting,  NULL, NULL, _log.error_stream());
 197       assert(success, "test unable to apply test log configuration");
 198     }
 199   }
 200 
 201   ~TestLogSavedConfig() {
 202     ResourceMark rm;
 203     if (_new_output) {
 204       bool success = LogConfiguration::parse_log_arguments(_new_output, "all=off", NULL, NULL, _log.error_stream());
 205       assert(success, "test unable to turn all off");
 206       os::free(_new_output);
 207     }
 208 
 209     bool success = LogConfiguration::parse_log_arguments("stdout", _saved_config, NULL, NULL, _log.error_stream());
 210     assert(success, "test unable to restore log configuration");
 211     os::free(_saved_config);
 212   }
 213 };
 214 
 215 void Test_configure_stdout() {
 216   LogOutput* stdoutput = LogOutput::Stdout;
 217   TestLogSavedConfig tlsc;
 218 
 219   // Enable 'logging=info', verifying it has been set
 220   LogConfiguration::configure_stdout(LogLevel::Info, true, LOG_TAGS(logging));
 221   assert_str_eq("logging=info", stdoutput->config_string());
 222   assert(log_is_enabled(Info, logging), "logging was not properly enabled");
 223 
 224   // Enable 'gc=debug' (no wildcard), verifying no other tags are enabled
 225   LogConfiguration::configure_stdout(LogLevel::Debug, true, LOG_TAGS(gc));
 226   // No '+' character means only single tags are enabled, and no combinations
 227   assert_char_not_in('+', stdoutput->config_string());
 228   assert(log_is_enabled(Debug, gc), "logging was not properly enabled");
 229 
 230   // Enable 'gc*=trace' (with wildcard), verifying at least one tag combination is enabled (gc+...)
 231   LogConfiguration::configure_stdout(LogLevel::Trace, false, LOG_TAGS(gc));
 232   assert_char_in('+', stdoutput->config_string());
 233   assert(log_is_enabled(Trace, gc), "logging was not properly enabled");
 234 
 235   // Disable 'gc*' and 'logging', verifying all logging is properly disabled
 236   LogConfiguration::configure_stdout(LogLevel::Off, false, LOG_TAGS(gc));
 237   LogConfiguration::configure_stdout(LogLevel::Off, true, LOG_TAGS(logging));
 238   assert_str_eq("all=off", stdoutput->config_string());
 239 }
 240 
 241 static const char* ExpectedLine = "a (hopefully) unique log line for testing";
 242 
 243 static void init_file(const char* filename, const char* options = "") {
 244   LogConfiguration::parse_log_arguments(filename, "logging=trace", "", options,
 245                                         Log(logging)::error_stream());
 246   log_debug(logging)("%s", ExpectedLine);
 247   LogConfiguration::parse_log_arguments(filename, "all=off", "", "",
 248                                         Log(logging)::error_stream());
 249 }
 250 
 251 void Test_log_file_startup_rotation() {
 252   ResourceMark rm;
 253   const size_t rotations = 5;
 254   const char* filename = "start-rotate-test";
 255   char* rotated_file[rotations];
 256   for (size_t i = 0; i < rotations; i++) {
 257     size_t len = strlen(filename) + 3;
 258     rotated_file[i] = NEW_RESOURCE_ARRAY(char, len);
 259     jio_snprintf(rotated_file[i], len, "%s." SIZE_FORMAT, filename, i);
 260     delete_file(rotated_file[i]);
 261   };
 262 
 263   delete_file(filename);
 264   init_file(filename);
 265   assert(file_exists(filename),
 266          "configured logging to file '%s' but file was not found", filename);
 267 
 268   // Initialize the same file a bunch more times to trigger rotations
 269   for (size_t i = 0; i < rotations; i++) {
 270     init_file(filename);
 271     assert(file_exists(rotated_file[i]), "existing file was not rotated");
 272   }
 273 
 274   // Remove a file and expect its slot to be re-used
 275   delete_file(rotated_file[1]);
 276   init_file(filename);
 277   assert(file_exists(rotated_file[1]), "log file not properly rotated");
 278 
 279   // Clean up after test
 280   delete_file(filename);
 281   for (size_t i = 0; i < rotations; i++) {
 282     delete_file(rotated_file[i]);
 283   }
 284 }
 285 
 286 void Test_log_file_startup_truncation() {
 287   ResourceMark rm;
 288   const char* filename = "start-truncate-test";
 289   const char* archived_filename = "start-truncate-test.0";
 290 
 291   delete_file(filename);
 292   delete_file(archived_filename);
 293 
 294   // Use the same log file twice and expect it to be overwritten/truncated
 295   init_file(filename, "filecount=0");
 296   assert(file_exists(filename), "couldn't find log file: %s", filename);
 297 
 298   init_file(filename, "filecount=0");
 299   assert(file_exists(filename), "couldn't find log file: %s", filename);
 300   assert(!file_exists(archived_filename),
 301          "existing log file %s was not properly truncated when filecount was 0",
 302          filename);
 303 
 304   // Verify that the file was really truncated and not just appended
 305   assert(number_of_lines_with_substring_in_file(filename, ExpectedLine) == 1,
 306          "log file %s appended rather than truncated", filename);
 307 
 308   delete_file(filename);
 309   delete_file(archived_filename);
 310 }
 311 
 312 class LogMessageTest {
 313  private:
 314   static Log(logging) _log;
 315   static const char* _level_filename[];
 316 
 317   static void test_level_inclusion();
 318   static void test_long_message();
 319   static void test_message_with_many_lines();
 320   static void test_line_order();
 321   static void test_prefixing();
 322   static void test_scoped_messages();
 323   static void test_scoped_flushing();
 324   static void test_scoped_reset();
 325 
 326  public:
 327   static void test();
 328 };
 329 
 330 const char* LogMessageTest::_level_filename[] = {
 331   NULL, // LogLevel::Off
 332 #define LOG_LEVEL(name, printname) "multiline-" #printname ".log",
 333   LOG_LEVEL_LIST
 334 #undef LOG_LEVEL
 335 };
 336 
 337 void Test_multiline_logging() {
 338   LogMessageTest::test();
 339 }
 340 
 341 void LogMessageTest::test() {
 342   ResourceMark rm;
 343 
 344   for (int i = 0; i < LogLevel::Count; i++) {
 345     char buf[32];
 346     // Attempt to remove possibly pre-existing log files
 347     remove(_level_filename[i]);
 348 
 349     jio_snprintf(buf, sizeof(buf), "logging=%s", LogLevel::name(static_cast<LogLevelType>(i)));
 350     bool success = LogConfiguration::parse_log_arguments(_level_filename[i], buf,
 351                                                          NULL, NULL, _log.error_stream());
 352     assert(success, "unable to configure logging to file '%s'", _level_filename[i]);
 353   }
 354 
 355   test_level_inclusion();
 356   test_line_order();
 357   test_long_message();
 358   test_message_with_many_lines();
 359   test_prefixing();
 360   test_scoped_messages();
 361   test_scoped_flushing();
 362   test_scoped_reset();
 363 
 364   // Stop logging to the files and remove them.
 365   for (int i = 0; i < LogLevel::Count; i++) {
 366     LogConfiguration::parse_log_arguments(_level_filename[i], "all=off", NULL, NULL, _log.error_stream());
 367     remove(_level_filename[i]);
 368   }
 369 }
 370 
 371 // Verify that messages with multiple levels are written
 372 // to outputs configured for all the corresponding levels
 373 void LogMessageTest::test_level_inclusion() {
 374   const size_t message_count = 10;
 375   LogMessageBuffer msg[message_count];
 376 
 377   struct {
 378     int message_number;
 379     LogLevelType level;
 380   } lines[] = {
 381     { 0, LogLevel::Error },
 382     { 1, LogLevel::Info },
 383     { 2, LogLevel::Info }, { 2, LogLevel::Debug },
 384     { 3, LogLevel::Info }, { 3, LogLevel::Warning },
 385     { 4, LogLevel::Debug }, { 4, LogLevel::Warning },
 386     { 5, LogLevel::Trace }, { 5, LogLevel::Debug },
 387     { 6, LogLevel::Warning }, { 6, LogLevel::Error },
 388     { 7, LogLevel::Trace }, { 7, LogLevel::Info }, { 7, LogLevel::Debug },
 389     { 8, LogLevel::Trace }, { 8, LogLevel::Debug }, { 8, LogLevel::Info },
 390     { 8, LogLevel::Warning }, { 8, LogLevel::Error},
 391     { 9, LogLevel::Trace }
 392   };
 393 
 394   // Fill in messages with the above lines
 395   for (size_t i = 0; i < ARRAY_SIZE(lines); i++) {
 396     switch (lines[i].level) {
 397 #define LOG_LEVEL(name, printname) \
 398     case LogLevel::name: \
 399       msg[lines[i].message_number].printname("msg[%d]: " #printname, lines[i].message_number); \
 400       break;
 401 LOG_LEVEL_LIST
 402 #undef LOG_LEVEL
 403     }
 404   }
 405 
 406   for (size_t i = 0; i < message_count; i++) {
 407     _log.write(msg[i]);
 408   }
 409 
 410   // Verify that lines are written to the expected log files
 411   for (size_t i = 0; i < ARRAY_SIZE(lines); i++) {
 412     char expected[256];
 413     jio_snprintf(expected, sizeof(expected), "msg[%d]: %s",
 414                  lines[i].message_number, LogLevel::name(lines[i].level));
 415     for (int level = lines[i].level; level > 0; level--) {
 416       assert(file_contains_substring(_level_filename[level], expected),
 417       "line #" SIZE_FORMAT " missing from log file '%s'", i, _level_filename[level]);
 418     }
 419     for (int level = lines[i].level + 1; level < LogLevel::Count; level++) {
 420       assert(!file_contains_substring(_level_filename[level], expected),
 421       "line #" SIZE_FORMAT " erroneously included in log file '%s'", i, _level_filename[level]);
 422     }
 423   }
 424 }
 425 
 426 // Verify that messages are logged in the order they are added to the log message
 427 void LogMessageTest::test_line_order() {
 428   LogMessageBuffer msg;
 429   msg.info("info line").error("error line").trace("trace line")
 430       .error("another error").warning("warning line").debug("debug line");
 431   _log.write(msg);
 432 
 433   const char* expected[] = { "info line", "error line", "trace line",
 434                              "another error", "warning line", "debug line", NULL };
 435   assert(file_contains_substrings_in_order(_level_filename[LogLevel::Trace], expected),
 436          "output missing or in incorrect order");
 437 }
 438 
 439 void LogMessageTest::test_long_message() {
 440   // Write 10K bytes worth of log data
 441   LogMessageBuffer msg;
 442   const size_t size = 10 * K;
 443   const char* start_marker = "#start#";
 444   const char* end_marker = "#the end#";
 445   char* data = NEW_C_HEAP_ARRAY(char, size, mtLogging);
 446 
 447   // fill buffer with start_marker...some data...end_marker
 448   sprintf(data, "%s", start_marker);
 449   for (size_t i = strlen(start_marker); i < size; i++) {
 450     data[i] = '0' + (i % 10);
 451   }
 452   sprintf(data + size - strlen(end_marker) - 1, "%s", end_marker);
 453 
 454   msg.trace("%s", data); // Adds a newline, making the message exactly 10K in length.
 455   _log.write(msg);
 456 
 457   const char* expected[] = { start_marker, "0123456789", end_marker, NULL };
 458   assert(file_contains_substrings_in_order(_level_filename[LogLevel::Trace], expected),
 459          "unable to print long line");
 460   FREE_C_HEAP_ARRAY(char, data);
 461 }
 462 
 463 void LogMessageTest::test_message_with_many_lines() {
 464   const size_t lines = 100;
 465   const size_t line_length = 16;
 466 
 467   LogMessageBuffer msg;
 468   for (size_t i = 0; i < lines; i++) {
 469     msg.info("Line #" SIZE_FORMAT, i);
 470   }
 471   _log.write(msg);
 472 
 473   char expected_lines_data[lines][line_length];
 474   const char* expected_lines[lines + 1];
 475   for (size_t i = 0; i < lines; i++) {
 476     jio_snprintf(&expected_lines_data[i][0], line_length, "Line #" SIZE_FORMAT, i);
 477     expected_lines[i] = expected_lines_data[i];
 478   }
 479   expected_lines[lines] = NULL;
 480 
 481   assert(file_contains_substrings_in_order(_level_filename[LogLevel::Trace], expected_lines),
 482          "couldn't find all lines in multiline message");
 483 }
 484 
 485 static size_t dummy_prefixer(char* buf, size_t len) {
 486   static int i = 0;
 487   const char* prefix = "some prefix: ";
 488   const size_t prefix_len = strlen(prefix);
 489   if (len < prefix_len) {
 490     return prefix_len;
 491   }
 492   jio_snprintf(buf, len, "%s", prefix);
 493   return prefix_len;
 494 }
 495 
 496 void LogMessageTest::test_prefixing() {
 497   LogMessageBuffer msg;
 498   msg.set_prefix(dummy_prefixer);
 499   for (int i = 0; i < 3; i++) {
 500     msg.info("test %d", i);
 501   }
 502   msg.set_prefix(NULL);
 503   msg.info("test 3");
 504   _log.write(msg);
 505 
 506   const char* expected[] = {
 507     "] some prefix: test 0",
 508     "] some prefix: test 1",
 509     "] some prefix: test 2",
 510     "] test 3",
 511     NULL
 512   };
 513   assert(file_contains_substrings_in_order(_level_filename[LogLevel::Trace], expected), "error in prefixed output");
 514 }
 515 
 516 void LogMessageTest::test_scoped_messages() {
 517   {
 518     LogMessage(logging) msg;
 519     msg.info("scoped info");
 520     msg.warning("scoped warn");
 521     assert(!file_contains_substring(_level_filename[LogLevel::Info], "scoped info"),
 522            "scoped log message written prematurely");
 523   }
 524   assert(file_contains_substring(_level_filename[LogLevel::Info], "scoped info"),
 525          "missing output from scoped log message");
 526   assert(file_contains_substring(_level_filename[LogLevel::Warning], "scoped warn"),
 527          "missing output from scoped log message");
 528 }
 529 
 530 void LogMessageTest::test_scoped_flushing() {
 531   {
 532     LogMessage(logging) msg;
 533     msg.info("manual flush info");
 534     msg.flush();
 535     assert(file_contains_substring(_level_filename[LogLevel::Info], "manual flush info"),
 536            "missing output from manually flushed scoped log message");
 537   }
 538   const char* tmp[] = {"manual flush info", "manual flush info", NULL};
 539   assert(!file_contains_substrings_in_order(_level_filename[LogLevel::Info], tmp),
 540          "log file contains duplicate lines from single scoped log message");
 541 }
 542 
 543 void LogMessageTest::test_scoped_reset() {
 544   {
 545     LogMessage(logging) msg, partial;
 546     msg.info("%s", "info reset msg");
 547     msg.reset();
 548     partial.info("%s", "info reset msg");
 549     partial.reset();
 550     partial.trace("%s", "trace reset msg");
 551   }
 552   assert(!file_contains_substring(_level_filename[LogLevel::Info], "info reset msg"),
 553          "reset message written anyway");
 554   assert(file_contains_substring(_level_filename[LogLevel::Trace], "trace reset msg"),
 555          "missing message from partially reset scoped log message");
 556 }
 557 
 558 
 559 static int Test_logconfiguration_subscribe_triggered = 0;
 560 
 561 static void Test_logconfiguration_subscribe_helper() {
 562   Test_logconfiguration_subscribe_triggered++;
 563 }
 564 
 565 void Test_logconfiguration_subscribe() {
 566   ResourceMark rm;
 567   Log(logging) log;
 568 
 569   TestLogSavedConfig log_cfg("stdout", "logging*=trace");
 570 
 571   LogConfiguration::register_update_listener(&Test_logconfiguration_subscribe_helper);
 572 
 573   LogConfiguration::parse_log_arguments("stdout", "logging=trace", NULL, NULL, log.error_stream());
 574   assert(Test_logconfiguration_subscribe_triggered == 1, "subscription not triggered (1)");
 575 
 576   LogConfiguration::configure_stdout(LogLevel::Debug, true, LOG_TAGS(gc));
 577   assert(Test_logconfiguration_subscribe_triggered == 2, "subscription not triggered (2)");
 578 
 579   LogConfiguration::disable_logging();
 580   assert(Test_logconfiguration_subscribe_triggered == 3, "subscription not triggered (3)");
 581 }
 582 
 583 #define LOG_PREFIX_STR "THE_PREFIX "
 584 #define LOG_LINE_STR "a log line"
 585 
 586 size_t Test_log_prefix_prefixer(char* buf, size_t len) {
 587   int ret = jio_snprintf(buf, len, LOG_PREFIX_STR);
 588   assert(ret > 0, "Failed to print prefix. Log buffer too small?");
 589   return (size_t) ret;
 590 }
 591 
 592 void Test_log_prefix() {
 593   TestLogFile log_file("log_prefix");
 594   TestLogSavedConfig log_cfg(log_file.name(), "logging+test=trace");
 595 
 596   log_trace(logging, test)(LOG_LINE_STR);
 597 
 598   FILE* fp = fopen(log_file.name(), "r");
 599   assert(fp, "File read error");
 600   char output[1024];
 601   if (fgets(output, 1024, fp) != NULL) {
 602     assert(strstr(output, LOG_PREFIX_STR LOG_LINE_STR), "logging prefix error");
 603   }
 604   fclose(fp);
 605 }
 606 
 607 void Test_log_big() {
 608   char big_msg[4096] = {0};
 609   char Xchar = '~';
 610 
 611   TestLogFile log_file("log_big");
 612   TestLogSavedConfig log_cfg(log_file.name(), "logging+test=trace");
 613 
 614   memset(big_msg, Xchar, sizeof(big_msg) - 1);
 615 
 616   log_trace(logging, test)("%s", big_msg);
 617 
 618   FILE* fp = fopen(log_file.name(), "r");
 619   assert(fp, "File read error");
 620   char output[sizeof(big_msg)+128 /*decorators*/ ];
 621   if (fgets(output, sizeof(output), fp) != NULL) {
 622     assert(strstr(output, LOG_PREFIX_STR), "logging prefix error");
 623     size_t count = 0;
 624     for (size_t ps = 0 ; output[ps + count] != '\0'; output[ps + count] == Xchar ? count++ : ps++);
 625     assert(count == (sizeof(big_msg) - 1) , "logging msg error");
 626   }
 627   fclose(fp);
 628 }
 629 
 630 void Test_logtagset_duplicates() {
 631   for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
 632     char ts_name[512];
 633     ts->label(ts_name, sizeof(ts_name), ",");
 634 
 635     // verify that NO_TAG is never followed by a real tag
 636     for (size_t i = 0; i < LogTag::MaxTags; i++) {
 637       if (ts->tag(i) == LogTag::__NO_TAG) {
 638         for (i++; i < LogTag::MaxTags; i++) {
 639           assert(ts->tag(i) == LogTag::__NO_TAG,
 640                  "NO_TAG was followed by a real tag (%s) in tagset %s",
 641                  LogTag::name(ts->tag(i)), ts_name);
 642         }
 643       }
 644     }
 645 
 646     // verify that there are no duplicate tagsets (same tags in different order)
 647     for (LogTagSet* other = ts->next(); other != NULL; other = other->next()) {
 648       if (ts->ntags() != other->ntags()) {
 649         continue;
 650       }
 651       bool equal = true;
 652       for (size_t i = 0; i < ts->ntags(); i++) {
 653         LogTagType tag = ts->tag(i);
 654         if (!other->contains(tag)) {
 655           equal = false;
 656           break;
 657         }
 658       }
 659       // Since tagsets are implemented using template arguments, using both of
 660       // the (logically equivalent) tagsets (t1, t2) and (t2, t1) somewhere will
 661       // instantiate two different LogTagSetMappings. This causes multiple
 662       // tagset instances to be created for the same logical set. We want to
 663       // avoid this to save time, memory and prevent any confusion around it.
 664       if (equal) {
 665         char other_name[512];
 666         other->label(other_name, sizeof(other_name), ",");
 667         assert(false, "duplicate LogTagSets found: '%s' vs '%s' "
 668                "(tags must always be specified in the same order for each tagset)",
 669                ts_name, other_name);
 670       }
 671     }
 672   }
 673 }
 674 
 675 #define Test_logtarget_string_literal "First line"
 676 
 677 
 678 static void Test_logtarget_on() {
 679   TestLogFile log_file("log_target");
 680   TestLogSavedConfig tlsc(log_file.name(), "gc=debug");
 681 
 682   LogTarget(Debug, gc) log;
 683 
 684   assert(log.is_enabled(), "assert");
 685 
 686   // Log the line and expect it to be available in the output file.
 687   log.print(Test_logtarget_string_literal);
 688 
 689   FILE* fp = fopen(log_file.name(), "r");
 690   assert(fp != NULL, "File read error");
 691 
 692   char output[256 /* Large enough buffer */];
 693   char* res = fgets(output, sizeof(output), fp);
 694   assert(res != NULL, "assert");
 695 
 696   assert(strstr(output, Test_logtarget_string_literal) != NULL, "log line missing");
 697 
 698   fclose(fp);
 699 }
 700 
 701 static void Test_logtarget_off() {
 702   TestLogFile log_file("log_target");
 703   TestLogSavedConfig tlsc(log_file.name(), "gc=info");
 704 
 705   LogTarget(Debug, gc) log;
 706 
 707   if (log.is_enabled()) {
 708     // The log config could have been redirected gc=debug to a file. If gc=debug
 709     // is enabled, we can only test that the LogTarget returns the same value
 710     // as the log_is_enabled function. The rest of the test will be ignored.
 711     assert(log.is_enabled() == log_is_enabled(Debug, gc), "assert");
 712     log_warning(logging)("This test doesn't support runs with -Xlog");
 713     return;
 714   }
 715 
 716   // Try to log, but expect this to be filtered out.
 717   log.print(Test_logtarget_string_literal);
 718 
 719   // Log a dummy line so that fgets doesn't return NULL because the file is empty.
 720   log_info(gc)("Dummy line");
 721 
 722   FILE* fp = fopen(log_file.name(), "r");
 723   assert(fp != NULL, "File read error");
 724 
 725   char output[256 /* Large enough buffer */];
 726   char* res = fgets(output, sizeof(output), fp);
 727   assert(res != NULL, "assert");
 728 
 729   assert(strstr(output, Test_logtarget_string_literal) == NULL, "log line not missing");
 730 
 731   fclose(fp);
 732 }
 733 
 734 void Test_logtarget() {
 735   Test_logtarget_on();
 736   Test_logtarget_off();
 737 }
 738 
 739 
 740 static void Test_logstream_helper(outputStream* stream) {
 741   TestLogFile log_file("log_stream");
 742   TestLogSavedConfig tlsc(log_file.name(), "gc=debug");
 743 
 744   // Try to log, but expect this to be filtered out.
 745   stream->print("%d ", 3); stream->print("workers"); stream->cr();
 746 
 747   FILE* fp = fopen(log_file.name(), "r");
 748   assert(fp != NULL, "File read error");
 749 
 750   char output[256 /* Large enough buffer */];
 751   char* res = fgets(output, sizeof(output), fp);
 752   assert(res != NULL, "assert");
 753 
 754   assert(strstr(output, "3 workers") != NULL, "log line missing");
 755 
 756   fclose(fp);
 757 }
 758 
 759 static void Test_logstream_log() {
 760   Log(gc) log;
 761   LogStream stream(log.debug());
 762 
 763   Test_logstream_helper(&stream);
 764 }
 765 
 766 static void Test_logstream_logtarget() {
 767   LogTarget(Debug, gc) log;
 768   LogStream stream(log);
 769 
 770   Test_logstream_helper(&stream);
 771 }
 772 
 773 static void Test_logstream_logstreamhandle() {
 774   LogStreamHandle(Debug, gc) stream;
 775 
 776   Test_logstream_helper(&stream);
 777 }
 778 
 779 static void Test_logstream_no_rm() {
 780   ResourceMark rm;
 781   outputStream* stream = LogTarget(Debug, gc)::stream();
 782 
 783   Test_logstream_helper(stream);
 784 }
 785 
 786 static void Test_logstreamcheap_log() {
 787   Log(gc) log;
 788   LogStreamCHeap stream(log.debug());
 789 
 790   Test_logstream_helper(&stream);
 791 }
 792 
 793 static void Test_logstreamcheap_logtarget() {
 794   LogTarget(Debug, gc) log;
 795   LogStreamCHeap stream(log);
 796 
 797   Test_logstream_helper(&stream);
 798 }
 799 
 800 void Test_logstream() {
 801   // Test LogStreams with embedded ResourceMark.
 802   Test_logstream_log();
 803   Test_logstream_logtarget();
 804   Test_logstream_logstreamhandle();
 805 
 806   // Test LogStreams without embedded ResourceMark.
 807   Test_logstream_no_rm();
 808 
 809   // Test LogStreams backed by CHeap memory.
 810   Test_logstreamcheap_log();
 811   Test_logstreamcheap_logtarget();
 812 }
 813 
 814 void Test_loghandle_on() {
 815   TestLogFile log_file("log_handle");
 816   TestLogSavedConfig tlsc(log_file.name(), "gc=debug");
 817 
 818   Log(gc) log;
 819   LogHandle log_handle(log);
 820 
 821   assert(log_handle.is_debug(), "assert");
 822 
 823   // Try to log through a LogHandle.
 824   log_handle.debug("%d workers", 3);
 825 
 826   FILE* fp = fopen(log_file.name(), "r");
 827   assert(fp, "File read error");
 828 
 829   char output[256 /* Large enough buffer */];
 830   char* res = fgets(output, sizeof(output), fp);
 831   assert(res != NULL, "assert");
 832 
 833   assert(strstr(output, "3 workers") != NULL, "log line missing");
 834 
 835   fclose(fp);
 836 }
 837 
 838 void Test_loghandle_off() {
 839   TestLogFile log_file("log_handle");
 840   TestLogSavedConfig tlsc(log_file.name(), "gc=info");
 841 
 842   Log(gc) log;
 843   LogHandle log_handle(log);
 844 
 845   if (log_handle.is_debug()) {
 846     // The log config could have been redirected gc=debug to a file. If gc=debug
 847     // is enabled, we can only test that the LogTarget returns the same value
 848     // as the log_is_enabled function. The rest of the test will be ignored.
 849     assert(log_handle.is_debug() == log_is_enabled(Debug, gc), "assert");
 850     log_warning(logging)("This test doesn't support runs with -Xlog");
 851     return;
 852   }
 853 
 854   // Try to log through a LogHandle. Should fail, since only info is turned on.
 855   log_handle.debug("%d workers", 3);
 856 
 857   // Log a dummy line so that fgets doesn't return NULL because the file is empty.
 858   log_info(gc)("Dummy line");
 859 
 860   FILE* fp = fopen(log_file.name(), "r");
 861   assert(fp, "File read error");
 862 
 863   char output[256 /* Large enough buffer */];
 864   char* res = fgets(output, sizeof(output), fp);
 865   assert(res != NULL, "assert");
 866 
 867   assert(strstr(output, "3 workers") == NULL, "log line missing");
 868 
 869   fclose(fp);
 870 }
 871 
 872 void Test_loghandle() {
 873   Test_loghandle_on();
 874   Test_loghandle_off();
 875 }
 876 
 877 static void Test_logtargethandle_on() {
 878   TestLogFile log_file("log_handle");
 879   TestLogSavedConfig tlsc(log_file.name(), "gc=debug");
 880 
 881   LogTarget(Debug, gc) log;
 882   LogTargetHandle log_handle(log);
 883 
 884   assert(log_handle.is_enabled(), "assert");
 885 
 886   // Try to log through a LogHandle.
 887   log_handle.print("%d workers", 3);
 888 
 889   FILE* fp = fopen(log_file.name(), "r");
 890   assert(fp, "File read error");
 891 
 892   char output[256 /* Large enough buffer */];
 893   char* res = fgets(output, sizeof(output), fp);
 894   assert(res != NULL, "assert");
 895 
 896   assert(strstr(output, "3 workers") != NULL, "log line missing");
 897 
 898   fclose(fp);
 899 }
 900 
 901 static void Test_logtargethandle_off() {
 902   TestLogFile log_file("log_handle");
 903   TestLogSavedConfig tlsc(log_file.name(), "gc=info");
 904 
 905   LogTarget(Debug, gc) log;
 906   LogTargetHandle log_handle(log);
 907 
 908   if (log_handle.is_enabled()) {
 909     // The log config could have been redirected gc=debug to a file. If gc=debug
 910     // is enabled, we can only test that the LogTarget returns the same value
 911     // as the log_is_enabled function. The rest of the test will be ignored.
 912     assert(log_handle.is_enabled() == log_is_enabled(Debug, gc), "assert");
 913     log_warning(logging)("This test doesn't support runs with -Xlog");
 914     return;
 915   }
 916 
 917   // Try to log through a LogHandle. Should fail, since only info is turned on.
 918   log_handle.print("%d workers", 3);
 919 
 920   // Log a dummy line so that fgets doesn't return NULL because the file is empty.
 921   log_info(gc)("Dummy line");
 922 
 923   FILE* fp = fopen(log_file.name(), "r");
 924   assert(fp, "File read error");
 925 
 926   char output[256 /* Large enough buffer */];
 927   char* res = fgets(output, sizeof(output), fp);
 928   assert(res != NULL, "assert");
 929 
 930   assert(strstr(output, "3 workers") == NULL, "log line missing");
 931 
 932   fclose(fp);
 933 }
 934 
 935 void Test_logtargethandle() {
 936   Test_logtargethandle_on();
 937   Test_logtargethandle_off();
 938 }
 939 
 940 static void Test_log_gctracetime_full() {
 941   TestLogFile log_file("log_gctracetime");
 942   TestLogSavedConfig tlsc(log_file.name(), "gc=debug,gc+start=debug");
 943 
 944   LogTarget(Debug, gc) gc_debug;
 945   LogTarget(Debug, gc, start) gc_start_debug;
 946 
 947   assert(gc_debug.is_enabled(), "assert");
 948   assert(gc_start_debug.is_enabled(), "assert");
 949 
 950   {
 951     MutexLocker lock(Heap_lock); // Needed to read heap usage
 952     GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_allocation_failure, true);
 953   }
 954 
 955   FILE* fp = fopen(log_file.name(), "r");
 956   assert(fp, "File read error");
 957 
 958   char output[256 /* Large enough buffer */];
 959 
 960   char* res = fgets(output, sizeof(output), fp);
 961   assert(res != NULL, "assert");
 962 
 963   // [2.975s][debug][gc,start] Test GC (Allocation Failure) (2.975s)
 964   assert(strstr(output, "[gc,start") != NULL, "Incorrect tag set");
 965   assert(strstr(output, "] Test GC (Allocation Failure) (") != NULL, "Incorrect log line");
 966   assert(strstr(output, "s)") != NULL, "Incorrect log line");
 967 
 968   res = fgets(output, sizeof(output), fp);
 969   assert(res != NULL, "assert");
 970 
 971   // [2.975s][debug][gc      ] Test GC (Allocation Failure) 59M->59M(502M) (2.975s, 2.975s) 0.026ms
 972   assert(strstr(output, "[gc ") != NULL, "Incorrect tag set");
 973   assert(strstr(output, "] Test GC (Allocation Failure) ") != NULL, "Incorrect log line");
 974   assert(strstr(output, "M) (") != NULL, "Incorrect log line");
 975   assert(strstr(output, "s, ") != NULL, "Incorrect log line");
 976   assert(strstr(output, "s) ") != NULL, "Incorrect log line");
 977   assert(strstr(output, "ms") != NULL, "Incorrect log line");
 978 
 979   fclose(fp);
 980 }
 981 
 982 static void Test_log_gctracetime_full_multitag() {
 983   TestLogFile log_file("log_gctracetime");
 984   TestLogSavedConfig tlsc(log_file.name(), "gc+ref=debug,gc+ref+start=debug");
 985 
 986   LogTarget(Debug, gc, ref) gc_debug;
 987   LogTarget(Debug, gc, ref, start) gc_start_debug;
 988 
 989   assert(gc_debug.is_enabled(), "assert");
 990   assert(gc_start_debug.is_enabled(), "assert");
 991 
 992   {
 993     MutexLocker lock(Heap_lock); // Needed to read heap usage
 994     GCTraceTime(Debug, gc, ref) timer("Test GC", NULL, GCCause::_allocation_failure, true);
 995   }
 996 
 997   FILE* fp = fopen(log_file.name(), "r");
 998   assert(fp, "File read error");
 999 
1000   char output[256 /* Large enough buffer */];
1001 
1002   char* res = fgets(output, sizeof(output), fp);
1003   assert(res != NULL, "assert");
1004 
1005   // [2.975s][debug][gc,start] Test GC (Allocation Failure) (2.975s)
1006   assert(strstr(output, "[gc,ref,start") != NULL, "Incorrect tag set");
1007   assert(strstr(output, "] Test GC (Allocation Failure) (") != NULL, "Incorrect log line");
1008   assert(strstr(output, "s)") != NULL, "Incorrect log line");
1009 
1010   res = fgets(output, sizeof(output), fp);
1011   assert(res != NULL, "assert");
1012 
1013   // [2.975s][debug][gc      ] Test GC (Allocation Failure) 59M->59M(502M) (2.975s, 2.975s) 0.026ms
1014   assert(strstr(output, "[gc,ref ") != NULL, "Incorrect tag set");
1015   assert(strstr(output, "] Test GC (Allocation Failure) ") != NULL, "Incorrect log line");
1016   assert(strstr(output, "M) (") != NULL, "Incorrect log line");
1017   assert(strstr(output, "s, ") != NULL, "Incorrect log line");
1018   assert(strstr(output, "s) ") != NULL, "Incorrect log line");
1019   assert(strstr(output, "ms") != NULL, "Incorrect log line");
1020 
1021   fclose(fp);
1022 }
1023 
1024 static void Test_log_gctracetime_no_heap() {
1025   TestLogFile log_file("log_gctracetime");
1026   TestLogSavedConfig tlsc(log_file.name(), "gc=debug,gc+start=debug");
1027 
1028   LogTarget(Debug, gc) gc_debug;
1029   LogTarget(Debug, gc, start) gc_start_debug;
1030 
1031   assert(gc_debug.is_enabled(), "assert");
1032   assert(gc_start_debug.is_enabled(), "assert");
1033 
1034   {
1035     GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_allocation_failure, false);
1036   }
1037 
1038   FILE* fp = fopen(log_file.name(), "r");
1039   assert(fp, "File read error");
1040 
1041   char output[256 /* Large enough buffer */];
1042 
1043   char* res = fgets(output, sizeof(output), fp);
1044   assert(res != NULL, "assert");
1045 
1046   // [2.975s][debug][gc,start] Test GC (Allocation Failure) (2.975s)
1047   assert(strstr(output, "[gc,start") != NULL, "Incorrect tag set");
1048   assert(strstr(output, "] Test GC (Allocation Failure) (") != NULL, "Incorrect log line");
1049   assert(strstr(output, "s)") != NULL, "Incorrect log line");
1050 
1051   res = fgets(output, sizeof(output), fp);
1052   assert(res != NULL, "assert");
1053 
1054   // [2.975s][debug][gc      ] Test GC (Allocation Failure) (2.975s, 2.975s) 0.026ms
1055   assert(strstr(output, "[gc ") != NULL, "Incorrect tag set");
1056   assert(strstr(output, "] Test GC (Allocation Failure) (") != NULL, "Incorrect log line");
1057   assert(strstr(output, "M) (") == NULL, "Incorrect log line");
1058   assert(strstr(output, "s, ") != NULL, "Incorrect log line");
1059   assert(strstr(output, "s) ") != NULL, "Incorrect log line");
1060   assert(strstr(output, "ms") != NULL, "Incorrect log line");
1061 
1062   fclose(fp);
1063 }
1064 
1065 static void Test_log_gctracetime_no_cause() {
1066   TestLogFile log_file("log_gctracetime");
1067   TestLogSavedConfig tlsc(log_file.name(), "gc=debug,gc+start=debug");
1068 
1069   LogTarget(Debug, gc) gc_debug;
1070   LogTarget(Debug, gc, start) gc_start_debug;
1071 
1072   assert(gc_debug.is_enabled(), "assert");
1073   assert(gc_start_debug.is_enabled(), "assert");
1074 
1075   {
1076     MutexLocker lock(Heap_lock); // Needed to read heap usage
1077     GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_no_gc, true);
1078   }
1079 
1080   FILE* fp = fopen(log_file.name(), "r");
1081   assert(fp, "File read error");
1082 
1083   char output[256 /* Large enough buffer */];
1084 
1085   char* res = fgets(output, sizeof(output), fp);
1086   assert(res != NULL, "assert");
1087 
1088   // [2.975s][debug][gc,start] Test GC (2.975s)
1089   assert(strstr(output, "[gc,start") != NULL, "Incorrect tag set");
1090   assert(strstr(output, "] Test GC (") != NULL, "Incorrect log line");
1091   assert(strstr(output, "s)") != NULL, "Incorrect log line");
1092 
1093   res = fgets(output, sizeof(output), fp);
1094   assert(res != NULL, "assert");
1095 
1096   // [2.975s][debug][gc      ] Test GC 59M->59M(502M) (2.975s, 2.975s) 0.026ms
1097   assert(strstr(output, "[gc ") != NULL, "Incorrect tag set");
1098   assert(strstr(output, "] Test GC ") != NULL, "Incorrect log line");
1099   assert(strstr(output, "M) (") != NULL, "Incorrect log line");
1100   assert(strstr(output, "s, ") != NULL, "Incorrect log line");
1101   assert(strstr(output, "s) ") != NULL, "Incorrect log line");
1102   assert(strstr(output, "ms") != NULL, "Incorrect log line");
1103 
1104   fclose(fp);
1105 }
1106 
1107 static void Test_log_gctracetime_no_heap_no_cause() {
1108   TestLogFile log_file("log_gctracetime");
1109   TestLogSavedConfig tlsc(log_file.name(), "gc=debug,gc+start=debug");
1110 
1111   LogTarget(Debug, gc) gc_debug;
1112   LogTarget(Debug, gc, start) gc_start_debug;
1113 
1114   assert(gc_debug.is_enabled(), "assert");
1115   assert(gc_start_debug.is_enabled(), "assert");
1116 
1117   {
1118     MutexLocker lock(Heap_lock); // Needed to read heap usage
1119     GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_no_gc, false);
1120   }
1121 
1122   FILE* fp = fopen(log_file.name(), "r");
1123   assert(fp, "File read error");
1124 
1125   char output[256 /* Large enough buffer */];
1126 
1127   char* res = fgets(output, sizeof(output), fp);
1128   assert(res != NULL, "assert");
1129 
1130   // [2.975s][debug][gc,start] Test GC (2.975s)
1131   assert(strstr(output, "[gc,start") != NULL, "Incorrect tag set");
1132   assert(strstr(output, "] Test GC (") != NULL, "Incorrect log line");
1133   assert(strstr(output, "s)") != NULL, "Incorrect log line");
1134 
1135   res = fgets(output, sizeof(output), fp);
1136   assert(res != NULL, "assert");
1137 
1138   // [2.975s][debug][gc      ] Test GC (2.975s, 2.975s) 0.026ms
1139   assert(strstr(output, "[gc ") != NULL, "Incorrect tag set");
1140   assert(strstr(output, "] Test GC (") != NULL, "Incorrect log line");
1141   assert(strstr(output, "M) (") == NULL, "Incorrect log line");
1142   assert(strstr(output, "s, ") != NULL, "Incorrect log line");
1143   assert(strstr(output, "s) ") != NULL, "Incorrect log line");
1144   assert(strstr(output, "ms") != NULL, "Incorrect log line");
1145 
1146   fclose(fp);
1147 }
1148 
1149 void Test_log_gctracetime() {
1150   Test_log_gctracetime_full();
1151   Test_log_gctracetime_full_multitag();
1152   Test_log_gctracetime_no_heap();
1153   Test_log_gctracetime_no_cause();
1154   Test_log_gctracetime_no_heap_no_cause();
1155 }
1156 
1157 void Test_invalid_log_file() {
1158   ResourceMark rm;
1159   stringStream ss;
1160   const char* target_name = "tmplogdir";
1161 
1162   // Attempt to log to a directory (existing log not a regular file)
1163   create_directory(target_name);
1164   LogFileOutput bad_file("tmplogdir");
1165   assert(bad_file.initialize("", &ss) == false, "file was initialized "
1166          "when there was an existing directory with the same name");
1167   assert(strstr(ss.as_string(), "tmplogdir is not a regular file") != NULL,
1168          "missing expected error message, received msg: %s", ss.as_string());
1169   ss.reset();
1170   remove(target_name);
1171 }
1172 
1173 // Ensure -Xlog:help and LogConfiguration::describe contain tagset descriptions
1174 void Test_logtagset_descriptions() {
1175   for (LogTagSetDescription* d = tagset_descriptions; d->tagset != NULL; d++) {
1176     char expected[1024];
1177     d->tagset->label(expected, sizeof(expected), "+");
1178     jio_snprintf(expected + strlen(expected),
1179                  sizeof(expected) - strlen(expected),
1180                  ": %s", d->descr);
1181 
1182     ResourceMark rm;
1183     stringStream ss;
1184     LogConfiguration::describe(&ss);
1185     assert(strstr(ss.as_string(), expected) != NULL,
1186            "missing log tag set descriptions in LogConfiguration::describe");
1187 
1188     TestLogFile file("log_tagset_descriptions");
1189     FILE* fp = fopen(file.name(), "w+");
1190     assert(fp != NULL, "File open error");
1191     LogConfiguration::print_command_line_help(fp);
1192     fclose(fp);
1193     assert(number_of_lines_with_substring_in_file(file.name(), expected) > 0,
1194            "missing log tag set descriptions in -Xlog:help output");
1195   }
1196 }
1197 #endif // PRODUCT