Revised log levels: less WARN and INFO, fine-tuned DEBUG vs TRACE

Issue: SPR-16946
This commit is contained in:
Juergen Hoeller
2018-07-20 15:05:13 +02:00
parent a410d90439
commit 9a43d2ec20
99 changed files with 461 additions and 486 deletions

View File

@@ -509,8 +509,8 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
@Override
public Integer doInStatement(Statement stmt) throws SQLException {
int rows = stmt.executeUpdate(sql);
if (logger.isDebugEnabled()) {
logger.debug("SQL update affected " + rows + " rows");
if (logger.isTraceEnabled()) {
logger.trace("SQL update affected " + rows + " rows");
}
return rows;
}
@@ -865,8 +865,8 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
pss.setValues(ps);
}
int rows = ps.executeUpdate();
if (logger.isDebugEnabled()) {
logger.debug("SQL update affected " + rows + " rows");
if (logger.isTraceEnabled()) {
logger.trace("SQL update affected " + rows + " rows");
}
return rows;
}
@@ -905,8 +905,8 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
JdbcUtils.closeResultSet(keys);
}
}
if (logger.isDebugEnabled()) {
logger.debug("SQL update affected " + rows + " rows and returned " + generatedKeys.size() + " keys");
if (logger.isTraceEnabled()) {
logger.trace("SQL update affected " + rows + " rows and returned " + generatedKeys.size() + " keys");
}
return rows;
}));
@@ -999,7 +999,7 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
boolean batchSupported = true;
if (!JdbcUtils.supportsBatchUpdates(ps.getConnection())) {
batchSupported = false;
logger.warn("JDBC Driver does not support Batch updates; resorting to single statement execution");
logger.debug("JDBC Driver does not support Batch updates; resorting to single statement execution");
}
int n = 0;
for (T obj : batchArgs) {
@@ -1008,10 +1008,10 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
if (batchSupported) {
ps.addBatch();
if (n % batchSize == 0 || n == batchArgs.size()) {
if (logger.isDebugEnabled()) {
if (logger.isTraceEnabled()) {
int batchIdx = (n % batchSize == 0) ? n / batchSize : (n / batchSize) + 1;
int items = n - ((n % batchSize == 0) ? n / batchSize - 1 : (n / batchSize)) * batchSize;
logger.debug("Sending SQL batch update #" + batchIdx + " with " + items + " items");
logger.trace("Sending SQL batch update #" + batchIdx + " with " + items + " items");
}
rowsAffected.add(ps.executeBatch());
}
@@ -1116,9 +1116,9 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
Map<String, Object> result = execute(csc, cs -> {
boolean retVal = cs.execute();
int updateCount = cs.getUpdateCount();
if (logger.isDebugEnabled()) {
logger.debug("CallableStatement.execute() returned '" + retVal + "'");
logger.debug("CallableStatement.getUpdateCount() returned " + updateCount);
if (logger.isTraceEnabled()) {
logger.trace("CallableStatement.execute() returned '" + retVal + "'");
logger.trace("CallableStatement.getUpdateCount() returned " + updateCount);
}
Map<String, Object> returnedResults = createResultsMap();
if (retVal || updateCount != -1) {
@@ -1159,8 +1159,8 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
if (!this.skipUndeclaredResults) {
String rsName = RETURN_RESULT_SET_PREFIX + (rsIndex + 1);
SqlReturnResultSet undeclaredRsParam = new SqlReturnResultSet(rsName, getColumnMapRowMapper());
if (logger.isDebugEnabled()) {
logger.debug("Added default SqlReturnResultSet parameter named '" + rsName + "'");
if (logger.isTraceEnabled()) {
logger.trace("Added default SqlReturnResultSet parameter named '" + rsName + "'");
}
returnedResults.putAll(processResultSet(cs.getResultSet(), undeclaredRsParam));
rsIndex++;
@@ -1177,8 +1177,8 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
else {
if (!this.skipUndeclaredResults) {
String undeclaredName = RETURN_UPDATE_COUNT_PREFIX + (updateIndex + 1);
if (logger.isDebugEnabled()) {
logger.debug("Added default SqlReturnUpdateCount parameter named '" + undeclaredName + "'");
if (logger.isTraceEnabled()) {
logger.trace("Added default SqlReturnUpdateCount parameter named '" + undeclaredName + "'");
}
returnedResults.put(undeclaredName, updateCount);
updateIndex++;
@@ -1187,8 +1187,8 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
}
moreResults = cs.getMoreResults();
updateCount = cs.getUpdateCount();
if (logger.isDebugEnabled()) {
logger.debug("CallableStatement.getUpdateCount() returned " + updateCount);
if (logger.isTraceEnabled()) {
logger.trace("CallableStatement.getUpdateCount() returned " + updateCount);
}
}
while (moreResults || updateCount != -1);
@@ -1226,8 +1226,8 @@ public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {
String rsName = outParam.getName();
SqlReturnResultSet rsParam = new SqlReturnResultSet(rsName, getColumnMapRowMapper());
returnedResults.putAll(processResultSet((ResultSet) out, rsParam));
if (logger.isDebugEnabled()) {
logger.debug("Added default SqlReturnResultSet parameter named '" + rsName + "'");
if (logger.isTraceEnabled()) {
logger.trace("Added default SqlReturnResultSet parameter named '" + rsName + "'");
}
}
}

View File

@@ -292,7 +292,7 @@ public class CallMetaDataContext {
}
else {
if (this.outParameterNames.size() > 1) {
logger.warn("Accessing single output value when procedure has more than one output parameter");
logger.info("Accessing single output value when procedure has more than one output parameter");
}
return (!this.outParameterNames.isEmpty() ? this.outParameterNames.get(0) : null);
}
@@ -520,8 +520,8 @@ public class CallMetaDataContext {
matchedParameters.put(parameterName,
SqlParameterSourceUtils.getTypedValue(parameterSource, sourceName));
}
else {
logger.warn("Unable to locate the corresponding parameter value for '" +
else if (logger.isInfoEnabled()) {
logger.info("Unable to locate the corresponding parameter value for '" +
parameterName + "' within the parameter values provided: " +
caseInsensitiveParameterNames.values());
}
@@ -587,8 +587,8 @@ public class CallMetaDataContext {
for (String parameterName : callParameterNames.keySet()) {
String parameterNameToMatch = provider.parameterNameToUse(parameterName);
String callParameterName = callParameterNames.get(lowerCase(parameterNameToMatch));
if (!matchedParameters.containsKey(callParameterName)) {
logger.warn("Unable to locate the corresponding parameter value for '" + parameterName +
if (!matchedParameters.containsKey(callParameterName) && logger.isInfoEnabled()) {
logger.info("Unable to locate the corresponding parameter value for '" + parameterName +
"' within the parameter values provided: " + inParameters.keySet());
}
}

View File

@@ -76,24 +76,24 @@ public final class CallMetaDataProviderFactory {
boolean accessProcedureColumnMetaData = context.isAccessCallParameterMetaData();
if (context.isFunction()) {
if (!supportedDatabaseProductsForFunctions.contains(databaseProductName)) {
if (logger.isWarnEnabled()) {
logger.warn(databaseProductName + " is not one of the databases fully supported for function calls " +
if (logger.isInfoEnabled()) {
logger.info(databaseProductName + " is not one of the databases fully supported for function calls " +
"-- supported are: " + supportedDatabaseProductsForFunctions);
}
if (accessProcedureColumnMetaData) {
logger.warn("Metadata processing disabled - you must specify all parameters explicitly");
logger.info("Metadata processing disabled - you must specify all parameters explicitly");
accessProcedureColumnMetaData = false;
}
}
}
else {
if (!supportedDatabaseProductsForProcedures.contains(databaseProductName)) {
if (logger.isWarnEnabled()) {
logger.warn(databaseProductName + " is not one of the databases fully supported for procedure calls " +
if (logger.isInfoEnabled()) {
logger.info(databaseProductName + " is not one of the databases fully supported for procedure calls " +
"-- supported are: " + supportedDatabaseProductsForProcedures);
}
if (accessProcedureColumnMetaData) {
logger.warn("Metadata processing disabled - you must specify all parameters explicitly");
logger.info("Metadata processing disabled - you must specify all parameters explicitly");
accessProcedureColumnMetaData = false;
}
}

View File

@@ -40,8 +40,8 @@ public class DerbyTableMetaDataProvider extends GenericTableMetaDataProvider {
public void initializeWithMetaData(DatabaseMetaData databaseMetaData) throws SQLException {
super.initializeWithMetaData(databaseMetaData);
if (!databaseMetaData.supportsGetGeneratedKeys()) {
if (logger.isWarnEnabled()) {
logger.warn("Overriding supportsGetGeneratedKeys from DatabaseMetaData to 'true'; it was reported as " +
if (logger.isInfoEnabled()) {
logger.info("Overriding supportsGetGeneratedKeys from DatabaseMetaData to 'true'; it was reported as " +
"'false' by " + databaseMetaData.getDriverName() + " " + databaseMetaData.getDriverVersion());
}
this.supportsGeneratedKeysOverride = true;

View File

@@ -338,8 +338,8 @@ public class GenericTableMetaDataProvider implements TableMetaDataProvider {
}
if (tableMeta.isEmpty()) {
if (logger.isWarnEnabled()) {
logger.warn("Unable to locate table meta-data for '" + tableName + "': column names must be provided");
if (logger.isInfoEnabled()) {
logger.info("Unable to locate table meta-data for '" + tableName + "': column names must be provided");
}
}
else {

View File

@@ -122,7 +122,7 @@ public class OracleTableMetaDataProvider extends GenericTableMetaDataProvider {
Connection con = databaseMetaData.getConnection();
if (con == null) {
logger.warn("Unable to include synonyms in table meta-data lookup - no Connection from DatabaseMetaData");
logger.info("Unable to include synonyms in table meta-data lookup - no Connection from DatabaseMetaData");
super.initializeWithTableColumnMetaData(databaseMetaData, catalogName, schemaName, tableName);
return;
}
@@ -132,8 +132,8 @@ public class OracleTableMetaDataProvider extends GenericTableMetaDataProvider {
con = (Connection) con.unwrap(oracleConClass);
}
catch (ClassNotFoundException | SQLException ex) {
if (logger.isWarnEnabled()) {
logger.warn("Unable to include synonyms in table meta-data lookup - no Oracle Connection: " + ex);
if (logger.isInfoEnabled()) {
logger.info("Unable to include synonyms in table meta-data lookup - no Oracle Connection: " + ex);
}
super.initializeWithTableColumnMetaData(databaseMetaData, catalogName, schemaName, tableName);
return;

View File

@@ -294,8 +294,10 @@ public class TableMetaDataContext {
insertStatement.append(") VALUES(");
if (columnCount < 1) {
if (this.generatedKeyColumnsUsed) {
logger.info("Unable to locate non-key columns for table '" +
getTableName() + "' so an empty insert statement is generated");
if (logger.isDebugEnabled()) {
logger.debug("Unable to locate non-key columns for table '" +
getTableName() + "' so an empty insert statement is generated");
}
}
else {
throw new InvalidDataAccessApiUsageException("Unable to locate columns for table '" +

View File

@@ -129,8 +129,8 @@ public class DriverManagerDataSource extends AbstractDriverBasedDataSource {
catch (ClassNotFoundException ex) {
throw new IllegalStateException("Could not load JDBC driver class [" + driverClassNameToUse + "]", ex);
}
if (logger.isInfoEnabled()) {
logger.info("Loaded JDBC driver: " + driverClassNameToUse);
if (logger.isDebugEnabled()) {
logger.debug("Loaded JDBC driver: " + driverClassNameToUse);
}
}

View File

@@ -168,7 +168,7 @@ public class LazyConnectionDataSourceProxy extends DelegatingDataSource {
}
}
catch (SQLException ex) {
logger.warn("Could not retrieve default auto-commit and transaction isolation settings", ex);
logger.info("Could not retrieve default auto-commit and transaction isolation settings", ex);
}
}
}

View File

@@ -223,8 +223,8 @@ public class SingleConnectionDataSource extends DriverManagerDataSource implemen
closeConnection();
this.target = getConnectionFromDriver(getUsername(), getPassword());
prepareConnection(this.target);
if (logger.isInfoEnabled()) {
logger.info("Established shared JDBC Connection: " + this.target);
if (logger.isDebugEnabled()) {
logger.debug("Established shared JDBC Connection: " + this.target);
}
this.connection = (isSuppressClose() ? getCloseSuppressingConnectionProxy(this.target) : this.target);
}
@@ -264,7 +264,7 @@ public class SingleConnectionDataSource extends DriverManagerDataSource implemen
this.target.close();
}
catch (Throwable ex) {
logger.warn("Could not close shared JDBC Connection", ex);
logger.info("Could not close shared JDBC Connection", ex);
}
}
}

View File

@@ -46,7 +46,7 @@ abstract class AbstractEmbeddedDatabaseConfigurer implements EmbeddedDatabaseCon
}
}
catch (SQLException ex) {
logger.warn("Could not shut down embedded database", ex);
logger.info("Could not shut down embedded database", ex);
}
finally {
if (con != null) {

View File

@@ -187,7 +187,7 @@ public class EmbeddedDatabaseFactory {
if (this.dataSource instanceof SimpleDriverDataSource) {
SimpleDriverDataSource simpleDriverDataSource = (SimpleDriverDataSource) this.dataSource;
logger.info(String.format("Starting embedded database: url='%s', username='%s'",
simpleDriverDataSource.getUrl(), simpleDriverDataSource.getUsername()));
simpleDriverDataSource.getUrl(), simpleDriverDataSource.getUsername()));
}
else {
logger.info(String.format("Starting embedded database '%s'", this.databaseName));

View File

@@ -440,8 +440,8 @@ public abstract class ScriptUtils {
String blockCommentStartDelimiter, String blockCommentEndDelimiter) throws ScriptException {
try {
if (logger.isInfoEnabled()) {
logger.info("Executing SQL script from " + resource);
if (logger.isDebugEnabled()) {
logger.debug("Executing SQL script from " + resource);
}
long startTime = System.currentTimeMillis();
@@ -501,13 +501,13 @@ public abstract class ScriptUtils {
stmt.close();
}
catch (Throwable ex) {
logger.debug("Could not close JDBC Statement", ex);
logger.trace("Could not close JDBC Statement", ex);
}
}
long elapsedTime = System.currentTimeMillis() - startTime;
if (logger.isInfoEnabled()) {
logger.info("Executed SQL script from " + resource + " in " + elapsedTime + " ms.");
if (logger.isDebugEnabled()) {
logger.debug("Executed SQL script from " + resource + " in " + elapsedTime + " ms.");
}
}
catch (Exception ex) {

View File

@@ -66,6 +66,7 @@ public final class CustomSQLExceptionTranslatorRegistry {
private CustomSQLExceptionTranslatorRegistry() {
}
/**
* Register a new custom translator for the specified database name.
* @param dbName the database name
@@ -74,11 +75,11 @@ public final class CustomSQLExceptionTranslatorRegistry {
public void registerTranslator(String dbName, SQLExceptionTranslator translator) {
SQLExceptionTranslator replaced = this.translatorMap.put(dbName, translator);
if (replaced != null) {
logger.warn("Replacing custom translator [" + replaced + "] for database '" + dbName +
logger.debug("Replacing custom translator [" + replaced + "] for database '" + dbName +
"' with [" + translator + "]");
}
else {
logger.info("Adding custom translator of type [" + translator.getClass().getName() +
logger.debug("Adding custom translator of type [" + translator.getClass().getName() +
"] for database '" + dbName + "'");
}
}

View File

@@ -139,7 +139,7 @@ public class DatabaseStartupValidator implements InitializingBean {
if (logger.isWarnEnabled()) {
float rest = ((float) (deadLine - System.currentTimeMillis())) / 1000;
if (rest > this.interval) {
logger.warn("Database has not started up yet - retrying in " + this.interval +
logger.info("Database has not started up yet - retrying in " + this.interval +
" seconds (timeout in " + rest + " seconds)");
}
}

View File

@@ -1,5 +1,5 @@
/*
* Copyright 2002-2017 the original author or authors.
* Copyright 2002-2018 the original author or authors.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -112,20 +112,20 @@ public class SQLErrorCodesFactory {
bdr.loadBeanDefinitions(resource);
}
else {
logger.warn("Default sql-error-codes.xml not found (should be included in spring.jar)");
logger.info("Default sql-error-codes.xml not found (should be included in spring-jdbc jar)");
}
// Load custom SQL error codes, overriding defaults.
resource = loadResource(SQL_ERROR_CODE_OVERRIDE_PATH);
if (resource != null && resource.exists()) {
bdr.loadBeanDefinitions(resource);
logger.info("Found custom sql-error-codes.xml file at the root of the classpath");
logger.debug("Found custom sql-error-codes.xml file at the root of the classpath");
}
// Check all beans of type SQLErrorCodes.
errorCodes = lbf.getBeansOfType(SQLErrorCodes.class, true, false);
if (logger.isInfoEnabled()) {
logger.info("SQLErrorCodes loaded: " + errorCodes.keySet());
if (logger.isTraceEnabled()) {
logger.trace("SQLErrorCodes loaded: " + errorCodes.keySet());
}
}
catch (BeansException ex) {
@@ -280,14 +280,14 @@ public class SQLErrorCodesFactory {
SQLExceptionTranslator customTranslator =
CustomSQLExceptionTranslatorRegistry.getInstance().findTranslatorForDatabase(databaseName);
if (customTranslator != null) {
if (errorCodes.getCustomSqlExceptionTranslator() != null && logger.isWarnEnabled()) {
logger.warn("Overriding already defined custom translator '" +
if (errorCodes.getCustomSqlExceptionTranslator() != null && logger.isDebugEnabled()) {
logger.debug("Overriding already defined custom translator '" +
errorCodes.getCustomSqlExceptionTranslator().getClass().getSimpleName() +
" with '" + customTranslator.getClass().getSimpleName() +
"' found in the CustomSQLExceptionTranslatorRegistry for database '" + databaseName + "'");
}
else if (logger.isInfoEnabled()) {
logger.info("Using custom translator '" + customTranslator.getClass().getSimpleName() +
else if (logger.isTraceEnabled()) {
logger.trace("Using custom translator '" + customTranslator.getClass().getSimpleName() +
"' found in the CustomSQLExceptionTranslatorRegistry for database '" + databaseName + "'");
}
errorCodes.setCustomSqlExceptionTranslator(customTranslator);

View File

@@ -1,5 +1,5 @@
/*
* Copyright 2002-2017 the original author or authors.
* Copyright 2002-2018 the original author or authors.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -179,16 +179,21 @@ public class TemporaryLobCreator implements LobCreator {
@Override
public void close() {
try {
for (Blob blob : this.temporaryBlobs) {
for (Blob blob : this.temporaryBlobs) {
try {
blob.free();
}
for (Clob clob : this.temporaryClobs) {
clob.free();
catch (SQLException ex) {
logger.warn("Could not free BLOB", ex);
}
}
catch (SQLException ex) {
logger.error("Could not free LOB", ex);
for (Clob clob : this.temporaryClobs) {
try {
clob.free();
}
catch (SQLException ex) {
logger.warn("Could not free CLOB", ex);
}
}
}