Add query logger

[resolves #201]

Author: mp911de

README.md

@@ -362,7 +362,15 @@ This driver accepts the following extensions:
 
 * `CodecRegistrar` to contribute `Codec`s for Postgres ObjectIDs. 
 
-Extensions can be registered programmatically using `PostgresConnectionConfiguration` or discovered using Java's `ServiceLoader` mechanism (from `META-INF/services/io.r2dbc.postgresql.extension.Extension`).                                                                                                                                                                                                
+Extensions can be registered programmatically using `PostgresConnectionConfiguration` or discovered using Java's `ServiceLoader` mechanism (from `META-INF/services/io.r2dbc.postgresql.extension.Extension`).
+
+## Logging
+If SL4J is on the classpath, it will be used. Otherwise, there are two possible fallbacks: Console or `java.util.logging.Logger`). By default, the Console fallback is used. To use the JDK loggers, set the `reactor.logging.fallback` System property to `JDK`.
+
+Logging facilities:
+
+* Driver Logging: `io.r2dbc.postgresql`.                                                                                                                                                                                            
+* Query Logging: `io.r2dbc.postgresql.QUERY` on `DEBUG` level.                                                                                                                                                                                            
 
 ## License
 This project is released under version 2.0 of the [Apache License][l].

src/main/java/io/r2dbc/postgresql/ExtendedQueryPostgresqlStatement.java

@@ -183,7 +183,7 @@ private Flux<io.r2dbc.postgresql.api.PostgresqlResult> execute(String sql) {
         ExceptionFactory factory = ExceptionFactory.withSql(sql);
         return this.statementCache.getName(this.bindings.first(), sql)
             .flatMapMany(name -> ExtendedQueryMessageFlow
-                .execute(Flux.fromIterable(this.bindings.bindings), this.client, this.portalNameSupplier, name, this.forceBinary))
+                .execute(Flux.fromIterable(this.bindings.bindings), this.client, this.portalNameSupplier, name, sql, this.forceBinary))
             .filter(RESULT_FRAME_FILTER)
             .windowUntil(CloseComplete.class::isInstance)
             .map(messages -> PostgresqlResult.toResult(this.codecs, messages, factory));

src/main/java/io/r2dbc/postgresql/client/ExtendedQueryMessageFlow.java

@@ -65,19 +65,20 @@ private ExtendedQueryMessageFlow() {
      * @param bindings           the {@link Binding}s to bind
      * @param client             the {@link Client} to exchange messages with
      * @param portalNameSupplier supplier unique portal names for each binding
-     * @param statement          the name of the statement to execute
+     * @param statementName      the name of the statementName to execute
+     * @param query              the query to execute
      * @param forceBinary        force backend to return column data values in binary format for all columns
      * @return the messages received in response to the exchange
-     * @throws IllegalArgumentException if {@code bindings}, {@code client}, {@code portalNameSupplier}, or {@code statement} is {@code null}
+     * @throws IllegalArgumentException if {@code bindings}, {@code client}, {@code portalNameSupplier}, or {@code statementName} is {@code null}
      */
-    public static Flux<BackendMessage> execute(Publisher<Binding> bindings, Client client, PortalNameSupplier portalNameSupplier, String statement, boolean forceBinary) {
+    public static Flux<BackendMessage> execute(Publisher<Binding> bindings, Client client, PortalNameSupplier portalNameSupplier, String statementName, String query, boolean forceBinary) {
         Assert.requireNonNull(bindings, "bindings must not be null");
         Assert.requireNonNull(client, "client must not be null");
         Assert.requireNonNull(portalNameSupplier, "portalNameSupplier must not be null");
-        Assert.requireNonNull(statement, "statement must not be null");
+        Assert.requireNonNull(statementName, "statementName must not be null");
 
         return client.exchange(Flux.from(bindings)
-            .flatMap(binding -> toBindFlow(binding, portalNameSupplier, statement, forceBinary))
+            .flatMap(binding -> toBindFlow(binding, portalNameSupplier, statementName, query, forceBinary))
             .concatWith(Mono.just(Sync.INSTANCE)));
     }
 
@@ -109,7 +110,7 @@ private static Collection<Format> resultFormat(boolean forceBinary) {
         }
     }
 
-    private static Flux<FrontendMessage> toBindFlow(Binding binding, PortalNameSupplier portalNameSupplier, String statement, boolean forceBinary) {
+    private static Flux<FrontendMessage> toBindFlow(Binding binding, PortalNameSupplier portalNameSupplier, String statementName, String query, boolean forceBinary) {
         String portal = portalNameSupplier.get();
 
         return Flux.fromIterable(binding.getParameterValues())
@@ -123,10 +124,10 @@ private static Flux<FrontendMessage> toBindFlow(Binding binding, PortalNameSuppl
             })
             .collectList()
             .flatMapMany(values -> {
-                Bind bind = new Bind(portal, binding.getParameterFormats(), values, resultFormat(forceBinary), statement);
+                Bind bind = new Bind(portal, binding.getParameterFormats(), values, resultFormat(forceBinary), statementName);
 
                 return Flux.just(bind, new Describe(portal, PORTAL), new Execute(portal, NO_LIMIT), new Close(portal, PORTAL));
-            });
+            }).doOnSubscribe(ignore -> QueryLogger.logQuery(query));
     }
 
 }

