8264768: JFR: Allow events to be printed to the log

Reviewed-by: mgronlun
This commit is contained in:
Erik Gahlin 2021-04-13 20:06:39 +00:00
parent 3b576ed99d
commit e80012ede3
29 changed files with 1116 additions and 33 deletions

View File

@ -487,26 +487,28 @@ Klass* JfrJavaSupport::klass(const jobject handle) {
return obj->klass();
}
// caller needs ResourceMark
const char* JfrJavaSupport::c_str(oop string, Thread* t) {
DEBUG_ONLY(check_java_thread_in_vm(t));
char* resource_copy = NULL;
const typeArrayOop value = java_lang_String::value(string);
if (value != NULL) {
const int length = java_lang_String::utf8_length(string, value);
resource_copy = NEW_RESOURCE_ARRAY_IN_THREAD(t, char, (length + 1));
if (resource_copy == NULL) {
JfrJavaSupport::throw_out_of_memory_error("Unable to allocate thread local native memory", t);
return NULL;
}
assert(resource_copy != NULL, "invariant");
java_lang_String::as_utf8_string(string, value, resource_copy, length + 1);
}
return resource_copy;
}
// caller needs ResourceMark
const char* JfrJavaSupport::c_str(jstring string, Thread* t) {
DEBUG_ONLY(check_java_thread_in_vm(t));
if (string == NULL) {
return NULL;
}
const char* temp = NULL;
const oop java_string = resolve_non_null(string);
const typeArrayOop value = java_lang_String::value(java_string);
if (value != NULL) {
const size_t length = java_lang_String::utf8_length(java_string, value);
temp = NEW_RESOURCE_ARRAY_IN_THREAD(t, const char, (length + 1));
if (temp == NULL) {
JfrJavaSupport::throw_out_of_memory_error("Unable to allocate thread local native memory", t);
return NULL;
}
assert(temp != NULL, "invariant");
java_lang_String::as_utf8_string(java_string, value, const_cast<char*>(temp), (int) length + 1);
}
return temp;
return string != NULL ? c_str(resolve_non_null(string), t) : NULL;
}
/*

View File

@ -77,6 +77,7 @@ class JfrJavaSupport : public AllStatic {
static Klass* klass(const jobject handle);
// caller needs ResourceMark
static const char* c_str(jstring string, Thread* jt);
static const char* c_str(oop string, Thread* t);
// exceptions
static void throw_illegal_state_exception(const char* message, TRAPS);

View File

@ -258,6 +258,10 @@ JVM_ENTRY_NO_ENV(void, jfr_log(JNIEnv* env, jobject jvm, jint tag_set, jint leve
JfrJavaLog::log(tag_set, level, message, thread);
JVM_END
JVM_ENTRY_NO_ENV(void, jfr_log_event(JNIEnv* env, jobject jvm, jint level, jobjectArray lines, jboolean system))
JfrJavaLog::log_event(env, level, lines, system == JNI_TRUE, thread);
JVM_END
JVM_ENTRY_NO_ENV(void, jfr_subscribe_log_level(JNIEnv* env, jobject jvm, jobject log_tag, jint id))
JfrJavaLog::subscribe_log_level(log_tag, id, thread);
JVM_END

View File

@ -71,6 +71,8 @@ void JNICALL jfr_subscribe_log_level(JNIEnv* env, jobject jvm, jobject log_tag,
void JNICALL jfr_log(JNIEnv* env, jobject jvm, jint tag_set, jint level, jstring message);
void JNICALL jfr_log_event(JNIEnv* env, jobject jvm, jint level, jobjectArray lines, jboolean system);
void JNICALL jfr_retransform_classes(JNIEnv* env, jobject jvm, jobjectArray classes);
void JNICALL jfr_set_enabled(JNIEnv* env, jobject jvm, jlong event_type_id, jboolean enabled);

View File

@ -51,6 +51,7 @@ JfrJniMethodRegistration::JfrJniMethodRegistration(JNIEnv* env) {
(char*)"getTicksFrequency", (char*)"()J", (void*)jfr_elapsed_frequency,
(char*)"subscribeLogLevel", (char*)"(Ljdk/jfr/internal/LogTag;I)V", (void*)jfr_subscribe_log_level,
(char*)"log", (char*)"(IILjava/lang/String;)V", (void*)jfr_log,
(char*)"logEvent", (char*)"(I[Ljava/lang/String;Z)V", (void*)jfr_log_event,
(char*)"retransformClasses", (char*)"([Ljava/lang/Class;)V", (void*)jfr_retransform_classes,
(char*)"setEnabled", (char*)"(JZ)V", (void*)jfr_set_enabled,
(char*)"setFileNotification", (char*)"(J)V", (void*)jfr_set_file_notification,

View File

@ -156,7 +156,6 @@ void JfrNetworkUtilization::send_events() {
if (!get_interfaces(&network_interfaces)) {
return;
}
log_trace(jfr, event)("Reporting network utilization");
static JfrTicks last_sample_instant;
const JfrTicks cur_time = JfrTicks::now();
if (cur_time > last_sample_instant) {

View File

@ -28,7 +28,9 @@
#include "jfr/utilities/jfrLogTagSets.hpp"
#include "logging/log.hpp"
#include "logging/logConfiguration.hpp"
#include "logging/logMessage.hpp"
#include "memory/resourceArea.hpp"
#include "oops/objArrayOop.inline.hpp"
#include "runtime/thread.inline.hpp"
#define JFR_LOG_TAGS_CONCATED(T0, T1, T2, T3, T4, T5, ...) \
@ -119,6 +121,38 @@ void JfrJavaLog::subscribe_log_level(jobject log_tag, jint id, TRAPS) {
}
}
void JfrJavaLog::log_event(JNIEnv* env, jint level, jobjectArray lines, bool system, TRAPS) {
DEBUG_ONLY(JfrJavaSupport::check_java_thread_in_vm(THREAD));
if (lines == NULL) {
return;
}
if (level < (jint)LogLevel::First || level > (jint)LogLevel::Last) {
JfrJavaSupport::throw_illegal_argument_exception("LogLevel passed is outside valid range", THREAD);
return;
}
objArrayOop the_lines = objArrayOop(JfrJavaSupport::resolve_non_null(lines));
assert(the_lines != NULL, "invariant");
assert(the_lines->is_array(), "must be array");
const int length = the_lines->length();
ResourceMark rm(THREAD);
LogMessage(jfr, event) jfr_event;
LogMessage(jfr, system, event) jfr_event_system;
for (int i = 0; i < length; ++i) {
const char* text = JfrJavaSupport::c_str(the_lines->obj_at(i), THREAD);
if (text == NULL) {
// An oome has been thrown and is pending.
return;
}
if (system) {
jfr_event_system.write((LogLevelType)level, "%s", text);
} else {
jfr_event.write((LogLevelType)level, "%s", text);
}
}
}
void JfrJavaLog::log(jint tag_set, jint level, jstring message, TRAPS) {
DEBUG_ONLY(JfrJavaSupport::check_java_thread_in_vm(THREAD));
if (message == NULL) {

View File

@ -43,6 +43,7 @@ class JfrJavaLog : public AllStatic {
public:
static void subscribe_log_level(jobject log_tag, jint id, TRAPS);
static void log(jint tag_set, jint level, jstring message, TRAPS);
static void log_event(JNIEnv* env, jint level, jobjectArray lines, bool system, TRAPS);
};
#endif // SHARE_JFR_UTILITIES_JFRJAVALOG_HPP

View File

@ -188,6 +188,17 @@ public final class JVM {
*/
public static native void log(int tagSetId, int level, String message);
/**
* Log an event to jfr+event or jfr+event+system.
* <p>
* Caller should ensure that message is not null or too large to handle.
*
* @param level log level
* @param lines lines to log
* @param system if lines should be written to jfr+event+system
*/
public static native void logEvent(int level, String[] lines, boolean system);
/**
* Subscribe to LogLevel updates for LogTag
*

View File

@ -95,4 +95,13 @@ public enum LogTag {
LogTag(int tagId) {
id = tagId;
}
}
public LogLevel level() {
for (LogLevel l : LogLevel.values()) {
if (l.level == tagSetLevel) {
return l;
}
}
return LogLevel.WARN; // default
}
}

View File

@ -25,6 +25,8 @@
package jdk.jfr.internal;
import java.util.Arrays;
/**
* JFR logger
*
@ -32,7 +34,8 @@ package jdk.jfr.internal;
public final class Logger {
private static final int MAX_SIZE = 10000;
private static final int MAX_SIZE = 10_000;
private static final int MAX_EVENT_SIZE = 100_000;
static {
// This will try to initialize the JVM logging system
JVMSupport.tryToInitializeJVM();
@ -45,6 +48,25 @@ public final class Logger {
}
}
public static void logEvent(LogLevel logLevel, String[] lines, boolean system) {
if (lines == null || lines.length == 0) {
return;
}
if (shouldLog(LogTag.JFR_EVENT, logLevel) || shouldLog(LogTag.JFR_SYSTEM_EVENT, logLevel)) {
int size = 0;
for (int i = 0; i < lines.length; i++) {
String line = lines[i];
if (size + line.length() > MAX_EVENT_SIZE) {
lines = Arrays.copyOf(lines, i + 1);
lines[i] = "...";
break;
}
size+=line.length();
}
JVM.logEvent(logLevel.level, lines, system);
}
}
private static void logInternal(LogTag logTag, LogLevel logLevel, String message) {
if (message == null || message.length() < MAX_SIZE) {
JVM.log(logTag.id, logLevel.level, message);

View File

@ -39,7 +39,7 @@ import jdk.jfr.SettingDescriptor;
*/
public final class PlatformEventType extends Type {
private final boolean isJVM;
private final boolean isJDK;
private final boolean isJDK;
private final boolean isMethodSampling;
private final List<SettingDescriptor> settings = new ArrayList<>(5);
private final boolean dynamicSettings;
@ -188,6 +188,10 @@ public final class PlatformEventType extends Type {
return enabled;
}
public boolean isSystem() {
return isJVM || isJDK;
}
public boolean isJVM() {
return isJVM;
}
@ -285,7 +289,7 @@ public final class PlatformEventType extends Type {
if (this.registered != registered) {
this.registered = registered;
updateCommittable();
LogTag logTag = isJVM() || isJDK() ? LogTag.JFR_SYSTEM_EVENT : LogTag.JFR_EVENT;
LogTag logTag = isSystem() ? LogTag.JFR_SYSTEM_METADATA : LogTag.JFR_METADATA;
if (registered) {
Logger.log(logTag, LogLevel.INFO, "Registered " + getLogName());
} else {

View File

@ -57,12 +57,13 @@ import jdk.jfr.events.ActiveRecordingEvent;
import jdk.jfr.events.ActiveSettingEvent;
import jdk.jfr.internal.SecuritySupport.SafePath;
import jdk.jfr.internal.SecuritySupport.SecureRecorderListener;
import jdk.jfr.internal.consumer.EventLog;
import jdk.jfr.internal.instrument.JDKEvents;
public final class PlatformRecorder {
private final List<PlatformRecording> recordings = new ArrayList<>();
private final ArrayList<PlatformRecording> recordings = new ArrayList<>();
private static final List<SecureRecorderListener> changeListeners = new ArrayList<>();
private final Repository repository;
private static final JVM jvm = JVM.getJVM();
@ -245,6 +246,9 @@ public final class PlatformRecorder {
RepositoryChunk newChunk = null;
if (toDisk) {
newChunk = repository.newChunk(zdtNow);
if (EventLog.shouldLog()) {
EventLog.start();
}
MetadataRepository.getInstance().setOutput(newChunk.getFile().toString());
} else {
MetadataRepository.getInstance().setOutput(null);
@ -259,6 +263,9 @@ public final class PlatformRecorder {
RepositoryChunk newChunk = null;
if (toDisk) {
newChunk = repository.newChunk(zdtNow);
if (EventLog.shouldLog()) {
EventLog.start();
}
RequestEngine.doChunkEnd();
MetadataRepository.getInstance().setOutput(newChunk.getFile().toString());
startNanos = jvm.getChunkStartNanos();
@ -347,6 +354,9 @@ public final class PlatformRecorder {
RequestEngine.setFlushInterval(Long.MAX_VALUE);
}
recording.setState(RecordingState.STOPPED);
if (!isToDisk()) {
EventLog.stop();
}
}
private void dumpMemoryToDestination(PlatformRecording recording) {
@ -476,6 +486,9 @@ public final class PlatformRecorder {
if (jvm.shouldRotateDisk()) {
rotateDisk();
}
if (isToDisk()) {
EventLog.update();
}
}
long minDelta = RequestEngine.doPeriodic();
long wait = Math.min(minDelta, Options.getWaitInterval());
@ -483,6 +496,18 @@ public final class PlatformRecorder {
}
}
private boolean isToDisk() {
// Use indexing to avoid Iterator allocation if nothing happens
int count = recordings.size();
for (int i = 0; i < count; i++) {
PlatformRecording r = recordings.get(i);
if (r.isToDisk() && r.getState() == RecordingState.RUNNING) {
return true;
}
}
return false;
}
private void takeNap(long duration) {
try {
synchronized (JVM.FILE_DELTA_CHANGE) {

View File

@ -68,15 +68,15 @@ public final class RequestEngine {
} else {
jvm.emitEvent(type.getId(), JVM.counterTime(), 0);
}
if (Logger.shouldLog(LogTag.JFR_SYSTEM_EVENT, LogLevel.DEBUG)) {
Logger.log(LogTag.JFR_SYSTEM_EVENT, LogLevel.DEBUG, "Executed periodic hook for " + type.getLogName());
if (Logger.shouldLog(LogTag.JFR_SYSTEM, LogLevel.DEBUG)) {
Logger.log(LogTag.JFR_SYSTEM, LogLevel.DEBUG, "Executed periodic hook for " + type.getLogName());
}
} else {
executeSecure();
}
} catch (Throwable e) {
// Prevent malicious user to propagate exception callback in the wrong context
Logger.log(LogTag.JFR_SYSTEM_EVENT, LogLevel.WARN, "Exception occurred during execution of period hook for " + type.getLogName());
Logger.log(LogTag.JFR_SYSTEM, LogLevel.WARN, "Exception occurred during execution of period hook for " + type.getLogName());
}
}
@ -137,10 +137,10 @@ public final class RequestEngine {
}
private static void logHook(String action, PlatformEventType type) {
if (type.isJDK() || type.isJVM()) {
Logger.log(LogTag.JFR_SYSTEM_EVENT, LogLevel.INFO, action + " periodic hook for " + type.getLogName());
if (type.isSystem()) {
Logger.log(LogTag.JFR_SYSTEM, LogLevel.INFO, action + " periodic hook for " + type.getLogName());
} else {
Logger.log(LogTag.JFR_EVENT, LogLevel.INFO, action + " periodic hook for " + type.getLogName());
Logger.log(LogTag.JFR, LogLevel.INFO, action + " periodic hook for " + type.getLogName());
}
}

View File

@ -469,7 +469,7 @@ public final class SecuritySupport {
return doPrivilegedWithReturn(() -> new Thread(runnable, threadName), new Permission[0]);
}
static void setDaemonThread(Thread t, boolean daemon) {
public static void setDaemonThread(Thread t, boolean daemon) {
doPrivileged(()-> t.setDaemon(daemon), new RuntimePermission("modifyThread"));
}

View File

@ -66,6 +66,8 @@ public abstract class AbstractEventStream implements EventStream {
private volatile boolean closed;
private boolean daemon = false;
AbstractEventStream(AccessControlContext acc, PlatformRecording recording, List<Configuration> configurations) throws IOException {
this.accessControllerContext = Objects.requireNonNull(acc);
this.recording = recording;
@ -101,6 +103,11 @@ public abstract class AbstractEventStream implements EventStream {
streamConfiguration.setReuse(reuse);
}
// Only used if -Xlog:jfr+event* is specified
public final void setDaemon(boolean daemon) {
this.daemon = daemon;
}
@Override
public final void setStartTime(Instant startTime) {
Objects.nonNull(startTime);
@ -219,6 +226,7 @@ public abstract class AbstractEventStream implements EventStream {
startInternal(startNanos);
Runnable r = () -> run(accessControllerContext);
thread = SecuritySupport.createThreadWitNoPermissions(nextThreadName(), r);
SecuritySupport.setDaemonThread(thread, daemon);
thread.start();
}

View File

@ -0,0 +1,193 @@
/*
* Copyright (c) 2021, 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. Oracle designates this
* particular file as subject to the "Classpath" exception as provided
* by Oracle in the LICENSE file that accompanied this code.
*
* 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.
*/
package jdk.jfr.internal.consumer;
import java.io.IOException;
import java.io.PrintWriter;
import java.io.Writer;
import java.util.HashSet;
import java.util.Set;
import jdk.jfr.EventType;
import jdk.jfr.FlightRecorder;
import jdk.jfr.consumer.EventStream;
import jdk.jfr.consumer.RecordedEvent;
import jdk.jfr.internal.LogLevel;
import jdk.jfr.internal.LogTag;
import jdk.jfr.internal.Logger;
import jdk.jfr.internal.PlatformEventType;
import jdk.jfr.internal.PrivateAccess;
import jdk.jfr.internal.tool.PrettyWriter;
public final class EventLog {
private static final class LogWriter extends Writer {
private final StringBuilder builder = new StringBuilder();
private LogLevel level = LogLevel.WARN;
private boolean system;
public void setSystem(boolean system) {
this.system = system;
}
public void setLevel(LogLevel level) {
this.level = level;
}
@Override
public void write(char[] buffer, int off, int len) throws IOException {
builder.append(buffer, off, len);
}
@Override
public void flush() throws IOException {
String[] lines = builder.toString().split("\n");
builder.setLength(0);
Logger.logEvent(level, lines, system);
}
@Override
public void close() throws IOException {
// ignore
}
}
private static EventStream logStream;
private static PrettyWriter prettyWriter;
private static LogWriter logWriter;
private static Set<Long> systemEventLookup;
// 1) At least one disk recording must be running
// before calling this method
// 2) Caller must hold PlatformRecorder lock
public static void update() {
boolean shouldLog = shouldLog();
if (shouldLog && !isLogging()) {
start();
return;
}
if (!shouldLog && isLogging()) {
stop();
return;
}
}
// 1) At least one disk recording must be running
// before calling this method
// 2) Caller must hold PlatformRecorder lock
public static void start() {
if (logStream != null) {
return;
}
try {
ensureSystemEventLookup();
logStream = EventStream.openRepository();
((AbstractEventStream)logStream).setDaemon(true);
logStream.onEvent(EventLog::log);
logWriter = new LogWriter();
prettyWriter = new PrettyWriter(new PrintWriter(logWriter));
prettyWriter.setLineSeparator("\n");
logStream.startAsync();
Logger.log(LogTag.JFR_SYSTEM, LogLevel.DEBUG, "Log stream started");
} catch (Exception e) {
Logger.log(LogTag.JFR_SYSTEM, LogLevel.WARN, "Unable to print events to the log");
}
}
// Caller must hold PlatformRecorder lock
public static void stop() {
if (logStream == null) {
return;
}
try {
logStream.close();
logStream = null;
Logger.log(LogTag.JFR_SYSTEM, LogLevel.DEBUG, "Log stream stopped");
} catch (Exception e) {
Logger.log(LogTag.JFR_SYSTEM, LogLevel.WARN, "Unable to stop printing events to the log");
}
}
public static boolean shouldLog() {
if (Logger.shouldLog(LogTag.JFR_EVENT, LogLevel.DEBUG)) {
return true;
}
if (Logger.shouldLog(LogTag.JFR_SYSTEM_EVENT, LogLevel.DEBUG)) {
return true;
}
return false;
}
private static void log(RecordedEvent event) {
boolean system = isSystemEvent(event);
LogTag tag = system ? LogTag.JFR_SYSTEM_EVENT : LogTag.JFR_EVENT;
LogLevel level = tag.level();
if (Logger.shouldLog(tag, LogLevel.TRACE)) {
log(event, 64, level, system);
return;
}
if (Logger.shouldLog(tag, LogLevel.DEBUG)) {
log(event, 5, level, system);
return;
}
}
private static void log(RecordedEvent event, int stackDepth, LogLevel level, boolean system) {
logWriter.setSystem(system);
logWriter.setLevel(level);
prettyWriter.setStackDepth(stackDepth);
prettyWriter.print(event);
prettyWriter.flush(true);
try {
logWriter.flush();
} catch (IOException e) {
Logger.log(LogTag.JFR_SYSTEM, LogLevel.WARN, "Unable to print event to the log");
}
}
private static boolean isSystemEvent(RecordedEvent event) {
return systemEventLookup.contains(event.getEventType().getId());
}
// The file format doesn't contains information if an event is
// from the JDK/JVM, besides the prefix "jdk." which is not reliable
// Therefore, create a lookup by event type ID to see if is a JDK/JVM event.
private static void ensureSystemEventLookup() {
if (systemEventLookup == null) {
systemEventLookup = new HashSet<>();
for (EventType type : FlightRecorder.getFlightRecorder().getEventTypes()) {
PlatformEventType pe = PrivateAccess.getInstance().getPlatformEventType(type);
if (pe.isSystem()) {
systemEventLookup.add(pe.getId());
}
}
}
}
private static boolean isLogging() {
return logStream != null;
}
}

View File

@ -28,8 +28,6 @@ package jdk.jfr.internal.tool;
import java.io.PrintWriter;
abstract class StructuredWriter {
private static final String LINE_SEPARATOR = String.format("%n");
private final PrintWriter out;
private final StringBuilder builder = new StringBuilder(4000);
@ -38,11 +36,16 @@ abstract class StructuredWriter {
private int column;
// print first event immediately so tool feels responsive
private boolean first = true;
private String lineSeparator = String.format("%n");
StructuredWriter(PrintWriter p) {
out = p;
}
public void setLineSeparator(String lineSeparator) {
this.lineSeparator = lineSeparator;
}
protected final int getColumn() {
return column;
}
@ -67,7 +70,7 @@ abstract class StructuredWriter {
}
public final void println() {
builder.append(LINE_SEPARATOR);
builder.append(lineSeparator);
column = 0;
}

View File

@ -0,0 +1,72 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Path;
// Helper class for analyzing log output from a live process
public class LogAnalyzer {
private final Path path;
public LogAnalyzer(String filename) throws IOException {
this.path = Path.of(filename);
}
public void shouldNotContain(String text) throws Exception {
System.out.println("Should not contain: '" + text + "'");
while (true) {
try {
for (String line : Files.readAllLines(path)) {
if (line.contains(text)) {
throw new Exception("Found unexpected log message: " + line);
}
}
return;
} catch (IOException e) {
System.out.println("Could not read log file " + path.toAbsolutePath());
e.printStackTrace();
}
Thread.sleep(100);
}
}
public void await(String text) throws InterruptedException {
System.out.println("Awaiting... '" + text + "' ");
while (true) {
try {
for (String line : Files.readAllLines(path)) {
if (line.contains(text)) {
System.out.println("Found!");
return;
}
}
} catch (IOException e) {
System.out.println("Could not read log file " + path.toAbsolutePath());
e.printStackTrace();
}
Thread.sleep(100);
}
}
}

View File

@ -0,0 +1,69 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import java.time.Duration;
import jdk.jfr.Event;
import jdk.jfr.FlightRecorder;
import jdk.jfr.Recording;
/**
* @test
* @summary Tests that the event payload is printed when using
* -Xlog:jfr+event=trace
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm
* -Xlog:jfr+event=trace:file=test-content.log
* jdk.jfr.api.consumer.log.TestContent
*/
public class TestContent {
public static class ApplicationEvent extends Event {
int value;
String text;
boolean truth;
}
public static void main(String... args) throws Exception {
FlightRecorder.addPeriodicEvent(ApplicationEvent.class, () -> {
ApplicationEvent e = new ApplicationEvent();
e.value = 4711;
e.text = "hello, world!";
e.truth = true;
e.commit();
});
LogAnalyzer la = new LogAnalyzer("test-content.log");
try (Recording r = new Recording()) {
r.enable(ApplicationEvent.class).withPeriod(Duration.ofSeconds(1));
r.start();
la.await("value = 4711");
la.await("text = \"hello, world!\"");
la.await("truth = true");
r.stop();
}
}
}

View File

@ -0,0 +1,53 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import jdk.jfr.Recording;
/**
* @test
* @summary Tests that event logging can't be turned on and off
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm
* -Xlog:jfr+event*=debug,jfr+system=debug:file=disk-on-off.log
* jdk.jfr.api.consumer.log.TestDiskOnOff
*/
public class TestDiskOnOff {
public static void main(String... args) throws Exception {
LogAnalyzer la = new LogAnalyzer("disk-on-off.log");
try (Recording r = new Recording()) {
r.start();
la.await("Log stream started");
}
la.await("Log stream stopped");
try (Recording r = new Recording()) {
r.start();
la.await("Log stream started");
}
la.await("Log stream stopped");
}
}

View File

@ -0,0 +1,74 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import java.time.Duration;
import jdk.jfr.Event;
import jdk.jfr.FlightRecorder;
import jdk.jfr.Recording;
import jdk.test.lib.dcmd.CommandExecutor;
import jdk.test.lib.dcmd.PidJcmdExecutor;
import jdk.test.lib.process.OutputAnalyzer;
/**
* @test
* @summary Tests that log responds to log level changes after JVM has
* started
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm jdk.jfr.api.consumer.log.TestDynamicStart
*/
public class TestDynamicStart {
private static final String FILE = "log.txt";
static class UserEvent extends Event {
String message;
}
public static void main(String... args) throws Exception {
FlightRecorder.addPeriodicEvent(UserEvent.class, () -> {
UserEvent event = new UserEvent();
event.message = "Giraffe";
event.commit();
});
LogAnalyzer la = new LogAnalyzer(FILE);
try (Recording r = new Recording()) {
r.enable(UserEvent.class).withPeriod(Duration.ofSeconds(1));
r.start();
executeJcmd("VM.log what=jfr+event=debug,jfr+system=debug output=" + FILE);
la.await("Log stream started");
la.await("Giraffe");
executeJcmd("VM.log what=jfr+event=warning output=" + FILE);
la.await("Log stream stopped");
}
}
private static void executeJcmd(String cmd) {
CommandExecutor executor = new PidJcmdExecutor();
OutputAnalyzer oa = executor.execute(cmd);
oa.shouldHaveExitValue(0);
}
}

View File

@ -0,0 +1,56 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import jdk.jfr.Recording;
/**
* @test
* @summary Tests that transition between disk=true/false works
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm
* -Xlog:jfr+event*=debug,jfr+system=debug:file=memory-disk.log
* jdk.jfr.api.consumer.log.TestMemoryDiskTransition
*/
public class TestMemoryDiskTransition {
public static void main(String... args) throws Exception {
LogAnalyzer la = new LogAnalyzer("memory-disk.log");
try (Recording r1 = new Recording()) {
r1.setToDisk(false);
r1.start();
la.shouldNotContain("Log stream started");
try (Recording r2 = new Recording()) {
r2.setToDisk(true);
r2.start(); // transition to disk
la.shouldNotContain("Log stream stopped");
la.await("Log stream started");
r2.stop(); // transition back to memory
}
la.await("Log stream stopped");
}
}
}

View File

@ -0,0 +1,50 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import jdk.jfr.Recording;
/**
* @test
* @summary Tests that a stream is not started if disk=false
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm
* -Xlog:jfr+event*=debug,jfr+system=debug:file=memory-only.log
* jdk.jfr.api.consumer.log.TestMemoryOnly
*/
public class TestMemoryOnly {
public static void main(String... args) throws Exception {
LogAnalyzer la = new LogAnalyzer("memory-only.log");
try (Recording r = new Recording()) {
r.setToDisk(false);
r.start();
r.stop();
la.shouldNotContain("Log stream started");
}
la.shouldNotContain("Log stream stopped");
}
}

View File

@ -0,0 +1,59 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import jdk.jfr.Event;
import jdk.jfr.FlightRecorder;
import jdk.jfr.Name;
import jdk.jfr.Period;
/**
* @test
* @summary Tests that only system events are emitted
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm
* -Xlog:jfr+event+system=trace:file=system.log
* -XX:StartFlightRecording jdk.jfr.api.consumer.log.TestSystemEvents
*/
public class TestSystemEvents {
// Testing with -XX:StartFlightRecording, since it's
// a likely use case and there could be issues
// with starting the stream before main.
@Period("1 s")
@Name("UserDefined")
static class UserEvent extends Event {
}
public static void main(String... args) throws Exception {
FlightRecorder.addPeriodicEvent(UserEvent.class, () -> {
UserEvent e = new UserEvent();
e.commit();
});
LogAnalyzer la = new LogAnalyzer("system.log");
la.await("CPULoad"); // emitted 1/s
la.shouldNotContain("UserDefined");
}
}

View File

@ -0,0 +1,81 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import jdk.jfr.Event;
import jdk.jfr.FlightRecorder;
import jdk.jfr.Period;
import jdk.jfr.Recording;
import jdk.jfr.StackTrace;
/**
* @test
* @summary Tests that large output is truncated
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm
* -Xlog:jfr+event*=debug:file=truncate.log
* jdk.jfr.api.consumer.log.TestTruncation
*/
public class TestTruncation {
@StackTrace(false) // Avoids '...' from stack trace truncation
@Period("1 s")
static class LargeEvent extends Event {
String message1;
String message2;
String message3;
String message4;
String message5;
String message6;
String message7;
String message8;
String message9;
String message10;
}
public static void main(String... args) throws Exception {
FlightRecorder.addPeriodicEvent(LargeEvent.class, () -> {
String text = "#".repeat(10_000);
LargeEvent event = new LargeEvent();
event.message1 = text;
event.message2 = text;
event.message3 = text;
event.message4 = text;
event.message5 = text;
event.message6 = text;
event.message7 = text;
event.message8 = text;
event.message9 = text;
event.message10 = text;
event.commit();
});
LogAnalyzer la = new LogAnalyzer("truncate.log");
try (Recording r = new Recording()) {
r.start();
la.await("...");
}
}
}

View File

@ -0,0 +1,60 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import jdk.jfr.Event;
import jdk.jfr.FlightRecorder;
import jdk.jfr.Name;
import jdk.jfr.Period;
/**
* @test
* @summary Tests that only user events are emitted
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm
* -Xlog:jfr+event=trace:file=user.log
* -XX:StartFlightRecording
* jdk.jfr.api.consumer.log.TestUserEvents
*/
public class TestUserEvents {
// Testing with -XX:StartFlightRecording, since it's
// a likely use case and there could be issues
// with starting the stream before main.
@Period("1 s")
@Name("UserDefined")
static class UserEvent extends Event {
}
public static void main(String... args) throws Exception {
FlightRecorder.addPeriodicEvent(UserEvent.class, () -> {
UserEvent e = new UserEvent();
e.commit();
});
LogAnalyzer la = new LogAnalyzer("user.log");
la.await("UserDefined");
la.shouldNotContain("CPULoad"); // Emitted 1/s
}
}

View File

@ -0,0 +1,112 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import java.io.Closeable;
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;
import jdk.jfr.Event;
import jdk.jfr.Name;
/**
* @test
* @summary Tests output from various tag sets and levels
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm
* -Xlog:jfr+event*=trace:file=trace.log
* -XX:StartFlightRecording
* jdk.jfr.api.consumer.log.TestVerbosity trace
* @run main/othervm
* -Xlog:jfr+event*=debug:file=debug.log
* -XX:StartFlightRecording
* jdk.jfr.api.consumer.log.TestVerbosity debug
* @run main/othervm
* -Xlog:jfr+event*=info:file=info.log
* -XX:StartFlightRecording
* jdk.jfr.api.consumer.log.TestVerbosity info
*/
public class TestVerbosity {
@Name("UserDefined")
static class UserEvent extends Event {
}
public static void main(String... args) throws Exception {
String level = args[0];
var scheduler = Executors.newScheduledThreadPool(1);
try (Closeable close = scheduler::shutdown) {
scheduler.scheduleAtFixedRate(() -> {
method1();
}, 0, 10, TimeUnit.MILLISECONDS);
LogAnalyzer la = new LogAnalyzer(level + ".log");
System.out.println("Testing log level: " + level);
if (level.equals("trace")) {
la.await("CPULoad"); // Emitted 1/s
la.await("UserDefined");
la.await("method6");
la.await("method1");
}
if (level.equals("debug")) {
la.await("CPULoad");
la.await("UserDefined");
la.await("method6");
la.shouldNotContain("method1");
}
if (level.equals("info")) {
la.shouldNotContain("CPULoad");
la.shouldNotContain("UserDefined");
}
}
}
private static void method1() {
method2();
}
private static void method2() {
method3();
}
private static void method3() {
method4();
}
private static void method4() {
method5();
}
private static void method5() {
method6();
}
private static void method6() {
UserEvent event = new UserEvent();
event.commit();
}
}

View File

@ -0,0 +1,78 @@
/*
* Copyright (c) 2021, 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.
*/
package jdk.jfr.api.consumer.log;
import java.io.Closeable;
import java.time.Instant;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;
import jdk.jfr.Event;
import jdk.jfr.Name;
import jdk.jfr.consumer.RecordingStream;
/**
* @test
* @summary Checks that it is possible to stream together with log stream
* @key jfr
* @requires vm.hasJFR
* @library /test/lib
* @build jdk.jfr.api.consumer.log.LogAnalyzer
* @run main/othervm -Xlog:jfr+event*=debug:file=with-streaming.log
* jdk.jfr.api.consumer.log.TestWithStreaming
*/
public class TestWithStreaming {
@Name("TwoStreams")
static class TwoStreams extends Event {
String message;
}
public static void main(String... args) throws Exception {
LogAnalyzer la = new LogAnalyzer("with-streaming.log");
CountDownLatch latch = new CountDownLatch(2);
try (RecordingStream rs = new RecordingStream()) {
rs.enable(TwoStreams.class);
rs.onEvent("TwoStreams", e -> {
latch.countDown();
});
rs.setStartTime(Instant.MIN);
rs.startAsync();
TwoStreams e1 = new TwoStreams();
e1.commit();
TwoStreams e2 = new TwoStreams();
e2.commit();
latch.await();
var scheduler = Executors.newScheduledThreadPool(1);
try (Closeable close = scheduler::shutdown) {
scheduler.scheduleAtFixedRate(() -> {
TwoStreams e = new TwoStreams();
e.message = "hello";
e.commit();
}, 0, 10, TimeUnit.MILLISECONDS);
la.await("hello");
}
}
}
}