Use logback and offer structured logging options

Dockerfile

@@ -17,7 +17,8 @@
 # KIND, either express or implied.  See the License for the
 # specific language governing permissions and limitations
 # under the License.
-FROM adoptopenjdk/openjdk8-openj9:jre8u322-b06_openj9-0.30.0-ubuntu
+ARG platform=linux/amd64
+FROM --platform=$platform adoptopenjdk/openjdk8-openj9:jre8u322-b06_openj9-0.30.0-ubuntu
 
 ARG revision=latest
 ARG repository=ClickHouse/clickhouse-jdbc-bridge

NOTICE

@@ -35,10 +35,17 @@ This project includes:
   Jackson-core under The Apache Software License, Version 2.0
   jackson-databind under The Apache Software License, Version 2.0
   Java Native Access under LGPL, version 2.1 or Apache License v2.0
+  JavaBeans Activation Framework (JAF) under Common Development and Distribution License (CDDL) v1.0
+  JavaMail API under CDDL/GPLv2+CE
   jcommander under Apache 2.0
   JetBrains Java Annotations under The Apache Software License, Version 2.0
   JUnit under Eclipse Public License 1.0
   LatencyUtils under Public Domain, per Creative Commons CC0
+  Logback Classic Module under Eclipse Public License - v 1.0 or GNU Lesser General Public License
+  Logback Contrib :: Jackson under Eclipse Public License - v 1.0 or GNU Lesser General Public License
+  Logback Contrib :: JSON :: Classic under Eclipse Public License - v 1.0 or GNU Lesser General Public License
+  Logback Contrib :: JSON :: Core under Eclipse Public License - v 1.0 or GNU Lesser General Public License
+  Logback Core Module under Eclipse Public License - v 1.0 or GNU Lesser General Public License
   micrometer-core under The Apache Software License, Version 2.0
   micrometer-registry-prometheus under The Apache Software License, Version 2.0
   Netty/Buffer under Apache License, Version 2.0
@@ -57,7 +64,6 @@ This project includes:
   Prometheus Java Simpleclient under The Apache Software License, Version 2.0
   Prometheus Java Simpleclient Common under The Apache Software License, Version 2.0
   SLF4J API Module under MIT License
-  SLF4J JDK14 Binding under MIT License
   Testcontainers Core under MIT
   testng under Apache 2.0
   Vert.x Bridge Common under The Apache Software License, Version 2.0 or Eclipse Public License - v 1.0

README.md

@@ -286,7 +286,13 @@ Assuming you started a test environment using docker-compose, please refer to ex
 
 * Logging
 
