Only log instances of TraceEventLogRecored when using AsyncFileHandler

Without this change other LogRecords are also logged.

Add unit tests for that. Update TraceLoggerBenchmark to account for
the filtered out LogRecords.

fixes #49

Signed-off-by: Bernd Hufmann <bernd.hufmann@ericsson.com>

Author: bhufmann

src/main/java/org/eclipse/tracecompass/traceeventlogger/AsyncFileHandler.java

@@ -333,10 +333,12 @@ public ErrorManager getErrorManager() {
     @Override
     public synchronized void publish(LogRecord record) {
         try {
-            fRecordBuffer.add(record);
-            if (fRecordBuffer.size() >= fMaxSize && isLoggable(record)) {
-                fQueue.put(fRecordBuffer);
-                fRecordBuffer = new ArrayList<>(fMaxSize);
+            if (isLoggable(record)) {
+                fRecordBuffer.add(record);
+                if (fRecordBuffer.size() >= fMaxSize) {
+                    fQueue.put(fRecordBuffer);
+                    fRecordBuffer = new ArrayList<>(fMaxSize);
+                }
             }
         } catch (InterruptedException e) {
             Thread.currentThread().interrupt();

src/test/java/org/eclipse/tracecompass/traceeventlogger/LoggerWithHandlerTest.java

@@ -0,0 +1,126 @@
+/*******************************************************************************
+ * Copyright (c) 2025 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.traceeventlogger;
+
+import static org.junit.Assert.assertEquals;
+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.IOException;
+import java.nio.file.Files;
+import java.nio.file.Paths;
+import java.util.Collections;
+import java.util.List;
+import java.util.Objects;
+import java.util.logging.Level;
+import java.util.logging.LogManager;
+import java.util.logging.Logger;
+import java.util.logging.SimpleFormatter;
+import java.util.logging.StreamHandler;
+import java.util.regex.Pattern;
+import java.util.stream.Collectors;
+
+import org.junit.Before;
+import org.junit.Test;
+
+/**
+ * Test cases for logger with AsyncFileHandler(line sensitive!)
+ *
+ * @author Bernd Hufmann
+ */
+public class LoggerWithHandlerTest {
+
+    private Logger fLogger;
+    private StreamHandler fStreamHandler;
+    private File fTempFile;
+
+    /**
+     * Set up logger
+     */
+    @Before
+    public void before() {
+        try {
+            System.setProperty("java.util.logging.SimpleFormatter.format", "%5$s%n"); //$NON-NLS-1$ //$NON-NLS-2$
+            LogManager.getLogManager().reset();
+            fLogger = Logger.getAnonymousLogger();
+            fTempFile = File.createTempFile("test", ".json"); //$NON-NLS-1$ //$NON-NLS-2$
+            fStreamHandler = new AsyncFileHandler(fTempFile.getAbsolutePath());
+            fStreamHandler.setLevel(Level.ALL);
+            fStreamHandler.setEncoding("UTF-8"); //$NON-NLS-1$
+            fStreamHandler.setFormatter(new SimpleFormatter());
+            fLogger.addHandler(fStreamHandler);
+
+        } catch (IOException e) {
+            fail(e.getMessage());
+        }
+    }
+
+    /**
+     * Test simple logging
+     */
+    @Test
+    public void testHelloWorld() {
+        Logger logger = fLogger;
+        assertNotNull(logger);
+        try (LogUtils.ScopeLog log = new LogUtils.ScopeLog(logger, Level.INFO, "world")) { //$NON-NLS-1$
+            // do something
+            new Object();
+        }
+        logger.log(Level.INFO, "Should not be logged"); //$NON-NLS-1$
+
+        fStreamHandler.flush();
+
+        List<String> filledLines = Collections.emptyList();
+        // Give writing thread time to write all events
+        try {
+            Thread.sleep(3000);
+        } catch (InterruptedException ex) {
+            // ignore
+        }
+        try {
+            for (int i = 0; i < 10; i++) {
+                List<String> allLines = Files.readAllLines(Paths.get(fTempFile.getAbsolutePath()));
+                filledLines = allLines.stream().filter(Objects::nonNull).collect(Collectors.toList());
+                if (filledLines.size() >= 2) {
+                    break;
+                }
+                try {
+                    Thread.sleep(1000);
+                } catch (InterruptedException ex) {
+                    // ignore
+                }
+            }
+            assertNotNull(filledLines);
+            assertEquals(2, filledLines.size());
+            Pattern pattern = Pattern.compile("\\{.*B.*world.*\\}"); //$NON-NLS-1$
+            assertTrue(pattern.matcher(filledLines.get(0)).matches());
+            pattern = Pattern.compile("\\{.*E.*\\}"); //$NON-NLS-1$
+            assertTrue(pattern.matcher(filledLines.get(1)).matches());
+        } catch (IOException e) {
+            fail(e.getMessage());
+        }
+    }
+}

src/test/java/org/eclipse/tracecompass/traceeventlogger/TestLoggerBenchmark.java

@@ -176,6 +176,10 @@ public String format(LogRecord record) {
                     }
                 }
             }
+            /*
+             * Note, that the instances of LogRecord created by OldLogUtils.ScopeLog won't be written to disk by the
+             * AsyncFileHandler since they are not instances of TraceEventLogRecord.
+             */
             long end = System.nanoTime();
             asyncNew.add(end - start);
             for (long i = 0; i < warmUp; i++) {
@@ -227,15 +231,27 @@ private static long linecount(Path path) throws IOException {
     @After
     public void waiting() {
         try {
-            while (linecount(files[0].toPath()) != linecount(files[1].toPath())) {
+            int nbRetries = 0;
+            int maxRetries = 25;
+            /*
+             * Note, that files[1] has half of number of events than files[0] because the instances of LogRecord created by
+             * OldLogUtils.ScopeLog won't be written to disk by the AsyncFileHandler since they are not instances of
+             * TraceEventLogRecord.
+             */
+            while (linecount(files[0].toPath()) != (2 * linecount(files[1].toPath())) && (nbRetries < maxRetries)) {
                 if (oldFileHandler != null) {
                     oldFileHandler.close();
                 }
                 if (newFileHandler != null) {
                     newFileHandler.close();
                 }
                 Thread.sleep(100);
-
+                nbRetries++;
+            }
+            if (nbRetries >= maxRetries) {
+                System.out.println("Max retries (" + nbRetries //$NON-NLS-1$
+                        + ") reached: line count of file[0]=" + linecount(files[0].toPath()) //$NON-NLS-1$
+                        + ", line count of file[1]=" + linecount(files[1].toPath())); //$NON-NLS-1$
             }
         } catch (IOException | InterruptedException e) {
             fail(e.toString());