src/share/vm/utilities/ostream.cpp
Index Unified diffs Context diffs Sdiffs Wdiffs Patch New Old Previous File Next File 7164841 Sdiff src/share/vm/utilities

src/share/vm/utilities/ostream.cpp

Print this page
7164841: Improvements to the GC log file rotation


 325       assert(rm == NULL || Thread::current()->current_resource_mark() == rm,
 326              "stringStream is re-allocated with a different ResourceMark");
 327       buffer = NEW_RESOURCE_ARRAY(char, end);
 328       strncpy(buffer, oldbuf, buffer_pos);
 329       buffer_length = end;
 330     }
 331   }
 332   // invariant: buffer is always null-terminated
 333   guarantee(buffer_pos + write_len + 1 <= buffer_length, "stringStream oob");
 334   buffer[buffer_pos + write_len] = 0;
 335   strncpy(buffer + buffer_pos, s, write_len);
 336   buffer_pos += write_len;
 337 
 338   // Note that the following does not depend on write_len.
 339   // This means that position and count get updated
 340   // even when overflow occurs.
 341   update_position(s, len);
 342 }
 343 
 344 char* stringStream::as_string() {
 345   char* copy = NEW_RESOURCE_ARRAY(char, buffer_pos+1);
 346   strncpy(copy, buffer, buffer_pos);
 347   copy[buffer_pos] = 0;  // terminating null
 348   return copy;
 349 }
 350 
 351 stringStream::~stringStream() {}
 352 
 353 xmlStream*   xtty;
 354 outputStream* tty;
 355 outputStream* gclog_or_tty;
 356 extern Mutex* tty_lock;
 357 


























































































 358 fileStream::fileStream(const char* file_name) {
 359   _file = fopen(file_name, "w");

 360   _need_close = true;

 361 }
 362 
 363 fileStream::fileStream(const char* file_name, const char* opentype) {
 364   _file = fopen(file_name, opentype);

 365   _need_close = true;

 366 }
 367 
 368 void fileStream::write(const char* s, size_t len) {
 369   if (_file != NULL)  {
 370     // Make an unused local variable to avoid warning from gcc 4.x compiler.
 371     size_t count = fwrite(s, 1, len, _file);
 372   }
 373   update_position(s, len);
 374 }
 375 
 376 long fileStream::fileSize() {
 377   long size = -1;
 378   if (_file != NULL) {
 379     long pos  = ::ftell(_file);
 380     if (::fseek(_file, 0, SEEK_END) == 0) {
 381       size = ::ftell(_file);
 382     }
 383     ::fseek(_file, pos, SEEK_SET);
 384   }
 385   return size;


 410 
 411 fdStream::~fdStream() {
 412   if (_fd != -1) {
 413     if (_need_close) close(_fd);
 414     _fd = -1;
 415   }
 416 }
 417 
 418 void fdStream::write(const char* s, size_t len) {
 419   if (_fd != -1) {
 420     // Make an unused local variable to avoid warning from gcc 4.x compiler.
 421     size_t count = ::write(_fd, s, (int)len);
 422   }
 423   update_position(s, len);
 424 }
 425 
 426 rotatingFileStream::~rotatingFileStream() {
 427   if (_file != NULL) {
 428     if (_need_close) fclose(_file);
 429     _file      = NULL;


 430     FREE_C_HEAP_ARRAY(char, _file_name, mtInternal);
 431     _file_name = NULL;
 432   }
 433 }
 434 
 435 rotatingFileStream::rotatingFileStream(const char* file_name) {

 436   _cur_file_num = 0;
 437   _bytes_written = 0L;
 438   _file_name = NEW_C_HEAP_ARRAY(char, strlen(file_name)+10, mtInternal);
 439   jio_snprintf(_file_name, strlen(file_name)+10, "%s.%d", file_name, _cur_file_num);





 440   _file = fopen(_file_name, "w");

 441   _need_close = true;
 442 }
 443 
 444 rotatingFileStream::rotatingFileStream(const char* file_name, const char* opentype) {
 445   _cur_file_num = 0;
 446   _bytes_written = 0L;
 447   _file_name = NEW_C_HEAP_ARRAY(char, strlen(file_name)+10, mtInternal);
 448   jio_snprintf(_file_name, strlen(file_name)+10, "%s.%d", file_name, _cur_file_num);
 449   _file = fopen(_file_name, opentype);
 450   _need_close = true;
 451 }
 452 
 453 void rotatingFileStream::write(const char* s, size_t len) {
 454   if (_file != NULL) {
 455     size_t count = fwrite(s, 1, len, _file);
 456     _bytes_written += count;
 457   }
 458   update_position(s, len);
 459 }
 460 
 461 // rotate_log must be called from VMThread at safepoint. In case need change parameters
 462 // for gc log rotation from thread other than VMThread, a sub type of VM_Operation
 463 // should be created and be submitted to VMThread's operation queue. DO NOT call this
 464 // function directly. Currently, it is safe to rotate log at safepoint through VMThread.
 465 // That is, no mutator threads and concurrent GC threads run parallel with VMThread to
 466 // write to gc log file at safepoint. If in future, changes made for mutator threads or
 467 // concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log
 468 // must be synchronized.
 469 void rotatingFileStream::rotate_log() {





 470   if (_bytes_written < (jlong)GCLogFileSize) {
 471     return;
 472   }
 473 
 474 #ifdef ASSERT
 475   Thread *thread = Thread::current();
 476   assert(thread == NULL ||
 477          (thread->is_VM_thread() && SafepointSynchronize::is_at_safepoint()),
 478          "Must be VMThread at safepoint");
 479 #endif
 480   if (NumberOfGCLogFiles == 1) {
 481     // rotate in same file
 482     rewind();
 483     _bytes_written = 0L;








 484     return;
 485   }
 486 
 487   // rotate file in names file.0, file.1, file.2, ..., file.<MaxGCLogFileNumbers-1>
 488   // close current file, rotate to next file











 489   if (_file != NULL) {
 490     _cur_file_num ++;
 491     if (_cur_file_num >= NumberOfGCLogFiles) _cur_file_num = 0;
 492     jio_snprintf(_file_name, strlen(Arguments::gc_log_filename()) + 10, "%s.%d",
 493              Arguments::gc_log_filename(), _cur_file_num);






 494     fclose(_file);
 495     _file = NULL;






 496   }
 497   _file = fopen(_file_name, "w");




















 498   if (_file != NULL) {
 499     _bytes_written = 0L;
 500     _need_close = true;


















 501   } else {
 502     tty->print_cr("failed to open rotation log file %s due to %s\n",

 503                   _file_name, strerror(errno));
 504     _need_close = false;

 505   }
 506 }
 507 
 508 defaultStream* defaultStream::instance = NULL;
 509 int defaultStream::_output_fd = 1;
 510 int defaultStream::_error_fd  = 2;
 511 FILE* defaultStream::_output_stream = stdout;
 512 FILE* defaultStream::_error_stream  = stderr;
 513 
 514 #define LOG_MAJOR_VERSION 160
 515 #define LOG_MINOR_VERSION 1
 516 
 517 void defaultStream::init() {
 518   _inited = true;
 519   if (LogVMOutput || LogCompilation) {
 520     init_log();
 521   }
 522 }
 523 
 524 bool defaultStream::has_log_file() {




 325       assert(rm == NULL || Thread::current()->current_resource_mark() == rm,
 326              "stringStream is re-allocated with a different ResourceMark");
 327       buffer = NEW_RESOURCE_ARRAY(char, end);
 328       strncpy(buffer, oldbuf, buffer_pos);
 329       buffer_length = end;
 330     }
 331   }
 332   // invariant: buffer is always null-terminated
 333   guarantee(buffer_pos + write_len + 1 <= buffer_length, "stringStream oob");
 334   buffer[buffer_pos + write_len] = 0;
 335   strncpy(buffer + buffer_pos, s, write_len);
 336   buffer_pos += write_len;
 337 
 338   // Note that the following does not depend on write_len.
 339   // This means that position and count get updated
 340   // even when overflow occurs.
 341   update_position(s, len);
 342 }
 343 
 344 char* stringStream::as_string() {
 345   char* copy = NEW_RESOURCE_ARRAY(char, buffer_pos + 1);
 346   strncpy(copy, buffer, buffer_pos);
 347   copy[buffer_pos] = 0;  // terminating null
 348   return copy;
 349 }
 350 
 351 stringStream::~stringStream() {}
 352 
 353 xmlStream*   xtty;
 354 outputStream* tty;
 355 outputStream* gclog_or_tty;
 356 extern Mutex* tty_lock;
 357 
 358 #define EXTRACHARLEN   32
 359 #define CURRENTAPPX    ".current"
 360 #define FILENAMEBUFLEN  1024
 361 // convert YYYY-MM-DD HH:MM:SS to YYYY-MM-DD_HH-MM-SS
 362 char* get_datetime_string(char *buf, size_t len) {
 363   os::local_time_string(buf, len);
 364   int i = strlen(buf);
 365   while (i-- >= 0) {
 366     if (buf[i] == ' ') buf[i] = '_';
 367     else if (buf[i] == ':') buf[i] = '-';
 368   }
 369   return buf;
 370 }
 371 
 372 
 373 char* extend_file_name(const char* file_name) {
 374   char*  extended_name = NULL;
 375   char   timestr[EXTRACHARLEN];
 376   char   pidtext[EXTRACHARLEN];
 377 
 378   const char*  spp = strstr(file_name, "%p");
 379   const char*  spt = strstr(file_name, "%t");
 380 
 381   int pp = (spp != NULL) ? spp - file_name : -1;
 382   int pt = (spt != NULL) ? spt - file_name : -1;
 383 
 384   if (pp < 0 && pt < 0) {
 385     extended_name = NEW_C_HEAP_ARRAY(char, strlen(file_name) + 1, mtInternal);
 386     strcpy(extended_name, file_name);
 387     return extended_name;
 388   }
 389 
 390   if (pp > 0) {
 391     jio_snprintf(pidtext, sizeof(pidtext), "pid%d", os::current_process_id());
 392   } else {
 393     pidtext[0] = '\0';
 394   }
 395   if (pt > 0) {
 396     get_datetime_string(timestr, sizeof(timestr));
 397   } else {
 398     timestr[0] = '\0';
 399   }
 400 
 401   size_t len = strlen(file_name) + strlen(pidtext) + strlen(timestr) + 2 * EXTRACHARLEN;
 402   extended_name = NEW_C_HEAP_ARRAY(char, len, mtInternal);
 403   if (pp > 0 && pt > 0 ) {
 404     // *%p*%t*
 405     if (pp < pt) {
 406       memcpy(extended_name, file_name, (size_t)pp);
 407       extended_name[pp] = '\0';
 408       strcat(extended_name, pidtext);
 409       size_t t_len  = strlen(extended_name);
 410       if (pt - pp > 2) {
 411         memcpy(extended_name + t_len, file_name + pp + 2, pt - pp - 2);
 412         extended_name[t_len + pt - pp - 2] = '\0';
 413       }
 414       strcat(extended_name, timestr);
 415       strcat(extended_name, file_name + pt + 2);
 416     // *%t*%p%
 417     } else {
 418       memcpy(extended_name, file_name, (size_t)(pt));
 419       extended_name[pt] = '\0';
 420       strcat(extended_name, timestr);
 421       size_t t_len  = strlen(extended_name);
 422       if (pp - pt > 2) {
 423         memcpy(extended_name + t_len, file_name + pt + 2, pp - pt - 2);
 424         extended_name[t_len + pp - pt - 2] = '\0';
 425       }
 426       strcat(extended_name, pidtext);
 427       strcat(extended_name, file_name + pp + 2);
 428     }
 429     return extended_name;
 430   }
 431   if (pp > 0) {
 432     memcpy(extended_name, file_name, (size_t)pp);
 433     extended_name[pp] = '\0';
 434     strcat(extended_name, pidtext); 
 435     strcat(extended_name, file_name + pp + 2);
 436   }
 437   
 438   if (pt > 0) {
 439     memcpy(extended_name, file_name, (size_t)pt);
 440     extended_name[pt] = '\0';
 441     strcat(extended_name, timestr); 
 442     strcat(extended_name, file_name + pt + 2);
 443   }
 444   return extended_name;
 445 }
 446 
 447 
 448 fileStream::fileStream(const char* file_name) {
 449   char* f_name = extend_file_name(file_name);
 450   _file = fopen(f_name, "w");
 451   _need_close = true;
 452   FREE_C_HEAP_ARRAY(char, f_name, mtInternal);
 453 }
 454 
 455 fileStream::fileStream(const char* file_name, const char* opentype) {
 456   char* f_name = extend_file_name(file_name);
 457   _file = fopen(f_name, opentype);
 458   _need_close = true;
 459   FREE_C_HEAP_ARRAY(char, f_name, mtInternal);
 460 }
 461 
 462 void fileStream::write(const char* s, size_t len) {
 463   if (_file != NULL)  {
 464     // Make an unused local variable to avoid warning from gcc 4.x compiler.
 465     size_t count = fwrite(s, 1, len, _file);
 466   }
 467   update_position(s, len);
 468 }
 469 
 470 long fileStream::fileSize() {
 471   long size = -1;
 472   if (_file != NULL) {
 473     long pos  = ::ftell(_file);
 474     if (::fseek(_file, 0, SEEK_END) == 0) {
 475       size = ::ftell(_file);
 476     }
 477     ::fseek(_file, pos, SEEK_SET);
 478   }
 479   return size;


 504 
 505 fdStream::~fdStream() {
 506   if (_fd != -1) {
 507     if (_need_close) close(_fd);
 508     _fd = -1;
 509   }
 510 }
 511 
 512 void fdStream::write(const char* s, size_t len) {
 513   if (_fd != -1) {
 514     // Make an unused local variable to avoid warning from gcc 4.x compiler.
 515     size_t count = ::write(_fd, s, (int)len);
 516   }
 517   update_position(s, len);
 518 }
 519 
 520 rotatingFileStream::~rotatingFileStream() {
 521   if (_file != NULL) {
 522     if (_need_close) fclose(_file);
 523     _file = NULL;
 524   }
 525   if (_file_name != NULL) {
 526     FREE_C_HEAP_ARRAY(char, _file_name, mtInternal);
 527     _file_name = NULL;
 528   }
 529 }
 530 
 531 rotatingFileStream::rotatingFileStream(const char* file_name) {
 532   assert(UseGCLogFileRotation, "Should use UseGCLogFileRotation");
 533   _cur_file_num = 0;
 534   _bytes_written = 0L;
 535   _file_name = extend_file_name(file_name);
 536 
 537   if (NumberOfGCLogFiles > 1) {
 538     char tempbuf[FILENAMEBUFLEN];
 539     jio_snprintf(tempbuf, sizeof(tempbuf), "%s.%d" CURRENTAPPX, _file_name, _cur_file_num);
 540     _file = fopen(tempbuf, "w");
 541   } else {
 542     _file = fopen(_file_name, "w");
 543   }
 544   _need_close = true;
 545 }
 546 








 547 
 548 void rotatingFileStream::write(const char* s, size_t len) {
 549   if (_file != NULL) {
 550     size_t count = fwrite(s, 1, len, _file);
 551     _bytes_written += count;
 552   }
 553   update_position(s, len);
 554 }
 555 
 556 // rotate_log must be called from VMThread at safepoint. In case need change parameters
 557 // for gc log rotation from thread other than VMThread, a sub type of VM_Operation
 558 // should be created and be submitted to VMThread's operation queue. DO NOT call this
 559 // function directly. Currently, it is safe to rotate log at safepoint through VMThread.
 560 // That is, no mutator threads and concurrent GC threads run parallel with VMThread to
 561 // write to gc log file at safepoint. If in future, changes made for mutator threads or
 562 // concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log
 563 // must be synchronized.
 564 void rotatingFileStream::rotate_log() {
 565   char time_msg[FILENAMEBUFLEN];
 566   char time_str[EXTRACHARLEN];
 567   char current_file_name[FILENAMEBUFLEN];
 568   char renamed_file_name[FILENAMEBUFLEN];
 569 
 570   if (_bytes_written < (jlong)GCLogFileSize) {
 571     return;
 572   }
 573 
 574 #ifdef ASSERT
 575   Thread *thread = Thread::current();
 576   assert(thread == NULL ||
 577          (thread->is_VM_thread() && SafepointSynchronize::is_at_safepoint()),
 578          "Must be VMThread at safepoint");
 579 #endif
 580   if (NumberOfGCLogFiles == 1) {
 581     // rotate in same file
 582     rewind();
 583     _bytes_written = 0L;
 584     jio_snprintf(time_msg, sizeof(time_msg), "File  %s rotated at %s\n",
 585                  _file_name, os::local_time_string((char *)time_str, sizeof(time_str)));
 586     this->write(time_msg, strlen(time_msg));
 587     // log more info: vm version, os version, native memory usage, commandline flags
 588     print_cr(Abstract_VM_Version::internal_vm_info_string());
 589     os::print_memory_info(this);
 590     print("CommandLine flags: ");
 591     CommandLineFlags::printSetFlags(this);
 592     return;
 593   }
 594 
 595 #if defined(_WINDOWS)
 596 #ifndef F_OK
 597 #define F_OK 0
 598 #endif
 599 #endif // _WINDOWS
 600 
 601   // rotate file in names extended_filename.0, extended_filename.1, ...,
 602   // extended_filename.<NumberOfGCLogFiles - 1>. File name contains pid and time
 603   // stamps which was the time when the first file created. The current filename
 604   // is gc_log_file_name + pid<pid> + YYYY-MM-DD_HH-MM-SS.<i>.current, where i is
 605   // current rotation file number. After it reaches max file size, the file will be
 606   // saved and renamed with .current removed from its tail.
 607   size_t filename_len = strlen(_file_name);
 608   if (_file != NULL) {
 609     jio_snprintf(renamed_file_name, filename_len + EXTRACHARLEN, "%s.%d",
 610                  _file_name, _cur_file_num);
 611     jio_snprintf(current_file_name, filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX, 
 612                  _file_name, _cur_file_num);
 613     jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file has reached the"
 614                            " maximum size. Saved as %s\n",
 615                            os::local_time_string((char *)time_str, sizeof(time_str)),
 616                            renamed_file_name);
 617     this->write(time_msg, strlen(time_msg));
 618 
 619     fclose(_file);
 620     _file = NULL;
 621 
 622     bool can_rename = true;
 623     if (access(current_file_name, F_OK) != 0) {
 624       // current file does not exist?
 625       warning("No source file exists, cannot rename\n");
 626       can_rename = false;
 627     }
 628     if (can_rename) {
 629       if (access(renamed_file_name, F_OK) == 0) {
 630         if (remove(renamed_file_name) != 0) {
 631           warning("Could not delete existing file %s\n", renamed_file_name);
 632           can_rename = false;
 633         }
 634       } else {
 635         // file does not exist, ok to rename
 636       }
 637     }
 638     if (can_rename && rename(current_file_name, renamed_file_name) != 0) {
 639       warning("Could not rename %s to %s\n", _file_name, renamed_file_name);
 640     }
 641   }
 642 
 643   _cur_file_num++;
 644   if (_cur_file_num > NumberOfGCLogFiles - 1) _cur_file_num = 0;
 645   jio_snprintf(current_file_name,  filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX,
 646                _file_name, _cur_file_num);
 647   _file = fopen(current_file_name, "w");
 648 
 649   if (_file != NULL) {
 650     _bytes_written = 0L;
 651     _need_close = true;
 652     // reuse current_file_name for time_msg
 653     jio_snprintf(current_file_name, filename_len + EXTRACHARLEN,
 654                  "%s.%d", _file_name, _cur_file_num);
 655     jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file created %s\n",
 656                            os::local_time_string((char *)time_str, sizeof(time_str)),
 657                            current_file_name);
 658     this->write(time_msg, strlen(time_msg));
 659     // log more info: vm version, os version, native memory usage, commandline flags
 660     print_cr(Abstract_VM_Version::internal_vm_info_string());
 661     os::print_memory_info(this);
 662     print("CommandLine flags: ");
 663     CommandLineFlags::printSetFlags(this); 
 664     // remove the existing file 
 665     if (access(current_file_name, F_OK) == 0) {
 666       if (remove(current_file_name) != 0) {
 667         warning("Could not delete existing file %s\n", current_file_name);
 668       }
 669     }
 670   } else {
 671     warning("failed to open rotation log file %s due to %s\n"
 672             "Turned off GC log file rotation\n",
 673                   _file_name, strerror(errno));
 674     _need_close = false;
 675     FLAG_SET_DEFAULT(UseGCLogFileRotation, false);
 676   }
 677 }
 678 
 679 defaultStream* defaultStream::instance = NULL;
 680 int defaultStream::_output_fd = 1;
 681 int defaultStream::_error_fd  = 2;
 682 FILE* defaultStream::_output_stream = stdout;
 683 FILE* defaultStream::_error_stream  = stderr;
 684 
 685 #define LOG_MAJOR_VERSION 160
 686 #define LOG_MINOR_VERSION 1
 687 
 688 void defaultStream::init() {
 689   _inited = true;
 690   if (LogVMOutput || LogCompilation) {
 691     init_log();
 692   }
 693 }
 694 
 695 bool defaultStream::has_log_file() {


src/share/vm/utilities/ostream.cpp
Index Unified diffs Context diffs Sdiffs Wdiffs Patch New Old Previous File Next File