Skip to content

Commit

Permalink
ftr: prevent eager closing of file writer upon every log invocation
Browse files Browse the repository at this point in the history
Closes #221. The eager behavior can be enabled by setting configuration
eclipse.log.closeFile.eagerClose to true (defaults to false).
  • Loading branch information
alxflam-work committed Oct 24, 2023
1 parent 7208dfa commit e63fa9c
Show file tree
Hide file tree
Showing 8 changed files with 221 additions and 9 deletions.
2 changes: 1 addition & 1 deletion bundles/org.eclipse.osgi.tests/META-INF/MANIFEST.MF
Original file line number Diff line number Diff line change
Expand Up @@ -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)",
Expand Down
2 changes: 1 addition & 1 deletion bundles/org.eclipse.osgi.tests/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@
</parent>
<groupId>org.eclipse.osgi</groupId>
<artifactId>org.eclipse.osgi.tests</artifactId>
<version>3.18.500-SNAPSHOT</version>
<version>3.18.600-SNAPSHOT</version>
<packaging>eclipse-test-plugin</packaging>

<properties>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
}
Original file line number Diff line number Diff line change
@@ -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</br>
* When: {@link FrameworkLog#log(FrameworkLogEntry)} is invoked multiple
* times</br>
* 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<Field> 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);
}
}
}
2 changes: 1 addition & 1 deletion bundles/org.eclipse.osgi/META-INF/MANIFEST.MF
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -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 */
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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);
Expand All @@ -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();
}
}
}

Expand Down Expand Up @@ -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() {
Expand Down
2 changes: 1 addition & 1 deletion bundles/org.eclipse.osgi/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@
</parent>
<groupId>org.eclipse.osgi</groupId>
<artifactId>org.eclipse.osgi</artifactId>
<version>3.18.500-SNAPSHOT</version>
<version>3.18.600-SNAPSHOT</version>
<packaging>eclipse-plugin</packaging>
<properties>
<!-- The actual TCKs are executed in the org.eclipse.osgi.tck module because of reference to other service implementations -->
Expand Down

0 comments on commit e63fa9c

Please sign in to comment.