1.1 --- a/src/share/vm/utilities/ostream.cpp Mon Sep 16 12:43:34 2013 -0700
1.2 +++ b/src/share/vm/utilities/ostream.cpp Mon Sep 16 15:35:04 2013 -0700
1.3 @@ -342,7 +342,7 @@
1.4 }
1.5
1.6 char* stringStream::as_string() {
1.7 - char* copy = NEW_RESOURCE_ARRAY(char, buffer_pos+1);
1.8 + char* copy = NEW_RESOURCE_ARRAY(char, buffer_pos + 1);
1.9 strncpy(copy, buffer, buffer_pos);
1.10 copy[buffer_pos] = 0; // terminating null
1.11 return copy;
1.12 @@ -355,14 +355,190 @@
1.13 outputStream* gclog_or_tty;
1.14 extern Mutex* tty_lock;
1.15
1.16 +#define EXTRACHARLEN 32
1.17 +#define CURRENTAPPX ".current"
1.18 +#define FILENAMEBUFLEN 1024
1.19 +// convert YYYY-MM-DD HH:MM:SS to YYYY-MM-DD_HH-MM-SS
1.20 +char* get_datetime_string(char *buf, size_t len) {
1.21 + os::local_time_string(buf, len);
1.22 + int i = (int)strlen(buf);
1.23 + while (i-- >= 0) {
1.24 + if (buf[i] == ' ') buf[i] = '_';
1.25 + else if (buf[i] == ':') buf[i] = '-';
1.26 + }
1.27 + return buf;
1.28 +}
1.29 +
1.30 +static const char* make_log_name_internal(const char* log_name, const char* force_directory,
1.31 + int pid, const char* tms) {
1.32 + const char* basename = log_name;
1.33 + char file_sep = os::file_separator()[0];
1.34 + const char* cp;
1.35 + char pid_text[32];
1.36 +
1.37 + for (cp = log_name; *cp != '\0'; cp++) {
1.38 + if (*cp == '/' || *cp == file_sep) {
1.39 + basename = cp + 1;
1.40 + }
1.41 + }
1.42 + const char* nametail = log_name;
1.43 + // Compute buffer length
1.44 + size_t buffer_length;
1.45 + if (force_directory != NULL) {
1.46 + buffer_length = strlen(force_directory) + strlen(os::file_separator()) +
1.47 + strlen(basename) + 1;
1.48 + } else {
1.49 + buffer_length = strlen(log_name) + 1;
1.50 + }
1.51 +
1.52 + // const char* star = strchr(basename, '*');
1.53 + const char* pts = strstr(basename, "%p");
1.54 + int pid_pos = (pts == NULL) ? -1 : (pts - nametail);
1.55 +
1.56 + if (pid_pos >= 0) {
1.57 + jio_snprintf(pid_text, sizeof(pid_text), "pid%u", pid);
1.58 + buffer_length += strlen(pid_text);
1.59 + }
1.60 +
1.61 + pts = strstr(basename, "%t");
1.62 + int tms_pos = (pts == NULL) ? -1 : (pts - nametail);
1.63 + if (tms_pos >= 0) {
1.64 + buffer_length += strlen(tms);
1.65 + }
1.66 +
1.67 + // Create big enough buffer.
1.68 + char *buf = NEW_C_HEAP_ARRAY(char, buffer_length, mtInternal);
1.69 +
1.70 + strcpy(buf, "");
1.71 + if (force_directory != NULL) {
1.72 + strcat(buf, force_directory);
1.73 + strcat(buf, os::file_separator());
1.74 + nametail = basename; // completely skip directory prefix
1.75 + }
1.76 +
1.77 + // who is first, %p or %t?
1.78 + int first = -1, second = -1;
1.79 + const char *p1st = NULL;
1.80 + const char *p2nd = NULL;
1.81 +
1.82 + if (pid_pos >= 0 && tms_pos >= 0) {
1.83 + // contains both %p and %t
1.84 + if (pid_pos < tms_pos) {
1.85 + // case foo%pbar%tmonkey.log
1.86 + first = pid_pos;
1.87 + p1st = pid_text;
1.88 + second = tms_pos;
1.89 + p2nd = tms;
1.90 + } else {
1.91 + // case foo%tbar%pmonkey.log
1.92 + first = tms_pos;
1.93 + p1st = tms;
1.94 + second = pid_pos;
1.95 + p2nd = pid_text;
1.96 + }
1.97 + } else if (pid_pos >= 0) {
1.98 + // contains %p only
1.99 + first = pid_pos;
1.100 + p1st = pid_text;
1.101 + } else if (tms_pos >= 0) {
1.102 + // contains %t only
1.103 + first = tms_pos;
1.104 + p1st = tms;
1.105 + }
1.106 +
1.107 + int buf_pos = (int)strlen(buf);
1.108 + const char* tail = nametail;
1.109 +
1.110 + if (first >= 0) {
1.111 + tail = nametail + first + 2;
1.112 + strncpy(&buf[buf_pos], nametail, first);
1.113 + strcpy(&buf[buf_pos + first], p1st);
1.114 + buf_pos = (int)strlen(buf);
1.115 + if (second >= 0) {
1.116 + strncpy(&buf[buf_pos], tail, second - first - 2);
1.117 + strcpy(&buf[buf_pos + second - first - 2], p2nd);
1.118 + tail = nametail + second + 2;
1.119 + }
1.120 + }
1.121 + strcat(buf, tail); // append rest of name, or all of name
1.122 + return buf;
1.123 +}
1.124 +
1.125 +// log_name comes from -XX:LogFile=log_name or -Xloggc:log_name
1.126 +// in log_name, %p => pipd1234 and
1.127 +// %t => YYYY-MM-DD_HH-MM-SS
1.128 +static const char* make_log_name(const char* log_name, const char* force_directory) {
1.129 + char timestr[32];
1.130 + get_datetime_string(timestr, sizeof(timestr));
1.131 + return make_log_name_internal(log_name, force_directory, os::current_process_id(),
1.132 + timestr);
1.133 +}
1.134 +
1.135 +#ifndef PRODUCT
1.136 +void test_loggc_filename() {
1.137 + int pid;
1.138 + char tms[32];
1.139 + char i_result[FILENAMEBUFLEN];
1.140 + const char* o_result;
1.141 + get_datetime_string(tms, sizeof(tms));
1.142 + pid = os::current_process_id();
1.143 +
1.144 + // test.log
1.145 + jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test.log", tms);
1.146 + o_result = make_log_name_internal("test.log", NULL, pid, tms);
1.147 + assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test.log\", NULL)");
1.148 + FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
1.149 +
1.150 + // test-%t-%p.log
1.151 + jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test-%s-pid%u.log", tms, pid);
1.152 + o_result = make_log_name_internal("test-%t-%p.log", NULL, pid, tms);
1.153 + assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test-%%t-%%p.log\", NULL)");
1.154 + FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
1.155 +
1.156 + // test-%t%p.log
1.157 + jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test-%spid%u.log", tms, pid);
1.158 + o_result = make_log_name_internal("test-%t%p.log", NULL, pid, tms);
1.159 + assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test-%%t%%p.log\", NULL)");
1.160 + FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
1.161 +
1.162 + // %p%t.log
1.163 + jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "pid%u%s.log", pid, tms);
1.164 + o_result = make_log_name_internal("%p%t.log", NULL, pid, tms);
1.165 + assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%p%%t.log\", NULL)");
1.166 + FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
1.167 +
1.168 + // %p-test.log
1.169 + jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "pid%u-test.log", pid);
1.170 + o_result = make_log_name_internal("%p-test.log", NULL, pid, tms);
1.171 + assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%p-test.log\", NULL)");
1.172 + FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
1.173 +
1.174 + // %t.log
1.175 + jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "%s.log", tms);
1.176 + o_result = make_log_name_internal("%t.log", NULL, pid, tms);
1.177 + assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%t.log\", NULL)");
1.178 + FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
1.179 +}
1.180 +#endif // PRODUCT
1.181 +
1.182 fileStream::fileStream(const char* file_name) {
1.183 _file = fopen(file_name, "w");
1.184 - _need_close = true;
1.185 + if (_file != NULL) {
1.186 + _need_close = true;
1.187 + } else {
1.188 + warning("Cannot open file %s due to %s\n", file_name, strerror(errno));
1.189 + _need_close = false;
1.190 + }
1.191 }
1.192
1.193 fileStream::fileStream(const char* file_name, const char* opentype) {
1.194 _file = fopen(file_name, opentype);
1.195 - _need_close = true;
1.196 + if (_file != NULL) {
1.197 + _need_close = true;
1.198 + } else {
1.199 + warning("Cannot open file %s due to %s\n", file_name, strerror(errno));
1.200 + _need_close = false;
1.201 + }
1.202 }
1.203
1.204 void fileStream::write(const char* s, size_t len) {
1.205 @@ -423,34 +599,51 @@
1.206 update_position(s, len);
1.207 }
1.208
1.209 -rotatingFileStream::~rotatingFileStream() {
1.210 +// dump vm version, os version, platform info, build id,
1.211 +// memory usage and command line flags into header
1.212 +void gcLogFileStream::dump_loggc_header() {
1.213 + if (is_open()) {
1.214 + print_cr(Abstract_VM_Version::internal_vm_info_string());
1.215 + os::print_memory_info(this);
1.216 + print("CommandLine flags: ");
1.217 + CommandLineFlags::printSetFlags(this);
1.218 + }
1.219 +}
1.220 +
1.221 +gcLogFileStream::~gcLogFileStream() {
1.222 if (_file != NULL) {
1.223 if (_need_close) fclose(_file);
1.224 - _file = NULL;
1.225 + _file = NULL;
1.226 + }
1.227 + if (_file_name != NULL) {
1.228 FREE_C_HEAP_ARRAY(char, _file_name, mtInternal);
1.229 _file_name = NULL;
1.230 }
1.231 }
1.232
1.233 -rotatingFileStream::rotatingFileStream(const char* file_name) {
1.234 +gcLogFileStream::gcLogFileStream(const char* file_name) {
1.235 _cur_file_num = 0;
1.236 _bytes_written = 0L;
1.237 - _file_name = NEW_C_HEAP_ARRAY(char, strlen(file_name)+10, mtInternal);
1.238 - jio_snprintf(_file_name, strlen(file_name)+10, "%s.%d", file_name, _cur_file_num);
1.239 - _file = fopen(_file_name, "w");
1.240 - _need_close = true;
1.241 + _file_name = make_log_name(file_name, NULL);
1.242 +
1.243 + // gc log file rotation
1.244 + if (UseGCLogFileRotation && NumberOfGCLogFiles > 1) {
1.245 + char tempbuf[FILENAMEBUFLEN];
1.246 + jio_snprintf(tempbuf, sizeof(tempbuf), "%s.%d" CURRENTAPPX, _file_name, _cur_file_num);
1.247 + _file = fopen(tempbuf, "w");
1.248 + } else {
1.249 + _file = fopen(_file_name, "w");
1.250 + }
1.251 + if (_file != NULL) {
1.252 + _need_close = true;
1.253 + dump_loggc_header();
1.254 + } else {
1.255 + warning("Cannot open file %s due to %s\n", _file_name, strerror(errno));
1.256 + _need_close = false;
1.257 + }
1.258 }
1.259
1.260 -rotatingFileStream::rotatingFileStream(const char* file_name, const char* opentype) {
1.261 - _cur_file_num = 0;
1.262 - _bytes_written = 0L;
1.263 - _file_name = NEW_C_HEAP_ARRAY(char, strlen(file_name)+10, mtInternal);
1.264 - jio_snprintf(_file_name, strlen(file_name)+10, "%s.%d", file_name, _cur_file_num);
1.265 - _file = fopen(_file_name, opentype);
1.266 - _need_close = true;
1.267 -}
1.268 -
1.269 -void rotatingFileStream::write(const char* s, size_t len) {
1.270 +void gcLogFileStream::write(const char* s, size_t len) {
1.271 if (_file != NULL) {
1.272 size_t count = fwrite(s, 1, len, _file);
1.273 _bytes_written += count;
1.274 @@ -466,7 +659,12 @@
1.275 // write to gc log file at safepoint. If in future, changes made for mutator threads or
1.276 // concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log
1.277 // must be synchronized.
1.278 -void rotatingFileStream::rotate_log() {
1.279 +void gcLogFileStream::rotate_log() {
1.280 + char time_msg[FILENAMEBUFLEN];
1.281 + char time_str[EXTRACHARLEN];
1.282 + char current_file_name[FILENAMEBUFLEN];
1.283 + char renamed_file_name[FILENAMEBUFLEN];
1.284 +
1.285 if (_bytes_written < (jlong)GCLogFileSize) {
1.286 return;
1.287 }
1.288 @@ -481,27 +679,89 @@
1.289 // rotate in same file
1.290 rewind();
1.291 _bytes_written = 0L;
1.292 + jio_snprintf(time_msg, sizeof(time_msg), "File %s rotated at %s\n",
1.293 + _file_name, os::local_time_string((char *)time_str, sizeof(time_str)));
1.294 + write(time_msg, strlen(time_msg));
1.295 + dump_loggc_header();
1.296 return;
1.297 }
1.298
1.299 - // rotate file in names file.0, file.1, file.2, ..., file.<MaxGCLogFileNumbers-1>
1.300 - // close current file, rotate to next file
1.301 +#if defined(_WINDOWS)
1.302 +#ifndef F_OK
1.303 +#define F_OK 0
1.304 +#endif
1.305 +#endif // _WINDOWS
1.306 +
1.307 + // rotate file in names extended_filename.0, extended_filename.1, ...,
1.308 + // extended_filename.<NumberOfGCLogFiles - 1>. Current rotation file name will
1.309 + // have a form of extended_filename.<i>.current where i is the current rotation
1.310 + // file number. After it reaches max file size, the file will be saved and renamed
1.311 + // with .current removed from its tail.
1.312 + size_t filename_len = strlen(_file_name);
1.313 if (_file != NULL) {
1.314 - _cur_file_num ++;
1.315 - if (_cur_file_num >= NumberOfGCLogFiles) _cur_file_num = 0;
1.316 - jio_snprintf(_file_name, strlen(Arguments::gc_log_filename()) + 10, "%s.%d",
1.317 - Arguments::gc_log_filename(), _cur_file_num);
1.318 + jio_snprintf(renamed_file_name, filename_len + EXTRACHARLEN, "%s.%d",
1.319 + _file_name, _cur_file_num);
1.320 + jio_snprintf(current_file_name, filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX,
1.321 + _file_name, _cur_file_num);
1.322 + jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file has reached the"
1.323 + " maximum size. Saved as %s\n",
1.324 + os::local_time_string((char *)time_str, sizeof(time_str)),
1.325 + renamed_file_name);
1.326 + write(time_msg, strlen(time_msg));
1.327 +
1.328 fclose(_file);
1.329 _file = NULL;
1.330 +
1.331 + bool can_rename = true;
1.332 + if (access(current_file_name, F_OK) != 0) {
1.333 + // current file does not exist?
1.334 + warning("No source file exists, cannot rename\n");
1.335 + can_rename = false;
1.336 + }
1.337 + if (can_rename) {
1.338 + if (access(renamed_file_name, F_OK) == 0) {
1.339 + if (remove(renamed_file_name) != 0) {
1.340 + warning("Could not delete existing file %s\n", renamed_file_name);
1.341 + can_rename = false;
1.342 + }
1.343 + } else {
1.344 + // file does not exist, ok to rename
1.345 + }
1.346 + }
1.347 + if (can_rename && rename(current_file_name, renamed_file_name) != 0) {
1.348 + warning("Could not rename %s to %s\n", _file_name, renamed_file_name);
1.349 + }
1.350 }
1.351 - _file = fopen(_file_name, "w");
1.352 +
1.353 + _cur_file_num++;
1.354 + if (_cur_file_num > NumberOfGCLogFiles - 1) _cur_file_num = 0;
1.355 + jio_snprintf(current_file_name, filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX,
1.356 + _file_name, _cur_file_num);
1.357 + _file = fopen(current_file_name, "w");
1.358 +
1.359 if (_file != NULL) {
1.360 _bytes_written = 0L;
1.361 _need_close = true;
1.362 + // reuse current_file_name for time_msg
1.363 + jio_snprintf(current_file_name, filename_len + EXTRACHARLEN,
1.364 + "%s.%d", _file_name, _cur_file_num);
1.365 + jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file created %s\n",
1.366 + os::local_time_string((char *)time_str, sizeof(time_str)),
1.367 + current_file_name);
1.368 + write(time_msg, strlen(time_msg));
1.369 + dump_loggc_header();
1.370 + // remove the existing file
1.371 + if (access(current_file_name, F_OK) == 0) {
1.372 + if (remove(current_file_name) != 0) {
1.373 + warning("Could not delete existing file %s\n", current_file_name);
1.374 + }
1.375 + }
1.376 } else {
1.377 - tty->print_cr("failed to open rotation log file %s due to %s\n",
1.378 + warning("failed to open rotation log file %s due to %s\n"
1.379 + "Turned off GC log file rotation\n",
1.380 _file_name, strerror(errno));
1.381 _need_close = false;
1.382 + FLAG_SET_DEFAULT(UseGCLogFileRotation, false);
1.383 }
1.384 }
1.385
1.386 @@ -530,66 +790,6 @@
1.387 return _log_file != NULL;
1.388 }
1.389
1.390 -static const char* make_log_name(const char* log_name, const char* force_directory) {
1.391 - const char* basename = log_name;
1.392 - char file_sep = os::file_separator()[0];
1.393 - const char* cp;
1.394 - for (cp = log_name; *cp != '\0'; cp++) {
1.395 - if (*cp == '/' || *cp == file_sep) {
1.396 - basename = cp+1;
1.397 - }
1.398 - }
1.399 - const char* nametail = log_name;
1.400 -
1.401 - // Compute buffer length
1.402 - size_t buffer_length;
1.403 - if (force_directory != NULL) {
1.404 - buffer_length = strlen(force_directory) + strlen(os::file_separator()) +
1.405 - strlen(basename) + 1;
1.406 - } else {
1.407 - buffer_length = strlen(log_name) + 1;
1.408 - }
1.409 -
1.410 - const char* star = strchr(basename, '*');
1.411 - int star_pos = (star == NULL) ? -1 : (star - nametail);
1.412 - int skip = 1;
1.413 - if (star == NULL) {
1.414 - // Try %p
1.415 - star = strstr(basename, "%p");
1.416 - if (star != NULL) {
1.417 - skip = 2;
1.418 - }
1.419 - }
1.420 - star_pos = (star == NULL) ? -1 : (star - nametail);
1.421 -
1.422 - char pid[32];
1.423 - if (star_pos >= 0) {
1.424 - jio_snprintf(pid, sizeof(pid), "%u", os::current_process_id());
1.425 - buffer_length += strlen(pid);
1.426 - }
1.427 -
1.428 - // Create big enough buffer.
1.429 - char *buf = NEW_C_HEAP_ARRAY(char, buffer_length, mtInternal);
1.430 -
1.431 - strcpy(buf, "");
1.432 - if (force_directory != NULL) {
1.433 - strcat(buf, force_directory);
1.434 - strcat(buf, os::file_separator());
1.435 - nametail = basename; // completely skip directory prefix
1.436 - }
1.437 -
1.438 - if (star_pos >= 0) {
1.439 - // convert foo*bar.log or foo%pbar.log to foo123bar.log
1.440 - int buf_pos = (int) strlen(buf);
1.441 - strncpy(&buf[buf_pos], nametail, star_pos);
1.442 - strcpy(&buf[buf_pos + star_pos], pid);
1.443 - nametail += star_pos + skip; // skip prefix and pid format
1.444 - }
1.445 -
1.446 - strcat(buf, nametail); // append rest of name, or all of name
1.447 - return buf;
1.448 -}
1.449 -
1.450 void defaultStream::init_log() {
1.451 // %%% Need a MutexLocker?
1.452 const char* log_name = LogFile != NULL ? LogFile : "hotspot.log";
1.453 @@ -877,11 +1077,8 @@
1.454
1.455 gclog_or_tty = tty; // default to tty
1.456 if (Arguments::gc_log_filename() != NULL) {
1.457 - fileStream * gclog = UseGCLogFileRotation ?
1.458 - new(ResourceObj::C_HEAP, mtInternal)
1.459 - rotatingFileStream(Arguments::gc_log_filename()) :
1.460 - new(ResourceObj::C_HEAP, mtInternal)
1.461 - fileStream(Arguments::gc_log_filename());
1.462 + fileStream * gclog = new(ResourceObj::C_HEAP, mtInternal)
1.463 + gcLogFileStream(Arguments::gc_log_filename());
1.464 if (gclog->is_open()) {
1.465 // now we update the time stamp of the GC log to be synced up
1.466 // with tty.
