8049253: Better GC validation

Summary: Also reviewed by: boris.molodenkov@oracle.com
Reviewed-by: dcubed, minqi, mschoene
Contributed-by: yasuenag@gmail.com, bengt.rutisson@oracle.com

src/share/vm/utilities/defaultStream.hpp

@@ -41,6 +41,8 @@ class defaultStream : public xmlTextStream {
 
   void init();
   void init_log();
+  fileStream* open_file(const char* log_name);
+  void start_log();
   void finish_log();
   void finish_log_on_error(char *buf, int buflen);
  public:

src/share/vm/utilities/ostream.cpp

@@ -360,7 +360,6 @@ extern Mutex* tty_lock;
 
 #define EXTRACHARLEN   32
 #define CURRENTAPPX    ".current"
-#define FILENAMEBUFLEN  1024
 // convert YYYY-MM-DD HH:MM:SS to YYYY-MM-DD_HH-MM-SS
 char* get_datetime_string(char *buf, size_t len) {
   os::local_time_string(buf, len);
@@ -394,7 +393,6 @@ static const char* make_log_name_internal(const char* log_name, const char* forc
     buffer_length = strlen(log_name) + 1;
   }
 
-  // const char* star = strchr(basename, '*');
   const char* pts = strstr(basename, "%p");
   int pid_pos = (pts == NULL) ? -1 : (pts - nametail);
 
@@ -409,6 +407,11 @@ static const char* make_log_name_internal(const char* log_name, const char* forc
     buffer_length += strlen(tms);
   }
 
+  // File name is too long.
+  if (buffer_length > JVM_MAXPATHLEN) {
+    return NULL;
+  }
+
   // Create big enough buffer.
   char *buf = NEW_C_HEAP_ARRAY(char, buffer_length, mtInternal);
 
@@ -481,46 +484,88 @@ static const char* make_log_name(const char* log_name, const char* force_directo
 void test_loggc_filename() {
   int pid;
   char  tms[32];
-  char  i_result[FILENAMEBUFLEN];
+  char  i_result[JVM_MAXPATHLEN];
   const char* o_result;
   get_datetime_string(tms, sizeof(tms));
   pid = os::current_process_id();
 
   // test.log
-  jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test.log", tms);
+  jio_snprintf(i_result, JVM_MAXPATHLEN, "test.log", tms);
   o_result = make_log_name_internal("test.log", NULL, pid, tms);
   assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test.log\", NULL)");
   FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
 
   // test-%t-%p.log
-  jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test-%s-pid%u.log", tms, pid);
+  jio_snprintf(i_result, JVM_MAXPATHLEN, "test-%s-pid%u.log", tms, pid);
   o_result = make_log_name_internal("test-%t-%p.log", NULL, pid, tms);
   assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test-%%t-%%p.log\", NULL)");
   FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
 
   // test-%t%p.log
-  jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test-%spid%u.log", tms, pid);
+  jio_snprintf(i_result, JVM_MAXPATHLEN, "test-%spid%u.log", tms, pid);
   o_result = make_log_name_internal("test-%t%p.log", NULL, pid, tms);
   assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test-%%t%%p.log\", NULL)");
   FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
 
   // %p%t.log
-  jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "pid%u%s.log", pid, tms);
+  jio_snprintf(i_result, JVM_MAXPATHLEN, "pid%u%s.log", pid, tms);
   o_result = make_log_name_internal("%p%t.log", NULL, pid, tms);
   assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%p%%t.log\", NULL)");
   FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
 
   // %p-test.log
-  jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "pid%u-test.log", pid);
+  jio_snprintf(i_result, JVM_MAXPATHLEN, "pid%u-test.log", pid);
   o_result = make_log_name_internal("%p-test.log", NULL, pid, tms);
   assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%p-test.log\", NULL)");
   FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
 
   // %t.log
-  jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "%s.log", tms);
+  jio_snprintf(i_result, JVM_MAXPATHLEN, "%s.log", tms);
   o_result = make_log_name_internal("%t.log", NULL, pid, tms);
   assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%t.log\", NULL)");
   FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
