--- old/src/share/vm/utilities/ostream.cpp Wed Sep 4 19:27:25 2013 +++ new/src/share/vm/utilities/ostream.cpp Wed Sep 4 19:27:25 2013 @@ -342,7 +342,7 @@ } char* stringStream::as_string() { - char* copy = NEW_RESOURCE_ARRAY(char, buffer_pos+1); + char* copy = NEW_RESOURCE_ARRAY(char, buffer_pos + 1); strncpy(copy, buffer, buffer_pos); copy[buffer_pos] = 0; // terminating null return copy; @@ -355,14 +355,121 @@ outputStream* gclog_or_tty; 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); + int i = strlen(buf); + while (i-- >= 0) { + if (buf[i] == ' ') buf[i] = '_'; + else if (buf[i] == ':') buf[i] = '-'; + } + return buf; +} + +char* extend_file_name(const char* file_name) { + char* extended_name = NULL; + char timestr[EXTRACHARLEN]; + char pidtext[EXTRACHARLEN]; + const char* spp = strstr(file_name, "%p"); + const char* spt = strstr(file_name, "%t"); + int pp = (spp != NULL) ? spp - file_name : -1; + int pt = (spt != NULL) ? spt - file_name : -1; + + if (pp < 0 && pt < 0) { + extended_name = NEW_C_HEAP_ARRAY(char, strlen(file_name) + 1, mtInternal); + strcpy(extended_name, file_name); + return extended_name; + } + + if (pp > 0) { + jio_snprintf(pidtext, sizeof(pidtext), "pid%d", os::current_process_id()); + } else { + pidtext[0] = '\0'; + } + + if (pt > 0) { + get_datetime_string(timestr, sizeof(timestr)); + } else { + timestr[0] = '\0'; + } + + size_t len = strlen(file_name) + strlen(pidtext) + strlen(timestr) + 2 * EXTRACHARLEN; + extended_name = NEW_C_HEAP_ARRAY(char, len, mtInternal); + if (pp > 0 && pt > 0 ) { + // *%p*%t* + if (pp < pt) { + memcpy(extended_name, file_name, (size_t)pp); + extended_name[pp] = '\0'; + strcat(extended_name, pidtext); + size_t t_len = strlen(extended_name); + if (pt - pp > 2) { + memcpy(extended_name + t_len, file_name + pp + 2, pt - pp - 2); + extended_name[t_len + pt - pp - 2] = '\0'; + } + strcat(extended_name, timestr); + strcat(extended_name, file_name + pt + 2); + // *%t*%p* + } else { + memcpy(extended_name, file_name, (size_t)(pt)); + extended_name[pt] = '\0'; + strcat(extended_name, timestr); + size_t t_len = strlen(extended_name); + if (pp - pt > 2) { + memcpy(extended_name + t_len, file_name + pt + 2, pp - pt - 2); + extended_name[t_len + pp - pt - 2] = '\0'; + } + strcat(extended_name, pidtext); + strcat(extended_name, file_name + pp + 2); + } + return extended_name; + } + + if (pp > 0) { + // only requested pid + memcpy(extended_name, file_name, (size_t)pp); + extended_name[pp] = '\0'; + strcat(extended_name, pidtext); + strcat(extended_name, file_name + pp + 2); + } + + if (pt > 0) { + // only requested timestamp + memcpy(extended_name, file_name, (size_t)pt); + extended_name[pt] = '\0'; + strcat(extended_name, timestr); + strcat(extended_name, file_name + pt + 2); + } + return extended_name; +} + +// log vm version, os verison, platform info, build id, +// memory usage and command line flags into head of fileStream +void fileStream::dump_loggc_header() { + if(is_open()) { + this->print_cr(Abstract_VM_Version::internal_vm_info_string()); + os::print_memory_info(this); + this->print("CommandLine flags: "); + CommandLineFlags::printSetFlags(this); + } +} + fileStream::fileStream(const char* file_name) { - _file = fopen(file_name, "w"); + char* f_name = extend_file_name(file_name); + _file = fopen(f_name, "w"); _need_close = true; + FREE_C_HEAP_ARRAY(char, f_name, mtInternal); + dump_loggc_header(); } fileStream::fileStream(const char* file_name, const char* opentype) { - _file = fopen(file_name, opentype); + char* f_name = extend_file_name(file_name); + _file = fopen(f_name, opentype); _need_close = true; + FREE_C_HEAP_ARRAY(char, f_name, mtInternal); + dump_loggc_header(); } void fileStream::write(const char* s, size_t len) { @@ -426,7 +533,9 @@ rotatingFileStream::~rotatingFileStream() { if (_file != NULL) { if (_need_close) fclose(_file); - _file = NULL; + _file = NULL; + } + if (_file_name != NULL) { FREE_C_HEAP_ARRAY(char, _file_name, mtInternal); _file_name = NULL; } @@ -433,21 +542,20 @@ } rotatingFileStream::rotatingFileStream(const char* file_name) { + assert(UseGCLogFileRotation, "Should use UseGCLogFileRotation"); _cur_file_num = 0; _bytes_written = 0L; - _file_name = NEW_C_HEAP_ARRAY(char, strlen(file_name)+10, mtInternal); - jio_snprintf(_file_name, strlen(file_name)+10, "%s.%d", file_name, _cur_file_num); - _file = fopen(_file_name, "w"); - _need_close = true; -} + _file_name = extend_file_name(file_name); -rotatingFileStream::rotatingFileStream(const char* file_name, const char* opentype) { - _cur_file_num = 0; - _bytes_written = 0L; - _file_name = NEW_C_HEAP_ARRAY(char, strlen(file_name)+10, mtInternal); - jio_snprintf(_file_name, strlen(file_name)+10, "%s.%d", file_name, _cur_file_num); - _file = fopen(_file_name, opentype); + if (NumberOfGCLogFiles > 1) { + char tempbuf[FILENAMEBUFLEN]; + jio_snprintf(tempbuf, sizeof(tempbuf), "%s.%d" CURRENTAPPX, _file_name, _cur_file_num); + _file = fopen(tempbuf, "w"); + } else { + _file = fopen(_file_name, "w"); + } _need_close = true; + dump_loggc_header(); } void rotatingFileStream::write(const char* s, size_t len) { @@ -467,6 +575,11 @@ // concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log // must be synchronized. void rotatingFileStream::rotate_log() { + char time_msg[FILENAMEBUFLEN]; + char time_str[EXTRACHARLEN]; + char current_file_name[FILENAMEBUFLEN]; + char renamed_file_name[FILENAMEBUFLEN]; + if (_bytes_written < (jlong)GCLogFileSize) { return; } @@ -481,27 +594,89 @@ // rotate in same file rewind(); _bytes_written = 0L; + jio_snprintf(time_msg, sizeof(time_msg), "File %s rotated at %s\n", + _file_name, os::local_time_string((char *)time_str, sizeof(time_str))); + this->write(time_msg, strlen(time_msg)); + dump_loggc_header(); return; } - // rotate file in names file.0, file.1, file.2, ..., file. - // close current file, rotate to next file +#if defined(_WINDOWS) +#ifndef F_OK +#define F_OK 0 +#endif +#endif // _WINDOWS + + // rotate file in names extended_filename.0, extended_filename.1, ..., + // extended_filename.. Current rotation file name will + // 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) { - _cur_file_num ++; - if (_cur_file_num >= NumberOfGCLogFiles) _cur_file_num = 0; - jio_snprintf(_file_name, strlen(Arguments::gc_log_filename()) + 10, "%s.%d", - Arguments::gc_log_filename(), _cur_file_num); + 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, + _file_name, _cur_file_num); + jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file has reached the" + " maximum size. Saved as %s\n", + os::local_time_string((char *)time_str, sizeof(time_str)), + renamed_file_name); + this->write(time_msg, strlen(time_msg)); + fclose(_file); _file = NULL; + + bool can_rename = true; + if (access(current_file_name, F_OK) != 0) { + // current file does not exist? + warning("No source file exists, cannot rename\n"); + can_rename = false; + } + if (can_rename) { + if (access(renamed_file_name, F_OK) == 0) { + if (remove(renamed_file_name) != 0) { + warning("Could not delete existing file %s\n", renamed_file_name); + can_rename = false; + } + } else { + // file does not exist, ok to rename + } + } + if (can_rename && rename(current_file_name, renamed_file_name) != 0) { + warning("Could not rename %s to %s\n", _file_name, renamed_file_name); + } } - _file = fopen(_file_name, "w"); + + _cur_file_num++; + if (_cur_file_num > NumberOfGCLogFiles - 1) _cur_file_num = 0; + jio_snprintf(current_file_name, filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX, + _file_name, _cur_file_num); + _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, + "%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); + this->write(time_msg, strlen(time_msg)); + dump_loggc_header(); + // remove the existing file + if (access(current_file_name, F_OK) == 0) { + if (remove(current_file_name) != 0) { + warning("Could not delete existing file %s\n", current_file_name); + } + } } else { - tty->print_cr("failed to open rotation log file %s due to %s\n", + warning("failed to open rotation log file %s due to %s\n" + "Turned off GC log file rotation\n", _file_name, strerror(errno)); _need_close = false; + FLAG_SET_DEFAULT(UseGCLogFileRotation, false); } }