--- old/src/share/vm/utilities/ostream.cpp Fri Aug 30 23:29:20 2013 +++ new/src/share/vm/utilities/ostream.cpp Fri Aug 30 23:29:19 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,108 @@ 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) { + 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) { + 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; +} + + 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); } 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); } void fileStream::write(const char* s, size_t len) { @@ -426,7 +520,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,23 +529,22 @@ } 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; } + void rotatingFileStream::write(const char* s, size_t len) { if (_file != NULL) { size_t count = fwrite(s, 1, len, _file); @@ -467,6 +562,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 +581,98 @@ // 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)); + // log more info: vm version, os version, native memory usage, commandline flags + print_cr(Abstract_VM_Version::internal_vm_info_string()); + os::print_memory_info(this); + print("CommandLine flags: "); + CommandLineFlags::printSetFlags(this); 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.. File name contains pid and time + // stamps which was the time when the first file created. The current filename + // is gc_log_file_name + pid + YYYY-MM-DD_HH-MM-SS..current, where i is + // 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)); + // log more info: vm version, os version, native memory usage, commandline flags + print_cr(Abstract_VM_Version::internal_vm_info_string()); + os::print_memory_info(this); + print("CommandLine flags: "); + CommandLineFlags::printSetFlags(this); + // 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); } }