GH-2727: Ensure JDBC queries are logged

spring-integration-jdbc/src/main/java/org/springframework/integration/jdbc/JdbcMessageHandler.java

@@ -1,5 +1,5 @@
 /*
- * Copyright 2002-2018 the original author or authors.
+ * Copyright 2002-2019 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.
@@ -19,7 +19,6 @@
 import java.sql.PreparedStatement;
 import java.sql.ResultSet;
 import java.sql.SQLException;
-import java.sql.Statement;
 import java.util.Arrays;
 import java.util.Collections;
 import java.util.LinkedList;
@@ -35,7 +34,9 @@
 import org.springframework.jdbc.core.BatchPreparedStatementSetter;
 import org.springframework.jdbc.core.ColumnMapRowMapper;
 import org.springframework.jdbc.core.JdbcOperations;
+import org.springframework.jdbc.core.JdbcTemplate;
 import org.springframework.jdbc.core.PreparedStatementCreator;
+import org.springframework.jdbc.core.PreparedStatementCreatorFactory;
 import org.springframework.jdbc.core.ResultSetExtractor;
 import org.springframework.jdbc.core.RowMapperResultSetExtractor;
 import org.springframework.jdbc.core.namedparam.NamedParameterJdbcOperations;
@@ -44,6 +45,7 @@
 import org.springframework.jdbc.support.GeneratedKeyHolder;
 import org.springframework.jdbc.support.JdbcUtils;
 import org.springframework.jdbc.support.KeyHolder;
+import org.springframework.lang.Nullable;
 import org.springframework.messaging.Message;
 import org.springframework.messaging.MessageHeaders;
 import org.springframework.util.Assert;
@@ -84,11 +86,10 @@ public class JdbcMessageHandler extends AbstractMessageHandler {
 
 	private final NamedParameterJdbcOperations jdbcOperations;
 
-	private final PreparedStatementCreator generatedKeysStatementCreator =
-			con -> con.prepareStatement(JdbcMessageHandler.this.updateSql, Statement.RETURN_GENERATED_KEYS);
-
 	private String updateSql;
 
+	private PreparedStatementCreator generatedKeysStatementCreator;
+
 	private SqlParameterSourceFactory sqlParameterSourceFactory;
 
 	private boolean keysGenerated;
@@ -102,8 +103,7 @@ public class JdbcMessageHandler extends AbstractMessageHandler {
 	 * @param updateSql query to execute
 	 */
 	public JdbcMessageHandler(DataSource dataSource, String updateSql) {
-		this.jdbcOperations = new NamedParameterJdbcTemplate(dataSource);
-		this.updateSql = updateSql;
+		this(new JdbcTemplate(dataSource), updateSql);
 	}
 
 	/**
@@ -113,8 +113,10 @@ public JdbcMessageHandler(DataSource dataSource, String updateSql) {
 	 * @param updateSql query to execute
 	 */
 	public JdbcMessageHandler(JdbcOperations jdbcOperations, String updateSql) {
+		Assert.notNull(jdbcOperations, "'jdbcOperations' must not be null.");
+		Assert.hasText(updateSql, "'updateSql' must not be empty.");
 		this.jdbcOperations = new NamedParameterJdbcTemplate(jdbcOperations);
-		setUpdateSql(updateSql);
+		this.updateSql = updateSql;
 	}
 
 	/**
@@ -129,7 +131,9 @@ public void setKeysGenerated(boolean keysGenerated) {
 	/**
 	 * Configure an SQL statement to perform an UPDATE on the target database.
 	 * @param updateSql the SQL statement to perform.
+	 * @deprecated since 5.1.3 in favor of constructor argument.
 	 */
