Skip to content

Commit

Permalink
Fixed issues around rolling the server.log file
Browse files Browse the repository at this point in the history
- When rolling, several log records were lost - doesn't happen any more
- Refactoring: separated features to own classes, which resolved some locking
  and reduced need of sharing method handles.

Signed-off-by: David Matějček <david.matejcek@omnifish.ee>
  • Loading branch information
dmatej committed Jan 14, 2024
1 parent d6789bd commit fe2e65d
Show file tree
Hide file tree
Showing 6 changed files with 394 additions and 250 deletions.
@@ -1,5 +1,5 @@
/*
* Copyright (c) 2022 Eclipse Foundation and/or its affiliates. All rights reserved.
* Copyright (c) 2022, 2024 Eclipse Foundation and/or its affiliates. All rights reserved.
* Copyright (c) 2009, 2018 Oracle and/or its affiliates. All rights reserved.
*
* This program and the accompanying materials are made available under the
Expand All @@ -17,16 +17,17 @@

package org.glassfish.main.jul.handler;

import java.io.OutputStream;
import java.io.File;
import java.io.UnsupportedEncodingException;
import java.nio.charset.Charset;
import java.security.AccessController;
import java.security.PrivilegedAction;
import java.util.Timer;
import java.util.logging.ErrorManager;
import java.util.logging.Formatter;
import java.util.logging.Handler;
import java.util.logging.LogRecord;
import java.util.logging.Logger;
import java.util.logging.StreamHandler;

import org.glassfish.main.jul.cfg.GlassFishLoggingConstants;
import org.glassfish.main.jul.env.LoggingSystemEnvironment;
Expand Down Expand Up @@ -76,7 +77,7 @@
* @author Jerome Dochez (original concepts of GFFileHandler)
* @author Carla Mott (original concepts of GFFileHandler)
*/
public class GlassFishLogHandler extends StreamHandler implements ExternallyManagedLogHandler {
public class GlassFishLogHandler extends Handler implements ExternallyManagedLogHandler {

private static final String LOGGER_NAME_STDOUT = "jakarta.enterprise.logging.stdout";
private static final String LOGGER_NAME_STDERR = "jakarta.enterprise.logging.stderr";
Expand All @@ -98,6 +99,8 @@ public class GlassFishLogHandler extends StreamHandler implements ExternallyMana
private LoggingPump pump;
private LogFileManager logFileManager;

private boolean doneHeader;

/**
* Creates the configuration object for this class or it's descendants.
*
Expand Down Expand Up @@ -196,10 +199,6 @@ public synchronized void reconfigure(final GlassFishLogHandlerConfiguration newC
// stop pump. If reconfiguration would fail, it is better to leave it down.
// records from the buffer will be processed if the last configuration was valid.
stopPump();
if (this.logFileManager != null) {
this.logFileManager.disableOutput();
this.logFileManager = null;
}
this.configuration = newConfiguration;

try {
Expand All @@ -211,13 +210,6 @@ public synchronized void reconfigure(final GlassFishLogHandlerConfiguration newC
}


// this is only to be able to provide the handle to the LogFileManager
@Override
public void setOutputStream(final OutputStream out) throws SecurityException {
super.setOutputStream(out);
}


/**
* Does not publish the record, but puts it into the queue buffer to be processed by an internal
* thread.
Expand Down Expand Up @@ -253,9 +245,8 @@ public boolean isLoggable(final LogRecord record) {

@Override
public void flush() {
super.flush();
if (this.logFileManager != null) {
this.logFileManager.rollIfFileTooBig();
if (logFileManager != null) {
logFileManager.flush();
}
}

Expand Down Expand Up @@ -288,7 +279,6 @@ public synchronized void close() {
this.rotationTimerTask = null;
}
this.rotationTimer.cancel();
stopPump();
try {
LoggingSystemEnvironment.resetStandardOutputs();
if (this.stdoutStream != null) {
Expand All @@ -304,9 +294,7 @@ public synchronized void close() {
error(GlassFishLogHandler.class, "close partially failed!", e);
}

if (this.logFileManager != null) {
this.logFileManager.disableOutput();
}
stopPump();
}


Expand All @@ -329,19 +317,17 @@ private GlassFishLogHandlerStatus startLoggingIfPossible() {
return GlassFishLogHandlerStatus.ACCEPTING;
}

this.logFileManager = new LogFileManager(this.configuration.getLogFile(),
this.logFileManager = new LogFileManager(this.configuration.getLogFile(), this.configuration.getEncoding(),
this.configuration.getRotationSizeLimitBytes(), this.configuration.isCompressionOnRotation(),
this.configuration.getMaxArchiveFiles(), this::setOutputStream, super::close);
this.configuration.getMaxArchiveFiles());

final Formatter formatter = configuration.getFormatterConfiguration();
if (configuration.getLogFile().length() > 0) {
final String detectedFormatterName = new LogFormatDetector().detectFormatter(configuration.getLogFile());
if (detectedFormatterName == null || !formatter.getClass().getName().equals(detectedFormatterName)) {
this.logFileManager.roll();
}
}
setFormatter(formatter);
this.logFileManager.enableOutput();
if (isRollRequired(configuration.getLogFile(), formatter)) {
logFileManager.roll();
}
// Output is disabled after the creation of the LogFileManager.
logFileManager.enableOutput();
updateRollSchedule();

// enable only if everything else was ok to prevent situation when
Expand All @@ -364,16 +350,28 @@ private synchronized void stopPump() {
this.pump.interrupt();
this.pump = null;
}

if (logFileManager == null) {
return;
}

// we cannot publish anything if we don't have the stream configured.
if (this.logFileManager != null && this.logFileManager.isOutputEnabled()) {
// This protects us from the risk that this thread will not be fast enough to process
// all records and more is still coming. Records which would come after this
// process started will not be processed.
long counter = this.logRecordBuffer.getSize();
while (counter-- >= 0) {
if (!publishRecord(this.logRecordBuffer.poll())) {
return;
}
if (this.logFileManager.isOutputEnabled()) {
drainLogRecords();
}
this.logFileManager.disableOutput();
this.logFileManager = null;
}


private void drainLogRecords() {
// The counter protects us from the risk that this thread will not be fast enough to process
// all records and more are still coming. Records which would come after this process
// started will not be processed.
long counter = this.logRecordBuffer.getSize();
while (counter-- >= 0) {
if (!publishRecord(this.logRecordBuffer.poll())) {
return;
}
}
}
Expand Down Expand Up @@ -408,7 +406,7 @@ private void updateRollSchedule() {
/**
* If the file is not empty, rolls. Then updates the next roll schedule.
*/
private void scheduledRoll() {
private synchronized void scheduledRoll() {
this.logFileManager.rollIfFileNotEmpty();
updateRollSchedule();
}
Expand All @@ -424,11 +422,36 @@ private boolean publishRecord(final GlassFishLogRecord record) {
if (record == null) {
return false;
}
super.publish(record);
if (!isLoggable(record)) {
return true;
}
final String msg;
try {
msg = getFormatter().format(record);
} catch (Exception ex) {
// We don't want to throw an exception here, but we
// report the exception to any registered ErrorManager.
reportError(null, ex, ErrorManager.FORMAT_FAILURE);
return true;
}

if (!doneHeader) {
logFileManager.write(getFormatter().getHead(this));
doneHeader = true;
}
logFileManager.write(msg);
return true;
}


private static boolean isRollRequired(final File logFile, final Formatter formatter) {
if (logFile.length() == 0) {
return false;
}
final String detectedFormatterName = new LogFormatDetector().detectFormatter(logFile);
return detectedFormatterName == null || !formatter.getClass().getName().equals(detectedFormatterName);
}

private final class LoggingPump extends LoggingPumpThread {

private LoggingPump(String threadName, LogRecordBuffer buffer) {
Expand Down
@@ -0,0 +1,152 @@
/*
* Copyright (c) 2024 Contributors to the Eclipse Foundation
*
* This program and the accompanying materials are made available under the
* terms of the Eclipse Public License v. 2.0, which is available at
* http://www.eclipse.org/legal/epl-2.0.
*
* This Source Code may also be made available under the following Secondary
* Licenses when the conditions for such availability set forth in the
* Eclipse Public License v. 2.0 are satisfied: GNU General Public License,
* version 2 with the GNU Classpath Exception, which is available at
* https://www.gnu.org/software/classpath/license.html.
*
* SPDX-License-Identifier: EPL-2.0 OR GPL-2.0 WITH Classpath-exception-2.0
*/

package org.glassfish.main.jul.rotation;

import java.io.File;
import java.io.FileFilter;
import java.io.FileInputStream;
import java.io.FileOutputStream;
import java.io.IOException;
import java.lang.System.Logger;
import java.util.Arrays;
import java.util.Comparator;
import java.util.zip.GZIPOutputStream;

import org.glassfish.main.jul.tracing.GlassFishLoggingTracer;

import static java.lang.System.Logger.Level.ERROR;
import static java.lang.System.Logger.Level.INFO;

/**
* LogFileArchiver manages history of log files, compresses them into gz files, removes old files.
*/
class LogFileArchiver {
private static final Logger LOG = System.getLogger(LogFileArchiver.class.getName());
private static final String GZIP_EXTENSION = ".gz";

private final File mainLogFile;
private final boolean compressOldLogFiles;
private final int maxCountOfOldLogFiles;


LogFileArchiver(File mainLogFile, boolean compressOldLogFiles, final int maxCountOfOldLogFiles) {
this.mainLogFile = mainLogFile;
this.compressOldLogFiles = compressOldLogFiles;
this.maxCountOfOldLogFiles = maxCountOfOldLogFiles;
}


/**
* @return file with a name ie. server.log_2024-01-13T11-45-37.gz
*/
File getGzArchiveFile(final File rotatedFile) {
return new File(rotatedFile.getParentFile(), rotatedFile.getName() + GZIP_EXTENSION);
}


/**
* There is no need to block processing of new log records with this time consuming action,
* so this starts a parallel thread.
* However the cleanup is done in synchronized method to avoid collisions in a case when
* there would be more parallel slow threads.
*
* @param archivedFile
*/
void archive(File archivedFile) {
final Runnable cleanup = () -> cleanUpHistoryLogFiles(archivedFile);
new Thread(cleanup, "old-log-files-cleanup-" + mainLogFile.getName()).start();
}


private synchronized void cleanUpHistoryLogFiles(final File rotatedFile) {
if (this.compressOldLogFiles) {
compressFile(rotatedFile);
}
deleteOldLogFiles();
}


private void compressFile(final File rotatedFile) {
final long start = System.currentTimeMillis();
final File outFile = getGzArchiveFile(rotatedFile);
final boolean compressed = gzipFile(rotatedFile, outFile);
if (!compressed) {
logError("Could not compress log file: " + rotatedFile.getAbsolutePath());
return;
}
final long time = System.currentTimeMillis() - start;
LOG.log(INFO, "File {0} of size {1} has been archived to file {2} of size {3} in {4} ms",
rotatedFile, rotatedFile.length(), outFile, outFile.length(), time);
final boolean deleted = rotatedFile.delete();
if (!deleted) {
logError("Could not delete uncompressed log file: " + rotatedFile.getAbsolutePath());
}
}


private boolean gzipFile(final File inputFile, final File outputFile) {
try (
FileInputStream fis = new FileInputStream(inputFile);
FileOutputStream fos = new FileOutputStream(outputFile);
GZIPOutputStream gzos = new GZIPOutputStream(fos)
) {
byte[] buffer = new byte[1024];
int len;
while ((len = fis.read(buffer)) != -1) {
gzos.write(buffer, 0, len);
}
gzos.finish();
return true;
} catch (IOException e) {
final String message = "Error gzipping log file " + inputFile;
GlassFishLoggingTracer.error(getClass(), message, e);
LOG.log(ERROR, message, e);
return false;
}
}


private void deleteOldLogFiles() {
if (this.maxCountOfOldLogFiles == 0) {
return;
}

final File dir = this.mainLogFile.getParentFile();
final String logFileName = this.mainLogFile.getName();
if (dir == null) {
return;
}
final FileFilter filter = f -> f.isFile() && !f.getName().equals(logFileName)
&& f.getName().startsWith(logFileName);
Arrays.stream(dir.listFiles(filter)).sorted(Comparator.comparing(File::getName).reversed())
.skip(this.maxCountOfOldLogFiles).forEach(this::deleteFile);
}


private void deleteFile(final File file) {
final boolean delFile = file.delete();
if (!delFile) {
logError("Could not delete the log file: " + file);
}
}


private void logError(final String message) {
GlassFishLoggingTracer.error(getClass(), message);
LOG.log(ERROR, message);
}
}

0 comments on commit fe2e65d

Please sign in to comment.