data) {
+ Thread thread = new Thread(() -> {
+ Path path = new File(filePath + Long.toString((long) data.getFirst().getTs()) + ".json").toPath(); //$NON-NLS-1$
+ try (BufferedWriter fw = Files.newBufferedWriter(path, Charset.defaultCharset())) {
+ fw.write('[');
+ boolean first = true;
+ for (InnerEvent event : data) {
+ if (first) {
+ first = false;
+ } else {
+ fw.write(',');
+ fw.write('\n');
+ }
+ fw.write(event.getMessage());
+ }
+ data.clear();
+ fw.write(']');
+ } catch (IOException e) {
+ // we tried!
+ }
+ });
+ thread.setName("Trace Drainer"); //$NON-NLS-1$
+ thread.start();
+ }
- /**
- * Is the snapshotter enabled?
- * @return true if enabled
- */
- public boolean isEnabled() {
- return isEnabled;
- }
+ /**
+ * Enable or disable snapshotter
+ *
+ * @param isEnabled true is enabled, false is disabled
+ */
+ public void setEnabled(Boolean isEnabled) {
+ this.isEnabled = isEnabled;
+ }
+
+ /**
+ * Is the snapshotter enabled?
+ *
+ * @return true if enabled
+ */
+ public boolean isEnabled() {
+ return isEnabled;
+ }
}
diff --git a/src/test/java/org/eclipse/tracecompass/trace_event_logger/AsyncFileHandlerTest.java b/src/test/java/org/eclipse/tracecompass/trace_event_logger/AsyncFileHandlerTest.java
new file mode 100644
index 0000000..1826a81
--- /dev/null
+++ b/src/test/java/org/eclipse/tracecompass/trace_event_logger/AsyncFileHandlerTest.java
@@ -0,0 +1,132 @@
+/*******************************************************************************
+ * Copyright (c) 2024 Ericsson
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the “Software”), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED “AS IS”, WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL
+ * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
+ * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS
+ * IN THE SOFTWARE.
+ *
+ * SPDX-License-Identifier: MIT
+ *******************************************************************************/
+package org.eclipse.tracecompass.trace_event_logger;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.fail;
+
+import java.io.File;
+import java.io.FileInputStream;
+import java.io.FileNotFoundException;
+import java.io.IOException;
+import java.io.InputStream;
+import java.util.logging.ErrorManager;
+import java.util.logging.Filter;
+import java.util.logging.Formatter;
+import java.util.logging.Handler;
+import java.util.logging.Level;
+import java.util.logging.LogManager;
+import java.util.logging.LogRecord;
+import java.util.logging.Logger;
+
+import org.junit.Before;
+import org.junit.Test;
+
+public class AsyncFileHandlerTest {
+
+ private Logger logger;
+
+ @Before
+ public void before() {
+ this.logger = Logger.getAnonymousLogger();
+ }
+
+ /**
+ * Test with simple configuration
+ */
+ @Test
+ public void testConfigure() {
+ Logger logger = this.logger;
+ try (InputStream fis = new FileInputStream(
+ new File("./src/test/java/org/eclipse/tracecompass/trace_event_logger/res/logging.properties"))) {
+ LogManager manager = LogManager.getLogManager();
+ manager.readConfiguration(fis);
+ Handler first = new AsyncFileHandler(File.createTempFile("test", ".json").getAbsolutePath());
+ first.close();
+ } catch (FileNotFoundException e) {
+ fail(e.getMessage());
+ } catch (IOException e) {
+ fail(e.getMessage());
+ }
+ }
+
+ /**
+ * Test Bad configuration
+ */
+ @Test(expected = IllegalArgumentException.class)
+ public void testBadConfigure() {
+ Logger logger = this.logger;
+ try (InputStream fis = new FileInputStream(
+ new File("./src/test/java/org/eclipse/tracecompass/trace_event_logger/res/badlogging.properties"))) {
+ LogManager manager = LogManager.getLogManager();
+ manager.readConfiguration(fis);
+ String prop = manager.getProperty("org.eclipse.tracecompass.trace_event_logger.SnapshotHandler.maxEvents");
+ assertNotNull(prop);
+ Handler other = new AsyncFileHandler();
+ fail("should have failed above");
+ } catch (FileNotFoundException e) {
+ fail(e.getMessage());
+ } catch (IOException e) {
+ fail(e.getMessage());
+ }
+ }
+
+ /**
+ * Test the getters and setters. They pass everything to the filehandler.
+ *
+ * @throws SecurityException
+ * @throws IOException
+ */
+ @Test
+ public void testGetterSetters() throws SecurityException, IOException {
+ File test = File.createTempFile("test", ".json");
+ AsyncFileHandler toTest = new AsyncFileHandler(test.getAbsolutePath());
+ toTest.setEncoding("UTF-8");
+ assertEquals("UTF-8", toTest.getEncoding());
+ Filter f = new Filter() {
+ @Override
+ public boolean isLoggable(LogRecord record) {
+ return false;
+ }
+ };
+ toTest.setFilter(f);
+ assertEquals(f, toTest.getFilter());
+ toTest.setLevel(Level.CONFIG);
+ assertEquals(Level.CONFIG, toTest.getLevel());
+ ErrorManager em = new ErrorManager();
+ toTest.setErrorManager(em);
+ assertEquals(em, toTest.getErrorManager());
+ Formatter fmt = new Formatter() {
+ @Override
+ public String format(LogRecord record) {
+ // TODO Auto-generated method stub
+ return null;
+ }
+ };
+ toTest.setFormatter(fmt);
+ assertEquals(fmt, toTest.getFormatter());
+ }
+
+}
diff --git a/src/test/java/org/eclipse/tracecompass/trace_event_logger/LoggerTest.java b/src/test/java/org/eclipse/tracecompass/trace_event_logger/LoggerTest.java
index 25547a7..1d11a37 100644
--- a/src/test/java/org/eclipse/tracecompass/trace_event_logger/LoggerTest.java
+++ b/src/test/java/org/eclipse/tracecompass/trace_event_logger/LoggerTest.java
@@ -378,7 +378,43 @@ public void testFlowBuilderParentThenCat() {
}
}
}
+
+ /**
+ * Test the flow scope builder calling
+ * {@link FlowScopeLogBuilder#setParentScope(FlowScopeLog)}, then
+ * {@link FlowScopeLogBuilder#setCategory(String)}.
+ */
+ @Test(expected = IllegalStateException.class)
+ public void testFlowBuilderParentThenCatId() {
+ Logger logger = fLogger;
+ assertNotNull(logger);
+ try (FlowScopeLog log = new FlowScopeLogBuilder(logger, Level.WARNING, "foo").setCategory("myspider").build()) {
+ try (FlowScopeLog log1 = new FlowScopeLogBuilder(logger, Level.FINE, "bar").setParentScope(log).setCategoryAndId("myspider",1).build()) {
+ // do something
+ new Object();
+ }
+ }
+ }
+
+ /**
+ * Test the flow scope builder calling
+ * {@link FlowScopeLogBuilder#setParentScope(FlowScopeLog)}, then
+ * {@link FlowScopeLogBuilder#setCategory(String)}.
+ */
+ @Test(expected = IllegalStateException.class)
+ public void testFlowBuilderCatIdThenParent() {
+ Logger logger = fLogger;
+ assertNotNull(logger);
+ try (FlowScopeLog log = new FlowScopeLogBuilder(logger, Level.WARNING, "foo").setCategory("myspider").build()) {
+ try (FlowScopeLog log1 = new FlowScopeLogBuilder(logger, Level.FINE, "bar").setCategoryAndId("myspider",1).setParentScope(log).build()) {
+ // do something
+ new Object();
+ }
+ }
+ }
+
+
/**
* Test nesting with different arguments
*/
diff --git a/src/test/java/org/eclipse/tracecompass/trace_event_logger/OldLogUtils.java b/src/test/java/org/eclipse/tracecompass/trace_event_logger/OldLogUtils.java
new file mode 100644
index 0000000..a646c0d
--- /dev/null
+++ b/src/test/java/org/eclipse/tracecompass/trace_event_logger/OldLogUtils.java
@@ -0,0 +1,854 @@
+/*******************************************************************************
+ * Copyright (c) 2024 Ericsson
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the “Software”), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED “AS IS”, WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL
+ * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
+ * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS
+ * IN THE SOFTWARE.
+ *
+ * SPDX-License-Identifier: MIT
+ *******************************************************************************/
+
+package org.eclipse.tracecompass.trace_event_logger;
+
+import java.text.DecimalFormat;
+import java.text.Format;
+import java.util.Arrays;
+import java.util.HashMap;
+import java.util.HashSet;
+import java.util.Iterator;
+import java.util.Map;
+import java.util.Map.Entry;
+import java.util.Set;
+import java.util.concurrent.atomic.AtomicInteger;
+import java.util.function.Supplier;
+import java.util.logging.Level;
+import java.util.logging.Logger;
+
+/**
+ * Note: this was TraceCompassLogUtil copied as-is. It is relicensed to MIT,
+ * permissions from all contributing parties were obtained. This is used for
+ * testing purposes only.
+ *
+ * Logger helper
+ *
+ * This is a logger helper, it will allow entry-exit analysis to be much easier.
+ *
+ * The events are saved in a JSON-like message in the phase of the event. It is
+ * an event type but with extra information associated to it. Typical types can
+ * be the following.
+ *
+ * - Durations
+ *
+ * - B, Begin
+ * - E, End
+ * - X, Complete, this is an event with a duration field
+ * - i, Instant / Info
+ *
+ *
+ * - Asynchronous nested messages
+ *
+ * - b, nested begin
+ * - n, nested info
+ * - e, nested end
+ *
+ *
+ * - Flows
+ *
+ * - s, flow begin
+ * - t, flow step (info)
+ * - f, flow end
+ *
+ *
+ * - Object tracking
+ *
+ * - N, Object created
+ * - D, Object destroyed
+ *
+ *
+ * - Mark Events - events that generate markers
+ *
+ *
+ * - CounterEvents - events that count items
+ *
+ *
+ *
+ *
+ * To use durations and/or flows, see
+ * {@link ScopeLog} and {@link FlowScopeLog}. These 2 concepts are related.
+ * Durations would typically be used to instrument simple methods, while flows
+ * would be preferred if there are links to be made with other threads.
+ *
+ * To use Asynchronous nested messages, see
+ * {@link #traceAsyncStart(Logger, Level, String, String, int, Object...)}, and
+ * {@link #traceAsyncEnd(Logger, Level, String, String, int, Object...)}
+ *
+ * To use Object tracking, see
+ * {@link #traceObjectCreation(Logger, Level, Object)} and
+ * {@link #traceObjectDestruction(Logger, Level, Object)}
+ *
+ * The design philosophy of this class is very heavily inspired by the trace
+ * event format of Google. The full specification is available here.
+ *
+ *
+ * The main goals are clarity of output and simplicity for the developer.
+ * Performance is a nice to have, but is not the main concern of this helper. A
+ * minor performance impact compared to simply logging the events is to be
+ * expected.
+ *
+ * @author Matthew Khouzam
+ * @noinstantiate This class is not intended to be instantiated by clients. It
+ * is a helper class.
+ */
+public final class OldLogUtils {
+
+ private static final Format FORMAT = new DecimalFormat("#.###"); //$NON-NLS-1$
+
+ /*
+ * Field names
+ */
+ private static final String ARGS = "args"; //$NON-NLS-1$
+ private static final String NAME = "name"; //$NON-NLS-1$
+ private static final String CATEGORY = "cat"; //$NON-NLS-1$
+ private static final String ID = "id"; //$NON-NLS-1$
+ private static final String TID = "tid"; //$NON-NLS-1$
+ private static final String PID = "pid"; //$NON-NLS-1$
+ private static final String TIMESTAMP = "ts"; //$NON-NLS-1$
+ private static final String PHASE = "ph"; //$NON-NLS-1$
+
+ private static final String ARGS_ERROR_MESSAGE = "Data should be in the form of key, value, key1, value1, ... oldScopeLog was supplied "; //$NON-NLS-1$
+ private static final AtomicInteger ID_GENERATOR = new AtomicInteger(0);
+
+ private OldLogUtils() {
+ // do nothing
+ }
+
+ /**
+ * Scope Logger helper. This will automatically log entry and exit of the scope.
+ * This scope log will be shown under any scope enclosing it, but will not be
+ * the source, or destination of any link to other scopes. If relations should
+ * be done with other scopes, the {@link FlowScopeLog} class is more
+ * appropriate.
+ *
+ * Usage:
+ *
+ *
+ * {@code usage of ScopeLog}
+ * try (ScopeLog linksLogger = new ScopeLog(LOGGER, Level.CONFIG, "Perform Query")) { //$NON-NLS-1$
+ * ss.updateAllReferences();
+ * dataStore.addAll(ss.query(ts, trace));
+ * }
+ *
+ *
+ * will generate the following trace
+ *
+ *
+ * {@code trace output}
+ * INFO: {"ts":12345,"ph":"B",tid:1,"name:Perform Query"}
+ * INFO: {"ts":"12366,"ph":"E","tid":1}
+ *
+ */
+ public static class ScopeLog implements AutoCloseable {
+
+ private final long fTime;
+ private final long fThreadId;
+ private final Logger fLogger;
+ private final Level fLevel;
+ private final String fLabel;
+ private final Map fData = new HashMap<>();
+
+ /**
+ * Scope logger constructor
+ *
+ * @param log the JUL logger to log to
+ * @param level the log level see {@link Level}
+ * @param label The label of the event pair
+ * @param args Additional messages to pass for this scope, should be in pairs
+ * key, value, key2, value2.... typically arguments. Note that
+ * these arguments will be logged only at the beginning of the
+ * scope
+ */
+ public ScopeLog(Logger log, Level level, String label, Object... args) {
+ fTime = System.nanoTime();
+ fLogger = log;
+ fLevel = level;
+ fThreadId = Thread.currentThread().getId();
+ fLabel = label;
+ char phase = 'B';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, fTime, fThreadId);
+ appendName(sb, fLabel);
+ appendArgs(sb, args);
+ sb.append('}');
+ return sb.toString();
+ };
+ fLogger.log(fLevel, msgSupplier);
+ }
+
+ /**
+ * Add a tag to the scope logger, will be written at the exit. This can save
+ * space on the trace by having a field appended to an event rather than writing
+ * a whole new event for a small chunk of data.
+ *
+ * If the timing information is important than it would be more appropriate to
+ * call {@link OldLogUtils#traceInstant(Logger, Level, String, Object...)}
+ *
+ * @param name the name of the field
+ * @param value The value of the field.
+ */
+ public void addData(String name, Object value) {
+ fData.put(name, value);
+ }
+
+ @Override
+ public void close() {
+ long time = System.nanoTime();
+ char phase = 'E';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, fThreadId);
+ return appendArgs(sb, fData).append('}').toString();
+ };
+ fLogger.log(fLevel, msgSupplier);
+ }
+ }
+
+ /**
+ * Builder class for the {@link FlowScopeLog}. One can either set a category or
+ * a parent scope before building the flow scope log. If none is set, a default
+ * category called "null" will be used.
+ *
+ * @author Geneviève Bastien
+ */
+ public static class FlowScopeLogBuilder {
+
+ private final Logger fLogger;
+ private final Level fLevel;
+ private final String fLabel;
+ private final Object[] fArgs;
+ private int fId = Integer.MIN_VALUE;
+ private String fCategory = null;
+ private FlowScopeLog fParent = null;
+ private boolean fHasParent = false;
+
+ /**
+ * Flow scope log builder constructor
+ *
+ * @param logger the JUL logger
+ * @param level the log level see {@link Level}
+ * @param label The label of the event pair
+ * @param args the messages to pass, should be in pairs key, value, key2,
+ * value2.... typically arguments
+ */
+ public FlowScopeLogBuilder(Logger logger, Level level, String label, Object... args) {
+ fLogger = logger;
+ fLevel = level;
+ fLabel = label;
+ fArgs = args;
+ }
+
+ /**
+ * Set a category for the flow scope. When building the scope, an ID will be
+ * automatically generated.
+ *
+ * This method is mutually exclusive with {@link #setParentScope(FlowScopeLog)}.
+ * Calling both will throw an exception.
+ *
+ * @param category The category of this flow
+ * @return This builder
+ */
+ public FlowScopeLogBuilder setCategory(String category) {
+ if (fParent != null) {
+ throw new IllegalStateException(
+ "FlowScopeLogBuilder: Cannot set a category if a parent has already been set"); //$NON-NLS-1$
+ }
+ fCategory = category;
+ return this;
+ }
+
+ /**
+ * Set a category and ID for the flow scope.
+ *
+ * This method is mutually exclusive with {@link #setParentScope(FlowScopeLog)}.
+ * Calling both will throw an exception.
+ *
+ * @param category The category of this flow
+ * @param id The ID of this flow
+ * @return This builder
+ */
+ public FlowScopeLogBuilder setCategoryAndId(String category, int id) {
+ if (fParent != null) {
+ throw new IllegalStateException(
+ "FlowScopeLogBuilder: Cannot set a category if a parent has already been set"); //$NON-NLS-1$
+ }
+ fCategory = category;
+ fId = id;
+ // Id is already set, so assume this scope has a parent, even if the
+ // parent object is not available
+ fHasParent = true;
+ return this;
+ }
+
+ /**
+ * Set a parent scope for the flow scope to build. The scope will have the same
+ * category and ID as the parent scope.
+ *
+ * This method is mutually exclusive with {@link #setCategory(String)} and
+ * {@link #setCategoryAndId(String, int)}. Calling both will throw an exception.
+ *
+ * @param parent The parent scope
+ * @return This builder
+ */
+ public FlowScopeLogBuilder setParentScope(FlowScopeLog parent) {
+ if (fCategory != null) {
+ throw new IllegalStateException(
+ "FlowScopeLogBuilder: Cannot set a parent scope if a category has already been set"); //$NON-NLS-1$
+ }
+ fParent = parent;
+ return this;
+ }
+
+ /**
+ * Build the flow scope log
+ *
+ * @return The flow scope log
+ */
+ public FlowScopeLog build() {
+ FlowScopeLog parent = fParent;
+ if (parent != null) {
+ // Has a parent scope, so step in flow
+ return new FlowScopeLog(fLogger, fLevel, fLabel, parent.fCategory, parent.fId, false, fArgs);
+ }
+ return new FlowScopeLog(fLogger, fLevel, fLabel, String.valueOf(fCategory),
+ (fId == Integer.MIN_VALUE ? ID_GENERATOR.incrementAndGet() : fId), !fHasParent, fArgs);
+ }
+
+ }
+
+ /**
+ * Flow Scope Logger helper. It will automatically log entry and exit of the
+ * scope. It can be used with other flow scopes to follow the program flow
+ * across threads. To do so, these scopes save more data, so take more disk
+ * space. If there is no inter-process/thread communication to follow, the
+ * {@link ScopeLog} class would be more appropriate.
+ *
+ * Usage: this can be used to track asynchronous threads communication. This can
+ * be used in scatter-gather/map-reduce operations as well as threads that
+ * trigger a UI Thread operation.
+ *
+ *
+ * {@code usage of FlowScopeLog}
+ * try (FlowScopeLog linksLogger = new FlowScopeLog(LOGGER, Level.CONFIG, "Perform Query", "category", 0x100)) { //$NON-NLS-1$
+ * Display.asynchExec(()->{
+ * try(FlowScopeLog linksLogger2 = new FlowScopeLog(LOGGER, Level.CONFIG, "Update UI", "category", linksLogger.getId()) {
+ * linksLogger.step("updating ui");
+ * };
+ * linksLogger.step("forked thread");
+ * }
+ *
+ *
+ * will generate the following trace (order not guaranteed)
+ *
+ *
+ * {@code trace output}
+ * INFO: {"ts":12345,"ph":"s",tid:1,"name":"Perform Query", "cat":"category", "id":256}
+ * INFO: {"ts":12346","ph":"t",tid:1,"name":"forked thread","cat":"category", "id":256}
+ * INFO: {"ts":"12366,"ph":"f","tid":1,"cat":"category", "id":256}
+ * INFO: {"ts":12400,"ph":"s",tid:0,"name":"Update UI","cat":"category", "id":256}
+ * INFO: {"ts":12416","ph":"t",tid:0,"name":"updating ui", "cat":"category", "id":256}
+ * INFO: {"ts":"12420,"ph":"f","tid":0,"cat":"category", "id":256}
+ *
+ */
+ public static class FlowScopeLog implements AutoCloseable {
+
+ private final long fThreadId;
+ private final Logger fLogger;
+ private final Level fLevel;
+ private final int fId;
+ private final String fCategory;
+ private final Map fData = new HashMap<>();
+ private final String fLabel;
+ private final long fTime;
+
+ /**
+ * Flow scope logger constructor
+ *
+ * @param log the JUL logger
+ * @param level the log level see {@link Level}
+ * @param label The label of the event pair
+ * @param category the category of the flow events
+ * @param id The id of the flow
+ * @param startFlow Whether this flow scope object is the start of a flow, or a
+ * step
+ * @param args the messages to pass, should be in pairs key, value, key2,
+ * value2.... typically arguments
+ */
+ private FlowScopeLog(Logger log, Level level, String label, String category, int id, boolean startFlow,
+ Object... args) {
+ fTime = System.nanoTime();
+ fId = id;
+ fLogger = log;
+ fLevel = level;
+ fCategory = category;
+ fLabel = label;
+ fThreadId = Thread.currentThread().getId();
+ char phaseB = 'B';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phaseB, fTime, fThreadId);
+ appendName(sb, label);
+ appendArgs(sb, args);
+ sb.append('}');
+ return sb.toString();
+ };
+ fLogger.log(fLevel, msgSupplier);
+ // Add a flow event, either start or step in enclosing scope
+ char phase = startFlow ? 's' : 't';
+ msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, fTime, fThreadId);
+ appendName(sb, label);
+ appendCategory(sb, category);
+ appendId(sb, fId);
+ appendArgs(sb, args);
+ sb.append('}');
+ return sb.toString();
+ };
+ fLogger.log(fLevel, msgSupplier);
+ }
+
+ /**
+ * Flow step, it will add a stop point for an arrow
+ *
+ * @param label The label for this step
+ * @param args the arguments to log
+ */
+ public void step(String label, Object... args) {
+ long time = System.nanoTime();
+ char phase = 't';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, fThreadId);
+ appendName(sb, label);
+ appendCategory(sb, fCategory);
+ appendId(sb, fId);
+ appendArgs(sb, args);
+ sb.append('}');
+ return sb.toString();
+ };
+ fLogger.log(fLevel, msgSupplier);
+ }
+
+ /**
+ * Add a tag to the scope logger, will be written at the exit. This can save
+ * space on the trace by having a field appended to an event rather than writing
+ * a whole new event for a small chunk of data.
+ *
+ *
+ * If the timing information is important, then it would be more appropriate to
+ * call {@link #step(String, Object...)}
+ *
+ * @param name the name of the field
+ * @param value The value of the field.
+ */
+ public void addData(String name, Object value) {
+ fData.put(name, value);
+ }
+
+ /**
+ * Get the ID for this scope. The ID can be injected to other components that
+ * can use it for the scope loggers
+ *
+ * @return The ID of this scope
+ */
+ public int getId() {
+ return fId;
+ }
+
+ @Override
+ public void close() {
+ long time = System.nanoTime();
+ char phase = 'E';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, fThreadId);
+ appendArgs(sb, fData);
+ sb.append('}');
+ return sb.toString();
+ };
+ fLogger.log(fLevel, msgSupplier);
+ }
+ }
+
+ /**
+ * Trace Object Creation, logs the beginning of an object's life cycle.
+ * Typically one can put this in the object's constructor. However if an object
+ * is mutable, it can be tracked through phases with this method, then the
+ * object can be re-used, however, the resulting analyses may yield erroneous
+ * data if precautions are not taken.
+ *
+ * For mutable objects, save the return value of the call. This will be passed
+ * to the destruction of the object and then it can be matched.
+ *
+ * @param logger The JUL logger
+ * @param level The {@link Level} of this event.
+ * @param item the Object to trace
+ * @return The unique ID of this object (there may be collisions)
+ */
+ public static int traceObjectCreation(Logger logger, Level level, Object item) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ int identityHashCode = System.identityHashCode(item);
+ char phase = 'N';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, item.getClass().getSimpleName());
+ appendId(sb, identityHashCode);
+ return sb.append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ return identityHashCode;
+ }
+
+ /**
+ * Trace Object Destruction, logs the end of an object's life cycle. Typically
+ * one can put this in the object's Dispose(). However if an object is mutable,
+ * it can be tracked through phases with this method, then the object can be
+ * re-used, however, the resulting analyses may yield erroneous data if
+ * precautions are not taken.
+ *
+ * @param logger The JUL logger
+ * @param level The {@link Level} of this event.
+ * @param item the Object to trace
+ */
+ public static void traceObjectDestruction(Logger logger, Level level, Object item) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ char phase = 'D';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, item.getClass().getSimpleName());
+ appendId(sb, System.identityHashCode(item));
+ return sb.append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ }
+
+ /**
+ * Trace Object Destruction, logs the end of an object's life cycle. Typically
+ * one can put this in the object's Dispose(). However if an object is mutable,
+ * it can be tracked through phases with this method, then the object can be
+ * re-used, however, the resulting analyses may be
+ *
+ * @param logger The JUL logger
+ * @param level The {@link Level} of this event.
+ * @param item the Object to trace
+ * @param uniqueId The unique ID
+ */
+ public static void traceObjectDestruction(Logger logger, Level level, Object item, int uniqueId) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ char phase = 'D';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, item.getClass().getSimpleName());
+ appendId(sb, uniqueId);
+ return sb.append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ }
+
+ /**
+ * Asynchronous events are used to specify asynchronous operations, such as an
+ * asynchronous (or synchronous) draw, or a network operation. Call this method
+ * at the beginning of such an operation.
+ *
+ * @param logger The JUL logger
+ * @param level The {@link Level} of this event.
+ * @param name The name of the asynchronous message
+ * @param category the category of the asynchronous event
+ * @param id The unique ID of a transaction
+ * @param args Additional arguments to log
+ */
+ public static void traceAsyncStart(Logger logger, Level level, String name, String category, int id,
+ Object... args) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ char phase = 'b';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, name);
+ appendCategory(sb, category);
+ appendId(sb, id);
+ return appendArgs(sb, args).append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ }
+
+ /**
+ * Asynchronous events are used to specify asynchronous operations, such as an
+ * asynchronous (or synchronous) draw, or a network operation. Call this method
+ * to augment the asynchronous event with nested information.
+ *
+ * @param logger The JUL logger
+ * @param level The {@link Level} of this event.
+ * @param name The name of the asynchronous message
+ * @param category the category of the asynchronous event
+ * @param id The unique ID of a transaction
+ * @param args Additional arguments to log
+ */
+ public static void traceAsyncNested(Logger logger, Level level, String name, String category, int id,
+ Object... args) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ char phase = 'n';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, name);
+ appendCategory(sb, category);
+ appendId(sb, id);
+ return appendArgs(sb, args).append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ }
+
+ /**
+ * Asynchronous events are used to specify asynchronous operations, such as an
+ * asynchronous (or synchronous) draw, or a network operation. Call this method
+ * at the end of such an operation.
+ *
+ * @param logger The JUL logger
+ * @param level The {@link Level} of this event.
+ * @param name The name of the asynchronous message
+ * @param category the category of the asynchronous event
+ * @param id The unique ID of a transaction
+ * @param args Additional arguments to log
+ */
+ public static void traceAsyncEnd(Logger logger, Level level, String name, String category, int id, Object... args) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ char phase = 'e';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, name);
+ appendCategory(sb, category);
+ appendId(sb, id);
+ return appendArgs(sb, args).append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ }
+
+ /**
+ * Instant events, created to indicate an item of interest has occurred, similar
+ * to a standard System.out.println() or a Java.util.Logger#log(Level). This one
+ * provides an event in a more structured way. This should be the method to call
+ * to save data that should have a zero duration, as it will ensure a log format
+ * that can then be parsed by a trace type.
+ *
+ * @param logger The JUL logger
+ * @param level The {@link Level} of this event.
+ * @param name The name of the asynchronous message
+ * @param args Additional arguments to log
+ */
+ public static void traceInstant(Logger logger, Level level, String name, Object... args) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ char phase = 'i';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, name);
+ return appendArgs(sb, args).append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ }
+
+ /**
+ * The counter events can track a value or multiple values as they change over
+ * time.
+ *
+ * @param logger The Logger
+ * @param level The {@link Level} of this event.
+ * @param name The name of the asynchronous message
+ * @param args The counters to log in the format : "title", value
+ */
+ public static void traceCounter(Logger logger, Level level, String name, Object... args) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ char phase = 'C';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, name);
+ return appendArgs(sb, args).append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ }
+
+ /**
+ * The Marker events are events with a duration that define a region of
+ * interest. These regions can be displayed in views as Markers or other
+ * indicators.
+ *
+ * @param logger The Logger
+ * @param level The {@link Level} of this event.
+ * @param name The name of the marker message message
+ * @param duration How long the marker should last
+ * @param args The counters to log in the format : "title", value, note
+ * "color" and an rbga will be used
+ */
+ public static void traceMarker(Logger logger, Level level, String name, long duration, Object... args) {
+ long time = System.nanoTime();
+ long threadId = Thread.currentThread().getId();
+ char phase = 'R';
+ Supplier msgSupplier = () -> {
+ StringBuilder sb = new StringBuilder();
+ sb.append('{');
+ appendCommon(sb, phase, time, threadId);
+ appendName(sb, name);
+ sb.append(',');
+ writeObject(sb, "dur", duration); //$NON-NLS-1$
+ return appendArgs(sb, args).append('}').toString();
+ };
+ logger.log(level, msgSupplier);
+ }
+
+ // -------------------------------------------------------------------------
+ // Helpers
+ // -------------------------------------------------------------------------
+
+ /*
+ * USE ME FIRST
+ */
+ private static StringBuilder appendCommon(StringBuilder appendTo, char phase, long time, long threadId) {
+ writeObject(appendTo, TIMESTAMP, FORMAT.format((double) time / 1000)).append(','); // $NON-NLS-1$
+ writeObject(appendTo, PHASE, phase).append(',');
+ writeObject(appendTo, TID, threadId).append(',');
+ return writeObject(appendTo, PID, threadId); // $NON-NLS-1$
+ }
+
+ private static StringBuilder appendName(StringBuilder sb, String name) {
+ if (name != null) {
+ sb.append(',');
+ writeObject(sb, NAME, name);
+ }
+ return sb;
+ }
+
+ private static StringBuilder appendCategory(StringBuilder sb, String category) {
+ if (category != null) {
+ sb.append(',');
+ writeObject(sb, CATEGORY, category);
+ }
+ return sb;
+ }
+
+ private static StringBuilder appendId(StringBuilder sb, int id) {
+ return sb.append(',').append('"').append(ID).append("\":\"0x") //$NON-NLS-1$
+ .append(Integer.toHexString(id)).append('"');
+ }
+
+ private static StringBuilder appendArgs(StringBuilder sb, Map args) {
+ if (!args.isEmpty()) {
+ sb.append(',').append('"').append(ARGS).append('"').append(':');
+ Object[] argsArray = new Object[2 * args.size()];
+ Iterator> entryIter = args.entrySet().iterator();
+ for (int i = 0; i < args.size(); i++) {
+ Entry entry = entryIter.next();
+ argsArray[i] = entry.getKey();
+ argsArray[i + 1] = entry.getValue();
+ }
+ getArgs(sb, argsArray);
+ }
+ return sb;
+ }
+
+ private static StringBuilder appendArgs(StringBuilder sb, Object... args) {
+ if (args.length > 0) {
+ sb.append(',').append('"').append(ARGS).append('"').append(':');
+ getArgs(sb, args);
+ }
+ return sb;
+ }
+
+ private static StringBuilder getArgs(StringBuilder appendTo, Object[] data) {
+ if (data.length == 0) {
+ return appendTo;
+ }
+ Set tester = new HashSet<>();
+ appendTo.append('{');
+ if (data.length == 1) {
+ // not in contract, but let's assume here that people are still new
+ // at this
+ appendTo.append("\"msg\":\"").append(data[0]).append('"'); //$NON-NLS-1$
+ } else {
+ if (data.length % 2 != 0) {
+ throw new IllegalArgumentException(
+ ARGS_ERROR_MESSAGE + "an odd number of messages" + Arrays.asList(data).toString()); //$NON-NLS-1$
+ }
+ for (int i = 0; i < data.length - 1; i += 2) {
+ Object value = data[i + 1];
+ String keyVal = String.valueOf(data[i]);
+ if (tester.contains(keyVal)) {
+ throw new IllegalArgumentException(ARGS_ERROR_MESSAGE + "an duplicate field names : " + keyVal); //$NON-NLS-1$
+ }
+ tester.add(keyVal);
+ if (i > 0) {
+ appendTo.append(',');
+ }
+ writeObject(appendTo, keyVal, value);
+ }
+ }
+
+ return appendTo.append('}');
+ }
+
+ private static StringBuilder writeObject(StringBuilder appendTo, Object key, Object value) {
+ appendTo.append('"').append(key).append('"').append(':');
+ if (value instanceof Number) {
+ appendTo.append(value);
+ } else {
+ appendTo.append('"').append(String.valueOf(value)).append('"');
+ }
+ return appendTo;
+ }
+}
diff --git a/src/test/java/org/eclipse/tracecompass/trace_event_logger/SnapshotTest.java b/src/test/java/org/eclipse/tracecompass/trace_event_logger/SnapshotTest.java
new file mode 100644
index 0000000..50f2a9b
--- /dev/null
+++ b/src/test/java/org/eclipse/tracecompass/trace_event_logger/SnapshotTest.java
@@ -0,0 +1,221 @@
+/*******************************************************************************
+ * Copyright (c) 2024 Ericsson
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the “Software”), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED “AS IS”, WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL
+ * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
+ * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS
+ * IN THE SOFTWARE.
+ *
+ * SPDX-License-Identifier: MIT
+ *******************************************************************************/
+package org.eclipse.tracecompass.trace_event_logger;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertFalse;
+import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.fail;
+
+import java.io.File;
+import java.io.FileInputStream;
+import java.io.FileNotFoundException;
+import java.io.FileReader;
+import java.io.IOException;
+import java.io.InputStream;
+import java.util.logging.Handler;
+import java.util.logging.Level;
+import java.util.logging.LogManager;
+import java.util.logging.Logger;
+
+import org.junit.After;
+import org.junit.Before;
+import org.junit.Test;
+
+/**
+ * Test cases for snapshotter
+ *
+ * @author Matthew Khouzam
+ */
+public class SnapshotTest {
+
+ private Logger logger;
+ private SnapshotHandler streamHandler;
+
+ /**
+ * Default ctor
+ */
+ public SnapshotTest() {
+ // Do nothing
+ }
+
+ /**
+ * Setup function
+ *
+ * @throws SecurityException won't happen
+ * @throws IOException won't happen
+ */
+ @Before
+ public void before() throws SecurityException, IOException {
+ logger = Logger.getAnonymousLogger();
+ streamHandler = new SnapshotHandler(0.5);
+ for (Handler handler : logger.getHandlers()) {
+ logger.removeHandler(handler);
+ }
+ logger.addHandler(streamHandler);
+ logger.setLevel(Level.ALL);
+ streamHandler.setLevel(Level.ALL);
+ }
+
+ /**
+ * Test something too fast for the snapshot
+ */
+ @Test
+ public void fastTest() {
+ Logger logger = this.logger;
+ assertNotNull(logger);
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "", 0L, 'a', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "", 0L, 'B', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "", 0L, 'E', "Bla"));
+ streamHandler.flush();
+ }
+
+ /**
+ * Test malformed events
+ */
+ @Test
+ public void badTest() {
+ Logger logger = this.logger;
+ assertNotNull(logger);
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "", 0L, 'a'));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "", 0L, 'B'));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "", 0L, 'E'));
+ streamHandler.flush();
+ }
+
+ /**
+ * Test an actual snapshot
+ *
+ * @throws InterruptedException won't happen
+ * @throws IOException won't happen
+ */
+ @Test
+ public void slowTest() throws InterruptedException, IOException {
+ Logger logger = this.logger;
+ assertNotNull(logger);
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"a\"", 10000000000L, 'a', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"b\"", 20000000000L, 'B', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"c\"", 30000000000L, 'c', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"d\"", 40000000000L, 'd', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"e\"", 50000000000L, 'e', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"f\"", 60000000000L, 'f', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"g\"", 70000000000L, 'E', "Bla"));
+ Thread.currentThread().sleep(1000);
+ streamHandler.flush();
+ File input = new File("request-10000000.json");
+ try (FileReader fr = new FileReader(input)) {
+ char[] data = new char[(int) input.length()];
+ fr.read(data);
+ assertEquals("[\"a\",\n" + "\"b\",\n" + "\"c\",\n" + "\"d\",\n" + "\"e\",\n" + "\"f\",\n" + "\"g\"]",
+ String.valueOf(data));
+ }
+ }
+
+ /**
+ * Test disabling the snapshotter
+ */
+ @Test
+ public void testEnableDisable() {
+ Logger logger = this.logger;
+ assertNotNull(logger);
+ assertTrue(streamHandler.isEnabled());
+ streamHandler.setEnabled(false);
+ assertFalse(streamHandler.isEnabled());
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"a\"", 10000000001L, 'a', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"b\"", 20000000000L, 'B', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"c\"", 30000000000L, 'c', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"d\"", 40000000000L, 'd', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"e\"", 50000000000L, 'e', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"f\"", 60000000000L, 'f', "Bla"));
+ logger.log(new LogUtils.TraceEventLogRecord(Level.INFO, () -> "\"g\"", 70000000000L, 'E', "Bla"));
+ streamHandler.flush();
+ File input = new File("request-10000001.json");
+ assertFalse(input.exists());
+ }
+
+ /**
+ * Test with simple configuration
+ */
+ @Test
+ public void testConfigure() {
+ Logger logger = this.logger;
+ try (InputStream fis = new FileInputStream(
+ new File("./src/test/java/org/eclipse/tracecompass/trace_event_logger/res/logging.properties"))) {
+ LogManager manager = LogManager.getLogManager();
+ manager.readConfiguration(fis);
+ Handler first = new SnapshotHandler();
+ first.close();
+ } catch (FileNotFoundException e) {
+ fail(e.getMessage());
+ } catch (IOException e) {
+ fail(e.getMessage());
+ }
+ }
+
+ /**
+ * Test with simple bad config, should still be "OK"
+ *
+ * @throws IOException won't happen
+ * @throws SecurityException won't happen
+ */
+ @Test
+ public void testSimpleBadConfigure() throws SecurityException, IOException {
+ Logger logger = this.logger;
+ SnapshotHandler first = new SnapshotHandler(-1);
+ assertNotNull(first);
+ first.publish(null);
+
+ }
+
+ /**
+ * Test with bad configuration
+ */
+ @Test
+ public void testBadConfigure() {
+ Logger logger = this.logger;
+ try (InputStream fis = new FileInputStream(
+ new File("./src/test/java/org/eclipse/tracecompass/trace_event_logger/res/badlogging.properties"))) {
+ LogManager manager = LogManager.getLogManager();
+ manager.readConfiguration(fis);
+ String prop = manager.getProperty("org.eclipse.tracecompass.trace_event_logger.SnapshotHandler.maxEvents");
+ assertNotNull(prop);
+ Handler first = new SnapshotHandler();
+ first.close();
+ } catch (FileNotFoundException e) {
+ fail(e.getMessage());
+ } catch (IOException e) {
+ fail(e.getMessage());
+ }
+ }
+
+ /**
+ * Tear down
+ */
+ @After
+ public void after() {
+ logger.removeHandler(streamHandler);
+ }
+
+}
\ No newline at end of file
diff --git a/src/test/java/org/eclipse/tracecompass/trace_event_logger/TestLoggerBenchmark.java b/src/test/java/org/eclipse/tracecompass/trace_event_logger/TestLoggerBenchmark.java
new file mode 100644
index 0000000..ccd22ca
--- /dev/null
+++ b/src/test/java/org/eclipse/tracecompass/trace_event_logger/TestLoggerBenchmark.java
@@ -0,0 +1,351 @@
+package org.eclipse.tracecompass.trace_event_logger;
+
+import static org.junit.Assert.fail;
+
+import java.io.File;
+import java.io.IOException;
+import java.nio.charset.StandardCharsets;
+import java.nio.file.Files;
+import java.nio.file.Path;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.logging.FileHandler;
+import java.util.logging.Formatter;
+import java.util.logging.Handler;
+import java.util.logging.Level;
+import java.util.logging.LogRecord;
+import java.util.logging.Logger;
+import java.util.stream.Stream;
+
+import org.junit.After;
+import org.junit.Test;
+
+public class TestLoggerBenchmark {
+
+ private Logger fLogger;
+ private Handler oldFileHandler;
+ private Handler newFileHandler;
+ private File[] files = new File[2];
+
+ @Test
+ public void testBench() throws SecurityException, IOException {
+ long warmUp = 2000;
+ long maxRuns = warmUp * 10;
+ fLogger = Logger.getAnonymousLogger();
+ files[0] = File.createTempFile("trace-old" ,".json");
+ files[1] = File.createTempFile("trace-new" ,".json");
+ oldFileHandler = new FileHandler(files[0].getAbsolutePath());
+ oldFileHandler.setFormatter(new Formatter() {
+ @Override
+ public String format(LogRecord record) {
+ return record.getMessage() + ",\n";
+ }
+ });
+ oldFileHandler.setLevel(Level.ALL);
+ fLogger.addHandler(oldFileHandler);
+ fLogger.setLevel(Level.ALL);
+ Logger logger = fLogger;
+ List asyncNew = new ArrayList<>();
+ List asyncOld = new ArrayList<>();
+ List syncNew = new ArrayList<>();
+ List syncOld = new ArrayList<>();
+ List run = new ArrayList<>();
+ for (long runs = 2000; runs < maxRuns; runs *= 1.4) {
+ for (long i = 0; i < warmUp; i++) {
+ try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (LogUtils.ScopeLog log1 = new LogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (LogUtils.ScopeLog log2 = new LogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+
+ long start = System.nanoTime();
+ for (long i = 0; i < runs; i++) {
+ try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.FINE, "foo", "run", runs, "test", i)) {
+ try (LogUtils.ScopeLog log1 = new LogUtils.ScopeLog(logger, Level.FINER, "bar", "run", runs, "test",
+ i)) {
+ try (LogUtils.ScopeLog log2 = new LogUtils.ScopeLog(logger, Level.FINEST, "baz", "run", runs,
+ "test", i)) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+ long end = System.nanoTime();
+ syncNew.add(end - start);
+ for (long i = 0; i < warmUp; i++) {
+ try (OldLogUtils.ScopeLog log = new OldLogUtils.ScopeLog(logger, Level.FINE, "foo", "run", runs, "test",
+ i)) {
+ try (OldLogUtils.ScopeLog log1 = new OldLogUtils.ScopeLog(logger, Level.FINER, "bar", "run", runs,
+ "test", i)) {
+ try (OldLogUtils.ScopeLog log2 = new OldLogUtils.ScopeLog(logger, Level.FINEST, "baz", "run",
+ runs, "test", i)) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+
+ long start2 = System.nanoTime();
+ for (long i = 0; i < runs; i++) {
+ try (OldLogUtils.ScopeLog log = new OldLogUtils.ScopeLog(logger, Level.FINE, "foo", "run", runs, "test",
+ i)) {
+ try (OldLogUtils.ScopeLog log1 = new OldLogUtils.ScopeLog(logger, Level.FINER, "bar", "run", runs,
+ "test", i)) {
+ try (OldLogUtils.ScopeLog log2 = new OldLogUtils.ScopeLog(logger, Level.FINEST, "baz", "run",
+ runs, "test", i)) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+ long end2 = System.nanoTime();
+ syncOld.add(end2 - start2);
+ run.add(runs);
+ }
+ fLogger.removeHandler(oldFileHandler);
+ newFileHandler = new AsyncFileHandler(files[1].getAbsolutePath());
+ newFileHandler.setFormatter(new Formatter() {
+ @Override
+ public String format(LogRecord record) {
+ return record.getMessage() + ",\n";
+ }
+ });
+ newFileHandler.setLevel(Level.ALL);
+ fLogger.addHandler(newFileHandler);
+ for (long runs = 2000; runs < maxRuns; runs *= 1.4) {
+ for (long i = 0; i < warmUp; i++) {
+ try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (LogUtils.ScopeLog log1 = new LogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (LogUtils.ScopeLog log2 = new LogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+
+ long start = System.nanoTime();
+ for (long i = 0; i < runs; i++) {
+ try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.FINE, "foo", "run", runs, "test", i)) {
+ try (LogUtils.ScopeLog log1 = new LogUtils.ScopeLog(logger, Level.FINER, "bar", "run", runs, "test",
+ i)) {
+ try (LogUtils.ScopeLog log2 = new LogUtils.ScopeLog(logger, Level.FINEST, "baz", "run", runs,
+ "test", i)) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+ long end = System.nanoTime();
+ asyncNew.add(end - start);
+ for (long i = 0; i < warmUp; i++) {
+ try (OldLogUtils.ScopeLog log = new OldLogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (OldLogUtils.ScopeLog log1 = new OldLogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (OldLogUtils.ScopeLog log2 = new OldLogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+
+ long start2 = System.nanoTime();
+ for (long i = 0; i < runs; i++) {
+ try (OldLogUtils.ScopeLog log = new OldLogUtils.ScopeLog(logger, Level.FINE, "foo", "run", runs, "test",
+ i)) {
+ try (OldLogUtils.ScopeLog log1 = new OldLogUtils.ScopeLog(logger, Level.FINER, "bar", "run", runs,
+ "test", i)) {
+ try (OldLogUtils.ScopeLog log2 = new OldLogUtils.ScopeLog(logger, Level.FINEST, "baz", "run",
+ runs, "test", i)) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+ long end2 = System.nanoTime();
+ asyncOld.add(end2 - start2);
+ }
+ System.out.println("Runs,SyncOld,SyncNew,AsyncOld,AsyncNew");
+ for (int i = 0; i < run.size(); i++) {
+ System.out.println(String.format("%d,%d,%d,%d,%d", run.get(i), syncOld.get(i), syncNew.get(i),
+ asyncOld.get(i), asyncNew.get(i)));
+ }
+ }
+
+ private static long linecount(Path path) throws IOException {
+ long linecount = 0;
+ try (Stream stream = Files.lines(path, StandardCharsets.UTF_8)) {
+ linecount = stream.count();
+ }
+ return linecount;
+ }
+
+ @After
+ public void waiting() {
+ try {
+ while (linecount(files[0].toPath()) != linecount(files[1].toPath())) {
+ if(oldFileHandler != null) {
+ oldFileHandler.close();
+ }
+ if(newFileHandler != null) {
+ newFileHandler.close();
+ }
+ Thread.currentThread().sleep(100);
+ }
+ } catch (IOException | InterruptedException e) {
+ fail(e.toString());
+ }
+ }
+
+ @Test
+ public void testLeanBench() throws SecurityException, IOException {
+ long warmUp = 2000;
+ long maxRuns = warmUp * 10;
+ fLogger = Logger.getAnonymousLogger();
+ files[0] = File.createTempFile("trace-lean-old" ,".json");
+ files[1] = File.createTempFile("trace-lean-new" ,".json");
+ oldFileHandler = new FileHandler(files[0].getAbsolutePath());
+ oldFileHandler.setFormatter(new Formatter() {
+ @Override
+ public String format(LogRecord record) {
+ return record.getMessage() + ",\n";
+ }
+ });
+ oldFileHandler.setLevel(Level.ALL);
+ fLogger.addHandler(oldFileHandler);
+ fLogger.setLevel(Level.ALL);
+ Logger logger = fLogger;
+ List asyncNew = new ArrayList<>();
+ List asyncOld = new ArrayList<>();
+ List syncNew = new ArrayList<>();
+ List syncOld = new ArrayList<>();
+ List run = new ArrayList<>();
+ for (long runs = 2000; runs < maxRuns; runs *= 1.4) {
+ for (long i = 0; i < warmUp; i++) {
+ try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (LogUtils.ScopeLog log1 = new LogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (LogUtils.ScopeLog log2 = new LogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+
+ long start = System.nanoTime();
+ for (long i = 0; i < runs; i++) {
+ try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (LogUtils.ScopeLog log1 = new LogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (LogUtils.ScopeLog log2 = new LogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+ long end = System.nanoTime();
+ syncNew.add(end - start);
+ for (long i = 0; i < warmUp; i++) {
+ try (OldLogUtils.ScopeLog log = new OldLogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (OldLogUtils.ScopeLog log1 = new OldLogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (OldLogUtils.ScopeLog log2 = new OldLogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+
+ long start2 = System.nanoTime();
+ for (long i = 0; i < runs; i++) {
+ try (OldLogUtils.ScopeLog log = new OldLogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (OldLogUtils.ScopeLog log1 = new OldLogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (OldLogUtils.ScopeLog log2 = new OldLogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+ long end2 = System.nanoTime();
+ syncOld.add(end2 - start2);
+ run.add(runs);
+ }
+ fLogger.removeHandler(oldFileHandler);
+ newFileHandler = new AsyncFileHandler(files[1].getAbsolutePath());
+ newFileHandler.setFormatter(new Formatter() {
+ @Override
+ public String format(LogRecord record) {
+ return record.getMessage() + ",\n";
+ }
+ });
+ newFileHandler.setLevel(Level.ALL);
+ fLogger.addHandler(newFileHandler);
+ for (long runs = 2000; runs < maxRuns; runs *= 1.4) {
+ for (long i = 0; i < warmUp; i++) {
+ try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (LogUtils.ScopeLog log1 = new LogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (LogUtils.ScopeLog log2 = new LogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+
+ long start = System.nanoTime();
+ for (long i = 0; i < runs; i++) {
+ try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (LogUtils.ScopeLog log1 = new LogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (LogUtils.ScopeLog log2 = new LogUtils.ScopeLog(logger, Level.FINEST, "baz", "run", runs,
+ "test", i)) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+ long end = System.nanoTime();
+ asyncNew.add(end - start);
+ for (long i = 0; i < warmUp; i++) {
+ try (OldLogUtils.ScopeLog log = new OldLogUtils.ScopeLog(logger, Level.FINE, "foo")) {
+ try (OldLogUtils.ScopeLog log1 = new OldLogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (OldLogUtils.ScopeLog log2 = new OldLogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+
+ long start2 = System.nanoTime();
+ for (long i = 0; i < runs; i++) {
+ try (OldLogUtils.ScopeLog log = new OldLogUtils.ScopeLog(logger, Level.FINE, "foo", "run", runs, "test",
+ i)) {
+ try (OldLogUtils.ScopeLog log1 = new OldLogUtils.ScopeLog(logger, Level.FINER, "bar")) {
+ try (OldLogUtils.ScopeLog log2 = new OldLogUtils.ScopeLog(logger, Level.FINEST, "baz")) {
+ // do something
+ new Object();
+ }
+ }
+ }
+ }
+ long end2 = System.nanoTime();
+ asyncOld.add(end2 - start2);
+ }
+ System.out.println("Runs,SyncOldLean,SyncNewLean,AsyncOldLean,AsyncNewLean");
+ for (int i = 0; i < run.size(); i++) {
+ System.out.println(String.format("%d,%d,%d,%d,%d", run.get(i), syncOld.get(i), syncNew.get(i),
+ asyncOld.get(i), asyncNew.get(i)));
+ }
+ }
+}
\ No newline at end of file
diff --git a/src/test/java/org/eclipse/tracecompass/trace_event_logger/res/badlogging.properties b/src/test/java/org/eclipse/tracecompass/trace_event_logger/res/badlogging.properties
new file mode 100644
index 0000000..65d9024
--- /dev/null
+++ b/src/test/java/org/eclipse/tracecompass/trace_event_logger/res/badlogging.properties
@@ -0,0 +1,8 @@
+handlers= org.eclipse.tracecompass.trace_event_logger.SnapshotHandler, org.eclipse.tracecompass.trace_event_logger.AsyncFileHandler
+
+org.eclipse.tracecompass.trace_event_logger.SnapshotHandler.maxEvents = -1
+org.eclipse.tracecompass.trace_event_logger.SnapshotHandler.timeout = -1
+org.eclipse.tracecompass.trace_event_logger.SnapshotHandler.filePath =
+org.eclipse.tracecompass.trace_event_logger.AsyncFileHandler.maxSize = -1
+org.eclipse.tracecompass.trace_event_logger.AsyncFileHandler.queueDepth = -1
+org.eclipse.tracecompass.trace_event_logger.AsyncFileHandler.flushRate = -1
diff --git a/src/test/java/org/eclipse/tracecompass/trace_event_logger/res/logging.properties b/src/test/java/org/eclipse/tracecompass/trace_event_logger/res/logging.properties
new file mode 100644
index 0000000..86a58c1
--- /dev/null
+++ b/src/test/java/org/eclipse/tracecompass/trace_event_logger/res/logging.properties
@@ -0,0 +1 @@
+handlers= org.eclipse.tracecompass.trace_event_logger.SnapshotHandler, org.eclipse.tracecompass.trace_event_logger.AsyncFileHandler
\ No newline at end of file