Logging query, exec time and rs json metadata

src/main/java/com/mongodb/jdbc/MongoJsonSchema.java

@@ -17,7 +17,9 @@
 package com.mongodb.jdbc;
 
 import static com.mongodb.jdbc.BsonTypeInfo.*;
+import static org.bson.codecs.configuration.CodecRegistries.fromProviders;
 
+import java.io.StringWriter;
 import java.sql.DatabaseMetaData;
 import java.sql.SQLException;
 import java.util.HashMap;
@@ -29,18 +31,33 @@
 import java.util.Set;
 import java.util.stream.Collectors;
 import java.util.stream.Stream;
-import org.apache.commons.lang3.builder.ToStringBuilder;
-import org.apache.commons.lang3.builder.ToStringStyle;
 import org.bson.BsonInvalidOperationException;
 import org.bson.BsonType;
 import org.bson.BsonValue;
+import org.bson.codecs.BsonValueCodecProvider;
 import org.bson.codecs.Codec;
+import org.bson.codecs.EncoderContext;
+import org.bson.codecs.ValueCodecProvider;
+import org.bson.codecs.configuration.CodecRegistry;
+import org.bson.codecs.pojo.PojoCodecProvider;
 import org.bson.codecs.pojo.annotations.BsonIgnore;
+import org.bson.json.JsonMode;
+import org.bson.json.JsonWriter;
+import org.bson.json.JsonWriterSettings;
 
 public class MongoJsonSchema {
     private static final Codec<JsonSchema> JSON_SCHEMA_CODEC =
             MongoDriver.registry.get(JsonSchema.class);
 
+    private static final CodecRegistry REGISTRY =
+            fromProviders(
+                    new BsonValueCodecProvider(),
+                    new ValueCodecProvider(),
+                    PojoCodecProvider.builder().automatic(true).build());;
+    private static final Codec<MongoJsonSchema> CODEC = REGISTRY.get(MongoJsonSchema.class);
+    private static final JsonWriterSettings JSON_WRITER_SETTINGS =
+            JsonWriterSettings.builder().outputMode(JsonMode.RELAXED).indent(true).build();
+
     public static class ScalarProperties {
         protected String name;
         protected boolean isRequired = true;
@@ -421,7 +438,15 @@ public int hashCode() {
 
     @Override
     public String toString() {
-        return ToStringBuilder.reflectionToString(this, ToStringStyle.SHORT_PREFIX_STYLE);
+
+        StringWriter writer = new StringWriter();
+        CODEC.encode(
+                new JsonWriter(writer, JSON_WRITER_SETTINGS),
+                this,
+                EncoderContext.builder().build());
+        writer.flush();
+
+        return writer.toString();
     }
 
     // Any is represented by the empty json schema {}, so all fields

src/main/java/com/mongodb/jdbc/MongoResultSet.java

@@ -45,10 +45,8 @@
 import java.sql.Types;
 import java.text.ParseException;
 import java.text.SimpleDateFormat;
-import java.util.Calendar;
-import java.util.List;
-import java.util.Objects;
-import java.util.TimeZone;
+import java.util.*;
+import java.util.logging.Level;
 import javax.sql.rowset.serial.SerialBlob;
 import javax.sql.rowset.serial.SerialClob;
 import javax.sql.rowset.serial.SerialException;
@@ -85,6 +83,8 @@ public class MongoResultSet implements ResultSet {
     protected boolean extJsonMode;
     protected UuidRepresentation uuidRepresentation;
 
+    private MongoJsonSchema jsonSchema;
+
     /**
      * Constructor for a MongoResultset tied to a connection and statement.
      *
@@ -143,6 +143,7 @@ private void setUpResultset(
             Integer statementId)
             throws SQLException {
         Preconditions.checkNotNull(cursor);
+        this.jsonSchema = schema;
         // dateFormat is not thread safe, so we do not want to make it a static field.
         dateFormat.setTimeZone(UTC);
         // Only sort the columns alphabetically for SQL statement result sets and not for database metadata result sets.
@@ -155,6 +156,12 @@ private void setUpResultset(
                         schema, selectOrder, sortFieldsAlphabetically, parentLogger, statementId);
     }
 
+    public String getJsonSchema() throws SQLException {
+        checkClosed();
+
+        return this.jsonSchema.toString();
+    }
+
     // This is only used for testing, and that is why it has package level access, and the
     // tests have been moved into this package.
     BsonDocument getCurrent() {
@@ -174,14 +181,27 @@ private void checkBounds(int i) throws SQLException {
     @Override
     public boolean next() throws SQLException {
         checkClosed();
-
-        boolean result;
-        result = cursor.hasNext();
-        if (result) {
-            current = cursor.next();
-            ++rowNum;
+        try {
+            boolean result;
+            logger.log(Level.FINE, "More rows available ? ");
+            result = cursor.hasNext();
+            logger.log(Level.FINE, String.valueOf(result));
+            if (result) {
+                logger.log(Level.FINE, "Getting row " + (rowNum + 1));
+                long startTime = System.nanoTime();
+                current = cursor.next();
+                long endTime = System.nanoTime();
+                logger.log(
+                        Level.FINE,
+                        "Moved to next row in "
+                                + ((endTime - startTime) / 1000000d)
+                                + " milliseconds");
+                ++rowNum;
+            }
+            return result;
+        } catch (Exception e) {
+            throw new SQLException(e);
         }
-        return result;
     }
 
     @Override

src/main/java/com/mongodb/jdbc/MongoStatement.java

@@ -30,6 +30,7 @@
 import java.sql.*;
 import java.util.*;
 import java.util.concurrent.TimeUnit;
+import java.util.logging.Level;
 import org.bson.*;
 
 @AutoLoggable
@@ -264,12 +265,18 @@ private ResultSet executeDirectClusterQuery(String sql)
     public ResultSet executeQuery(String sql) throws SQLException {
         checkClosed();
         closeExistingResultSet();
-
+        long startTime = System.nanoTime();
+        logger.log(
+                Level.INFO,
+                "\n---------- Query ----------\n"
+                        + sql
+                        + "\n----------------------------------------\n");
+        ResultSet result = null;
         try {
             if (conn.getClusterType() == MongoConnection.MongoClusterType.AtlasDataFederation) {
-                return executeAtlasDataFederationQuery(sql);
+                result = executeAtlasDataFederationQuery(sql);
             } else if (conn.getClusterType() == MongoConnection.MongoClusterType.Enterprise) {
-                return executeDirectClusterQuery(sql);
+                result = executeDirectClusterQuery(sql);
             } else {
                 throw new SQLException("Unsupported cluster type: " + conn.clusterType);
             }
@@ -278,6 +285,16 @@ public ResultSet executeQuery(String sql) throws SQLException {
         } catch (MongoSQLException | MongoSerializationException e) {
             throw new RuntimeException(e);
         }
+        long endTime = System.nanoTime();
+        logger.log(
+                Level.INFO,
+                "Query executed in " + ((endTime - startTime) / 1000000000d) + " seconds");
+        logger.log(
+                Level.INFO,
+                "\n---------- Resultset schema -------\n"
+                        + ((MongoResultSet) result).getJsonSchema().toString()
+                        + "\n----------------------------------------\n");
+        return result;
     }
 
     @Override