Skip to content

Commit

Permalink
0002724: Eliminate Repeated Stack trace logging
Browse files Browse the repository at this point in the history
  • Loading branch information
@mmichalek
mmichalek committed Aug 12, 2016
1 parent 2970411 commit fba3500
Show file tree
Hide file tree
Showing 9 changed files with 536 additions and 175 deletions.
3 changes: 3 additions & 0 deletions symmetric-core/src/main/java/org/jumpmind/symmetric/io/DbCompareDiffWriter.java
View file
Expand Up @@ -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);
Expand Down
21 changes: 5 additions & 16 deletions symmetric-core/src/main/java/org/jumpmind/symmetric/service/impl/DataLoaderService.java
View file
Expand Up @@ -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;
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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();
Expand Down Expand Up @@ -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 {
Expand All @@ -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);
}
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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<IncomingBatch> getBatchesProcessed() {
return batchesProcessed;
}
Expand Down
9 changes: 2 additions & 7 deletions symmetric-io/src/main/java/org/jumpmind/symmetric/io/data/writer/DefaultDatabaseWriter.java
View file
Expand Up @@ -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;

Expand All @@ -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);
Expand Down Expand Up @@ -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
Expand Down
112 changes: 61 additions & 51 deletions symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTemplate.java
View file
Expand Up @@ -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;
Expand Down Expand Up @@ -134,7 +134,7 @@ public <T> ISqlReadCursor<T> queryForCursor(String sql, ISqlRowMapper<T> mapper,
ISqlReadCursor<T> cursor = new JdbcSqlReadCursor<T>(this, mapper, sql, args, types);
long endTime = System.currentTimeMillis();
logSqlBuilder.logSql(log, sql, args, types, (endTime-startTime));

return cursor;
}

Expand All @@ -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);
}
Expand All @@ -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<byte[]>() {
public byte[] execute(Connection con) throws SQLException {
if (lobHandler.needsAutoCommitFalseForBlob(jdbcTypeCode, jdbcTypeName)) {
Expand Down Expand Up @@ -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);
Expand All @@ -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);
}
Expand All @@ -266,12 +266,12 @@ public Map<String, Object> 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();
Expand Down Expand Up @@ -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);
Expand All @@ -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);
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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;
}
}
}
}
}
}
Expand Down Expand Up @@ -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;
}
}
}
}
}
}
Expand Down Expand Up @@ -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);
}
Expand All @@ -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;
}
}
}
}
Expand Down
2 changes: 1 addition & 1 deletion symmetric-server/src/main/deploy/conf/log4j.xml
View file
Expand Up @@ -25,7 +25,7 @@

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">

<appender name="ROLLING" class="org.apache.log4j.RollingFileAppender">
<appender name="ROLLING" class="org.jumpmind.util.SymRollingFileAppender">
<param name="File" value="${log4j.sym.home}/logs/symmetric.log" />
<param name="MaxFileSize" value="10MB" />
<param name="MaxBackupIndex" value="3" />
Expand Down

0 comments on commit fba3500

Please sign in to comment.