Mercurial > hg > graal-jvmci-8

comparison src/share/vm/utilities/ostream.cpp @ 20734:a4fdab16b621

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
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
author brutisso
date Tue, 19 Aug 2014 11:17:36 +0200
parents 78bbf4d43a14
children c2844108a708
comparison
equal deleted inserted replaced
20733:6709b033c725 20734:a4fdab16b621
358 outputStream* gclog_or_tty; 358 outputStream* gclog_or_tty;
359 extern Mutex* tty_lock; 359 extern Mutex* tty_lock;
360 360
361 #define EXTRACHARLEN 32 361 #define EXTRACHARLEN 32
362 #define CURRENTAPPX ".current" 362 #define CURRENTAPPX ".current"
363 #define FILENAMEBUFLEN 1024
364 // convert YYYY-MM-DD HH:MM:SS to YYYY-MM-DD_HH-MM-SS 363 // convert YYYY-MM-DD HH:MM:SS to YYYY-MM-DD_HH-MM-SS
365 char* get_datetime_string(char *buf, size_t len) { 364 char* get_datetime_string(char *buf, size_t len) {
366 os::local_time_string(buf, len); 365 os::local_time_string(buf, len);
367 int i = (int)strlen(buf); 366 int i = (int)strlen(buf);
368 while (i-- >= 0) { 367 while (i-- >= 0) {
392 strlen(basename) + 1; 391 strlen(basename) + 1;
393 } else { 392 } else {
394 buffer_length = strlen(log_name) + 1; 393 buffer_length = strlen(log_name) + 1;
395 } 394 }
396 395
397 // const char* star = strchr(basename, '*');
398 const char* pts = strstr(basename, "%p"); 396 const char* pts = strstr(basename, "%p");
399 int pid_pos = (pts == NULL) ? -1 : (pts - nametail); 397 int pid_pos = (pts == NULL) ? -1 : (pts - nametail);
400 398
401 if (pid_pos >= 0) { 399 if (pid_pos >= 0) {
402 jio_snprintf(pid_text, sizeof(pid_text), "pid%u", pid); 400 jio_snprintf(pid_text, sizeof(pid_text), "pid%u", pid);
405 403
406 pts = strstr(basename, "%t"); 404 pts = strstr(basename, "%t");
407 int tms_pos = (pts == NULL) ? -1 : (pts - nametail); 405 int tms_pos = (pts == NULL) ? -1 : (pts - nametail);
408 if (tms_pos >= 0) { 406 if (tms_pos >= 0) {
409 buffer_length += strlen(tms); 407 buffer_length += strlen(tms);
408 }
409
410 // File name is too long.
411 if (buffer_length > JVM_MAXPATHLEN) {
412 return NULL;
410 } 413 }
411 414
412 // Create big enough buffer. 415 // Create big enough buffer.
413 char *buf = NEW_C_HEAP_ARRAY(char, buffer_length, mtInternal); 416 char *buf = NEW_C_HEAP_ARRAY(char, buffer_length, mtInternal);
414 417
479 482
480 #ifndef PRODUCT 483 #ifndef PRODUCT
481 void test_loggc_filename() { 484 void test_loggc_filename() {
482 int pid; 485 int pid;
483 char tms[32]; 486 char tms[32];
484 char i_result[FILENAMEBUFLEN]; 487 char i_result[JVM_MAXPATHLEN];
485 const char* o_result; 488 const char* o_result;
486 get_datetime_string(tms, sizeof(tms)); 489 get_datetime_string(tms, sizeof(tms));
487 pid = os::current_process_id(); 490 pid = os::current_process_id();
488 491
489 // test.log 492 // test.log
490 jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test.log", tms); 493 jio_snprintf(i_result, JVM_MAXPATHLEN, "test.log", tms);
491 o_result = make_log_name_internal("test.log", NULL, pid, tms); 494 o_result = make_log_name_internal("test.log", NULL, pid, tms);
492 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test.log\", NULL)"); 495 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test.log\", NULL)");
493 FREE_C_HEAP_ARRAY(char, o_result, mtInternal); 496 FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
494 497
495 // test-%t-%p.log 498 // test-%t-%p.log
496 jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test-%s-pid%u.log", tms, pid); 499 jio_snprintf(i_result, JVM_MAXPATHLEN, "test-%s-pid%u.log", tms, pid);
497 o_result = make_log_name_internal("test-%t-%p.log", NULL, pid, tms); 500 o_result = make_log_name_internal("test-%t-%p.log", NULL, pid, tms);
498 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test-%%t-%%p.log\", NULL)"); 501 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test-%%t-%%p.log\", NULL)");
499 FREE_C_HEAP_ARRAY(char, o_result, mtInternal); 502 FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
500 503
501 // test-%t%p.log 504 // test-%t%p.log
502 jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "test-%spid%u.log", tms, pid); 505 jio_snprintf(i_result, JVM_MAXPATHLEN, "test-%spid%u.log", tms, pid);
503 o_result = make_log_name_internal("test-%t%p.log", NULL, pid, tms); 506 o_result = make_log_name_internal("test-%t%p.log", NULL, pid, tms);
504 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test-%%t%%p.log\", NULL)"); 507 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"test-%%t%%p.log\", NULL)");
505 FREE_C_HEAP_ARRAY(char, o_result, mtInternal); 508 FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
506 509
507 // %p%t.log 510 // %p%t.log
508 jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "pid%u%s.log", pid, tms); 511 jio_snprintf(i_result, JVM_MAXPATHLEN, "pid%u%s.log", pid, tms);
509 o_result = make_log_name_internal("%p%t.log", NULL, pid, tms); 512 o_result = make_log_name_internal("%p%t.log", NULL, pid, tms);
510 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%p%%t.log\", NULL)"); 513 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%p%%t.log\", NULL)");
511 FREE_C_HEAP_ARRAY(char, o_result, mtInternal); 514 FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
512 515
513 // %p-test.log 516 // %p-test.log
514 jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "pid%u-test.log", pid); 517 jio_snprintf(i_result, JVM_MAXPATHLEN, "pid%u-test.log", pid);
515 o_result = make_log_name_internal("%p-test.log", NULL, pid, tms); 518 o_result = make_log_name_internal("%p-test.log", NULL, pid, tms);
516 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%p-test.log\", NULL)"); 519 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%p-test.log\", NULL)");
517 FREE_C_HEAP_ARRAY(char, o_result, mtInternal); 520 FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
518 521
519 // %t.log 522 // %t.log
520 jio_snprintf(i_result, sizeof(char)*FILENAMEBUFLEN, "%s.log", tms); 523 jio_snprintf(i_result, JVM_MAXPATHLEN, "%s.log", tms);
521 o_result = make_log_name_internal("%t.log", NULL, pid, tms); 524 o_result = make_log_name_internal("%t.log", NULL, pid, tms);
522 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%t.log\", NULL)"); 525 assert(strcmp(i_result, o_result) == 0, "failed on testing make_log_name(\"%%t.log\", NULL)");
523 FREE_C_HEAP_ARRAY(char, o_result, mtInternal); 526 FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
527
528 {
529 // longest filename
530 char longest_name[JVM_MAXPATHLEN];
531 memset(longest_name, 'a', sizeof(longest_name));
532 longest_name[JVM_MAXPATHLEN - 1] = '\0';
533 o_result = make_log_name_internal((const char*)&longest_name, NULL, pid, tms);
534 assert(strcmp(longest_name, o_result) == 0, err_msg("longest name does not match. expected '%s' but got '%s'", longest_name, o_result));
535 FREE_C_HEAP_ARRAY(char, o_result, mtInternal);
536 }
537
538 {
539 // too long file name
540 char too_long_name[JVM_MAXPATHLEN + 100];
541 int too_long_length = sizeof(too_long_name);
542 memset(too_long_name, 'a', too_long_length);
543 too_long_name[too_long_length - 1] = '\0';
544 o_result = make_log_name_internal((const char*)&too_long_name, NULL, pid, tms);
545 assert(o_result == NULL, err_msg("Too long file name should return NULL, but got '%s'", o_result));
546 }
547
548 {
549 // too long with timestamp
550 char longest_name[JVM_MAXPATHLEN];
551 memset(longest_name, 'a', JVM_MAXPATHLEN);
552 longest_name[JVM_MAXPATHLEN - 3] = '%';
553 longest_name[JVM_MAXPATHLEN - 2] = 't';
554 longest_name[JVM_MAXPATHLEN - 1] = '\0';
555 o_result = make_log_name_internal((const char*)&longest_name, NULL, pid, tms);
556 assert(o_result == NULL, err_msg("Too long file name after timestamp expansion should return NULL, but got '%s'", o_result));
557 }
558
559 {
560 // too long with pid
561 char longest_name[JVM_MAXPATHLEN];
562 memset(longest_name, 'a', JVM_MAXPATHLEN);
563 longest_name[JVM_MAXPATHLEN - 3] = '%';
564 longest_name[JVM_MAXPATHLEN - 2] = 'p';
565 longest_name[JVM_MAXPATHLEN - 1] = '\0';
566 o_result = make_log_name_internal((const char*)&longest_name, NULL, pid, tms);
567 assert(o_result == NULL, err_msg("Too long file name after pid expansion should return NULL, but got '%s'", o_result));
568 }
524 } 569 }
525 #endif // PRODUCT 570 #endif // PRODUCT
526 571
527 fileStream::fileStream(const char* file_name) { 572 fileStream::fileStream(const char* file_name) {
528 _file = fopen(file_name, "w"); 573 _file = fopen(file_name, "w");
627 gcLogFileStream::gcLogFileStream(const char* file_name) { 672 gcLogFileStream::gcLogFileStream(const char* file_name) {
628 _cur_file_num = 0; 673 _cur_file_num = 0;
629 _bytes_written = 0L; 674 _bytes_written = 0L;
630 _file_name = make_log_name(file_name, NULL); 675 _file_name = make_log_name(file_name, NULL);
631 676
677 if (_file_name == NULL) {
678 warning("Cannot open file %s: file name is too long.\n", file_name);
679 _need_close = false;
680 UseGCLogFileRotation = false;
681 return;
682 }
683
632 // gc log file rotation 684 // gc log file rotation
633 if (UseGCLogFileRotation && NumberOfGCLogFiles > 1) { 685 if (UseGCLogFileRotation && NumberOfGCLogFiles > 1) {
634 char tempbuf[FILENAMEBUFLEN]; 686 char tempbuf[JVM_MAXPATHLEN];
635 jio_snprintf(tempbuf, sizeof(tempbuf), "%s.%d" CURRENTAPPX, _file_name, _cur_file_num); 687 jio_snprintf(tempbuf, sizeof(tempbuf), "%s.%d" CURRENTAPPX, _file_name, _cur_file_num);
636 _file = fopen(tempbuf, "w"); 688 _file = fopen(tempbuf, "w");
637 } else { 689 } else {
638 _file = fopen(_file_name, "w"); 690 _file = fopen(_file_name, "w");
639 } 691 }
661 // That is, no mutator threads and concurrent GC threads run parallel with VMThread to 713 // That is, no mutator threads and concurrent GC threads run parallel with VMThread to
662 // write to gc log file at safepoint. If in future, changes made for mutator threads or 714 // write to gc log file at safepoint. If in future, changes made for mutator threads or
663 // concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log 715 // concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log
664 // must be synchronized. 716 // must be synchronized.
665 void gcLogFileStream::rotate_log(bool force, outputStream* out) { 717 void gcLogFileStream::rotate_log(bool force, outputStream* out) {
666 char time_msg[FILENAMEBUFLEN]; 718 char time_msg[O_BUFLEN];
667 char time_str[EXTRACHARLEN]; 719 char time_str[EXTRACHARLEN];
668 char current_file_name[FILENAMEBUFLEN]; 720 char current_file_name[JVM_MAXPATHLEN];
669 char renamed_file_name[FILENAMEBUFLEN]; 721 char renamed_file_name[JVM_MAXPATHLEN];
670 722
671 if (!should_rotate(force)) { 723 if (!should_rotate(force)) {
672 return; 724 return;
673 } 725 }
674 726
703 // rotate file in names extended_filename.0, extended_filename.1, ..., 755 // rotate file in names extended_filename.0, extended_filename.1, ...,
704 // extended_filename.<NumberOfGCLogFiles - 1>. Current rotation file name will 756 // extended_filename.<NumberOfGCLogFiles - 1>. Current rotation file name will
705 // have a form of extended_filename.<i>.current where i is the current rotation 757 // have a form of extended_filename.<i>.current where i is the current rotation
706 // file number. After it reaches max file size, the file will be saved and renamed 758 // file number. After it reaches max file size, the file will be saved and renamed
707 // with .current removed from its tail. 759 // with .current removed from its tail.
708 size_t filename_len = strlen(_file_name);
709 if (_file != NULL) { 760 if (_file != NULL) {
710 jio_snprintf(renamed_file_name, filename_len + EXTRACHARLEN, "%s.%d", 761 jio_snprintf(renamed_file_name, JVM_MAXPATHLEN, "%s.%d",
711 _file_name, _cur_file_num); 762 _file_name, _cur_file_num);
712 jio_snprintf(current_file_name, filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX, 763 int result = jio_snprintf(current_file_name, JVM_MAXPATHLEN,
713 _file_name, _cur_file_num); 764 "%s.%d" CURRENTAPPX, _file_name, _cur_file_num);
765 if (result >= JVM_MAXPATHLEN) {
766 warning("Cannot create new log file name: %s: file name is too long.\n", current_file_name);
767 return;
768 }
714 769
715 const char* msg = force ? "GC log rotation request has been received." 770 const char* msg = force ? "GC log rotation request has been received."
716 : "GC log file has reached the maximum size."; 771 : "GC log file has reached the maximum size.";
717 jio_snprintf(time_msg, sizeof(time_msg), "%s %s Saved as %s\n", 772 jio_snprintf(time_msg, sizeof(time_msg), "%s %s Saved as %s\n",
718 os::local_time_string((char *)time_str, sizeof(time_str)), 773 os::local_time_string((char *)time_str, sizeof(time_str)),
747 } 802 }
748 } 803 }
749 804
750 _cur_file_num++; 805 _cur_file_num++;
751 if (_cur_file_num > NumberOfGCLogFiles - 1) _cur_file_num = 0; 806 if (_cur_file_num > NumberOfGCLogFiles - 1) _cur_file_num = 0;
752 jio_snprintf(current_file_name, filename_len + EXTRACHARLEN, "%s.%d" CURRENTAPPX, 807 int result = jio_snprintf(current_file_name, JVM_MAXPATHLEN, "%s.%d" CURRENTAPPX,
753 _file_name, _cur_file_num); 808 _file_name, _cur_file_num);
809 if (result >= JVM_MAXPATHLEN) {
810 warning("Cannot create new log file name: %s: file name is too long.\n", current_file_name);
811 return;
812 }
813
754 _file = fopen(current_file_name, "w"); 814 _file = fopen(current_file_name, "w");
755 815
756 if (_file != NULL) { 816 if (_file != NULL) {
757 _bytes_written = 0L; 817 _bytes_written = 0L;
758 _need_close = true; 818 _need_close = true;
759 // reuse current_file_name for time_msg 819 // reuse current_file_name for time_msg
760 jio_snprintf(current_file_name, filename_len + EXTRACHARLEN, 820 jio_snprintf(current_file_name, JVM_MAXPATHLEN,
761 "%s.%d", _file_name, _cur_file_num); 821 "%s.%d", _file_name, _cur_file_num);
762 jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file created %s\n", 822 jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file created %s\n",
763 os::local_time_string((char *)time_str, sizeof(time_str)), 823 os::local_time_string((char *)time_str, sizeof(time_str)), current_file_name);
764 current_file_name);
765 write(time_msg, strlen(time_msg)); 824 write(time_msg, strlen(time_msg));
766 825
767 if (out != NULL) { 826 if (out != NULL) {
768 out->print("%s", time_msg); 827 out->print("%s", time_msg);
769 } 828 }
807 // if a VM error has been reported. 866 // if a VM error has been reported.
808 if (!_inited && !is_error_reported()) init(); 867 if (!_inited && !is_error_reported()) init();
809 return _log_file != NULL; 868 return _log_file != NULL;
810 } 869 }
811 870
871 fileStream* defaultStream::open_file(const char* log_name) {
872 const char* try_name = make_log_name(log_name, NULL);
873 if (try_name == NULL) {
874 warning("Cannot open file %s: file name is too long.\n", log_name);
875 return NULL;
876 }
877
878 fileStream* file = new(ResourceObj::C_HEAP, mtInternal) fileStream(try_name);
879 FREE_C_HEAP_ARRAY(char, try_name, mtInternal);
880 if (file->is_open()) {
881 return file;
882 }
883
884 // Try again to open the file in the temp directory.
885 delete file;
886 char warnbuf[O_BUFLEN*2];
887 jio_snprintf(warnbuf, sizeof(warnbuf), "Warning: Cannot open log file: %s\n", log_name);
888 // Note: This feature is for maintainer use only. No need for L10N.
889 jio_print(warnbuf);
890 try_name = make_log_name(log_name, os::get_temp_directory());
891 if (try_name == NULL) {
892 warning("Cannot open file %s: file name is too long for directory %s.\n", log_name, os::get_temp_directory());
893 return NULL;
894 }
895
896 jio_snprintf(warnbuf, sizeof(warnbuf),
897 "Warning: Forcing option -XX:LogFile=%s\n", try_name);
898 jio_print(warnbuf);
899
900 file = new(ResourceObj::C_HEAP, mtInternal) fileStream(try_name);
901 FREE_C_HEAP_ARRAY(char, try_name, mtInternal);
902 if (file->is_open()) {
903 return file;
904 }
905
906 delete file;
907 return NULL;
908 }
909
812 void defaultStream::init_log() { 910 void defaultStream::init_log() {
813 // %%% Need a MutexLocker? 911 // %%% Need a MutexLocker?
814 const char* log_name = LogFile != NULL ? LogFile : "hotspot_%p.log"; 912 const char* log_name = LogFile != NULL ? LogFile : "hotspot_%p.log";
815 const char* try_name = make_log_name(log_name, NULL); 913 fileStream* file = open_file(log_name);
816 fileStream* file = new(ResourceObj::C_HEAP, mtInternal) fileStream(try_name); 914
817 if (!file->is_open()) { 915 if (file != NULL) {
818 // Try again to open the file.
819 char warnbuf[O_BUFLEN*2];
820 jio_snprintf(warnbuf, sizeof(warnbuf),
821 "Warning: Cannot open log file: %s\n", try_name);
822 // Note: This feature is for maintainer use only. No need for L10N.
823 jio_print(warnbuf);
824 FREE_C_HEAP_ARRAY(char, try_name, mtInternal);
825 try_name = make_log_name(log_name, os::get_temp_directory());
826 jio_snprintf(warnbuf, sizeof(warnbuf),
827 "Warning: Forcing option -XX:LogFile=%s\n", try_name);
828 jio_print(warnbuf);
829 delete file;
830 file = new(ResourceObj::C_HEAP, mtInternal) fileStream(try_name);
831 }
832 FREE_C_HEAP_ARRAY(char, try_name, mtInternal);
833
834 if (file->is_open()) {
835 _log_file = file; 916 _log_file = file;
836 xmlStream* xs = new(ResourceObj::C_HEAP, mtInternal) xmlStream(file); 917 _outer_xmlStream = new(ResourceObj::C_HEAP, mtInternal) xmlStream(file);
837 _outer_xmlStream = xs; 918 start_log();
919 } else {
920 // and leave xtty as NULL
921 LogVMOutput = false;
922 DisplayVMOutput = true;
923 LogCompilation = false;
924 }
925 }
926
927 void defaultStream::start_log() {
928 xmlStream*xs = _outer_xmlStream;
838 if (this == tty) xtty = xs; 929 if (this == tty) xtty = xs;
839 // Write XML header. 930 // Write XML header.
840 xs->print_cr("<?xml version='1.0' encoding='UTF-8'?>"); 931 xs->print_cr("<?xml version='1.0' encoding='UTF-8'?>");
841 // (For now, don't bother to issue a DTD for this private format.) 932 // (For now, don't bother to issue a DTD for this private format.)
842 jlong time_ms = os::javaTimeMillis() - tty->time_stamp().milliseconds(); 933 jlong time_ms = os::javaTimeMillis() - tty->time_stamp().milliseconds();
887 xs->tail("vm_arguments"); 978 xs->tail("vm_arguments");
888 // tty output per se is grouped under the <tty>...</tty> element. 979 // tty output per se is grouped under the <tty>...</tty> element.
889 xs->head("tty"); 980 xs->head("tty");
890 // All further non-markup text gets copied to the tty: 981 // All further non-markup text gets copied to the tty:
891 xs->_text = this; // requires friend declaration! 982 xs->_text = this; // requires friend declaration!
892 } else {
893 delete(file);
894 // and leave xtty as NULL
895 LogVMOutput = false;
896 DisplayVMOutput = true;
897 LogCompilation = false;
898 }
899 } 983 }
900 984
901 // finish_log() is called during normal VM shutdown. finish_log_on_error() is 985 // finish_log() is called during normal VM shutdown. finish_log_on_error() is
902 // called by ostream_abort() after a fatal error. 986 // called by ostream_abort() after a fatal error.
903 // 987 //