Individualizing loggers on journal

This commit is contained in:
Clebert Suconic 2016-04-28 14:26:51 -04:00
parent f0df9d8c78
commit 7bebe507cf
5 changed files with 73 additions and 97 deletions

View File

@ -33,10 +33,11 @@ import org.apache.activemq.artemis.jlibaio.LibaioFile;
import org.apache.activemq.artemis.jlibaio.SubmitInfo;
import org.apache.activemq.artemis.jlibaio.util.CallbackCache;
import org.apache.activemq.artemis.journal.ActiveMQJournalLogger;
import org.jboss.logging.Logger;
public final class AIOSequentialFileFactory extends AbstractSequentialFileFactory {
private static final boolean trace = ActiveMQJournalLogger.LOGGER.isTraceEnabled();
private static final Logger logger = Logger.getLogger(AIOSequentialFileFactory.class);
private final ReuseBuffersController buffersControl = new ReuseBuffersController();
@ -52,13 +53,6 @@ public final class AIOSequentialFileFactory extends AbstractSequentialFileFactor
private static final String AIO_TEST_FILE = ".aio-test";
// This method exists just to make debug easier.
// I could replace log.trace by log.info temporarily while I was debugging
// Journal
private static void trace(final String message) {
ActiveMQJournalLogger.LOGGER.trace(message);
}
public AIOSequentialFileFactory(final File journalDir, int maxIO) {
this(journalDir, ArtemisConstants.DEFAULT_JOURNAL_BUFFER_SIZE_AIO, ArtemisConstants.DEFAULT_JOURNAL_BUFFER_TIMEOUT_AIO, maxIO, false, null);
}
@ -398,8 +392,8 @@ public final class AIOSequentialFileFactory extends AbstractSequentialFileFactor
// This is being done this way as we don't need another Timeout Thread
// just to cleanup this
if (bufferSize > 0 && System.currentTimeMillis() - bufferReuseLastTime > 10000) {
if (AIOSequentialFileFactory.trace) {
AIOSequentialFileFactory.trace("Clearing reuse buffers queue with " + reuseBuffersQueue.size() +
if (logger.isTraceEnabled()) {
logger.trace("Clearing reuse buffers queue with " + reuseBuffersQueue.size() +
" elements");
}

View File

@ -24,8 +24,7 @@ import org.jboss.logging.Logger;
public class FileIOUtil {
private static final Logger logger = Logger.getLogger(Logger.class);
private static final boolean isTrace = logger.isTraceEnabled();
private static final Logger logger = Logger.getLogger(FileIOUtil.class);
public static void copyData(SequentialFile from, SequentialFile to, ByteBuffer buffer) throws Exception {
@ -50,7 +49,7 @@ public class FileIOUtil {
buffer.clear();
int bytesRead = from.read(buffer);
if (isTrace) {
if (logger.isTraceEnabled()) {
logger.trace("appending " + bytesRead + " bytes on " + to.getFileName());
}

View File

@ -36,6 +36,7 @@ import org.apache.activemq.artemis.core.io.SequentialFile;
import org.apache.activemq.artemis.core.io.SequentialFileFactory;
import org.apache.activemq.artemis.journal.ActiveMQJournalBundle;
import org.apache.activemq.artemis.journal.ActiveMQJournalLogger;
import org.jboss.logging.Logger;
/**
* This is a helper class for the Journal, which will control access to dataFiles, openedFiles and freeFiles
@ -43,7 +44,7 @@ import org.apache.activemq.artemis.journal.ActiveMQJournalLogger;
*/
public class JournalFilesRepository {
private static final boolean trace = ActiveMQJournalLogger.LOGGER.isTraceEnabled();
private static final Logger logger = Logger.getLogger(JournalFilesRepository.class);
/**
* Used to debug the consistency of the journal ordering.
@ -52,13 +53,6 @@ public class JournalFilesRepository {
*/
private static final boolean CHECK_CONSISTENCE = false;
// This method exists just to make debug easier.
// I could replace log.trace by log.info temporarily while I was debugging
// Journal
private static void trace(final String message) {
ActiveMQJournalLogger.LOGGER.trace(message);
}
private final SequentialFileFactory fileFactory;
private final JournalImpl journal;
@ -365,8 +359,8 @@ public class JournalFilesRepository {
else if (!checkDelete || (freeFilesCount.get() + dataFiles.size() + 1 + openedFiles.size() < poolSize) || (poolSize < 0)) {
// Re-initialise it
if (JournalFilesRepository.trace) {
JournalFilesRepository.trace("Adding free file " + file);
if (logger.isTraceEnabled()) {
logger.trace("Adding free file " + file);
}
JournalFile jf = reinitializeFile(file);
@ -379,15 +373,14 @@ public class JournalFilesRepository {
freeFilesCount.getAndIncrement();
}
else {
if (trace) {
ActiveMQJournalLogger.LOGGER.trace("DataFiles.size() = " + dataFiles.size());
ActiveMQJournalLogger.LOGGER.trace("openedFiles.size() = " + openedFiles.size());
ActiveMQJournalLogger.LOGGER.trace("minfiles = " + minFiles + ", poolSize = " + poolSize);
ActiveMQJournalLogger.LOGGER.trace("Free Files = " + freeFilesCount.get());
ActiveMQJournalLogger.LOGGER.trace("File " + file +
" being deleted as freeFiles.size() + dataFiles.size() + 1 + openedFiles.size() (" +
(freeFilesCount.get() + dataFiles.size() + 1 + openedFiles.size()) +
") < minFiles (" + minFiles + ")");
if (logger.isTraceEnabled()) {
logger.trace("DataFiles.size() = " + dataFiles.size());
logger.trace("openedFiles.size() = " + openedFiles.size());
logger.trace("minfiles = " + minFiles + ", poolSize = " + poolSize);
logger.trace("Free Files = " + freeFilesCount.get());
logger.trace("File " + file + " being deleted as freeFiles.size() + dataFiles.size() + 1 + openedFiles.size() (" +
(freeFilesCount.get() + dataFiles.size() + 1 + openedFiles.size()) +
") < minFiles (" + minFiles + ")");
}
file.getFile().delete();
}
@ -421,8 +414,8 @@ public class JournalFilesRepository {
* @throws ActiveMQIOErrorException In case the file could not be opened
*/
public JournalFile openFile() throws InterruptedException, ActiveMQIOErrorException {
if (JournalFilesRepository.trace) {
JournalFilesRepository.trace("enqueueOpenFile with openedFiles.size=" + openedFiles.size());
if (logger.isTraceEnabled()) {
logger.trace("enqueueOpenFile with openedFiles.size=" + openedFiles.size());
}
if (openFilesExecutor == null) {
@ -441,8 +434,8 @@ public class JournalFilesRepository {
throw ActiveMQJournalBundle.BUNDLE.fileNotOpened();
}
if (JournalFilesRepository.trace) {
JournalFilesRepository.trace("Returning file " + nextFile);
if (logger.isTraceEnabled()) {
logger.trace("Returning file " + nextFile);
}
return nextFile;
@ -454,8 +447,8 @@ public class JournalFilesRepository {
public void pushOpenedFile() throws Exception {
JournalFile nextOpenedFile = takeFile(true, true, true, false);
if (JournalFilesRepository.trace) {
JournalFilesRepository.trace("pushing openFile " + nextOpenedFile);
if (logger.isTraceEnabled()) {
logger.trace("pushing openFile " + nextOpenedFile);
}
if (!openedFiles.offer(nextOpenedFile)) {
@ -580,8 +573,8 @@ public class JournalFilesRepository {
final String fileName = createFileName(tmpCompact, fileID);
if (JournalFilesRepository.trace) {
JournalFilesRepository.trace("Creating file " + fileName);
if (logger.isTraceEnabled()) {
logger.trace("Creating file " + fileName);
}
String tmpFileName = fileName + ".tmp";
@ -600,8 +593,8 @@ public class JournalFilesRepository {
sequentialFile.close();
if (JournalFilesRepository.trace) {
JournalFilesRepository.trace("Renaming file " + tmpFileName + " as " + fileName);
if (logger.isTraceEnabled()) {
logger.trace("Renaming file " + tmpFileName + " as " + fileName);
}
sequentialFile.renameTo(fileName);

View File

@ -69,6 +69,7 @@ import org.apache.activemq.artemis.journal.ActiveMQJournalBundle;
import org.apache.activemq.artemis.journal.ActiveMQJournalLogger;
import org.apache.activemq.artemis.utils.ConcurrentHashSet;
import org.apache.activemq.artemis.utils.DataConstants;
import org.jboss.logging.Logger;
/**
* <p>A circular log implementation.</p>
@ -84,22 +85,7 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
private static final int[] COMPATIBLE_VERSIONS = new int[]{1};
// Static --------------------------------------------------------
private static final boolean trace = ActiveMQJournalLogger.LOGGER.isTraceEnabled();
// This is useful at debug time...
// if you set it to true, all the appends, deletes, rollbacks, commits, etc.. are sent to System.out
private static final boolean TRACE_RECORDS = trace;
// This method exists just to make debug easier.
// I could replace log.trace by log.info temporarily while I was debugging
// Journal
private static void trace(final String message) {
ActiveMQJournalLogger.LOGGER.trace(message);
}
private static void traceRecord(final String message) {
ActiveMQJournalLogger.LOGGER.trace(message);
}
private static final Logger logger = Logger.getLogger(JournalImpl.class);
// The sizes of primitive types
@ -550,7 +536,7 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
preparedTransactionExtraDataSize)) {
// Avoid a buffer overflow caused by damaged data... continue
// scanning for more pendingTransactions...
JournalImpl.trace("Record at position " + pos +
logger.trace("Record at position " + pos +
" recordType = " +
recordType +
" file:" +
@ -583,7 +569,7 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
// This is like testing a hash for the record. (We could replace the
// checkSize by some sort of calculated hash)
if (checkSize != variableSize + recordSize + preparedTransactionExtraDataSize) {
JournalImpl.trace("Record at position " + pos +
logger.trace("Record at position " + pos +
" recordType = " +
recordType +
" possible transactionID = " +
@ -722,10 +708,11 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
synchronized (lockAppend) {
JournalFile usedFile = appendRecord(addRecord, false, sync, null, callback);
if (JournalImpl.TRACE_RECORDS) {
JournalImpl.traceRecord("appendAddRecord::id=" + id +
if (logger.isTraceEnabled()) {
logger.trace("appendAddRecord::id=" + id +
", userRecordType=" +
recordType +
", record = " + record +
", usedFile = " +
usedFile);
}
@ -766,10 +753,11 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
synchronized (lockAppend) {
JournalFile usedFile = appendRecord(updateRecord, false, sync, null, callback);
if (JournalImpl.TRACE_RECORDS) {
JournalImpl.traceRecord("appendUpdateRecord::id=" + id +
if (logger.isTraceEnabled()) {
logger.trace("appendUpdateRecord::id=" + id +
", userRecordType=" +
recordType +
", record = " + record +
", usedFile = " +
usedFile);
}
@ -820,8 +808,8 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
synchronized (lockAppend) {
JournalFile usedFile = appendRecord(deleteRecord, false, sync, null, callback);
if (JournalImpl.TRACE_RECORDS) {
JournalImpl.traceRecord("appendDeleteRecord::id=" + id + ", usedFile = " + usedFile);
if (logger.isTraceEnabled()) {
logger.trace("appendDeleteRecord::id=" + id + ", usedFile = " + usedFile);
}
// record== null here could only mean there is a compactor, and computing the delete should be done after
@ -857,12 +845,13 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
synchronized (lockAppend) {
JournalFile usedFile = appendRecord(addRecord, false, false, tx, null);
if (JournalImpl.TRACE_RECORDS) {
JournalImpl.traceRecord("appendAddRecordTransactional:txID=" + txID +
if (logger.isTraceEnabled()) {
logger.trace("appendAddRecordTransactional:txID=" + txID +
",id=" +
id +
", userRecordType=" +
recordType +
", record = " + record +
", usedFile = " +
usedFile);
}
@ -902,12 +891,13 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
synchronized (lockAppend) {
JournalFile usedFile = appendRecord(updateRecordTX, false, false, tx, null);
if (JournalImpl.TRACE_RECORDS) {
JournalImpl.traceRecord("appendUpdateRecordTransactional::txID=" + txID +
if (logger.isTraceEnabled()) {
logger.trace("appendUpdateRecordTransactional::txID=" + txID +
",id=" +
id +
", userRecordType=" +
recordType +
", record = " + record +
", usedFile = " +
usedFile);
}
@ -936,8 +926,8 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
synchronized (lockAppend) {
JournalFile usedFile = appendRecord(deleteRecordTX, false, false, tx, null);
if (JournalImpl.TRACE_RECORDS) {
JournalImpl.traceRecord("appendDeleteRecordTransactional::txID=" + txID +
if (logger.isTraceEnabled()) {
logger.trace("appendDeleteRecordTransactional::txID=" + txID +
", id=" +
id +
", usedFile = " +
@ -986,8 +976,8 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
synchronized (lockAppend) {
JournalFile usedFile = appendRecord(prepareRecord, true, sync, tx, callback);
if (JournalImpl.TRACE_RECORDS) {
JournalImpl.traceRecord("appendPrepareRecord::txID=" + txID + ", usedFile = " + usedFile);
if (logger.isTraceEnabled()) {
logger.trace("appendPrepareRecord::txID=" + txID + ", usedFile = " + usedFile);
}
tx.prepare(usedFile);
@ -1032,8 +1022,8 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
synchronized (lockAppend) {
JournalFile usedFile = appendRecord(commitRecord, true, sync, tx, callback);
if (JournalImpl.TRACE_RECORDS) {
JournalImpl.traceRecord("appendCommitRecord::txID=" + txID + ", usedFile = " + usedFile);
if (logger.isTraceEnabled()) {
logger.trace("appendCommitRecord::txID=" + txID + ", usedFile = " + usedFile);
}
tx.commit(usedFile);
@ -1301,7 +1291,7 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
filesRepository.clearDataFiles();
if (dataFilesToProcess.size() == 0) {
trace("Finishing compacting, nothing to process");
logger.trace("Finishing compacting, nothing to process");
return;
}
@ -1367,14 +1357,14 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
// Restore compacted dataFiles
for (int i = newDatafiles.size() - 1; i >= 0; i--) {
JournalFile fileToAdd = newDatafiles.get(i);
if (JournalImpl.trace) {
JournalImpl.trace("Adding file " + fileToAdd + " back as datafile");
if (logger.isTraceEnabled()) {
logger.trace("Adding file " + fileToAdd + " back as datafile");
}
filesRepository.addDataFileOnTop(fileToAdd);
}
if (JournalImpl.trace) {
JournalImpl.trace("There are " + filesRepository.getDataFilesCount() + " datafiles Now");
if (logger.isTraceEnabled()) {
logger.trace("There are " + filesRepository.getDataFilesCount() + " datafiles Now");
}
// Replay pending commands (including updates, deletes and commits)
@ -1390,8 +1380,8 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
// that happened during the compacting
for (JournalTransaction newTransaction : localCompactor.getNewTransactions().values()) {
if (JournalImpl.trace) {
JournalImpl.trace("Merging pending transaction " + newTransaction + " after compacting the journal");
if (logger.isTraceEnabled()) {
logger.trace("Merging pending transaction " + newTransaction + " after compacting the journal");
}
JournalTransaction liveTransaction = transactions.get(newTransaction.getId());
if (liveTransaction != null) {
@ -1513,7 +1503,7 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
final AtomicLong maxID = new AtomicLong(-1);
for (final JournalFile file : orderedFiles) {
JournalImpl.trace("Loading file " + file.getFile().getFileName());
logger.trace("Loading file " + file.getFile().getFileName());
final AtomicBoolean hasData = new AtomicBoolean(false);
@ -1824,8 +1814,8 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
for (JournalFile file : filesRepository.getDataFiles()) {
if (file.isCanReclaim()) {
// File can be reclaimed or deleted
if (JournalImpl.trace) {
JournalImpl.trace("Reclaiming file " + file);
if (logger.isTraceEnabled()) {
logger.trace("Reclaiming file " + file);
}
filesRepository.removeDataFile(file);
@ -2800,8 +2790,8 @@ public class JournalImpl extends JournalBase implements TestableJournal, Journal
scheduleReclaim();
}
if (trace) {
ActiveMQJournalLogger.LOGGER.trace("Moving next file " + currentFile);
if (logger.isTraceEnabled()) {
logger.trace("Moving next file " + currentFile);
}
fileFactory.activateBuffer(currentFile.getFile());

View File

@ -16,7 +16,7 @@
*/
package org.apache.activemq.artemis.core.journal.impl;
import org.apache.activemq.artemis.journal.ActiveMQJournalLogger;
import org.jboss.logging.Logger;
/**
* <p>The journal consists of an ordered list of journal files Fn where {@code 0 <= n <= N}</p>
@ -34,10 +34,10 @@ import org.apache.activemq.artemis.journal.ActiveMQJournalLogger;
*/
public class Reclaimer {
private static boolean trace = ActiveMQJournalLogger.LOGGER.isTraceEnabled();
private static final Logger logger = Logger.getLogger(Reclaimer.class);
private static void trace(final String message) {
ActiveMQJournalLogger.LOGGER.trace(message);
logger.trace(message);
}
public void scan(final JournalFile[] files) {
@ -50,14 +50,14 @@ public class Reclaimer {
int totNeg = 0;
if (Reclaimer.trace) {
Reclaimer.trace("posCount on " + currentFile + " = " + posCount);
if (logger.isTraceEnabled()) {
logger.trace("posCount on " + currentFile + " = " + posCount);
}
for (int j = i; j < files.length; j++) {
if (Reclaimer.trace) {
if (logger.isTraceEnabled()) {
if (files[j].getNegCount(currentFile) != 0) {
Reclaimer.trace("Negative from " + files[j] +
logger.trace("Negative from " + files[j] +
" into " +
currentFile +
" = " +
@ -83,8 +83,8 @@ public class Reclaimer {
// Ok
}
else {
if (Reclaimer.trace) {
Reclaimer.trace(currentFile + " Can't be reclaimed because " + file + " has negative values");
if (logger.isTraceEnabled()) {
logger.trace(currentFile + " Can't be reclaimed because " + file + " has negative values");
}
currentFile.setCanReclaim(false);