From 934df645c8afc849908379ab681d2ba6aeb3c20d Mon Sep 17 00:00:00 2001 From: Sven Diedrichsen Date: Fri, 1 Feb 2019 14:09:40 +0100 Subject: [PATCH] Prevent cpu wastage when not logging to file (#3508) * #3506 prevent processor wastage when not logging to file. Only start pump thread if logging to file. Store into queue only if logging to file. * add logToFile to the pumps loop condition to stop looping if logToFile is set to false. * draining pendingRecords if the pump gets disabled. reusing the draining code for the log method. * initialize collection to drain to with the correct size * Adding call to flush() after draining pending records. --- .../server/logging/GFFileHandler.java | 136 +++++++++++------- 1 file changed, 83 insertions(+), 53 deletions(-) diff --git a/nucleus/core/logging/src/main/java/com/sun/enterprise/server/logging/GFFileHandler.java b/nucleus/core/logging/src/main/java/com/sun/enterprise/server/logging/GFFileHandler.java index a55719a4d0d..e2ef3f34c29 100644 --- a/nucleus/core/logging/src/main/java/com/sun/enterprise/server/logging/GFFileHandler.java +++ b/nucleus/core/logging/src/main/java/com/sun/enterprise/server/logging/GFFileHandler.java @@ -195,19 +195,12 @@ public void postConstruct() { changeFileName(logFile); // Reading just few lines of log file to get the log formatter used. - String strLine = ""; + String strLine; int odlFormatter = 0; int uniformLogFormatter = 0; int otherFormatter = 0; boolean mustRotate = false; - String propertyValue = manager.getProperty(className + ".logtoFile"); - logToFile = true; - - if (propertyValue != null) { - logToFile = Boolean.parseBoolean(propertyValue); - } - try (BufferedReader br = new BufferedReader(new FileReader(logFile))) { while ((strLine = br.readLine()) != null) { strLine = strLine.trim(); @@ -242,8 +235,12 @@ public void postConstruct() { currentFileHandlerFormatter = "com.sun.enterprise.server.logging.UniformLogFormatter"; } - // start the Queue consumer thread. - initializePump(); + String propertyValue = manager.getProperty(className + ".logtoFile"); + boolean logToFile = true; + if (propertyValue != null) { + logToFile = Boolean.parseBoolean(propertyValue); + } + setLogToFile(logToFile); logRecord.setParameters(new Object[]{Version.getFullVersion()}); logRecord.setResourceBundle(ResourceBundle.getBundle(LogFacade.LOGGING_RB_NAME)); @@ -569,18 +566,27 @@ private void configureUniformLogFormatter(String excludeFields, boolean multiLin } void initializePump() { - pumpFuture = payaraExecutorService.submit( - () -> { - while (!done.isSignalled()) { - try { - log(); - } catch (Exception e) { - // GLASSFISH-19125 - // Continue the loop without exiting + if (pumpFuture != null) { + pumpFuture.cancel(true); + pumpFuture = null; + } + if (logToFile) { + pumpFuture = payaraExecutorService.submit( + () -> { + while (!done.isSignalled() && logToFile) { + try { + log(); + } catch (Exception e) { + // GLASSFISH-19125 + // Continue the loop without exiting + } } } - } - ); + ); + } else { + drainAllPendingRecords(); + flush(); + } } @Override @@ -590,18 +596,38 @@ public void preDestroy() { LogFacade.LOGGING_LOGGER.fine("Logger handler killed"); } done.tryReleaseShared(1); - pumpFuture.cancel(true); + if (pumpFuture != null) { + pumpFuture.cancel(true); + } - // drain and return - final int size = pendingRecords.size(); - if (size > 0) { - Collection records = new ArrayList<>(size); - pendingRecords.drainTo(records, size); + // drain and return all + drainAllPendingRecords(); + flush(); + } + + private void drainAllPendingRecords() { + drainPendingRecords(0); + } + + /** + * Drains the amount of {@link LogRecord}s in the pending records queue. + * If passed in the amount <= 0 all of the records get drained. + * @param flushAmount number of records to drain from the queue of pending records. + */ + private void drainPendingRecords(int flushAmount) { + if (!pendingRecords.isEmpty()) { + Collection records; + if (flushAmount > 0) { + records = new ArrayList<>(flushAmount); + pendingRecords.drainTo(records, flushAmount); + } else { + records = new ArrayList<>(pendingRecords.size()); + pendingRecords.drainTo(records); + } for (LogRecord record : records) { super.publish(record); } } - } /** @@ -677,7 +703,7 @@ private void configureJSONFormatter(String excludeFields) { */ private static final class MeteredStream extends OutputStream { - private volatile boolean isOpen = false; + private volatile boolean isOpen; OutputStream out; long written; @@ -695,13 +721,13 @@ public void write(int b) throws IOException { } @Override - public void write(byte buff[]) throws IOException { + public void write(byte[] buff) throws IOException { out.write(buff); written += buff.length; } @Override - public void write(byte buff[], int off, int len) throws IOException { + public void write(byte[] buff, int off, int len) throws IOException { out.write(buff, off, len); written += len; } @@ -907,23 +933,22 @@ record = pendingRecords.take(); return; } - // now try to read more. we end up blocking on the above take call if nothing is in the queue - List v = new ArrayList<>(); - int msgs = pendingRecords.drainTo(v, flushFrequency); - for (int j = 0; j < msgs; j++) { - super.publish(v.get(j)); + if (flushFrequency > 1) { + // now try to read more. we end up blocking on the above take call if nothing is in the queue + drainPendingRecords(flushFrequency - 1); } - } - flush(); - if ((rotationRequested.get()) - || ((limitForFileRotation > 0) - && (meter.written >= limitForFileRotation))) { - // If we have written more than the limit set for the - // file, or rotation requested from the Timer Task or LogMBean - // start fresh with a new file after renaming the old file. - synchronized (rotationLock) { - rotate(); - rotationRequested.set(false); + + flush(); + if ((rotationRequested.get()) + || ((limitForFileRotation > 0) + && (meter.written >= limitForFileRotation))) { + // If we have written more than the limit set for the + // file, or rotation requested from the Timer Task or LogMBean + // start fresh with a new file after renaming the old file. + synchronized (rotationLock) { + rotate(); + rotationRequested.set(false); + } } } } @@ -961,14 +986,18 @@ public void publish(LogRecord record) { recordWrapper.setThreadName(Thread.currentThread().getName()); } - try { - pendingRecords.add(recordWrapper); - } catch (IllegalStateException e) { - // queue is full, start waiting. + if (logToFile) { try { - pendingRecords.put(recordWrapper); - } catch (InterruptedException e1) { - // too bad, record is lost... + pendingRecords.add(recordWrapper); + } catch (IllegalStateException e) { + // queue is full, start waiting. + new ErrorManager().error("GFFileHandler: Queue full. Waiting to submit.", e, ErrorManager.GENERIC_FAILURE); + try { + pendingRecords.put(recordWrapper); + } catch (InterruptedException e1) { + // too bad, record is lost... + new ErrorManager().error("GFFileHandler: Waiting was interrupted. Log record lost.", e1, ErrorManager.GENERIC_FAILURE); + } } } @@ -1041,6 +1070,7 @@ public synchronized void setLogFile(String fileName) { public synchronized void setLogToFile(boolean logToFile) { this.logToFile = logToFile; + initializePump(); } public synchronized void setRotationOnDateChange(boolean rotationOnDateChange) {