6941923: RFE: Handling large log files produced by long running Java Applications
Summary: supply optinal flags to realize gc log rotation
Reviewed-by: ysr, jwilhelm
--- a/hotspot/src/share/vm/gc_implementation/shared/concurrentGCThread.cpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/shared/concurrentGCThread.cpp Fri Jun 10 15:08:36 2011 -0700
@@ -43,17 +43,6 @@
_sts.initialize();
};
-void ConcurrentGCThread::stopWorldAndDo(VoidClosure* op) {
- MutexLockerEx x(Heap_lock,
- Mutex::_no_safepoint_check_flag);
- // warning("CGC: about to try stopping world");
- SafepointSynchronize::begin();
- // warning("CGC: successfully stopped world");
- op->do_void();
- SafepointSynchronize::end();
- // warning("CGC: successfully restarted world");
-}
-
void ConcurrentGCThread::safepoint_synchronize() {
_sts.suspend_all();
}
--- a/hotspot/src/share/vm/gc_implementation/shared/concurrentGCThread.hpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/shared/concurrentGCThread.hpp Fri Jun 10 15:08:36 2011 -0700
@@ -95,8 +95,6 @@
static int set_CGC_flag(int b) { return _CGC_flag |= b; }
static int reset_CGC_flag(int b) { return _CGC_flag &= ~b; }
- void stopWorldAndDo(VoidClosure* op);
-
// All instances share this one set.
static SuspendibleThreadSet _sts;
--- a/hotspot/src/share/vm/runtime/arguments.cpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/runtime/arguments.cpp Fri Jun 10 15:08:36 2011 -0700
@@ -1680,8 +1680,33 @@
UseParallelGC || UseParallelOldGC));
}
+// check if do gclog rotation
+// +UseGCLogFileRotation is a must,
+// no gc log rotation when log file not supplied or
+// NumberOfGCLogFiles is 0, or GCLogFileSize is 0
+void check_gclog_consistency() {
+ if (UseGCLogFileRotation) {
+ if ((Arguments::gc_log_filename() == NULL) ||
+ (NumberOfGCLogFiles == 0) ||
+ (GCLogFileSize == 0)) {
+ jio_fprintf(defaultStream::output_stream(),
+ "To enable GC log rotation, use -Xloggc:<filename> -XX:+UseGCLogRotaion -XX:NumberOfGCLogFiles=<num_of_files> -XX:GCLogFileSize=<num_of_size>\n"
+ "where num_of_file > 0 and num_of_size > 0\n"
+ "GC log rotation is turned off\n");
+ UseGCLogFileRotation = false;
+ }
+ }
+
+ if (UseGCLogFileRotation && GCLogFileSize < 8*K) {
+ FLAG_SET_CMDLINE(uintx, GCLogFileSize, 8*K);
+ jio_fprintf(defaultStream::output_stream(),
+ "GCLogFileSize changed to minimum 8K\n");
+ }
+}
+
// Check consistency of GC selection
bool Arguments::check_gc_consistency() {
+ check_gclog_consistency();
bool status = true;
// Ensure that the user has not selected conflicting sets
// of collectors. [Note: this check is merely a user convenience;
@@ -2672,6 +2697,7 @@
return JNI_ERR;
}
}
+
// Change the default value for flags which have different default values
// when working with older JDKs.
if (JDK_Version::current().compare_major(6) <= 0 &&
--- a/hotspot/src/share/vm/runtime/atomic.cpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/runtime/atomic.cpp Fri Jun 10 15:08:36 2011 -0700
@@ -83,3 +83,13 @@
return (unsigned int)Atomic::cmpxchg((jint)exchange_value, (volatile jint*)dest,
(jint)compare_value);
}
+
+jlong Atomic::add(jlong add_value, volatile jlong* dest) {
+ jlong old = load(dest);
+ jlong new_value = old + add_value;
+ while (old != cmpxchg(new_value, dest, old)) {
+ old = load(dest);
+ new_value = old + add_value;
+ }
+ return old;
+}
--- a/hotspot/src/share/vm/runtime/atomic.hpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/runtime/atomic.hpp Fri Jun 10 15:08:36 2011 -0700
@@ -51,6 +51,8 @@
static intptr_t add_ptr(intptr_t add_value, volatile intptr_t* dest);
static void* add_ptr(intptr_t add_value, volatile void* dest);
+ static jlong add (jlong add_value, volatile jlong* dest);
+
// Atomically increment location
static void inc (volatile jint* dest);
static void inc_ptr(volatile intptr_t* dest);
--- a/hotspot/src/share/vm/runtime/globals.hpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/runtime/globals.hpp Fri Jun 10 15:08:36 2011 -0700
@@ -2332,6 +2332,20 @@
"Print diagnostic message when GC is stalled" \
"by JNI critical section") \
\
+ /* GC log rotation setting */ \
+ \
+ product(bool, UseGCLogFileRotation, false, \
+ "Prevent large gclog file for long running app. " \
+ "Requires -Xloggc:<filename>") \
+ \
+ product(uintx, NumberOfGCLogFiles, 0, \
+ "Number of gclog files in rotation, " \
+ "Default: 0, no rotation") \
+ \
+ product(uintx, GCLogFileSize, 0, \
+ "GC log file size, Default: 0 bytes, no rotation " \
+ "Only valid with UseGCLogFileRotation") \
+ \
/* JVMTI heap profiling */ \
\
diagnostic(bool, TraceJVMTIObjectTagging, false, \
--- a/hotspot/src/share/vm/runtime/safepoint.cpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/runtime/safepoint.cpp Fri Jun 10 15:08:36 2011 -0700
@@ -511,6 +511,11 @@
TraceTime t4("sweeping nmethods", TraceSafepointCleanupTime);
NMethodSweeper::scan_stacks();
+
+ // rotate log files?
+ if (UseGCLogFileRotation) {
+ gclog_or_tty->rotate_log();
+ }
}
--- a/hotspot/src/share/vm/utilities/ostream.cpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/utilities/ostream.cpp Fri Jun 10 15:08:36 2011 -0700
@@ -349,7 +349,7 @@
fileStream::~fileStream() {
if (_file != NULL) {
if (_need_close) fclose(_file);
- _file = NULL;
+ _file = NULL;
}
}
@@ -377,6 +377,86 @@
update_position(s, len);
}
+rotatingFileStream::~rotatingFileStream() {
+ if (_file != NULL) {
+ if (_need_close) fclose(_file);
+ _file = NULL;
+ FREE_C_HEAP_ARRAY(char, _file_name);
+ _file_name = NULL;
+ }
+}
+
+rotatingFileStream::rotatingFileStream(const char* file_name) {
+ _cur_file_num = 0;
+ _bytes_writen = 0L;
+ _file_name = NEW_C_HEAP_ARRAY(char, strlen(file_name)+10);
+ jio_snprintf(_file_name, strlen(file_name)+10, "%s.%d", file_name, _cur_file_num);
+ _file = fopen(_file_name, "w");
+ _need_close = true;
+}
+
+rotatingFileStream::rotatingFileStream(const char* file_name, const char* opentype) {
+ _cur_file_num = 0;
+ _bytes_writen = 0L;
+ _file_name = NEW_C_HEAP_ARRAY(char, strlen(file_name)+10);
+ jio_snprintf(_file_name, strlen(file_name)+10, "%s.%d", file_name, _cur_file_num);
+ _file = fopen(_file_name, opentype);
+ _need_close = true;
+}
+
+void rotatingFileStream::write(const char* s, size_t len) {
+ if (_file != NULL) {
+ // Make an unused local variable to avoid warning from gcc 4.x compiler.
+ size_t count = fwrite(s, 1, len, _file);
+ Atomic::add((jlong)count, &_bytes_writen);
+ }
+ update_position(s, len);
+}
+
+// rotate_log must be called from VMThread at safepoint. In case need change parameters
+// for gc log rotation from thread other than VMThread, a sub type of VM_Operation
+// should be created and be submitted to VMThread's operation queue. DO NOT call this
+// function directly. Currently, it is safe to rotate log at safepoint through VMThread.
+// That is, no mutator threads and concurrent GC threads run parallel with VMThread to
+// write to gc log file at safepoint. If in future, changes made for mutator threads or
+// concurrent GC threads to run parallel with VMThread at safepoint, write and rotate_log
+// must be synchronized.
+void rotatingFileStream::rotate_log() {
+ if (_bytes_writen < (jlong)GCLogFileSize) return;
+#ifdef ASSERT
+ Thread *thread = Thread::current();
+ assert(thread == NULL ||
+ (thread->is_VM_thread() && SafepointSynchronize::is_at_safepoint()),
+ "Must be VMThread at safepoint");
+#endif
+ if (NumberOfGCLogFiles == 1) {
+ // rotate in same file
+ rewind();
+ _bytes_writen = 0L;
+ return;
+ }
+
+ // rotate file in names file.0, file.1, file.2, ..., file.<MaxGCLogFileNumbers-1>
+ // close current file, rotate to next file
+ 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);
+ fclose(_file);
+ _file = NULL;
+ }
+ _file = fopen(_file_name, "w");
+ if (_file != NULL) {
+ _bytes_writen = 0L;
+ _need_close = true;
+ } else {
+ tty->print_cr("failed to open rotation log file %s due to %s\n",
+ _file_name, strerror(errno));
+ _need_close = false;
+ }
+}
+
defaultStream* defaultStream::instance = NULL;
int defaultStream::_output_fd = 1;
int defaultStream::_error_fd = 2;
@@ -749,14 +829,17 @@
gclog_or_tty = tty; // default to tty
if (Arguments::gc_log_filename() != NULL) {
- fileStream * gclog = new(ResourceObj::C_HEAP)
- fileStream(Arguments::gc_log_filename());
+ fileStream * gclog = UseGCLogFileRotation ?
+ new(ResourceObj::C_HEAP)
+ rotatingFileStream(Arguments::gc_log_filename()) :
+ new(ResourceObj::C_HEAP)
+ fileStream(Arguments::gc_log_filename());
if (gclog->is_open()) {
// now we update the time stamp of the GC log to be synced up
// with tty.
gclog->time_stamp().update_to(tty->time_stamp().ticks());
- gclog_or_tty = gclog;
}
+ gclog_or_tty = gclog;
}
// If we haven't lazily initialized the logfile yet, do it now,
--- a/hotspot/src/share/vm/utilities/ostream.hpp Wed Jun 08 21:48:38 2011 -0400
+++ b/hotspot/src/share/vm/utilities/ostream.hpp Fri Jun 10 15:08:36 2011 -0700
@@ -110,14 +110,15 @@
// flushing
virtual void flush() {}
virtual void write(const char* str, size_t len) = 0;
- virtual ~outputStream() {} // close properly on deletion
+ virtual void rotate_log() {} // GC log rotation
+ virtual ~outputStream() {} // close properly on deletion
void dec_cr() { dec(); cr(); }
void inc_cr() { inc(); cr(); }
};
// standard output
- // ANSI C++ name collision
+// ANSI C++ name collision
extern outputStream* tty; // tty output
extern outputStream* gclog_or_tty; // stream for gc log if -Xloggc:<f>, or tty
@@ -176,6 +177,7 @@
FILE* _file;
bool _need_close;
public:
+ fileStream() { _file = NULL; _need_close = false; }
fileStream(const char* file_name);
fileStream(const char* file_name, const char* opentype);
fileStream(FILE* file) { _file = file; _need_close = false; }
@@ -210,6 +212,20 @@
void flush() {};
};
+class rotatingFileStream : public fileStream {
+ protected:
+ char* _file_name;
+ jlong _bytes_writen;
+ uintx _cur_file_num; // current logfile rotation number, from 0 to MaxGCLogFileNumbers-1
+ public:
+ rotatingFileStream(const char* file_name);
+ rotatingFileStream(const char* file_name, const char* opentype);
+ rotatingFileStream(FILE* file) : fileStream(file) {}
+ ~rotatingFileStream();
+ virtual void write(const char* c, size_t len);
+ virtual void rotate_log();
+};
+
void ostream_init();
void ostream_init_log();
void ostream_exit();
--- /dev/null Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/test/gc/6941923/test6941923.sh Fri Jun 10 15:08:36 2011 -0700
@@ -0,0 +1,179 @@
+##
+## @test @(#)test6941923.sh
+## @bug 6941923
+## @summary test new added flags for gc log rotation
+## @author yqi
+## @run shell test6941923.sh
+##
+
+## skip on windows
+OS=`uname -s`
+case "$OS" in
+ SunOS | Linux )
+ NULL=/dev/null
+ PS=":"
+ FS="/"
+ ;;
+ Windows_* )
+ echo "Test skipped for Windows"
+ exit 0
+ ;;
+ * )
+ echo "Unrecognized system!"
+ exit 1;
+ ;;
+esac
+
+if [ "${JAVA_HOME}" = "" ]
+then
+ echo "JAVA_HOME not set"
+ exit 0
+fi
+
+$JAVA_HOME/bin/java -version > $NULL 2>&1
+
+if [ $? != 0 ]; then
+ echo "Wrong JAVA_HOME? JAVA_HOME: $JAVA_HOME"
+ exit $?
+fi
+
+# create a small test case
+testname="Test"
+if [ -e ${testname}.java ]; then
+ rm -rf ${testname}.*
+fi
+
+cat >> ${testname}.java << __EOF__
+import java.util.Vector;
+
+public class Test implements Runnable
+{
+ private boolean _should_stop = false;
+
+ public static void main(String[] args) throws Exception {
+
+ long limit = Long.parseLong(args[0]) * 60L * 1000L; // minutes
+ Test t = new Test();
+ t.set_stop(false);
+ Thread thr = new Thread(t);
+ thr.start();
+
+ long time1 = System.currentTimeMillis();
+ long time2 = System.currentTimeMillis();
+ while (time2 - time1 < limit) {
+ try {
+ Thread.sleep(2000); // 2 seconds
+ }
+ catch(Exception e) {}
+ time2 = System.currentTimeMillis();
+ System.out.print("\r... " + (time2 - time1)/1000 + " seconds");
+ }
+ System.out.println();
+ t.set_stop(true);
+ }
+ public void set_stop(boolean value) { _should_stop = value; }
+ public void run() {
+ int cap = 20000;
+ int fix_size = 2048;
+ int loop = 0;
+ Vector< byte[] > v = new Vector< byte[] >(cap);
+ while(!_should_stop) {
+ byte[] g = new byte[fix_size];
+ v.add(g);
+ loop++;
+ if (loop > cap) {
+ v = null;
+ cap *= 2;
+ if (cap > 80000) cap = 80000;
+ v = new Vector< byte[] >(cap);
+ }
+ }
+ }
+}
+__EOF__
+
+msgsuccess="succeeded"
+msgfail="failed"
+gclogsize="16K"
+filesize=$((16*1024))
+$JAVA_HOME/bin/javac ${testname}.java > $NULL 2>&1
+
+if [ $? != 0 ]; then
+ echo "$JAVA_HOME/bin/javac ${testname}.java $fail"
+ exit -1
+fi
+
+# test for 2 minutes, it will complete circulation of gc log rotation
+tts=2
+logfile="test.log"
+hotspotlog="hotspot.log"
+
+if [ -e $logfile ]; then
+ rm -rf $logfile
+fi
+
+#also delete $hotspotlog if it exists
+if [ -f $hotspotlog ]; then
+ rm -rf $hotspotlog
+fi
+
+options="-Xloggc:$logfile -XX:+UseConcMarkSweepGC -XX:+PrintGC -XX:+PrintGCDetails -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=1 -XX:GCLogFileSize=$gclogsize"
+echo "Test gc log rotation in same file, wait for $tts minutes ...."
+$JAVA_HOME/bin/java $options $testname $tts
+if [ $? != 0 ]; then
+ echo "$msgfail"
+ exit -1
+fi
+
+# rotation file will be $logfile.0
+if [ -f $logfile.0 ]; then
+ outfilesize=`ls -l $logfile.0 | awk '{print $5 }'`
+ if [ $((outfilesize)) -ge $((filesize)) ]; then
+ echo $msgsuccess
+ else
+ echo $msgfail
+ fi
+else
+ echo $msgfail
+ exit -1
+fi
+
+# delete log file
+rm -rf $logfile.0
+if [ -f $hotspotlog ]; then
+ rm -rf $hotspotlog
+fi
+
+#multiple log files
+numoffiles=3
+options="-Xloggc:$logfile -XX:+UseConcMarkSweepGC -XX:+PrintGC -XX:+PrintGCDetails -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=$numoffiles -XX:GCLogFileSize=$gclogsize"
+echo "Test gc log rotation in $numoffiles files, wait for $tts minutes ...."
+$JAVA_HOME/bin/java $options $testname $tts
+if [ $? != 0 ]; then
+ echo "$msgfail"
+ exit -1
+fi
+
+atleast=0 # at least size of numoffile-1 files >= $gclogsize
+tk=0
+while [ $(($tk)) -lt $(($numoffiles)) ]
+do
+ if [ -f $logfile.$tk ]; then
+ outfilesize=`ls -l $logfile.$tk | awk '{ print $5 }'`
+ if [ $(($outfilesize)) -ge $(($filesize)) ]; then
+ atleast=$((atleast+1))
+ fi
+ fi
+ tk=$((tk+1))
+done
+
+rm -rf $logfile.*
+rm -rf $testname.*
+rm -rf $hotspotlog
+
+if [ $(($atleast)) -ge $(($numoffiles-1)) ]; then
+ echo $msgsuccess
+else
+ echo $msgfail
+ exit -1
+fi