diff --git a/symmetric-core/src/main/java/org/jumpmind/symmetric/io/DbCompareDiffWriter.java b/symmetric-core/src/main/java/org/jumpmind/symmetric/io/DbCompareDiffWriter.java index 668ae81ef2..1a12e79725 100644 --- a/symmetric-core/src/main/java/org/jumpmind/symmetric/io/DbCompareDiffWriter.java +++ b/symmetric-core/src/main/java/org/jumpmind/symmetric/io/DbCompareDiffWriter.java @@ -171,6 +171,9 @@ protected FileOutputStream initStreamIfNeeded(FileOutputStream diffStream, Strin if (diffStream != null) { return diffStream; } else { + if (fileName == null) { + return null; + } log.info("Writing diffs to {}", fileName); try { return new FileOutputStream(fileName); diff --git a/symmetric-core/src/main/java/org/jumpmind/symmetric/service/impl/DataLoaderService.java b/symmetric-core/src/main/java/org/jumpmind/symmetric/service/impl/DataLoaderService.java index 6abf60e61d..377a66c406 100644 --- a/symmetric-core/src/main/java/org/jumpmind/symmetric/service/impl/DataLoaderService.java +++ b/symmetric-core/src/main/java/org/jumpmind/symmetric/service/impl/DataLoaderService.java @@ -37,10 +37,8 @@ import java.util.HashMap; import java.util.List; import java.util.Map; -import java.util.concurrent.ConcurrentHashMap; import org.apache.commons.lang.StringUtils; -import org.apache.commons.lang.exception.ExceptionUtils; import org.jumpmind.db.model.Table; import org.jumpmind.db.sql.ISqlRowMapper; import org.jumpmind.db.sql.ISqlTransaction; @@ -123,7 +121,6 @@ import org.jumpmind.symmetric.transport.http.HttpTransportManager; import org.jumpmind.symmetric.transport.internal.InternalIncomingTransport; import org.jumpmind.symmetric.web.WebConstants; -import org.jumpmind.util.LogSuppressor; /** * Responsible for writing batch data to the database @@ -158,8 +155,6 @@ public class DataLoaderService extends AbstractService implements IDataLoaderSer private Date lastUpdateTime; - private final LogSuppressor logSuppressor = new LogSuppressor(log); - public DataLoaderService(ISymmetricEngine engine) { super(engine.getParameterService(), engine.getSymmetricDialect()); this.incomingBatchService = engine.getIncomingBatchService(); @@ -307,7 +302,7 @@ public void loadDataFromPull(Node remote, RemoteNodeStatus status) throws IOExce } catch (RegistrationRequiredException e) { if (StringUtils.isBlank(remote.getSyncUrl()) || remote.getSyncUrl().equals(parameterService.getRegistrationUrl())) { - log.warn("Node information missing on the server. Attempting to re-register"); + log.warn("Node information missing on the server. Attempting to re-register remote.getSyncUrl()={}", remote.getSyncUrl()); loadDataFromPull(null, status); nodeService.findIdentity(false); } else { @@ -317,8 +312,8 @@ public void loadDataFromPull(Node remote, RemoteNodeStatus status) throws IOExce } } catch (MalformedURLException e) { if (remote != null) { - log.error("Could not connect to the {} node's transport because of a bad URL: {}", - remote.getNodeId(), remote.getSyncUrl()); + log.error("Could not connect to the {} node's transport because of a bad URL: '{}' {}", + remote.getNodeId(), remote.getSyncUrl(), e); } else { log.error("", e); } @@ -975,11 +970,10 @@ public void batchInError(DataContext context, Throwable ex) { if (ex instanceof IOException || ex instanceof TransportException || ex instanceof IoException) { - log.warn("Failed to load batch {} because: {}", - this.currentBatch.getNodeBatchId(), ex.getMessage()); + log.warn("Failed to load batch " + this.currentBatch.getNodeBatchId(), ex); this.currentBatch.setSqlMessage(ex.getMessage()); } else { - logBatchInError(ex); + log.error(String.format("Failed to load batch %s", this.currentBatch.getNodeBatchId()), ex); SQLException se = unwrapSqlException(ex); if (ex instanceof ConflictException) { @@ -1070,11 +1064,6 @@ public void batchInError(DataContext context, Throwable ex) { } } - protected void logBatchInError(Throwable ex) { - final String ERROR_KEY = this.currentBatch.getNodeBatchId() + ex.getMessage(); - logSuppressor.logError(ERROR_KEY, String.format("Failed to load batch %s", this.currentBatch.getNodeBatchId()), ex); - } - public List getBatchesProcessed() { return batchesProcessed; } diff --git a/symmetric-io/src/main/java/org/jumpmind/symmetric/io/data/writer/DefaultDatabaseWriter.java b/symmetric-io/src/main/java/org/jumpmind/symmetric/io/data/writer/DefaultDatabaseWriter.java index e0904bd95f..651fb64656 100644 --- a/symmetric-io/src/main/java/org/jumpmind/symmetric/io/data/writer/DefaultDatabaseWriter.java +++ b/symmetric-io/src/main/java/org/jumpmind/symmetric/io/data/writer/DefaultDatabaseWriter.java @@ -54,7 +54,6 @@ import org.jumpmind.symmetric.io.data.writer.Conflict.DetectExpressionKey; import org.jumpmind.util.CollectionUtils; import org.jumpmind.util.FormatUtils; -import org.jumpmind.util.LogSuppressor; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -71,8 +70,6 @@ public class DefaultDatabaseWriter extends AbstractDatabaseWriter { protected DmlStatement currentDmlStatement; protected Object[] currentDmlValues; - - protected static LogSuppressor logSuppressor = new LogSuppressor(log, 1); public DefaultDatabaseWriter(IDatabasePlatform platform) { this(platform, null, null); @@ -665,10 +662,8 @@ protected void logFailureDetails(Throwable e, CsvData data, boolean logLastDmlDe } data.writeCsvDataDetails(failureMessage); - - String msg = failureMessage.toString(); - logSuppressor.logInfo(msg, msg, null); - + + log.info(failureMessage.toString(), e); } @Override diff --git a/symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTemplate.java b/symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTemplate.java index 4322224d8a..d805e75734 100644 --- a/symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTemplate.java +++ b/symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTemplate.java @@ -79,13 +79,13 @@ public class JdbcSqlTemplate extends AbstractSqlTemplate implements ISqlTemplate protected int[] primaryKeyViolationCodes; protected String[] primaryKeyViolationSqlStates; - + protected String[] primaryKeyViolationMessageParts; protected int[] foreignKeyViolationCodes; protected String[] foreignKeyViolationSqlStates; - + protected String[] foreignKeyViolationMessageParts; protected int isolationLevel; @@ -134,7 +134,7 @@ public ISqlReadCursor queryForCursor(String sql, ISqlRowMapper mapper, ISqlReadCursor cursor = new JdbcSqlReadCursor(this, mapper, sql, args, types); long endTime = System.currentTimeMillis(); logSqlBuilder.logSql(log, sql, args, types, (endTime-startTime)); - + return cursor; } @@ -157,12 +157,12 @@ public T execute(Connection con) throws SQLException { ps = con.prepareStatement(expandedSql); ps.setQueryTimeout(settings.getQueryTimeout()); setValues(ps, expandArgs(sql, args)); - + long startTime = System.currentTimeMillis(); rs = ps.executeQuery(); long endTime = System.currentTimeMillis(); logSqlBuilder.logSql(log, expandedSql, args, null, (endTime-startTime)); - + if (rs.next()) { result = getObjectFromResultSet(rs, clazz); } @@ -184,7 +184,7 @@ public byte[] queryForBlob(final String sql, final Object... args) { public byte[] queryForBlob(final String sql, final int jdbcTypeCode, final String jdbcTypeName, final Object... args) { - + return execute(new IConnectionCallback() { public byte[] execute(Connection con) throws SQLException { if (lobHandler.needsAutoCommitFalseForBlob(jdbcTypeCode, jdbcTypeName)) { @@ -218,7 +218,7 @@ public byte[] execute(Connection con) throws SQLException { } }); } - + @Deprecated public String queryForClob(final String sql, final Object... args) { return queryForClob(sql, -1, null, args); @@ -234,12 +234,12 @@ public String execute(Connection con) throws SQLException { ps = con.prepareStatement(sql); ps.setQueryTimeout(settings.getQueryTimeout()); setValues(ps, args); - + long startTime = System.currentTimeMillis(); rs = ps.executeQuery(); long endTime = System.currentTimeMillis(); logSqlBuilder.logSql(log, sql, args, null, (endTime-startTime)); - + if (rs.next()) { result = lobHandler.getClobAsString(rs, 1, jdbcTypeCode, jdbcTypeName); } @@ -266,12 +266,12 @@ public Map execute(Connection con) throws SQLException { if (args != null && args.length > 0) { setValues(ps, args); } - + long startTime = System.currentTimeMillis(); rs = ps.executeQuery(); long endTime = System.currentTimeMillis(); logSqlBuilder.logSql(log, sql, args, null, (endTime-startTime)); - + if (rs.next()) { ResultSetMetaData meta = rs.getMetaData(); int colCount = meta.getColumnCount(); @@ -340,12 +340,12 @@ public Integer execute(Connection con) throws SQLException { try { stmt = con.createStatement(); stmt.setQueryTimeout(settings.getQueryTimeout()); - + long startTime = System.currentTimeMillis(); stmt.execute(sql); long endTime = System.currentTimeMillis(); logSqlBuilder.logSql(log, sql, args, types, (endTime-startTime)); - + return stmt.getUpdateCount(); } catch (SQLException e) { throw logSqlBuilder.logSqlAfterException(log, sql, args, e); @@ -368,7 +368,7 @@ public Integer execute(Connection con) throws SQLException { ps.execute(); long endTime = System.currentTimeMillis(); logSqlBuilder.logSql(log, sql, args, types, (endTime-startTime)); - + return ps.getUpdateCount(); } catch (SQLException e) { throw logSqlBuilder.logSqlAfterException(log, sql, args, e); @@ -410,7 +410,7 @@ public Integer execute(Connection con) throws SQLException { boolean hasResults = stmt.execute(statement); long endTime = System.currentTimeMillis(); logSqlBuilder.logSql(log, statement, null, null, (endTime-startTime)); - + int updateCount = stmt.getUpdateCount(); totalUpdateCount += updateCount; int rowsRetrieved = 0; @@ -879,18 +879,18 @@ public boolean isUniqueKeyViolation(Throwable ex) { } } } - + if (primaryKeyViolationMessageParts != null) { - String sqlMessage = sqlEx.getMessage(); - if (sqlMessage != null) { - sqlMessage = sqlMessage.toLowerCase(); - for (String primaryKeyViolationMessagePart : primaryKeyViolationMessageParts) { - if (primaryKeyViolationMessagePart != null && sqlMessage.contains(primaryKeyViolationMessagePart.toLowerCase())) { - primaryKeyViolation = true; - break; - } - } - } + String sqlMessage = sqlEx.getMessage(); + if (sqlMessage != null) { + sqlMessage = sqlMessage.toLowerCase(); + for (String primaryKeyViolationMessagePart : primaryKeyViolationMessageParts) { + if (primaryKeyViolationMessagePart != null && sqlMessage.contains(primaryKeyViolationMessagePart.toLowerCase())) { + primaryKeyViolation = true; + break; + } + } + } } } } @@ -925,18 +925,18 @@ public boolean isForeignKeyViolation(Throwable ex) { } } } - + if (foreignKeyViolationMessageParts != null) { - String sqlMessage = sqlEx.getMessage(); - if (sqlMessage != null) { - sqlMessage = sqlMessage.toLowerCase(); - for (String foreignKeyViolationMessagePart : foreignKeyViolationMessageParts) { - if (foreignKeyViolationMessagePart != null && sqlMessage.contains(foreignKeyViolationMessagePart.toLowerCase())) { - foreignKeyViolation = true; - break; - } - } - } + String sqlMessage = sqlEx.getMessage(); + if (sqlMessage != null) { + sqlMessage = sqlMessage.toLowerCase(); + for (String foreignKeyViolationMessagePart : foreignKeyViolationMessageParts) { + if (foreignKeyViolationMessagePart != null && sqlMessage.contains(foreignKeyViolationMessagePart.toLowerCase())) { + foreignKeyViolation = true; + break; + } + } + } } } } @@ -984,22 +984,27 @@ public void setValues(PreparedStatement ps, Object[] args, int[] argTypes, for (int i = 1; i <= args.length; i++) { Object arg = args[i - 1]; int argType = argTypes != null && argTypes.length >= i ? argTypes[i - 1] : SqlTypeValue.TYPE_UNKNOWN; - if (argType == Types.BLOB && lobHandler != null && arg instanceof byte[]) { - lobHandler.getLobCreator().setBlobAsBytes(ps, i, (byte[]) arg); - } else if (argType == Types.BLOB && lobHandler != null && arg instanceof String) { - lobHandler.getLobCreator().setBlobAsBytes(ps, i, arg.toString().getBytes()); - } else if (argType == Types.CLOB && lobHandler != null) { - lobHandler.getLobCreator().setClobAsString(ps, i, (String) arg); - } else if ((argType == Types.DECIMAL || argType == Types.NUMERIC) && arg != null) { - setDecimalValue(ps, i, arg, argType); - } else if (argType == Types.TINYINT) { - setTinyIntValue(ps, i, arg, argType); - } else { - StatementCreatorUtils.setParameterValue(ps, i, verifyArgType(arg, argType), arg); + try { + if (argType == Types.BLOB && lobHandler != null && arg instanceof byte[]) { + lobHandler.getLobCreator().setBlobAsBytes(ps, i, (byte[]) arg); + } else if (argType == Types.BLOB && lobHandler != null && arg instanceof String) { + lobHandler.getLobCreator().setBlobAsBytes(ps, i, arg.toString().getBytes()); + } else if (argType == Types.CLOB && lobHandler != null) { + lobHandler.getLobCreator().setClobAsString(ps, i, (String) arg); + } else if ((argType == Types.DECIMAL || argType == Types.NUMERIC) && arg != null) { + setDecimalValue(ps, i, arg, argType); + } else if (argType == Types.TINYINT) { + setTinyIntValue(ps, i, arg, argType); + } else { + StatementCreatorUtils.setParameterValue(ps, i, verifyArgType(arg, argType), arg); + } + } catch (SQLException ex) { + log.warn("Parameter arg '{}' type: {} caused exception: {}", arg, argType, ex.getMessage()); + throw ex; } } } - + protected void setTinyIntValue(PreparedStatement ps, int i, Object arg, int argType) throws SQLException { StatementCreatorUtils.setParameterValue(ps, i, verifyArgType(arg, argType), arg); } @@ -1023,7 +1028,12 @@ public void setValues(PreparedStatement ps, Object[] args) throws SQLException { if (args != null) { for (int i = 0; i < args.length; i++) { Object arg = args[i]; - doSetValue(ps, i + 1, arg); + try { + doSetValue(ps, i + 1, arg); + } catch (SQLException ex) { + log.warn("Parameter arg '{}' caused exception: {}", arg, ex.getMessage()); + throw ex; + } } } } diff --git a/symmetric-server/src/main/deploy/conf/log4j.xml b/symmetric-server/src/main/deploy/conf/log4j.xml index 2ece44c63e..b2f01e873e 100644 --- a/symmetric-server/src/main/deploy/conf/log4j.xml +++ b/symmetric-server/src/main/deploy/conf/log4j.xml @@ -25,7 +25,7 @@ - + diff --git a/symmetric-util/src/main/java/org/jumpmind/util/LogSuppressor.java b/symmetric-util/src/main/java/org/jumpmind/util/LogSuppressor.java deleted file mode 100644 index 627f362ffc..0000000000 --- a/symmetric-util/src/main/java/org/jumpmind/util/LogSuppressor.java +++ /dev/null @@ -1,99 +0,0 @@ -/** - * Licensed to JumpMind Inc under one or more contributor - * license agreements. See the NOTICE file distributed - * with this work for additional information regarding - * copyright ownership. JumpMind Inc licenses this file - * to you under the GNU General Public License, version 3.0 (GPLv3) - * (the "License"); you may not use this file except in compliance - * with the License. - * - * You should have received a copy of the GNU General Public License, - * version 3.0 (GPLv3) along with this library; if not, see - * . - * - * Unless required by applicable law or agreed to in writing, - * software distributed under the License is distributed on an - * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY - * KIND, either express or implied. See the License for the - * specific language governing permissions and limitations - * under the License. - */ -package org.jumpmind.util; - -import java.util.Collections; -import java.util.LinkedHashMap; -import java.util.Map; -import java.util.Map.Entry; - -import org.apache.log4j.Level; -import org.slf4j.Logger; - -public class LogSuppressor { - - private int reportMessageXTimes; - - protected final Logger log; - - private Map logCounts = Collections.synchronizedMap(new LinkedHashMap() { - private static final long serialVersionUID = 1L; - - @Override - protected boolean removeEldestEntry(Entry eldest) { - return (this.size() > 2048); - } - }); - - public LogSuppressor(Logger log) { - this(log, 10); - } - - public LogSuppressor(Logger log, int reportMessageXTimes) { - this.log = log; - this.reportMessageXTimes = reportMessageXTimes; - } - - protected void log(int initialLevel, String key, String message, Throwable ex) { - if (!logCounts.containsKey(key)) { - if (initialLevel == Level.ERROR_INT) { - if (ex != null) { - log.error(message, ex); - } else { - log.error(message); - } - } else { - if (ex != null) { - log.info(message, ex); - } else { - log.info(message); - } - } - - logCounts.put(key, Integer.valueOf(1)); - } else { - String exceptionText = ex != null ? " "+ex.getMessage() : ""; - - Integer count = logCounts.get(key); - String messagePreviouslyReported = message + " (Previously reported " + count + " time(s), will report " + reportMessageXTimes + ")"; - if (count < reportMessageXTimes) { - if (initialLevel == Level.ERROR_INT) { - log.error(messagePreviouslyReported + exceptionText); - } else { - log.info(messagePreviouslyReported + exceptionText); - } - - } else { - log.debug(messagePreviouslyReported + exceptionText); - } - count = count+1; - logCounts.put(key, count); - } - } - - public void logError(String key, String message, Throwable ex) { - log(Level.ERROR_INT, key, message, ex); - } - - public void logInfo(String key, String message, Throwable ex) { - log(Level.INFO_INT, key, message, ex); - } -} diff --git a/symmetric-util/src/main/java/org/jumpmind/util/SymRollingFileAppender.java b/symmetric-util/src/main/java/org/jumpmind/util/SymRollingFileAppender.java new file mode 100644 index 0000000000..e2e16ddf4b --- /dev/null +++ b/symmetric-util/src/main/java/org/jumpmind/util/SymRollingFileAppender.java @@ -0,0 +1,184 @@ +/** + * Licensed to JumpMind Inc under one or more contributor + * license agreements. See the NOTICE file distributed + * with this work for additional information regarding + * copyright ownership. JumpMind Inc licenses this file + * to you under the GNU General Public License, version 3.0 (GPLv3) + * (the "License"); you may not use this file except in compliance + * with the License. + * + * You should have received a copy of the GNU General Public License, + * version 3.0 (GPLv3) along with this library; if not, see + * . + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.jumpmind.util; + +import java.io.BufferedWriter; +import java.io.IOException; +import java.io.OutputStream; +import java.io.Writer; +import java.util.LinkedHashMap; +import java.util.Map; +import java.util.Map.Entry; +import java.util.zip.CRC32; + +import org.apache.commons.lang.ArrayUtils; +import org.apache.log4j.Level; +import org.apache.log4j.RollingFileAppender; +import org.apache.log4j.helpers.LogLog; +import org.apache.log4j.spi.LoggingEvent; + +public class SymRollingFileAppender extends RollingFileAppender { + + private static final int DEFAULT_HISTORY_SIZE = 2048; + + // All access to this field should come from method calls that are otherwise synchronized + // (e.g. AppenderSkeleton.doAppend()) + private Map loggedEventKeys = new LinkedHashMap() { + private static final long serialVersionUID = 1L; + + @Override + protected boolean removeEldestEntry(Entry eldest) { + return (size() >= getHistorySize()); + } + }; + + private OutputStream os; // for unit testing. + + private int historySize = DEFAULT_HISTORY_SIZE; + + @Override + public void rollOver() { + loggedEventKeys.clear(); + super.rollOver(); + } + + // Note that this is called from AppenderSkeleton.doAppend() which is synchronized. + @Override + public void append(LoggingEvent event) { + if (!isLoggerAtDebug(event)) { // don't filter logging at all if the logger is at DEBUG level. + String key = toKey(event); + if (key != null) { + if (loggedEventKeys.containsKey(key)) { + event = supressStackTrace(event, key); + } else { + event = appendKey(event, key); + loggedEventKeys.put(key, null); + } + } + } + + super.append(event); + } + + /** + * @param event + * @return + */ + private boolean isLoggerAtDebug(LoggingEvent event) { + if (event != null && event.getLogger() != null && event.getLogger().getLevel() != null) { + return event.getLogger().getLevel().toInt() <= Level.DEBUG_INT; + } + return false; + } + + protected String toKey(LoggingEvent event) { + if (event.getThrowableInformation() == null + || event.getThrowableStrRep() == null) { + return null; + } + + try { + CRC32 crc = new CRC32(); + crc.update(ArrayUtils.toString(event.getThrowableStrRep()).getBytes("UTF8")); + return event.getThrowableInformation().getThrowable().getClass().getSimpleName() + ":" + crc.getValue(); + } catch (Exception ex) { + LogLog.error("Failed to hash stack trace.", ex); + return null; + } + } + + protected LoggingEvent appendKey(LoggingEvent event, String key) { + String message = getMessageWithKey(event, key, ".init"); + + LoggingEvent eventClone = new LoggingEvent(event.getFQNOfLoggerClass(), + event.getLogger(), event.getTimeStamp(), event.getLevel(), message, event.getThreadName(), + event.getThrowableInformation(), event.getNDC(), event.getLocationInformation(), event.getProperties()); + + return eventClone; + } + + protected LoggingEvent supressStackTrace(LoggingEvent event, String key) { + String message = getMessageWithKey(event, key); + + LoggingEvent eventClone = new LoggingEvent(event.getFQNOfLoggerClass(), + event.getLogger(), event.getTimeStamp(), event.getLevel(), message, event.getThreadName(), + null, event.getNDC(), event.getLocationInformation(), event.getProperties()); + + return eventClone; + } + + protected String getMessageWithKey(LoggingEvent event, String key) { + return getMessageWithKey(event, key, null); + } + + protected String getMessageWithKey(LoggingEvent event, String key, String prefix) { + StringBuilder buff = new StringBuilder(128); + if (event.getMessage() != null) { + buff.append(event.getMessage()).append(" "); + } + buff.append("StackTraceKey"); + if (prefix != null) { + buff.append(prefix); + } + buff.append(" [").append(key).append("]"); + return buff.toString(); + } + + @Override + protected void writeHeader() { + if(layout != null) { + String h = layout.getHeader(); + if(h != null && this.qw != null) + this.qw.write(h); + } + } + + @Override + public synchronized void setFile(String fileName, boolean append, boolean bufferedIO, int bufferSize) + throws IOException { + if (os == null) { + super.setFile(fileName, append, bufferedIO, bufferSize); + } + } + + // For unit testing. + public synchronized void setOutputStream(OutputStream os) throws IOException { + this.os = os; + reset(); + + Writer fw = createWriter(os); + if(bufferedIO) { + fw = new BufferedWriter(fw, bufferSize); + } + this.setQWForFiles(fw); + this.fileName = os.toString(); + this.fileAppend = true; + writeHeader(); + } + + public int getHistorySize() { + return historySize; + } + + public void setHistorySize(int historySize) { + this.historySize = historySize; + } +} diff --git a/symmetric-util/src/test/java/org/jumpmind/util/SymRollingFileAppenderTest.java b/symmetric-util/src/test/java/org/jumpmind/util/SymRollingFileAppenderTest.java new file mode 100644 index 0000000000..8ce80326d3 --- /dev/null +++ b/symmetric-util/src/test/java/org/jumpmind/util/SymRollingFileAppenderTest.java @@ -0,0 +1,279 @@ +/** + * Licensed to JumpMind Inc under one or more contributor + * license agreements. See the NOTICE file distributed + * with this work for additional information regarding + * copyright ownership. JumpMind Inc licenses this file + * to you under the GNU General Public License, version 3.0 (GPLv3) + * (the "License"); you may not use this file except in compliance + * with the License. + * + * You should have received a copy of the GNU General Public License, + * version 3.0 (GPLv3) along with this library; if not, see + * . + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.jumpmind.util; + +import static org.junit.Assert.*; + +import java.util.ArrayList; +import java.util.List; +import java.util.regex.Matcher; +import java.util.regex.Pattern; + +import org.apache.commons.io.output.ByteArrayOutputStream; +import org.apache.commons.lang.StringUtils; +import org.apache.log4j.Category; +import org.apache.log4j.Level; +import org.apache.log4j.PatternLayout; +import org.apache.log4j.spi.LoggingEvent; +import org.junit.Test; + +import com.sun.corba.se.impl.oa.poa.AOMEntry; + +public class SymRollingFileAppenderTest { + + @Test + public void testDuplicatedLogMessages() throws Exception { + ByteArrayOutputStream os = new ByteArrayOutputStream(1024); + SymRollingFileAppender appender = getAppenderForTest(os); + + Exception ex = new Exception("Test exception."); + + LoggingEvent event1 = getLoggingEventForTest("Test Exception.", ex); + LoggingEvent event2 = getLoggingEventForTest("Test Exception.", ex); + LoggingEvent event3 = getLoggingEventForTest("Test Exception.", ex); + + appender.append(event1); + appender.append(event2); + appender.append(event3); + + String logging = os.toString("UTF8"); + + // 2016-08-11 11:55:38,487 ERROR [] [SymRollingFileAppenderTest] [main] Test Exception. StackTraceKey.init [Exception:1478675418] + Pattern initPattern = Pattern.compile(".*StackTraceKey.init \\[Exception:([0-9]*)\\].*", Pattern.DOTALL); + Matcher m = initPattern.matcher(logging); + if (m.matches()) { + String stackTraceKey = "Exception:" + m.group(1); + assertEquals(3, StringUtils.countMatches(logging, stackTraceKey)); + } else { + fail("Didn't find proper logging pattern."); + } + } + + @Test + public void testDistinctLogMessages() throws Exception { + ByteArrayOutputStream os = new ByteArrayOutputStream(1024); + SymRollingFileAppender appender = getAppenderForTest(os); + + Exception ex = new Exception("Test exception."); + Exception ex2 = new Exception("Test exception."); + + LoggingEvent event1 = getLoggingEventForTest("Test Exception.", ex); + LoggingEvent event2 = getLoggingEventForTest("Test Exception.", ex2); + + appender.append(event1); + appender.append(event2); + + String logging = os.toString("UTF8"); + + // 2016-08-11 11:55:38,487 ERROR [] [SymRollingFileAppenderTest] [main] Test Exception. StackTraceKey.init [Exception:1478675418] + Pattern initPattern = Pattern.compile(".*StackTraceKey.init \\[Exception:([0-9]*)\\].*", Pattern.DOTALL); + Matcher m = initPattern.matcher(logging); + if (m.matches()) { + { + String stackTraceKey = "Exception:" + m.group(1); + assertEquals(1, StringUtils.countMatches(logging, stackTraceKey)); + } + m.matches(); + { + String stackTraceKey = "Exception:" + m.group(1); + assertEquals(1, StringUtils.countMatches(logging, stackTraceKey)); + } + } else { + fail("Didn't find proper logging pattern."); + } + } + + @Test + public void testMixedMessages() throws Exception { + ByteArrayOutputStream os = new ByteArrayOutputStream(1024); + SymRollingFileAppender appender = getAppenderForTest(os); + + Exception ex = new Exception("Test exception."); + Exception ex2 = new Exception("Test exception."); + + LoggingEvent event1 = getLoggingEventForTest("Test Exception.", ex); + LoggingEvent event2 = getLoggingEventForTest("Test Exception.", ex2); + LoggingEvent event3 = getLoggingEventForTest("Test Exception.", ex); + LoggingEvent event4 = getLoggingEventForTest("Test Exception.", ex2); + + appender.append(event1); + appender.append(event2); + appender.append(event3); + appender.append(event4); + + String logging = os.toString("UTF8"); + + // 2016-08-11 11:55:38,487 ERROR [] [SymRollingFileAppenderTest] [main] Test Exception. StackTraceKey.init [Exception:1478675418] + Pattern initPattern = Pattern.compile(".*StackTraceKey.init \\[Exception:([0-9]*)\\].*", Pattern.DOTALL); + Matcher m = initPattern.matcher(logging); + if (m.matches()) { + { + String stackTraceKey = "Exception:" + m.group(1); + assertEquals(2, StringUtils.countMatches(logging, stackTraceKey)); + } + m.matches(); + { + String stackTraceKey = "Exception:" + m.group(1); + assertEquals(2, StringUtils.countMatches(logging, stackTraceKey)); + } + } else { + fail("Didn't find proper logging pattern."); + } + } + + @Test + public void testRollover() throws Exception { + ByteArrayOutputStream os = new ByteArrayOutputStream(1024); + SymRollingFileAppender appender = getAppenderForTest(os); + + Exception ex = new Exception("Test exception."); + Exception ex2 = new Exception("Test exception."); + + LoggingEvent event1 = getLoggingEventForTest("Test Exception.", ex); + LoggingEvent event2 = getLoggingEventForTest("Test Exception.", ex); + LoggingEvent event3 = getLoggingEventForTest("Test Exception.", ex); + LoggingEvent event4 = getLoggingEventForTest("Test Exception.", ex); + + appender.append(event1); + appender.append(event2); + + String logging = os.toString("UTF8"); + + String stackTraceKey1 = null; + + // 2016-08-11 11:55:38,487 ERROR [] [SymRollingFileAppenderTest] [main] Test Exception. StackTraceKey.init [Exception:1478675418] + Pattern initPattern = Pattern.compile(".*StackTraceKey.init \\[Exception:([0-9]*)\\].*", Pattern.DOTALL); + { + Matcher m = initPattern.matcher(logging); + if (m.matches()) { + { + stackTraceKey1 = "Exception:" + m.group(1); + assertEquals(2, StringUtils.countMatches(logging, stackTraceKey1)); + } + } else { + fail("Didn't find proper logging pattern."); + } + } + + appender.rollOver(); + os = new ByteArrayOutputStream(1024); + appender.setOutputStream(os); + + appender.append(event3); + appender.append(event4); + + logging = os.toString("UTF8"); + + String stackTraceKey2 = null; + + { + Matcher m = initPattern.matcher(logging); + if (m.matches()) { + { + stackTraceKey2 = "Exception:" + m.group(1); + assertEquals(2, StringUtils.countMatches(logging, stackTraceKey2)); + } + } else { + fail("Didn't find proper logging pattern."); + } + } + + // should reprint stack trace and get a new key after the roll over. + assertEquals(stackTraceKey1, stackTraceKey2); + + + } + + @Test + public void testDebugMode() throws Exception { + ByteArrayOutputStream os = new ByteArrayOutputStream(1024); + SymRollingFileAppender appender = getAppenderForTest(os); + + Exception ex = new Exception("Test exception."); + + LoggingEvent event1 = getLoggingEventForTest("Test Exception.", ex, Level.DEBUG); + LoggingEvent event2 = getLoggingEventForTest("Test Exception.", ex, Level.DEBUG); + LoggingEvent event3 = getLoggingEventForTest("Test Exception.", ex, Level.DEBUG); + + appender.append(event1); + appender.append(event2); + appender.append(event3); + + String logging = os.toString("UTF8"); + + // 2016-08-11 11:55:38,487 ERROR [] [SymRollingFileAppenderTest] [main] Test Exception. StackTraceKey.init [Exception:1478675418] + Pattern initPattern = Pattern.compile(".*StackTraceKey.init \\[Exception:([0-9]*)\\].*", Pattern.DOTALL); + Matcher m = initPattern.matcher(logging); + assertFalse(m.matches()); // everything should get logged with a DEBUG logger, so we should't find the StackTraceKey pattern. + } + + @Test + public void testCacheExceeded() throws Exception { + ByteArrayOutputStream os = new ByteArrayOutputStream(1024); + SymRollingFileAppender appender = getAppenderForTest(os); + + final int HISTORY_SIZE = 100; + + final int TEST_TOTAL = HISTORY_SIZE*4; + + appender.setHistorySize(HISTORY_SIZE); + + for (int i = 0; i < TEST_TOTAL; i++) { + Exception ex = new Exception("Test exception."+i); + LoggingEvent event = getLoggingEventForTest("Test Exception.", ex); + appender.append(event); + LoggingEvent event1 = getLoggingEventForTest("Test Exception.", ex); + appender.append(event1); + } + + String logging = os.toString("UTF8"); + + assertEquals(TEST_TOTAL, StringUtils.countMatches(logging, "StackTraceKey.init")); + } + + protected LoggingEvent getLoggingEventForTest(String message, Throwable ex) { + return getLoggingEventForTest(message, ex, Level.INFO); + } + + protected LoggingEvent getLoggingEventForTest(String message, Throwable ex, Level loggerLevel) { + TestCategory category = new TestCategory(SymRollingFileAppenderTest.class.getName()); + category.setLevel(loggerLevel); + + LoggingEvent event = new LoggingEvent(SymRollingFileAppenderTest.class.getName(), + category, System.currentTimeMillis(), Level.ERROR, message, ex); + return event; + } + + protected SymRollingFileAppender getAppenderForTest(ByteArrayOutputStream os) throws Exception { + SymRollingFileAppender appender = new SymRollingFileAppender(); + PatternLayout layout = new PatternLayout("%d %p [%X{engineName}] [%c{1}] [%t] %m%n"); + appender.setLayout(layout); + + appender.setOutputStream(os); + return appender; + } + + class TestCategory extends Category { + public TestCategory(String name) { + super(name); + } + } +} diff --git a/symmetric-util/src/test/resources/log4j.xml b/symmetric-util/src/test/resources/log4j.xml index 258c354b02..1f29acf9a5 100644 --- a/symmetric-util/src/test/resources/log4j.xml +++ b/symmetric-util/src/test/resources/log4j.xml @@ -31,7 +31,7 @@ - +