TEST_VM_F(GCTraceTimeTest, no_heap) { set_log_config(TestLogFileName, "gc=debug,gc+start=debug"); LogTarget(Debug, gc) gc_debug; LogTarget(Debug, gc, start) gc_start_debug; EXPECT_TRUE(gc_debug.is_enabled()); EXPECT_TRUE(gc_start_debug.is_enabled()); { GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_allocation_failure, false); } const char* expected[] = { // [2.975s][debug][gc,start] Test GC (Allocation Failure) "[gc,start", "] Test GC (Allocation Failure)", // [2.975s][debug][gc ] Test GC (Allocation Failure) 0.026ms "[gc", "] Test GC (Allocation Failure) ", "ms", NULL }; EXPECT_TRUE(file_contains_substrings_in_order(TestLogFileName, expected)); const char* not_expected[] = { // [2.975s][debug][gc ] Test GC 59M->59M(502M) 0.026ms "[gc", "] Test GC ", "M) ", "ms", }; EXPECT_FALSE(file_contains_substrings_in_order(TestLogFileName, not_expected)); }
TEST(LogFileOutput, startup_truncation) { const char* filename = "start-truncate-test"; const char* archived_filename = "start-truncate-test.0"; delete_file(filename); delete_file(archived_filename); // Use the same log file twice and expect it to be overwritten/truncated init_log_file(filename, "filecount=0"); ASSERT_TRUE(file_exists(filename)) << "configured logging to file '" << filename << "' but file was not found"; init_log_file(filename, "filecount=0"); ASSERT_TRUE(file_exists(filename)) << "configured logging to file '" << filename << "' but file was not found"; EXPECT_FALSE(file_exists(archived_filename)) << "existing log file was not properly truncated when filecount was 0"; // Verify that the file was really truncated and not just appended EXPECT_TRUE(file_contains_substring(filename, LOG_TEST_STRING_LITERAL)); const char* repeated[] = { LOG_TEST_STRING_LITERAL, LOG_TEST_STRING_LITERAL }; EXPECT_FALSE(file_contains_substrings_in_order(filename, repeated)) << "log file " << filename << " appended rather than truncated"; delete_file(filename); delete_file(archived_filename); }
TEST_VM_F(GCTraceTimeTest, full_multitag) { set_log_config(TestLogFileName, "gc+ref=debug,gc+ref+start=debug"); LogTarget(Debug, gc, ref) gc_debug; LogTarget(Debug, gc, ref, start) gc_start_debug; EXPECT_TRUE(gc_debug.is_enabled()); EXPECT_TRUE(gc_start_debug.is_enabled()); { ThreadInVMfromNative tvn(JavaThread::current()); MutexLocker lock(Heap_lock); // Needed to read heap usage GCTraceTime(Debug, gc, ref) timer("Test GC", NULL, GCCause::_allocation_failure, true); } const char* expected[] = { "[gc,ref,start", "] Test GC (Allocation Failure)", "[gc,ref", "] Test GC (Allocation Failure) ", "M) ", "ms", NULL }; EXPECT_TRUE(file_contains_substrings_in_order(TestLogFileName, expected)); }
TEST_VM_F(GCTraceTimeTest, no_cause) { set_log_config(TestLogFileName, "gc=debug,gc+start=debug"); LogTarget(Debug, gc) gc_debug; LogTarget(Debug, gc, start) gc_start_debug; EXPECT_TRUE(gc_debug.is_enabled()); EXPECT_TRUE(gc_start_debug.is_enabled()); { ThreadInVMfromNative tvn(JavaThread::current()); MutexLocker lock(Heap_lock); // Needed to read heap usage GCTraceTime(Debug, gc) timer("Test GC", NULL, GCCause::_no_gc, true); } const char* expected[] = { // [2.975s][debug][gc,start] Test GC "[gc,start", "] Test GC", // [2.975s][debug][gc ] Test GC 59M->59M(502M) 0.026ms "[gc", "] Test GC ", "M) ", "ms", NULL }; EXPECT_TRUE(file_contains_substrings_in_order(TestLogFileName, expected)); }