-    You can customize logging configuration in [logging.properties](docker/logging.properties).
+    You can customize logging configuration in [logback.xml](docker/logback.xml). See the [logback documentation](https://logback.qos.ch/manual/configuration.html) for details about the contents of this file.
+
+    Note that the default logging level is `trace` -- you may wish to set this to `info` or `warning` for less verbose logs in production.
+
+    Note also that the default logging format is the default plaintext format suggested by logback. We also provide (by way of example) a structured log appender named `JSON_STDOUT`; to use it you will need to change the `appender-ref` property of the root logger to point to it.
+
+    WARNING: because the shaded jar build process relocates most classes to the `com.clickhouse.jdbcbridge.internal` path, using the default class paths offered in the logback documentation will result in import errors. If building your own logback.xml file, you will need to replace all references to `ch.qos.logback` with `com.clickhouse.jdbcbridge.internal.qos.logback` -- the included logback.xml file does this for you.
 
 * Vert.x
 

docker/docker-entrypoint.sh

@@ -3,39 +3,39 @@
 set -e
 
 start_server() {
-	local base_url="${MAVEN_REPO_URL:="https://repo1.maven.org/maven2"}"
-	local driver_dir="$JDBC_BRIDGE_HOME/drivers"
-	local jdbc_drivers="${JDBC_DRIVERS:=""}"
+  local base_url="${MAVEN_REPO_URL:="https://repo1.maven.org/maven2"}"
+  local driver_dir="$JDBC_BRIDGE_HOME/drivers"
+  local jdbc_drivers="${JDBC_DRIVERS:=""}"
 
-	# change work directory explicitly
-	cd $JDBC_BRIDGE_HOME
+  # change work directory explicitly
+  cd $JDBC_BRIDGE_HOME
 
-	if [ "$jdbc_drivers" != "" ] && [ "$(ls -A $driver_dir)" == "" ]; then
-		echo "Downloading JDBC drivers to directory [$driver_dir]..."
-		for i in $(echo "$jdbc_drivers" | sed "s/,/ /g"); do
-			if [ "$i" != "" ]; then
-				echo "  => [$base_url/$i]..."
-				wget -q -P "$driver_dir" "$base_url/$i"
-			fi
-		done
-	fi
+  if [ "$jdbc_drivers" != "" ] && [ "$(ls -A $driver_dir)" == "" ]; then
+    echo "Downloading JDBC drivers to directory [$driver_dir]..."
+    for i in $(echo "$jdbc_drivers" | sed "s/,/ /g"); do
+      if [ "$i" != "" ]; then
+        echo "  => [$base_url/$i]..."
+        wget -q -P "$driver_dir" "$base_url/$i"
+      fi
+    done
+  fi
 
-	if [ "$(echo ${CUSTOM_DRIVER_LOADER:="true"} | tr '[:upper:]' '[:lower:]')" != "true" ]; then
-		local classpath="./clickhouse-jdbc-bridge-shaded.jar:$(echo $(ls ${DRIVER_DIR:="drivers"}/*.jar) | tr ' ' ':'):."
-		java -XX:+UseContainerSupport -XX:+IdleTuningCompactOnIdle -XX:+IdleTuningGcOnIdle \
-			-Xdump:none -Xdump:tool:events=systhrow+throw,filter=*OutOfMemoryError,exec="kill -9 %pid" \
-			-Djava.util.logging.config.file=$JDBC_BRIDGE_HOME/logging.properties -Dnashorn.args=--language=es6 \
-			${JDBC_BRIDGE_JVM_OPTS:=""} -cp $classpath com.clickhouse.jdbcbridge.JdbcBridgeVerticle
-	else
-		java -XX:+UseContainerSupport -XX:+IdleTuningCompactOnIdle -XX:+IdleTuningGcOnIdle \
-			-Xdump:none -Xdump:tool:events=systhrow+throw,filter=*OutOfMemoryError,exec="kill -9 %pid" \
-			-Djava.util.logging.config.file=$JDBC_BRIDGE_HOME/logging.properties -Dnashorn.args=--language=es6 \
-			${JDBC_BRIDGE_JVM_OPTS:=""} -jar clickhouse-jdbc-bridge-shaded.jar
-	fi
+  if [ "$(echo ${CUSTOM_DRIVER_LOADER:="true"} | tr '[:upper:]' '[:lower:]')" != "true" ]; then
+    local classpath="./clickhouse-jdbc-bridge-shaded.jar:$(echo $(ls ${DRIVER_DIR:="drivers"}/*.jar) | tr ' ' ':'):."
+    java -XX:+UseContainerSupport -XX:+IdleTuningCompactOnIdle -XX:+IdleTuningGcOnIdle \
+      -Xdump:none -Xdump:tool:events=systhrow+throw,filter=*OutOfMemoryError,exec="kill -9 %pid" \
+      -Dlogback.configurationFile=$JDBC_BRIDGE_HOME/logback.xml -Dnashorn.args=--language=es6 \
+      ${JDBC_BRIDGE_JVM_OPTS:=""} -cp $classpath com.clickhouse.jdbcbridge.JdbcBridgeVerticle
+  else
+    java -XX:+UseContainerSupport -XX:+IdleTuningCompactOnIdle -XX:+IdleTuningGcOnIdle \
+      -Xdump:none -Xdump:tool:events=systhrow+throw,filter=*OutOfMemoryError,exec="kill -9 %pid" \
+      -Dlogback.configurationFile=$JDBC_BRIDGE_HOME/logback.xml -Dnashorn.args=--language=es6 \
+      ${JDBC_BRIDGE_JVM_OPTS:=""} -jar clickhouse-jdbc-bridge-shaded.jar
+  fi
 }
 
 if [ $# -eq 0 ]; then
-	start_server
+  start_server
 else
-	exec "$@"
+  exec "$@"
 fi

docker/logback.xml

@@ -0,0 +1,32 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+<!DOCTYPE configuration>
+
+<configuration>
+  <import class="com.clickhouse.jdbcbridge.internal.qos.logback.classic.encoder.PatternLayoutEncoder"/>
+  <import class="com.clickhouse.jdbcbridge.internal.qos.logback.contrib.jackson.JacksonJsonFormatter"/>
+  <import class="com.clickhouse.jdbcbridge.internal.qos.logback.contrib.json.classic.JsonLayout"/>
+  <import class="com.clickhouse.jdbcbridge.internal.qos.logback.core.ConsoleAppender"/>
+  <import class="com.clickhouse.jdbcbridge.internal.qos.logback.core.ConsoleAppender"/>
+  <import class="com.clickhouse.jdbcbridge.internal.qos.logback.core.encoder.LayoutWrappingEncoder"/>
+
+  <appender name="STDOUT" class="ConsoleAppender">
+    <encoder class="PatternLayoutEncoder">
+      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <appender name="JSON_STDOUT" class="ConsoleAppender">
+    <encoder class="LayoutWrappingEncoder">
+      <layout class="JsonLayout">
+        <appendLineSeparator>true</appendLineSeparator>
+        <timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSX</timestampFormat>
+        <timestampFormatTimezoneId>Etc/UTC</timestampFormatTimezoneId>
+        <jsonFormatter class="JacksonJsonFormatter"/>
+      </layout>
+    </encoder>
+  </appender>
+
+  <root level="trace">
+    <appender-ref ref="STDOUT"/>
+  </root>
+</configuration>

pom.xml

@@ -15,7 +15,7 @@
         <dnsjava.version>3.5.0</dnsjava.version>
         <vertx.version>3.9.13</vertx.version>
         <micrometer.version>1.1.19</micrometer.version>
-        <slf4j.version>1.7.36</slf4j.version>
+        <slf4j.version>2.0.1</slf4j.version>
         <hikaricp.version>3.4.5</hikaricp.version>
         <project.current.year>2022</project.current.year>
         <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
@@ -28,13 +28,18 @@
         <gpg-plugin.version>1.6</gpg-plugin.version>
         <replacer-plugin.version>1.5.3</replacer-plugin.version>
         <license-plugin.version>2.11</license-plugin.version>
+        <logback.version>1.3.4</logback.version>
         <notice-plugin.version>1.1.0</notice-plugin.version>
         <compiler-plugin.version>3.8.1</compiler-plugin.version>
         <source-plugin.version>3.2.1</source-plugin.version>
         <jar-plugin.version>3.2.0</jar-plugin.version>
         <javadoc-plugin.version>3.2.0</javadoc-plugin.version>
         <surefire-plugin.version>3.0.0-M5</surefire-plugin.version>
         <failsafe-plugin.version>3.0.0-M5</failsafe-plugin.version>
+        <logback-jackson.version>0.1.5</logback-jackson.version>
+        <logback-json.version>0.1.5</logback-json.version>
+        <jackson.version>2.13.4</jackson.version>
+        <jackson-databind.version>2.13.4.1</jackson-databind.version>
         <shade-plugin.version>3.2.4</shade-plugin.version>
         <shade.base>com.clickhouse.jdbcbridge.internal</shade.base>
         <deb-plugin.version>1.0.20</deb-plugin.version>
@@ -79,20 +84,38 @@
             <groupId>com.zaxxer</groupId>
             <artifactId>HikariCP</artifactId>
             <version>${hikaricp.version}</version>
+            <exclusions>
+                <exclusion>
+                    <groupId>org.slf4j</groupId>
+                    <artifactId>slf4j-api</artifactId>
+                </exclusion>
+            </exclusions>
         </dependency>
 
         <!-- SRV record resolving -->
         <dependency>
             <groupId>dnsjava</groupId>
             <artifactId>dnsjava</artifactId>
             <version>${dnsjava.version}</version>
+            <exclusions>
+                <exclusion>
+                    <groupId>org.slf4j</groupId>
+                    <artifactId>slf4j-api</artifactId>
+                </exclusion>
+            </exclusions>
         </dependency>
 
         <!-- Async Web server -->
         <dependency>
             <groupId>io.vertx</groupId>
             <artifactId>vertx-core</artifactId>
             <version>${vertx.version}</version>
+            <exclusions>
+                <exclusion>
+                    <groupId>com.fasterxml.jackson.core</groupId>
+                    <artifactId>jackson-core</artifactId>
+                </exclusion>
+            </exclusions>
         </dependency>
         <dependency>
             <groupId>io.vertx</groupId>
@@ -124,14 +147,29 @@
 
         <!-- Logging -->
         <dependency>
-            <groupId>org.slf4j</groupId>
-            <artifactId>slf4j-api</artifactId>
-            <version>${slf4j.version}</version>
+            <groupId>ch.qos.logback</groupId>
+            <artifactId>logback-classic</artifactId>
+            <version>${logback.version}</version>
+        </dependency>
+        <dependency>
+            <groupId>ch.qos.logback.contrib</groupId>
+            <artifactId>logback-json-classic</artifactId>
+            <version>${logback-json.version}</version>
+        </dependency>
+        <dependency>
+            <groupId>ch.qos.logback.contrib</groupId>
+            <artifactId>logback-jackson</artifactId>
+            <version>${logback-jackson.version}</version>
+        </dependency>
+        <dependency>
+            <groupId>com.fasterxml.jackson.core</groupId>
+            <artifactId>jackson-core</artifactId>
+            <version>${jackson.version}</version>
         </dependency>
         <dependency>
-            <groupId>org.slf4j</groupId>
-            <artifactId>slf4j-jdk14</artifactId>
-            <version>${slf4j.version}</version>
+            <groupId>com.fasterxml.jackson.core</groupId>
+            <artifactId>jackson-databind</artifactId>
+            <version>${jackson-databind.version}</version>
         </dependency>
 
         <!-- Unit/Integration test -->
@@ -300,7 +338,7 @@
                                     <groupname>root</groupname>
                                     <sources>
                                         <source>
-                                            <location>docker/logging.properties</location>
+                                            <location>docker/logback.xml</location>
                                         </source>
                                         <source>
                                             <location>docker/set-env.sh.example</location>
@@ -565,6 +603,10 @@
                             <pattern>org.LatencyUtils</pattern>
                             <shadedPattern>${shade.base}.LatencyUtils</shadedPattern>
                         </relocation>
+                        <relocation>
+                            <pattern>ch.qos</pattern>
+                            <shadedPattern>${shade.base}.qos</shadedPattern>
+                        </relocation>
                     </relocations>
                     <transformers>
                         <transformer implementation="org.apache.maven.plugins.shade.resource.ApacheLicenseResourceTransformer" />

src/main/bin/clickhouse-jdbc-bridge

@@ -25,45 +25,45 @@ INIT_SCRIPT="/etc/clickhouse-jdbc-bridge/set-env.sh"
 JAVA_CMD="java"
 
 init_env() {
-    if [ -f $INIT_SCRIPT ]; then
-        echo "Executing [$INIT_SCRIPT] to set environment variables..."
-        . $INIT_SCRIPT
-    else
-        echo "[$INIT_SCRIPT] is not found, will use default environment variables"
-    fi
+  if [ -f $INIT_SCRIPT ]; then
+    echo "Executing [$INIT_SCRIPT] to set environment variables..."
+    . $INIT_SCRIPT
+  else
+    echo "[$INIT_SCRIPT] is not found, will use default environment variables"
+  fi
 
-    # check if we have JRE
-    if [ -n "$JAVA_HOME" ] && [ -x "$JAVA_HOME/bin/java" ];  then
-        JAVA_CMD="$JAVA_HOME/bin/java"
-    elif ! type -p java > /dev/null; then
-        echo "ERROR: Java needs to be installed first"
-        exit 1
-    fi
+  # check if we have JRE
+  if [ -n "$JAVA_HOME" ] && [ -x "$JAVA_HOME/bin/java" ]; then
+    JAVA_CMD="$JAVA_HOME/bin/java"
+  elif ! type -p java >/dev/null; then
+    echo "ERROR: Java needs to be installed first"
+    exit 1
+  fi
 }
 
 start_server() {
-    # override below environment variables as needed in $INIT_SCRIPT
-    : ${APP_PACKAGE:="/usr/local/lib/java/clickhouse-jdbc-bridge-shaded.jar"}
-    : ${JVM_ARGS:="-Xmx512m"}
-    : ${WORK_DIRECTORY:=$(dirname "$INIT_SCRIPT")}
+  # override below environment variables as needed in $INIT_SCRIPT
+  : ${APP_PACKAGE:="/usr/local/lib/java/clickhouse-jdbc-bridge-shaded.jar"}
+  : ${JVM_ARGS:="-Xmx512m"}
+  : ${WORK_DIRECTORY:=$(dirname "$INIT_SCRIPT")}
 
-    # kill server if it's running
-    kill -9 $(ps -ef | grep java | grep "$APP_PACKAGE" | awk '{print $2}') 2>/dev/null || true
+  # kill server if it's running
+  kill -9 $(ps -ef | grep java | grep "$APP_PACKAGE" | awk '{print $2}') 2>/dev/null || true
 
-    if [ ! -f "$APP_PACKAGE" ]; then
-        echo "ERROR: ClickHouse JDBC Bridge could not start because [$APP_PACKAGE] is missing"
-        exit 1
-    fi
+  if [ ! -f "$APP_PACKAGE" ]; then
+    echo "ERROR: ClickHouse JDBC Bridge could not start because [$APP_PACKAGE] is missing"
+    exit 1
+  fi
 
-    if [ ! -d "$WORK_DIRECTORY" ]; then
-        echo "WARN: Work directory [$WORK_DIRECTORY] does not exist"
-        WORK_DIRECTORY=$(dirname "$INIT_SCRIPT")
-    fi
+  if [ ! -d "$WORK_DIRECTORY" ]; then
+    echo "WARN: Work directory [$WORK_DIRECTORY] does not exist"
+    WORK_DIRECTORY=$(dirname "$INIT_SCRIPT")
+  fi
 
-    echo "Work directory is set to [$WORK_DIRECTORY]"
-    cd "$WORK_DIRECTORY"
-    java $JVM_ARGS -Djava.util.logging.config.file=$WORK_DIRECTORY/logging.properties \
-        -Duser.dir="$WORK_DIRECTORY" -jar "$APP_PACKAGE"
+  echo "Work directory is set to [$WORK_DIRECTORY]"
+  cd "$WORK_DIRECTORY"
+  java $JVM_ARGS -Dlogback.configurationFile=$WORK_DIRECTORY/logback.xml \
+    -Duser.dir="$WORK_DIRECTORY" -jar "$APP_PACKAGE"
 }
 
 init_env