+	@Deprecated
 	public final void setUpdateSql(String updateSql) {
 		Assert.hasText(updateSql, "'updateSql' must not be empty.");
 		this.updateSql = updateSql;
@@ -146,8 +150,15 @@ public void setSqlParameterSourceFactory(SqlParameterSourceFactory sqlParameterS
 	 * @param preparedStatementSetter the {@link MessagePreparedStatementSetter} to set.
 	 * @since 4.2
 	 */
-	public void setPreparedStatementSetter(MessagePreparedStatementSetter preparedStatementSetter) {
+	public void setPreparedStatementSetter(@Nullable MessagePreparedStatementSetter preparedStatementSetter) {
 		this.preparedStatementSetter = preparedStatementSetter;
+		if (preparedStatementSetter != null) {
+			PreparedStatementCreatorFactory preparedStatementCreatorFactory =
+					new PreparedStatementCreatorFactory(this.updateSql);
+			preparedStatementCreatorFactory.setReturnGeneratedKeys(true);
+			this.generatedKeysStatementCreator =
+					preparedStatementCreatorFactory.newPreparedStatementCreator((Object[]) null);
+		}
 	}
 
 	@Override

spring-integration-jdbc/src/main/java/org/springframework/integration/jdbc/JdbcPollingChannelAdapter.java

@@ -16,22 +16,29 @@
 
 package org.springframework.integration.jdbc;
 
+import java.sql.Connection;
 import java.sql.PreparedStatement;
+import java.sql.SQLException;
 import java.util.List;
 import java.util.function.Consumer;
 
 import javax.sql.DataSource;
 
+import org.springframework.beans.factory.BeanFactory;
 import org.springframework.integration.endpoint.AbstractMessageSource;
 import org.springframework.jdbc.core.ColumnMapRowMapper;
 import org.springframework.jdbc.core.JdbcOperations;
 import org.springframework.jdbc.core.JdbcTemplate;
+import org.springframework.jdbc.core.ParameterDisposer;
 import org.springframework.jdbc.core.PreparedStatementCreator;
 import org.springframework.jdbc.core.PreparedStatementCreatorFactory;
+import org.springframework.jdbc.core.PreparedStatementSetter;
 import org.springframework.jdbc.core.RowMapper;
+import org.springframework.jdbc.core.SqlProvider;
 import org.springframework.jdbc.core.namedparam.NamedParameterJdbcOperations;
 import org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate;
 import org.springframework.jdbc.core.namedparam.SqlParameterSource;
+import org.springframework.lang.Nullable;
 import org.springframework.util.Assert;
 
 /**
@@ -87,24 +94,22 @@ public JdbcPollingChannelAdapter(JdbcOperations jdbcOperations, String selectQue
 
 			@Override
 			protected PreparedStatementCreator getPreparedStatementCreator(String sql,
-					SqlParameterSource paramSource, Consumer<PreparedStatementCreatorFactory> customizer) {
+					SqlParameterSource paramSource, @Nullable Consumer<PreparedStatementCreatorFactory> customizer) {
 
 				PreparedStatementCreator preparedStatementCreator =
 						super.getPreparedStatementCreator(sql, paramSource, customizer);
 
-				return con -> {
-					PreparedStatement preparedStatement = preparedStatementCreator.createPreparedStatement(con);
-					preparedStatement.setMaxRows(JdbcPollingChannelAdapter.this.maxRows);
-					return preparedStatement;
-				};
+				return new PreparedStatementCreatorWithMaxRows(preparedStatementCreator,
+						JdbcPollingChannelAdapter.this.maxRows);
 			}
+
 		};
 
 		this.selectQuery = selectQuery;
 		this.rowMapper = new ColumnMapRowMapper();
 	}
 
-	public void setRowMapper(RowMapper<?> rowMapper) {
+	public void setRowMapper(@Nullable RowMapper<?> rowMapper) {
 		this.rowMapper = rowMapper;
 		if (rowMapper == null) {
 			this.rowMapper = new ColumnMapRowMapper();
@@ -120,6 +125,7 @@ public void setUpdatePerRow(boolean updatePerRow) {
 	}
 
 	public void setUpdateSqlParameterSourceFactory(SqlParameterSourceFactory sqlParameterSourceFactory) {
+		Assert.notNull(sqlParameterSourceFactory, "'sqlParameterSourceFactory' must be null.");
 		this.sqlParameterSourceFactory = sqlParameterSourceFactory;
 		this.sqlParameterSourceFactorySet = true;
 	}
@@ -128,7 +134,7 @@ public void setUpdateSqlParameterSourceFactory(SqlParameterSourceFactory sqlPara
 	 * A source of parameters for the select query used for polling.
 	 * @param sqlQueryParameterSource the sql query parameter source to set
 	 */
-	public void setSelectSqlParameterSource(SqlParameterSource sqlQueryParameterSource) {
+	public void setSelectSqlParameterSource(@Nullable SqlParameterSource sqlQueryParameterSource) {
 		this.sqlQueryParameterSource = sqlQueryParameterSource;
 	}
 
@@ -155,9 +161,10 @@ public void setMaxRows(int maxRows) {
 
 	@Override
 	protected void onInit() {
-		if (!this.sqlParameterSourceFactorySet && getBeanFactory() != null) {
+		BeanFactory beanFactory = getBeanFactory();
+		if (!this.sqlParameterSourceFactorySet && beanFactory != null) {
 			((ExpressionEvaluatingSqlParameterSourceFactory) this.sqlParameterSourceFactory)
-					.setBeanFactory(getBeanFactory());
+					.setBeanFactory(beanFactory);
 		}
 	}
 
@@ -190,7 +197,7 @@ protected Object doReceive() {
 		return payload;
 	}
 
-	protected List<?> doPoll(SqlParameterSource sqlQueryParameterSource) {
+	protected List<?> doPoll(@Nullable SqlParameterSource sqlQueryParameterSource) {
 		if (sqlQueryParameterSource != null) {
 			return this.jdbcOperations.query(this.selectQuery, sqlQueryParameterSource, this.rowMapper);
 		}
@@ -200,8 +207,52 @@ protected List<?> doPoll(SqlParameterSource sqlQueryParameterSource) {
 	}
 
 	private void executeUpdateQuery(Object obj) {
-		SqlParameterSource updateParameterSource = this.sqlParameterSourceFactory.createParameterSource(obj);
-		this.jdbcOperations.update(this.updateSql, updateParameterSource);
+		this.jdbcOperations.update(this.updateSql, this.sqlParameterSourceFactory.createParameterSource(obj));
+	}
+
+	private static final class PreparedStatementCreatorWithMaxRows
+			implements PreparedStatementCreator, PreparedStatementSetter, SqlProvider, ParameterDisposer {
+
+		private final PreparedStatementCreator delegate;
+
+		private final int maxRows;
+
+		private PreparedStatementCreatorWithMaxRows(PreparedStatementCreator delegate, int maxRows) {
+			this.delegate = delegate;
+			this.maxRows = maxRows;
+		}
+
+		@Override
+		public PreparedStatement createPreparedStatement(Connection con) throws SQLException {
+			PreparedStatement preparedStatement = this.delegate.createPreparedStatement(con);
+			preparedStatement.setMaxRows(this.maxRows); // We can't mutate provided JdbOperations for this option
+			return preparedStatement;
+		}
+
+		@Override
+		public String getSql() {
+			if (this.delegate instanceof SqlProvider) {
+				return ((SqlProvider) this.delegate).getSql();
+			}
+			else {
+				return null;
+			}
+		}
+
+		@Override
+		public void setValues(PreparedStatement ps) throws SQLException {
+			if (this.delegate instanceof PreparedStatementSetter) {
+				((PreparedStatementSetter) this.delegate).setValues(ps);
+			}
+		}
+
+		@Override
+		public void cleanupParameters() {
+			if (this.delegate instanceof ParameterDisposer) {
+				((ParameterDisposer) this.delegate).cleanupParameters();
+			}
+		}
+
 	}
 
 }

spring-integration-jdbc/src/test/java/org/springframework/integration/jdbc/config/JdbcOutboundGatewayParserTests.java

@@ -1,5 +1,5 @@
 /*
- * Copyright 2002-2018 the original author or authors.
+ * Copyright 2002-2019 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.
@@ -20,6 +20,9 @@
 import static org.junit.Assert.assertFalse;
 import static org.junit.Assert.assertNotNull;
 import static org.junit.Assert.assertTrue;
+import static org.mockito.BDDMockito.given;
+import static org.mockito.Mockito.spy;
+import static org.mockito.Mockito.verify;
 
 import java.sql.PreparedStatement;
 import java.sql.SQLException;
@@ -28,6 +31,7 @@
 
 import javax.sql.DataSource;
 
+import org.apache.commons.logging.Log;
 import org.junit.After;
 import org.junit.Assert;
 import org.junit.Test;
@@ -97,6 +101,7 @@ public void testMapPayloadMapReply() {
 	@SuppressWarnings("unchecked")
 	public void testKeyGeneration() {
 		setUp("handlingKeyGenerationJdbcOutboundGatewayTest.xml", getClass());
+
 		Message<?> message = MessageBuilder.withPayload(Collections.singletonMap("foo", "bar")).build();
 
 		this.channel.send(message);
@@ -114,8 +119,19 @@ public void testKeyGeneration() {
 
 		this.jdbcTemplate.execute("DELETE FROM BARS");
 
+		Object insertGateway = this.context.getBean("insertGatewayWithSetter.handler");
+		JdbcTemplate handlerJdbcTemplate =
+				TestUtils.getPropertyValue(insertGateway,
+						"handler.jdbcOperations.classicJdbcTemplate", JdbcTemplate.class);
+
+		Log logger = spy(TestUtils.getPropertyValue(handlerJdbcTemplate, "logger", Log.class));
+
+		given(logger.isDebugEnabled()).willReturn(true);
+
+		new DirectFieldAccessor(handlerJdbcTemplate).setPropertyValue("logger", logger);
+
 		MessageChannel setterRequest = this.context.getBean("setterRequest", MessageChannel.class);
-		setterRequest.send(new GenericMessage<String>("bar2"));
+		setterRequest.send(new GenericMessage<>("bar2"));
 		reply = this.messagingTemplate.receive();
 		assertNotNull(reply);
 
@@ -125,6 +141,8 @@ public void testKeyGeneration() {
 		map = this.jdbcTemplate.queryForMap("SELECT * from BARS");
 		assertEquals("Wrong id", id, map.get("ID"));
 		assertEquals("Wrong name", "bar2", map.get("name"));
+
+		verify(logger).debug("Executing prepared SQL statement [insert into bars (status, name) values (0, ?)]");
 	}
 
 	@Test
@@ -142,8 +160,21 @@ public void testCountUpdates() {
 	}
 
 	@Test
-	public void testWithPoller() throws Exception {
+	public void testWithPoller() {
 		setUp("JdbcOutboundGatewayWithPollerTest-context.xml", this.getClass());
+
+		Object insertGateway = this.context.getBean("jdbcOutboundGateway.handler");
+		JdbcTemplate pollerJdbcTemplate =
+				TestUtils.getPropertyValue(insertGateway,
+						"poller.jdbcOperations.classicJdbcTemplate", JdbcTemplate.class);
+
+		Log logger = spy(TestUtils.getPropertyValue(pollerJdbcTemplate, "logger", Log.class));
+
+		given(logger.isDebugEnabled()).willReturn(true);
+
+		new DirectFieldAccessor(pollerJdbcTemplate).setPropertyValue("logger", logger);
+
+
 		Message<?> message = MessageBuilder.withPayload(Collections.singletonMap("foo", "bar")).build();
 
 		this.channel.send(message);
@@ -157,10 +188,12 @@ public void testWithPoller() throws Exception {
 		Map<String, Object> map = this.jdbcTemplate.queryForMap("SELECT * from BAZZ");
 		assertEquals("Wrong id", message.getHeaders().getId().toString(), map.get("ID"));
 		assertEquals("Wrong name", "bar", map.get("name"));
+
+		verify(logger).debug("Executing prepared SQL statement [select * from bazz where id=?]");
 	}
 
 	@Test
-	public void testWithSelectQueryOnly() throws Exception {
+	public void testWithSelectQueryOnly() {
 		setUp("JdbcOutboundGatewayWithSelectTest-context.xml", getClass());
 		Message<?> message = MessageBuilder.withPayload(100).build();
 

spring-integration-jdbc/src/test/java/org/springframework/integration/jdbc/config/handlingKeyGenerationJdbcOutboundGatewayTest.xml

@@ -20,7 +20,8 @@
 	<beans:bean id="messagePreparedStatementSetter"
 				class="org.springframework.integration.jdbc.config.JdbcOutboundGatewayParserTests$TestMessagePreparedStatementSetter"/>
 
-	<outbound-gateway update="insert into bars (status, name) values (0, ?)"
+	<outbound-gateway id="insertGatewayWithSetter"
+					  update="insert into bars (status, name) values (0, ?)"
 					  request-channel="setterRequest"
 					  reply-channel="output"
 					  data-source="dataSource"