+
+  {
+    // longest filename
+    char longest_name[JVM_MAXPATHLEN];
+    memset(longest_name, 'a', sizeof(longest_name));
+    longest_name[JVM_MAXPATHLEN - 1] = '\0';
+    o_result = make_log_name_internal((const char*)&longest_name, NULL, pid, tms);
+    assert(strcmp(longest_name, o_result) == 0, err_msg("longest name does not match. expected '%s' but got '%s'", longest_name, o_result));
+    FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
+  }
+
+  {
+    // too long file name
+    char too_long_name[JVM_MAXPATHLEN + 100];
+    int too_long_length = sizeof(too_long_name);
+    memset(too_long_name, 'a', too_long_length);
+    too_long_name[too_long_length - 1] = '\0';
+    o_result = make_log_name_internal((const char*)&too_long_name, NULL, pid, tms);
+    assert(o_result == NULL, err_msg("Too long file name should return NULL, but got '%s'", o_result));
+  }
+
+  {
+    // too long with timestamp
+    char longest_name[JVM_MAXPATHLEN];
+    memset(longest_name, 'a', JVM_MAXPATHLEN);
+    longest_name[JVM_MAXPATHLEN - 3] = '%';
+    longest_name[JVM_MAXPATHLEN - 2] = 't';
+    longest_name[JVM_MAXPATHLEN - 1] = '\0';
+    o_result = make_log_name_internal((const char*)&longest_name, NULL, pid, tms);
+    assert(o_result == NULL, err_msg("Too long file name after timestamp expansion should return NULL, but got '%s'", o_result));
+  }
+
+  {
+    // too long with pid
+    char longest_name[JVM_MAXPATHLEN];
+    memset(longest_name, 'a', JVM_MAXPATHLEN);
+    longest_name[JVM_MAXPATHLEN - 3] = '%';
+    longest_name[JVM_MAXPATHLEN - 2] = 'p';
+    longest_name[JVM_MAXPATHLEN - 1] = '\0';
+    o_result = make_log_name_internal((const char*)&longest_name, NULL, pid, tms);
+    assert(o_result == NULL, err_msg("Too long file name after pid expansion should return NULL, but got '%s'", o_result));
+  }
 }
 #endif // PRODUCT
 
