From aebaa21cb2af7e3b85035052bc2509c7017e5e36 Mon Sep 17 00:00:00 2001 From: brutisso Date: Tue, 19 Aug 2014 11:17:36 +0200 Subject: [PATCH] 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 | 2 + src/share/vm/utilities/ostream.cpp | 180 +++++++++++++++++------ 2 files changed, 134 insertions(+), 48 deletions(-) diff --git a/src/share/vm/utilities/defaultStream.hpp b/src/share/vm/utilities/defaultStream.hpp index 8b5c1a85a..bdc295511 100644 --- a/src/share/vm/utilities/defaultStream.hpp +++ b/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: diff --git a/src/share/vm/utilities/ostream.cpp b/src/share/vm/utilities/ostream.cpp index 0143e3f5a..a1871211e 100644 --- a/src/share/vm/utilities/ostream.cpp +++ b/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..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(""); @@ -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 -- GitLab