From e63fa9c684e4370c65902c284027fe9282308eb7 Mon Sep 17 00:00:00 2001 From: Alexander Flammer Date: Thu, 19 Oct 2023 14:10:28 +0200 Subject: [PATCH] ftr: prevent eager closing of file writer upon every log invocation Closes #221. The eager behavior can be enabled by setting configuration eclipse.log.closeFile.eagerClose to true (defaults to false). --- .../META-INF/MANIFEST.MF | 2 +- bundles/org.eclipse.osgi.tests/pom.xml | 2 +- .../equinox/log/test/AllLogServiceTests.java | 9 +- .../log/test/EquinoxLogWriterTest.java | 182 ++++++++++++++++++ bundles/org.eclipse.osgi/META-INF/MANIFEST.MF | 2 +- .../osgi/internal/log/EquinoxLogServices.java | 2 + .../osgi/internal/log/EquinoxLogWriter.java | 29 ++- bundles/org.eclipse.osgi/pom.xml | 2 +- 8 files changed, 221 insertions(+), 9 deletions(-) create mode 100644 bundles/org.eclipse.osgi.tests/src/org/eclipse/equinox/log/test/EquinoxLogWriterTest.java diff --git a/bundles/org.eclipse.osgi.tests/META-INF/MANIFEST.MF b/bundles/org.eclipse.osgi.tests/META-INF/MANIFEST.MF index 20ccf8545ab..324f86337a8 100644 --- a/bundles/org.eclipse.osgi.tests/META-INF/MANIFEST.MF +++ b/bundles/org.eclipse.osgi.tests/META-INF/MANIFEST.MF @@ -2,7 +2,7 @@ Manifest-Version: 1.0 Bundle-ManifestVersion: 2 Bundle-Name: Core OSGi Tests Bundle-SymbolicName: org.eclipse.osgi.tests;singleton:=true -Bundle-Version: 3.18.500.qualifier +Bundle-Version: 3.18.600.qualifier Bundle-Vendor: Eclipse.org Require-Bundle: org.eclipse.core.runtime;bundle-version="[3.29.0,4.0.0)", diff --git a/bundles/org.eclipse.osgi.tests/pom.xml b/bundles/org.eclipse.osgi.tests/pom.xml index d738ea7f32a..e29c2f12608 100644 --- a/bundles/org.eclipse.osgi.tests/pom.xml +++ b/bundles/org.eclipse.osgi.tests/pom.xml @@ -19,7 +19,7 @@ org.eclipse.osgi org.eclipse.osgi.tests - 3.18.500-SNAPSHOT + 3.18.600-SNAPSHOT eclipse-test-plugin diff --git a/bundles/org.eclipse.osgi.tests/src/org/eclipse/equinox/log/test/AllLogServiceTests.java b/bundles/org.eclipse.osgi.tests/src/org/eclipse/equinox/log/test/AllLogServiceTests.java index 966563ea28b..ed4f24836b4 100644 --- a/bundles/org.eclipse.osgi.tests/src/org/eclipse/equinox/log/test/AllLogServiceTests.java +++ b/bundles/org.eclipse.osgi.tests/src/org/eclipse/equinox/log/test/AllLogServiceTests.java @@ -15,9 +15,10 @@ @RunWith(Suite.class) @Suite.SuiteClasses({ // - LogServiceTest.class, // - LogReaderServiceTest.class, // - LogPermissionCollectionTest.class // - }) + LogServiceTest.class, // + LogReaderServiceTest.class, // + LogPermissionCollectionTest.class, // + EquinoxLogWriterTest.class // +}) public class AllLogServiceTests { } diff --git a/bundles/org.eclipse.osgi.tests/src/org/eclipse/equinox/log/test/EquinoxLogWriterTest.java b/bundles/org.eclipse.osgi.tests/src/org/eclipse/equinox/log/test/EquinoxLogWriterTest.java new file mode 100644 index 00000000000..ac464164b73 --- /dev/null +++ b/bundles/org.eclipse.osgi.tests/src/org/eclipse/equinox/log/test/EquinoxLogWriterTest.java @@ -0,0 +1,182 @@ +/******************************************************************************* + * Copyright (c) 2023 IBM Corporation and others. + * + * This program and the accompanying materials + * are made available under the terms of the Eclipse Public License 2.0 + * which accompanies this distribution, and is available at + * https://www.eclipse.org/legal/epl-2.0/ + * + * SPDX-License-Identifier: EPL-2.0 + * + * Contributors: + * Copyright (c) 2023 Robert Bosch GmbH - https://github.com/eclipse-equinox/equinox/issues/221 + *******************************************************************************/ +package org.eclipse.equinox.log.test; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.is; + +import java.io.File; +import java.io.IOException; +import java.io.Writer; +import java.lang.reflect.Field; +import java.util.Optional; +import java.util.stream.Stream; +import org.eclipse.osgi.framework.log.FrameworkLog; +import org.eclipse.osgi.framework.log.FrameworkLogEntry; +import org.eclipse.osgi.tests.OSGiTestsActivator; +import org.junit.Rule; +import org.junit.Test; +import org.junit.rules.TemporaryFolder; +import org.osgi.framework.ServiceReference; +import org.osgi.service.log.LogListener; + +/** + * Tests verifying that EquinoxLogWriter does not close the writer for a file + * log on every log invocation but only when the log file changes. + * + * See https://github.com/eclipse-equinox/equinox/issues/221 + */ +public class EquinoxLogWriterTest { + + /** + * Temporary folder rule used to create a log file for the EquinoxLogWriter + */ + @Rule + public TemporaryFolder tempFolder = new TemporaryFolder(); + + /** + * Helper class to capture the state of the internal writer used by the + * EquinoxLogWriter + */ + private static final class WriterState { + + private boolean isClosed; + private boolean isFlushed; + + public WriterState() { + reset(); + } + + public void reset() { + isClosed = false; + isFlushed = false; + } + + /** + * @return true, if the writer is closed + */ + public boolean isClosed() { + return isClosed; + } + + public void setClosed(boolean closed) { + this.isClosed = closed; + } + + /** + * @return true, if {@link Writer#flush()} got called + */ + public boolean isFlushed() { + return isFlushed; + } + + public void setFlushed(boolean flushed) { + this.isFlushed = flushed; + } + + } + + /** + * Given: A {@link FrameworkLog} configured to log to a file
+ * When: {@link FrameworkLog#log(FrameworkLogEntry)} is invoked multiple + * times
+ * Then: Every log invocation is synchronously written and flushed but the + * internally used {@link Writer} is never closed + * + * @throws IOException + * @throws NoSuchFieldException + * @throws SecurityException + * @throws IllegalArgumentException + * @throws IllegalAccessException + */ + @Test + public void testLogDoesNotCloseWriter() throws IOException, NoSuchFieldException, SecurityException, + IllegalArgumentException, IllegalAccessException { + // retrieve the framework log + ServiceReference logReference = OSGiTestsActivator.getContext().getServiceReference(FrameworkLog.class); + FrameworkLog log = (FrameworkLog) OSGiTestsActivator.getContext().getService(logReference); + + // create and set the log file + File tempFile = tempFolder.newFile(this.getClass().getSimpleName() + ".log"); + final File originalFile = log.getFile(); + log.setFile(tempFile, false); + + // create the dummy writer which makes use of a writer state + // to capture invocations (mockito is not available in this test bundle) + final WriterState state = new WriterState(); + Writer dummyWriter = new Writer() { + + @Override + public void write(char[] cbuf, int off, int len) { + // not needed + } + + @Override + public void flush() { + state.setFlushed(true); + } + + @Override + public void close() { + state.setClosed(true); + } + + }; + + // usually, either setFile or setWriter is called on the framework log + // for this test, we need to verify invocations on the writer instance used + // for file logging. therefore, we need to set the writer instance using + // reflection, as usually the writer is created automatically by the + // EquinoxLogWriter when the target is a file + + // retrieve the field which may be the EquinoxLogWriter + Optional logWriter = Stream.of(log.getClass().getDeclaredFields()) + .filter(a -> LogListener.class.isAssignableFrom(a.getType())).findFirst(); + assertThat(logWriter.isPresent(), is(true)); + + // retrieve the log writer instance + Field equinoxLogWriterField = logWriter.get(); + equinoxLogWriterField.setAccessible(true); + Object equinoxLogWriter = equinoxLogWriterField.get(log); + + // retrieve the internal writer member of the EquinoxLogWriter + Field internalWriter = equinoxLogWriter.getClass().getDeclaredField("writer"); + internalWriter.setAccessible(true); + Object originalWriter = internalWriter.get(equinoxLogWriter); + + try { + // set the dummy writer instance + internalWriter.set(equinoxLogWriter, dummyWriter); + + // log a few messages and verify the writer is never closed + for (int i = 1; i <= 3; i++) { + log.log(new FrameworkLogEntry("some.bundle", 1, 0, "Log Attempt: " + i, 0, null, null)); + assertThat(state.isFlushed(), is(true)); + assertThat(state.isClosed(), is(false)); + state.reset(); + } + + // changing the log file closes the current writer + log.setFile(null, false); + assertThat(state.isClosed(), is(true)); + } finally { + // set the original writer instance again + internalWriter.set(equinoxLogWriter, originalWriter); + // set the original log file again + log.setFile(originalFile, true); + // unget service reference + OSGiTestsActivator.getContext().ungetService(logReference); + } + } +} diff --git a/bundles/org.eclipse.osgi/META-INF/MANIFEST.MF b/bundles/org.eclipse.osgi/META-INF/MANIFEST.MF index 87b466c6f51..a37c9e0e909 100644 --- a/bundles/org.eclipse.osgi/META-INF/MANIFEST.MF +++ b/bundles/org.eclipse.osgi/META-INF/MANIFEST.MF @@ -107,7 +107,7 @@ Bundle-Activator: org.eclipse.osgi.internal.framework.SystemBundleActivator Bundle-Description: %systemBundle Bundle-Copyright: %copyright Bundle-Vendor: %eclipse.org -Bundle-Version: 3.18.500.qualifier +Bundle-Version: 3.18.600.qualifier Bundle-Localization: systembundle Bundle-DocUrl: http://www.eclipse.org Eclipse-ExtensibleAPI: true diff --git a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/log/EquinoxLogServices.java b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/log/EquinoxLogServices.java index 2efb30678a5..3639b5d9163 100644 --- a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/log/EquinoxLogServices.java +++ b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/log/EquinoxLogServices.java @@ -126,7 +126,9 @@ public void start(BundleContext context) throws BundleException { * @throws BundleException */ public void stop(BundleContext context) throws BundleException { + logWriter.close(); frameworkLogReg.unregister(); + perfWriter.close(); perfLogReg.unregister(); logServiceManager.stop(context); } diff --git a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/log/EquinoxLogWriter.java b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/log/EquinoxLogWriter.java index b0aee6d42f5..9e0d1fb3288 100644 --- a/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/log/EquinoxLogWriter.java +++ b/bundles/org.eclipse.osgi/container/src/org/eclipse/osgi/internal/log/EquinoxLogWriter.java @@ -10,6 +10,7 @@ * * Contributors: * IBM Corporation - initial API and implementation + * Copyright (c) 2023 Robert Bosch GmbH - https://github.com/eclipse-equinox/equinox/issues/221 *******************************************************************************/ package org.eclipse.osgi.internal.log; @@ -84,6 +85,9 @@ class EquinoxLogWriter implements SynchronousLogListener, LogFilter { /** The system property used to specify command line args should be omitted from the log */ private static final String PROP_LOG_INCLUDE_COMMAND_LINE = "eclipse.log.include.commandline"; //$NON-NLS-1$ + /** The system property used to specify the log file writer should be closed eagerly */ + private static final String PROP_CLOSE_LOG_FILE_EAGERLY = "eclipse.log.closeFile.eagerClose"; //$NON-NLS-1$ + /** Indicates if the console messages should be printed to the console (System.out) */ private boolean consoleLog = false; /** Indicates if the next log message is part of a new session */ @@ -111,6 +115,15 @@ class EquinoxLogWriter implements SynchronousLogListener, LogFilter { private LoggerAdmin loggerAdmin = null; + /** + * Controls whether the log file should be closed eagerly upon every log + * invocation. + * + * Can be controlled by property + * {@link EquinoxLogWriter#PROP_CLOSE_LOG_FILE_EAGERLY}. + */ + private boolean closeLogFileEagerly = false; + /** * Constructs an EclipseLog which uses the specified File to log messages to * @param outFile a file to log messages to @@ -303,6 +316,8 @@ private synchronized void log(FrameworkLogEntry logEntry) { writeLog(0, logEntry); writer.flush(); } catch (Exception e) { + // close log file writer upon exceptions + closeFile(); // any exceptions during logging should be caught System.err.println("An exception occurred while writing to the platform log:");//$NON-NLS-1$ e.printStackTrace(System.err); @@ -315,9 +330,14 @@ private synchronized void log(FrameworkLogEntry logEntry) { } catch (Exception e2) { System.err.println("An exception occurred while logging to the console:");//$NON-NLS-1$ e2.printStackTrace(System.err); + } finally { + // ensure that the error stream writer is closed + closeFile(); } } finally { - closeFile(); + if (closeLogFileEagerly) { + closeFile(); + } } } @@ -679,6 +699,13 @@ else if (newLogLevel.equals("INFO")) //$NON-NLS-1$ includeCommandLine = "true".equals(environmentInfo.getConfiguration(PROP_LOG_INCLUDE_COMMAND_LINE, "true")); //$NON-NLS-1$//$NON-NLS-2$ applyLogLevel(); + + String newCloseLogFileEagerlyValue = environmentInfo.getConfiguration(PROP_CLOSE_LOG_FILE_EAGERLY); + if (newCloseLogFileEagerlyValue != null) { + if (Boolean.valueOf(newCloseLogFileEagerlyValue) == Boolean.TRUE) { + closeLogFileEagerly = true; + } + } } void applyLogLevel() { diff --git a/bundles/org.eclipse.osgi/pom.xml b/bundles/org.eclipse.osgi/pom.xml index 4e7a606f955..17f72be34bf 100644 --- a/bundles/org.eclipse.osgi/pom.xml +++ b/bundles/org.eclipse.osgi/pom.xml @@ -19,7 +19,7 @@ org.eclipse.osgi org.eclipse.osgi - 3.18.500-SNAPSHOT + 3.18.600-SNAPSHOT eclipse-plugin