src/main/java/io/r2dbc/postgresql/client/QueryLogger.java

@@ -0,0 +1,32 @@
+/*
+ * Copyright 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.
+ * You may obtain a copy of the License at
+ *
+ *      https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * 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 io.r2dbc.postgresql.client;
+
+import reactor.util.Logger;
+import reactor.util.Loggers;
+
+/**
+ * Query logger to log queries.
+ */
+final class QueryLogger {
+
+    private static final Logger QUERY_LOGGER = Loggers.getLogger("io.r2dbc.postgresql.QUERY");
+
+    static void logQuery(String query) {
+        QUERY_LOGGER.debug("Executing query: {}", query);
+    }
+}

src/main/java/io/r2dbc/postgresql/client/SimpleQueryMessageFlow.java

@@ -17,6 +17,7 @@
 package io.r2dbc.postgresql.client;
 
 import io.r2dbc.postgresql.message.backend.BackendMessage;
+import io.r2dbc.postgresql.message.frontend.FrontendMessage;
 import io.r2dbc.postgresql.message.frontend.Query;
 import io.r2dbc.postgresql.util.Assert;
 import reactor.core.publisher.Flux;
@@ -42,7 +43,7 @@ public static Flux<BackendMessage> exchange(Client client, String query) {
         Assert.requireNonNull(client, "client must not be null");
         Assert.requireNonNull(query, "query must not be null");
 
-        return client.exchange(Mono.just(new Query(query)));
+        return client.exchange(Mono.<FrontendMessage>just(new Query(query)).doOnSubscribe(ignore -> QueryLogger.logQuery(query)));
     }
 
 }

src/test/java/io/r2dbc/postgresql/client/ExtendedQueryMessageFlowTest.java

@@ -69,7 +69,7 @@ BindComplete.INSTANCE, NoData.INSTANCE, new CommandComplete("test", null, null)
         PortalNameSupplier portalNameSupplier = new LinkedList<>(Arrays.asList("B_0", "B_1"))::remove;
 
         ExtendedQueryMessageFlow
-            .execute(bindings, client, portalNameSupplier, "test-name", false)
+            .execute(bindings, client, portalNameSupplier, "test-name", "", false)
             .as(StepVerifier::create)
             .expectNext(BindComplete.INSTANCE, NoData.INSTANCE, new CommandComplete("test", null, null))
             .expectNext(BindComplete.INSTANCE, NoData.INSTANCE, new CommandComplete("test", null, null))
@@ -78,25 +78,25 @@ BindComplete.INSTANCE, NoData.INSTANCE, new CommandComplete("test", null, null)
 
     @Test
     void executeNoBindings() {
-        assertThatIllegalArgumentException().isThrownBy(() -> ExtendedQueryMessageFlow.execute(null, NO_OP, () -> "", "test-statement", false))
+        assertThatIllegalArgumentException().isThrownBy(() -> ExtendedQueryMessageFlow.execute(null, NO_OP, () -> "", "test-statement", "", false))
             .withMessage("bindings must not be null");
     }
 
     @Test
     void executeNoClient() {
-        assertThatIllegalArgumentException().isThrownBy(() -> ExtendedQueryMessageFlow.execute(Flux.empty(), null, () -> "", "test-statement", false))
+        assertThatIllegalArgumentException().isThrownBy(() -> ExtendedQueryMessageFlow.execute(Flux.empty(), null, () -> "", "test-statement", "", false))
             .withMessage("client must not be null");
     }
 
     @Test
     void executeNoPortalNameSupplier() {
-        assertThatIllegalArgumentException().isThrownBy(() -> ExtendedQueryMessageFlow.execute(Flux.empty(), NO_OP, null, "test-statement", false))
+        assertThatIllegalArgumentException().isThrownBy(() -> ExtendedQueryMessageFlow.execute(Flux.empty(), NO_OP, null, "test-statement", "", false))
             .withMessage("portalNameSupplier must not be null");
     }
 
     @Test
     void executeNoStatement() {
-        assertThatIllegalArgumentException().isThrownBy(() -> ExtendedQueryMessageFlow.execute(Flux.empty(), NO_OP, () -> "", null, false))
+        assertThatIllegalArgumentException().isThrownBy(() -> ExtendedQueryMessageFlow.execute(Flux.empty(), NO_OP, () -> "", null, "", false))
             .withMessage("statement must not be null");
     }