8146009: "pure virtual method called" with using new GC logging mechanism
Reviewed-by: dsamersoff, dholmes, mchernov
Contributed-by: marcus.larsson@oracle.com, michail.chernov@oracle.com
--- a/hotspot/src/share/vm/logging/logConfiguration.cpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/src/share/vm/logging/logConfiguration.cpp Fri Oct 21 10:14:54 2016 +0200
@@ -98,14 +98,14 @@
LogDecorations::initialize(vm_start_time);
assert(_outputs == NULL, "Should not initialize _outputs before this function, initialize called twice?");
_outputs = NEW_C_HEAP_ARRAY(LogOutput*, 2, mtLogging);
- _outputs[0] = LogOutput::Stdout;
- _outputs[1] = LogOutput::Stderr;
+ _outputs[0] = &StdoutLog;
+ _outputs[1] = &StderrLog;
_n_outputs = 2;
}
void LogConfiguration::finalize() {
- for (size_t i = 2; i < _n_outputs; i++) {
- delete _outputs[i];
+ for (size_t i = _n_outputs; i > 0; i--) {
+ disable_output(i - 1);
}
FREE_C_HEAP_ARRAY(LogOutput*, _outputs);
}
@@ -279,8 +279,8 @@
ts->update_decorators();
}
- // Delete the output unless stdout/stderr
- if (out != LogOutput::Stderr && out != LogOutput::Stdout) {
+ // Delete the output unless stdout or stderr (idx 0 or 1)
+ if (idx > 1) {
delete_output(idx);
} else {
out->set_config_string("all=off");
@@ -322,7 +322,7 @@
// Apply configuration to stdout (output #0), with the same decorators as before.
ConfigurationLock cl;
- configure_output(0, expr, LogOutput::Stdout->decorators());
+ configure_output(0, expr, _outputs[0]->decorators());
notify_update_listeners();
}
--- a/hotspot/src/share/vm/logging/logDecorations.hpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/src/share/vm/logging/logDecorations.hpp Fri Oct 21 10:14:54 2016 +0200
@@ -36,7 +36,7 @@
char _decorations_buffer[DecorationsBufferSize];
char* _decoration_offset[LogDecorators::Count];
LogLevelType _level;
- LogTagSet _tagset;
+ const LogTagSet& _tagset;
jlong _millis;
static jlong _vm_start_time_millis;
static const char* _host_name;
--- a/hotspot/src/share/vm/logging/logFileStreamOutput.cpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/src/share/vm/logging/logFileStreamOutput.cpp Fri Oct 21 10:14:54 2016 +0200
@@ -28,8 +28,20 @@
#include "logging/logMessageBuffer.hpp"
#include "memory/allocation.inline.hpp"
-LogStdoutOutput LogStdoutOutput::_instance;
-LogStderrOutput LogStderrOutput::_instance;
+static bool initialized;
+static char stdoutmem[sizeof(LogStdoutOutput)];
+static char stderrmem[sizeof(LogStderrOutput)];
+
+LogStdoutOutput &StdoutLog = reinterpret_cast<LogStdoutOutput&>(stdoutmem);
+LogStderrOutput &StderrLog = reinterpret_cast<LogStderrOutput&>(stderrmem);
+
+LogFileStreamInitializer::LogFileStreamInitializer() {
+ if (!initialized) {
+ ::new (&StdoutLog) LogStdoutOutput();
+ ::new (&StderrLog) LogStderrOutput();
+ initialized = true;
+ }
+}
int LogFileStreamOutput::write_decorations(const LogDecorations& decorations) {
int total_written = 0;
--- a/hotspot/src/share/vm/logging/logFileStreamOutput.hpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/src/share/vm/logging/logFileStreamOutput.hpp Fri Oct 21 10:14:54 2016 +0200
@@ -30,6 +30,14 @@
class LogDecorations;
+class LogFileStreamInitializer {
+ public:
+ LogFileStreamInitializer();
+};
+
+// Ensure the default log streams have been initialized (stdout, stderr) using the static initializer below
+static LogFileStreamInitializer log_stream_initializer;
+
// Base class for all FileStream-based log outputs.
class LogFileStreamOutput : public LogOutput {
protected:
@@ -50,9 +58,8 @@
};
class LogStdoutOutput : public LogFileStreamOutput {
- friend class LogOutput;
+ friend class LogFileStreamInitializer;
private:
- static LogStdoutOutput _instance;
LogStdoutOutput() : LogFileStreamOutput(stdout) {
set_config_string("all=warning");
}
@@ -66,9 +73,8 @@
};
class LogStderrOutput : public LogFileStreamOutput {
- friend class LogOutput;
+ friend class LogFileStreamInitializer;
private:
- static LogStderrOutput _instance;
LogStderrOutput() : LogFileStreamOutput(stderr) {
set_config_string("all=off");
}
@@ -81,4 +87,7 @@
}
};
+extern LogStderrOutput &StderrLog;
+extern LogStdoutOutput &StdoutLog;
+
#endif // SHARE_VM_LOGGING_LOGFILESTREAMOUTPUT_HPP
--- a/hotspot/src/share/vm/logging/logOutput.cpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/src/share/vm/logging/logOutput.cpp Fri Oct 21 10:14:54 2016 +0200
@@ -29,9 +29,6 @@
#include "runtime/mutexLocker.hpp"
#include "runtime/os.inline.hpp"
-LogOutput* const LogOutput::Stdout = &LogStdoutOutput::_instance;
-LogOutput* const LogOutput::Stderr = &LogStderrOutput::_instance;
-
LogOutput::~LogOutput() {
os::free(_config_string);
}
--- a/hotspot/src/share/vm/logging/logOutput.hpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/src/share/vm/logging/logOutput.hpp Fri Oct 21 10:14:54 2016 +0200
@@ -57,9 +57,6 @@
void set_config_string(const char* string);
public:
- static LogOutput* const Stdout;
- static LogOutput* const Stderr;
-
void set_decorators(const LogDecorators &decorators) {
_decorators = decorators;
}
--- a/hotspot/src/share/vm/logging/logTagSet.cpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/src/share/vm/logging/logTagSet.cpp Fri Oct 21 10:14:54 2016 +0200
@@ -23,6 +23,7 @@
*/
#include "precompiled.hpp"
#include "logging/logDecorations.hpp"
+#include "logging/logFileStreamOutput.hpp"
#include "logging/logLevel.hpp"
#include "logging/logMessageBuffer.hpp"
#include "logging/logOutput.hpp"
@@ -50,7 +51,7 @@
_ntagsets++;
// Set the default output to warning and error level for all new tagsets.
- _output_list.set_output_level(LogOutput::Stdout, LogLevel::Default);
+ _output_list.set_output_level(&StdoutLog, LogLevel::Default);
}
void LogTagSet::update_decorators(const LogDecorators& decorator) {
--- /dev/null Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/test/gc/g1/logging/TestG1LoggingFailure.java Fri Oct 21 10:14:54 2016 +0200
@@ -0,0 +1,95 @@
+/*
+ * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+ /*
+ * @test TestG1LoggingFailure
+ * @bug 8151034
+ * @summary Regression test for G1 logging at OOME
+ * @requires vm.gc.G1
+ * @library /test/lib
+ * @modules java.management
+ * @build gc.g1.logging.TestG1LoggingFailure
+ * @run main/timeout=300 gc.g1.logging.TestG1LoggingFailure
+ */
+package gc.g1.logging;
+
+import java.util.ArrayList;
+import java.util.Collections;
+import java.util.List;
+import jdk.test.lib.process.OutputAnalyzer;
+import jdk.test.lib.process.ProcessTools;
+import jdk.test.lib.Utils;
+
+public class TestG1LoggingFailure {
+
+ public static void main(String[] args) throws Throwable {
+ List<String> options = new ArrayList<>();
+ Collections.addAll(options, Utils.getTestJavaOpts());
+ Collections.addAll(options,
+ "-XX:+UseG1GC",
+ "-Xmx20m",
+ "-Xmn10m",
+ "-Xlog:gc=info",
+ "-XX:G1HeapRegionSize=1m"
+ );
+
+ options.add(Alloc.class.getName());
+
+ // According to https://bugs.openjdk.java.net/browse/JDK-8146009 failure happens not every time.
+ // Will try to reproduce this failure.
+ for (int iteration = 0; iteration < 40; ++iteration) {
+ startVM(options);
+ }
+ }
+
+ private static void startVM(List<String> options) throws Throwable, RuntimeException {
+ OutputAnalyzer out = ProcessTools.executeTestJvm(options.toArray(new String[options.size()]));
+
+ out.shouldNotContain("pure virtual method called");
+ out.shouldContain("Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread \"main\"");
+
+ if (out.getExitValue() == 0) {
+ System.out.println(out.getOutput());
+ throw new RuntimeException("Expects Alloc failure.");
+ }
+ }
+
+ // Simple class to be executed in separate VM.
+ static class Alloc {
+
+ public static final int CHUNK = 1024;
+ public static ArrayList<Object> arr = new ArrayList<>();
+
+ public static void main(String[] args) {
+ try {
+ while (true) {
+ arr.add(new byte[CHUNK]);
+ }
+ } catch (OutOfMemoryError oome) {
+ }
+ while (true) {
+ arr.add(new byte[CHUNK]);
+ }
+ }
+ }
+}
--- a/hotspot/test/native/logging/test_logConfiguration.cpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/test/native/logging/test_logConfiguration.cpp Fri Oct 21 10:14:54 2016 +0200
@@ -25,6 +25,7 @@
#include "logTestFixture.hpp"
#include "logTestUtils.inline.hpp"
#include "logging/logConfiguration.hpp"
+#include "logging/logFileStreamOutput.hpp"
#include "logging/logLevel.hpp"
#include "logging/logOutput.hpp"
#include "logging/logTag.hpp"
@@ -68,8 +69,8 @@
const char* description = ss.as_string();
// Verify that stdout and stderr are listed by default
- EXPECT_PRED2(string_contains_substring, description, LogOutput::Stdout->name());
- EXPECT_PRED2(string_contains_substring, description, LogOutput::Stderr->name());
+ EXPECT_PRED2(string_contains_substring, description, StdoutLog.name());
+ EXPECT_PRED2(string_contains_substring, description, StderrLog.name());
// Verify that each tag, level and decorator is listed
for (size_t i = 0; i < LogTag::Count; i++) {
@@ -126,7 +127,7 @@
EXPECT_TRUE(is_described("logging=info"));
// Verify by iterating over tagsets
- LogOutput* o = LogOutput::Stdout;
+ LogOutput* o = &StdoutLog;
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
EXPECT_TRUE(ts->has_output(o));
EXPECT_TRUE(ts->is_level(LogLevel::Info));
@@ -178,8 +179,8 @@
// Verify that no tagset has logging enabled
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
- EXPECT_FALSE(ts->has_output(LogOutput::Stdout));
- EXPECT_FALSE(ts->has_output(LogOutput::Stderr));
+ EXPECT_FALSE(ts->has_output(&StdoutLog));
+ EXPECT_FALSE(ts->has_output(&StderrLog));
EXPECT_FALSE(ts->is_level(LogLevel::Error));
}
}
@@ -193,7 +194,7 @@
EXPECT_TRUE(is_described("#0: stdout all=off"));
// Verify by iterating over tagsets
- LogOutput* o = LogOutput::Stdout;
+ LogOutput* o = &StdoutLog;
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
EXPECT_FALSE(ts->has_output(o));
EXPECT_FALSE(ts->is_level(LogLevel::Error));
@@ -247,7 +248,7 @@
bool ret = LogConfiguration::parse_command_line_arguments(cmdline);
EXPECT_TRUE(ret) << "Error parsing command line arguments '" << cmdline << "'";
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
- EXPECT_EQ(LogLevel::Unspecified, ts->level_for(LogOutput::Stdout));
+ EXPECT_EQ(LogLevel::Unspecified, ts->level_for(&StdoutLog));
}
}
}
@@ -306,7 +307,7 @@
EXPECT_FALSE(log_is_enabled(Debug, logging));
EXPECT_FALSE(log_is_enabled(Info, gc));
LogTagSet* logging_ts = &LogTagSetMapping<LOG_TAGS(logging)>::tagset();
- EXPECT_EQ(LogLevel::Info, logging_ts->level_for(LogOutput::Stdout));
+ EXPECT_EQ(LogLevel::Info, logging_ts->level_for(&StdoutLog));
// Enable 'gc=debug' (no wildcard), verifying no other tags are enabled
LogConfiguration::configure_stdout(LogLevel::Debug, true, LOG_TAGS(gc));
@@ -316,9 +317,9 @@
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
if (ts->contains(PREFIX_LOG_TAG(gc))) {
if (ts->ntags() == 1) {
- EXPECT_EQ(LogLevel::Debug, ts->level_for(LogOutput::Stdout));
+ EXPECT_EQ(LogLevel::Debug, ts->level_for(&StdoutLog));
} else {
- EXPECT_EQ(LogLevel::Off, ts->level_for(LogOutput::Stdout));
+ EXPECT_EQ(LogLevel::Off, ts->level_for(&StdoutLog));
}
}
}
@@ -329,12 +330,12 @@
EXPECT_TRUE(log_is_enabled(Trace, gc, heap));
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
if (ts->contains(PREFIX_LOG_TAG(gc))) {
- EXPECT_EQ(LogLevel::Trace, ts->level_for(LogOutput::Stdout));
+ EXPECT_EQ(LogLevel::Trace, ts->level_for(&StdoutLog));
} else if (ts == logging_ts) {
// Previous setting for 'logging' should remain
- EXPECT_EQ(LogLevel::Info, ts->level_for(LogOutput::Stdout));
+ EXPECT_EQ(LogLevel::Info, ts->level_for(&StdoutLog));
} else {
- EXPECT_EQ(LogLevel::Off, ts->level_for(LogOutput::Stdout));
+ EXPECT_EQ(LogLevel::Off, ts->level_for(&StdoutLog));
}
}
@@ -345,7 +346,7 @@
EXPECT_FALSE(log_is_enabled(Error, gc));
EXPECT_FALSE(log_is_enabled(Error, gc, heap));
for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
- EXPECT_EQ(LogLevel::Off, ts->level_for(LogOutput::Stdout));
+ EXPECT_EQ(LogLevel::Off, ts->level_for(&StdoutLog));
}
}
--- a/hotspot/test/native/logging/test_logOutputList.cpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/test/native/logging/test_logOutputList.cpp Fri Oct 21 10:14:54 2016 +0200
@@ -22,6 +22,7 @@
*/
#include "precompiled.hpp"
+#include "logging/logFileStreamOutput.hpp"
#include "logging/logLevel.hpp"
#include "logging/logOutput.hpp"
#include "logging/logOutputList.hpp"
@@ -173,7 +174,7 @@
for (size_t i = LogLevel::First; i < LogLevel::Count; i++) {
LogLevelType level = static_cast<LogLevelType>(i);
LogOutputList list;
- list.set_output_level(LogOutput::Stdout, level);
+ list.set_output_level(&StdoutLog, level);
for (size_t j = LogLevel::First; j < LogLevel::Count; j++) {
LogLevelType other = static_cast<LogLevelType>(j);
// Verify that levels finer than the current level for stdout are reported as disabled,
@@ -201,8 +202,8 @@
// Test is_level() on lists with two outputs on different levels
TEST(LogOutputList, is_level_multiple_outputs) {
for (size_t i = LogLevel::First; i < LogLevel::Count - 1; i++) {
- LogOutput* dummy1 = LogOutput::Stdout;
- LogOutput* dummy2 = LogOutput::Stderr;
+ LogOutput* dummy1 = &StdoutLog;
+ LogOutput* dummy2 = &StderrLog;
LogLevelType first = static_cast<LogLevelType>(i);
LogLevelType second = static_cast<LogLevelType>(i + 1);
LogOutputList list;
@@ -226,19 +227,19 @@
LogOutputList list;
// Ask the empty list about stdout, stderr
- EXPECT_EQ(LogLevel::Off, list.level_for(LogOutput::Stdout));
- EXPECT_EQ(LogLevel::Off, list.level_for(LogOutput::Stderr));
+ EXPECT_EQ(LogLevel::Off, list.level_for(&StdoutLog));
+ EXPECT_EQ(LogLevel::Off, list.level_for(&StderrLog));
// Ask for level in a list with two outputs on different levels
- list.set_output_level(LogOutput::Stdout, LogLevel::Info);
- list.set_output_level(LogOutput::Stderr, LogLevel::Trace);
- EXPECT_EQ(LogLevel::Info, list.level_for(LogOutput::Stdout));
- EXPECT_EQ(LogLevel::Trace, list.level_for(LogOutput::Stderr));
+ list.set_output_level(&StdoutLog, LogLevel::Info);
+ list.set_output_level(&StderrLog, LogLevel::Trace);
+ EXPECT_EQ(LogLevel::Info, list.level_for(&StdoutLog));
+ EXPECT_EQ(LogLevel::Trace, list.level_for(&StderrLog));
// Remove and ask again
- list.set_output_level(LogOutput::Stdout, LogLevel::Off);
- EXPECT_EQ(LogLevel::Off, list.level_for(LogOutput::Stdout));
- EXPECT_EQ(LogLevel::Trace, list.level_for(LogOutput::Stderr));
+ list.set_output_level(&StdoutLog, LogLevel::Off);
+ EXPECT_EQ(LogLevel::Off, list.level_for(&StdoutLog));
+ EXPECT_EQ(LogLevel::Trace, list.level_for(&StderrLog));
// Ask about an unknown output
LogOutput* dummy = dummy_output(4711);
@@ -251,5 +252,5 @@
}
// Make sure the stderr level is still the same
- EXPECT_EQ(LogLevel::Trace, list.level_for(LogOutput::Stderr));
+ EXPECT_EQ(LogLevel::Trace, list.level_for(&StderrLog));
}
--- a/hotspot/test/native/logging/test_logTagSet.cpp Fri Oct 21 10:18:11 2016 +0200
+++ b/hotspot/test/native/logging/test_logTagSet.cpp Fri Oct 21 10:14:54 2016 +0200
@@ -22,6 +22,7 @@
*/
#include "precompiled.hpp"
+#include "logging/logFileStreamOutput.hpp"
#include "logging/logLevel.hpp"
#include "logging/logOutput.hpp"
#include "logging/logTag.hpp"
@@ -37,18 +38,18 @@
EXPECT_TRUE(ts->is_level(LogLevel::Error));
EXPECT_TRUE(ts->is_level(LogLevel::Warning));
EXPECT_FALSE(ts->is_level(LogLevel::Info));
- EXPECT_TRUE(ts->has_output(LogOutput::Stdout));
- EXPECT_FALSE(ts->has_output(LogOutput::Stderr));
+ EXPECT_TRUE(ts->has_output(&StdoutLog));
+ EXPECT_FALSE(ts->has_output(&StderrLog));
}
}
TEST(LogTagSet, has_output) {
LogTagSet& ts = LogTagSetMapping<LOG_TAGS(logging)>::tagset();
- ts.set_output_level(LogOutput::Stderr, LogLevel::Trace);
- EXPECT_TRUE(ts.has_output(LogOutput::Stderr));
+ ts.set_output_level(&StderrLog, LogLevel::Trace);
+ EXPECT_TRUE(ts.has_output(&StderrLog));
EXPECT_FALSE(ts.has_output(NULL));
- ts.set_output_level(LogOutput::Stderr, LogLevel::Off);
- EXPECT_FALSE(ts.has_output(LogOutput::Stderr));
+ ts.set_output_level(&StderrLog, LogLevel::Off);
+ EXPECT_FALSE(ts.has_output(&StderrLog));
}
TEST(LogTagSet, ntags) {
@@ -61,18 +62,18 @@
TEST(LogTagSet, is_level) {
LogTagSet& ts = LogTagSetMapping<LOG_TAGS(logging)>::tagset();
// Set info level on stdout and verify that is_level() reports correctly
- ts.set_output_level(LogOutput::Stdout, LogLevel::Info);
+ ts.set_output_level(&StdoutLog, LogLevel::Info);
EXPECT_TRUE(ts.is_level(LogLevel::Error));
EXPECT_TRUE(ts.is_level(LogLevel::Warning));
EXPECT_TRUE(ts.is_level(LogLevel::Info));
EXPECT_FALSE(ts.is_level(LogLevel::Debug));
EXPECT_FALSE(ts.is_level(LogLevel::Trace));
- ts.set_output_level(LogOutput::Stdout, LogLevel::Default);
+ ts.set_output_level(&StdoutLog, LogLevel::Default);
EXPECT_TRUE(ts.is_level(LogLevel::Default));
}
TEST(LogTagSet, level_for) {
- LogOutput* output = LogOutput::Stdout;
+ LogOutput* output = &StdoutLog;
LogTagSet& ts = LogTagSetMapping<LOG_TAGS(logging)>::tagset();
for (uint i = 0; i < LogLevel::Count; i++) {
LogLevelType level = static_cast<LogLevelType>(i);