@@ -629,9 +674,16 @@ gcLogFileStream::gcLogFileStream(const char* file_name) {
   _bytes_written = 0L;
   _file_name = make_log_name(file_name, NULL);
 
+  if (_file_name == NULL) {
+    warning("Cannot open file %s: file name is too long.\n", file_name);
+    _need_close = false;
+    UseGCLogFileRotation = false;
+    return;
+  }
+
   // gc log file rotation
   if (UseGCLogFileRotation && NumberOfGCLogFiles > 1) {
-    char tempbuf[FILENAMEBUFLEN];
+    char tempbuf[JVM_MAXPATHLEN];
     jio_snprintf(tempbuf, sizeof(tempbuf), "%s.%d" CURRENTAPPX, _file_name, _cur_file_num);
     _file = fopen(tempbuf, "w");
   } else {
@@ -663,10 +715,10 @@ void gcLogFileStream::write(const char* s, size_t len) {
 // concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log
 // must be synchronized.
 void gcLogFileStream::rotate_log(bool force, outputStream* out) {
-  char time_msg[FILENAMEBUFLEN];
+  char time_msg[O_BUFLEN];
   char time_str[EXTRACHARLEN];
-  char current_file_name[FILENAMEBUFLEN];
-  char renamed_file_name[FILENAMEBUFLEN];
+  char current_file_name[JVM_MAXPATHLEN];
+  char renamed_file_name[JVM_MAXPATHLEN];
 
   if (!should_rotate(force)) {
     return;
@@ -705,12 +757,15 @@ void gcLogFileStream::rotate_log(bool force, outputStream* out) {
   // have a form of extended_filename.<i>.current where i is the current rotation
   // file number. After it reaches max file size, the file will be saved and renamed
   // with .current removed from its tail.
-  size_t filename_len = strlen(_file_name);
   if (_file != NULL) {
-    jio_snprintf(renamed_file_name, filename_len + EXTRACHARLEN, "%s.%d",
-                 _file_name, _cur_file_num);
-    jio_snprintf(current_file_name, filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX,
+    jio_snprintf(renamed_file_name, JVM_MAXPATHLEN, "%s.%d",
                  _file_name, _cur_file_num);
+    int result = jio_snprintf(current_file_name, JVM_MAXPATHLEN,
+                              "%s.%d" CURRENTAPPX, _file_name, _cur_file_num);
+    if (result >= JVM_MAXPATHLEN) {
+      warning("Cannot create new log file name: %s: file name is too long.\n", current_file_name);
+      return;
+    }
 
     const char* msg = force ? "GC log rotation request has been received."
                             : "GC log file has reached the maximum size.";
@@ -749,19 +804,23 @@ void gcLogFileStream::rotate_log(bool force, outputStream* out) {
 
   _cur_file_num++;
   if (_cur_file_num > NumberOfGCLogFiles - 1) _cur_file_num = 0;
-  jio_snprintf(current_file_name,  filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX,
+  int result = jio_snprintf(current_file_name,  JVM_MAXPATHLEN, "%s.%d" CURRENTAPPX,
                _file_name, _cur_file_num);
+  if (result >= JVM_MAXPATHLEN) {
+    warning("Cannot create new log file name: %s: file name is too long.\n", current_file_name);
+    return;
+  }
+
   _file = fopen(current_file_name, "w");
 
   if (_file != NULL) {
     _bytes_written = 0L;
     _need_close = true;
     // reuse current_file_name for time_msg
-    jio_snprintf(current_file_name, filename_len + EXTRACHARLEN,
+    jio_snprintf(current_file_name, JVM_MAXPATHLEN,
                  "%s.%d", _file_name, _cur_file_num);
     jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file created %s\n",
-                           os::local_time_string((char *)time_str, sizeof(time_str)),
-                           current_file_name);
+                 os::local_time_string((char *)time_str, sizeof(time_str)), current_file_name);
     write(time_msg, strlen(time_msg));
 
     if (out != NULL) {
@@ -809,32 +868,64 @@ bool defaultStream::has_log_file() {
   return _log_file != NULL;
 }
 
-void defaultStream::init_log() {
-  // %%% Need a MutexLocker?
-  const char* log_name = LogFile != NULL ? LogFile : "hotspot_%p.log";
+fileStream* defaultStream::open_file(const char* log_name) {
   const char* try_name = make_log_name(log_name, NULL);
-  fileStream* file = new(ResourceObj::C_HEAP, mtInternal) fileStream(try_name);
-  if (!file->is_open()) {
-    // Try again to open the file.
-    char warnbuf[O_BUFLEN*2];
-    jio_snprintf(warnbuf, sizeof(warnbuf),
-                 "Warning:  Cannot open log file: %s\n", try_name);
-    // Note:  This feature is for maintainer use only.  No need for L10N.
-    jio_print(warnbuf);
-    FREE_C_HEAP_ARRAY(char, try_name, mtInternal);
-    try_name = make_log_name(log_name, os::get_temp_directory());
-    jio_snprintf(warnbuf, sizeof(warnbuf),
-                 "Warning:  Forcing option -XX:LogFile=%s\n", try_name);
-    jio_print(warnbuf);
-    delete file;
-    file = new(ResourceObj::C_HEAP, mtInternal) fileStream(try_name);
+  if (try_name == NULL) {
+    warning("Cannot open file %s: file name is too long.\n", log_name);
+    return NULL;
   }
+
+  fileStream* file = new(ResourceObj::C_HEAP, mtInternal) fileStream(try_name);
   FREE_C_HEAP_ARRAY(char, try_name, mtInternal);
+  if (file->is_open()) {
+    return file;
+  }
+
+  // Try again to open the file in the temp directory.
+  delete file;
+  char warnbuf[O_BUFLEN*2];
+  jio_snprintf(warnbuf, sizeof(warnbuf), "Warning:  Cannot open log file: %s\n", log_name);
+  // Note:  This feature is for maintainer use only.  No need for L10N.
+  jio_print(warnbuf);
+  try_name = make_log_name(log_name, os::get_temp_directory());
+  if (try_name == NULL) {
+    warning("Cannot open file %s: file name is too long for directory %s.\n", log_name, os::get_temp_directory());
+    return NULL;
+  }
 
+  jio_snprintf(warnbuf, sizeof(warnbuf),
+               "Warning:  Forcing option -XX:LogFile=%s\n", try_name);
+  jio_print(warnbuf);
+
+  file = new(ResourceObj::C_HEAP, mtInternal) fileStream(try_name);
+  FREE_C_HEAP_ARRAY(char, try_name, mtInternal);
   if (file->is_open()) {
+    return file;
+  }
+
+  delete file;
+  return NULL;
+}
+
+void defaultStream::init_log() {
+  // %%% Need a MutexLocker?
+  const char* log_name = LogFile != NULL ? LogFile : "hotspot_%p.log";
+  fileStream* file = open_file(log_name);
+
+  if (file != NULL) {
     _log_file = file;
-    xmlStream* xs = new(ResourceObj::C_HEAP, mtInternal) xmlStream(file);
-    _outer_xmlStream = xs;
+    _outer_xmlStream = new(ResourceObj::C_HEAP, mtInternal) xmlStream(file);
+    start_log();
+  } else {
+    // and leave xtty as NULL
+    LogVMOutput = false;
+    DisplayVMOutput = true;
+    LogCompilation = false;
+  }
+}
+
+void defaultStream::start_log() {
+  xmlStream*xs = _outer_xmlStream;
     if (this == tty)  xtty = xs;
     // Write XML header.
     xs->print_cr("<?xml version='1.0' encoding='UTF-8'?>");
@@ -889,13 +980,6 @@ void defaultStream::init_log() {
     xs->head("tty");
     // All further non-markup text gets copied to the tty:
     xs->_text = this;  // requires friend declaration!
-  } else {
-    delete(file);
-    // and leave xtty as NULL
-    LogVMOutput = false;
-    DisplayVMOutput = true;
-    LogCompilation = false;
-  }
 }
 
 // finish_log() is called during normal VM shutdown. finish_log_on_error() is