Skip to content

Commit

Permalink
Prevent cpu wastage when not logging to file (#3508)
Browse files Browse the repository at this point in the history
* #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.
  • Loading branch information
svendiedrichsen authored and MattGill98 committed Feb 1, 2019
1 parent c3c1aaf commit 934df64
Showing 1 changed file with 83 additions and 53 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand Down Expand Up @@ -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));
Expand Down Expand Up @@ -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
Expand All @@ -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<LogRecord> 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<LogRecord> 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);
}
}

}

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

Expand Down Expand Up @@ -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) {
Expand Down

0 comments on commit 934df64

Please sign in to comment.