Logging overhauls

src/main/java/mdnet/cache/DiskLruCache.java

@@ -17,8 +17,6 @@ package mdnet.cache;
 
 import org.apache.commons.io.FileUtils;
 import org.apache.commons.io.IOUtils;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
 
 import java.io.BufferedWriter;
 import java.io.Closeable;
@@ -94,8 +92,6 @@ import java.util.regex.Pattern;
  * responding appropriately.
  */
 public final class DiskLruCache implements Closeable {
-	private final static Logger LOGGER = LoggerFactory.getLogger(DiskLruCache.class);
-
 	private static final String JOURNAL_FILE = "journal";
 	private static final String JOURNAL_FILE_TEMP = "journal.tmp";
 	private static final String JOURNAL_FILE_BACKUP = "journal.bkp";
@@ -827,7 +823,6 @@ public final class DiskLruCache implements Closeable {
 						outputStream = new FileOutputStream(dirtyFile);
 					} catch (FileNotFoundException e2) {
 						// We are unable to recover. Silently eat the writes.
-						LOGGER.warn("Returning NULL_OUTPUT_STREAM", e2);
 						return NULL_OUTPUT_STREAM;
 					}
 				}
@@ -899,7 +894,6 @@ public final class DiskLruCache implements Closeable {
 				try {
 					out.write(oneByte);
 				} catch (IOException e) {
-					LOGGER.warn("FaultHidingOutputStream exception in write()", e);
 					hasErrors = true;
 				}
 			}
@@ -909,7 +903,6 @@ public final class DiskLruCache implements Closeable {
 				try {
 					out.write(buffer, offset, length);
 				} catch (IOException e) {
-					LOGGER.warn("FaultHidingOutputStream exception in write()", e);
 					hasErrors = true;
 				}
 			}
@@ -919,7 +912,6 @@ public final class DiskLruCache implements Closeable {
 				try {
 					out.close();
 				} catch (IOException e) {
-					LOGGER.warn("FaultHidingOutputStream exception in close()", e);
 					hasErrors = true;
 				}
 			}
@@ -929,7 +921,6 @@ public final class DiskLruCache implements Closeable {
 				try {
 					out.flush();
 				} catch (IOException e) {
-					LOGGER.warn("FaultHidingOutputStream exception in flush()", e);
 					hasErrors = true;
 				}
 			}

src/main/java/mdnet/cache/HeaderMismatchException.java

@@ -1,3 +1,18 @@
+/*
+ * Copyright (C) 2011 The Android Open Source Project
+ *
+ * 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
+ *
+ *      http://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 mdnet.cache;
 
 import java.io.IOException;

src/main/kotlin/mdnet/base/Constants.kt

@@ -22,7 +22,6 @@ import java.time.Duration
 
 object Constants {
     const val CLIENT_BUILD = 14
-    const val WEBUI_VERSION = "0.1.1"
     val MAX_AGE_CACHE: Duration = Duration.ofDays(14)
 
     const val MAX_READ_TIME_SECONDS = 300

src/main/kotlin/mdnet/base/Main.kt

@@ -85,26 +85,21 @@ object Main {
             }
         }.apply(::validateSettings)
 
-        if (LOGGER.isInfoEnabled) {
+            LOGGER.info { "Client settings loaded: $settings" }
-            LOGGER.info("Client settings loaded: {}", settings)
-        }
         val client = MangaDexClient(settings)
         Runtime.getRuntime().addShutdownHook(Thread { client.shutdown() })
         client.runLoop()
     }
 
     fun dieWithError(e: Throwable): Nothing {
-        if (LOGGER.isErrorEnabled) {
+            LOGGER.error(e) { "Critical Error" }
-            LOGGER.error("Critical Error", e)
-        }
         (LoggerFactory.getILoggerFactory() as LoggerContext).stop()
         exitProcess(1)
     }
 
     fun dieWithError(error: String): Nothing {
-        if (LOGGER.isErrorEnabled) {
+        LOGGER.error { "Critical Error: $error" }
-            LOGGER.error("Critical Error: {}", error)
+
-        }
         (LoggerFactory.getILoggerFactory() as LoggerContext).stop()
         exitProcess(1)
     }

src/main/kotlin/mdnet/base/MangaDexClient.kt

@@ -83,10 +83,10 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
                 statistics.set(JACKSON.readValue<Statistics>(it.getInputStream(0)))
             }
         } catch (e: HeaderMismatchException) {
-            LOGGER.warn("Cache version may be outdated - remove if necessary")
+            LOGGER.warn { "Cache version may be outdated - remove if necessary" }
             dieWithError(e)
         } catch (e: IOException) {
-            LOGGER.warn("Cache may be corrupt - remove if necessary")
+            LOGGER.warn { "Cache may be corrupt - remove if necessary" }
             dieWithError(e)
         }
     }
@@ -99,9 +99,7 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
             webUi = getUiServer(clientSettings.webSettings, statistics, statsMap)
             webUi!!.start()
         }
-        if (LOGGER.isInfoEnabled) {
+        LOGGER.info { "Mangadex@Home Client initialized. Starting normal operation." }
-            LOGGER.info("Mangadex@Home Client initialized. Starting normal operation.")
-        }
 
         executorService.scheduleAtFixedRate({
             try {
@@ -117,7 +115,7 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
                     }
                 }
             } catch (e: Exception) {
-                LOGGER.warn("Statistics update failed", e)
+                LOGGER.warn(e) { "Statistics update failed" }
             }
         }, 15, 15, TimeUnit.SECONDS)
 
@@ -128,19 +126,17 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
 
                 val state = this.state
                 if (state is GracefulShutdown) {
-                    if (LOGGER.isInfoEnabled) {
+                    LOGGER.info { "Aborting graceful shutdown started due to hourly bandwidth limit" }
-                        LOGGER.info("Aborting graceful shutdown started due to hourly bandwidth limit")
+
-                    }
                     this.state = state.lastRunning
                 }
                 if (state is Uninitialized) {
-                    if (LOGGER.isInfoEnabled) {
+                    LOGGER.info { "Restarting server stopped due to hourly bandwidth limit" }
-                        LOGGER.info("Restarting server stopped due to hourly bandwidth limit")
+
-                    }
                     loginAndStartServer()
                 }
             } catch (e: Exception) {
-                LOGGER.warn("Hourly bandwidth check failed", e)
+                LOGGER.warn(e) { "Hourly bandwidth check failed" }
             }
         }, 1, 1, TimeUnit.HOURS)
 
@@ -151,31 +147,27 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
                 if (state is GracefulShutdown) {
                     when {
                         state.counts == 0 -> {
-                            if (LOGGER.isInfoEnabled) {
+                            LOGGER.info { "Starting graceful shutdown" }
-                                LOGGER.info("Starting graceful shutdown")
+
-                            }
                             logout()
                             isHandled.set(false)
                             this.state = state.copy(counts = state.counts + 1)
                         }
                         state.counts == timesToWait || !isHandled.get() -> {
-                            if (LOGGER.isInfoEnabled) {
                             if (!isHandled.get()) {
-                                    LOGGER.info("No requests received, shutting down")
+                                LOGGER.info { "No requests received, shutting down" }
                             } else {
-                                    LOGGER.info("Max tries attempted (${state.counts} out of $timesToWait), shutting down")
+                                LOGGER.info { "Max tries attempted (${state.counts} out of $timesToWait), shutting down" }
-                                }
                             }
 
                             stopServer(state.nextState)
                             state.action()
                         }
                         else -> {
-                            if (LOGGER.isInfoEnabled) {
+                            LOGGER.info {
-                                LOGGER.info(
                                 "Waiting another 15 seconds for graceful shutdown (${state.counts} out of $timesToWait)"
-                                )
                             }
+
                             isHandled.set(false)
                             this.state = state.copy(counts = state.counts + 1)
                         }
@@ -192,16 +184,15 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
                 if (state is Running) {
                     val currentBytesSent = statistics.get().bytesSent - lastBytesSent
                     if (clientSettings.maxMebibytesPerHour != 0L && clientSettings.maxMebibytesPerHour * 1024 * 1024 /* MiB to bytes */ < currentBytesSent) {
-                        if (LOGGER.isInfoEnabled) {
+                        LOGGER.info { "Shutting down server as hourly bandwidth limit reached" }
-                            LOGGER.info("Shutting down server as hourly bandwidth limit reached")
+
-                        }
                         this.state = GracefulShutdown(lastRunning = state)
                     } else {
                         pingControl()
                     }
                 }
             } catch (e: Exception) {
-                LOGGER.warn("Graceful shutdown checker failed", e)
+                LOGGER.warn(e) { "Graceful shutdown checker failed" }
             }
         }, 45, 45, TimeUnit.SECONDS)
     }
@@ -211,30 +202,23 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
 
         val newSettings = serverHandler.pingControl(state.settings)
         if (newSettings != null) {
-            if (LOGGER.isInfoEnabled) {
+            LOGGER.info { "Server settings received: $newSettings" }
-                LOGGER.info("Server settings received: $newSettings")
-            }
 
             if (newSettings.latestBuild > Constants.CLIENT_BUILD) {
-                if (LOGGER.isWarnEnabled) {
+                LOGGER.warn {
-                    LOGGER.warn(
                     "Outdated build detected! Latest: ${newSettings.latestBuild}, Current: ${Constants.CLIENT_BUILD}"
-                    )
                 }
             }
             if (newSettings.tls != null || newSettings.imageServer != state.settings.imageServer) {
                 // certificates or upstream url must have changed, restart webserver
-                if (LOGGER.isInfoEnabled) {
+                LOGGER.info { "Doing internal restart of HTTP server to refresh certs/upstream URL" }
-                    LOGGER.info("Doing internal restart of HTTP server to refresh certs/upstream URL")
+
-                }
                 this.state = GracefulShutdown(lastRunning = state) {
                     loginAndStartServer()
                 }
             }
         } else {
-            if (LOGGER.isInfoEnabled) {
+            LOGGER.info { "Server ping failed - ignoring" }
-                LOGGER.info("Server ping failed - ignoring")
-            }
         }
     }
 
@@ -246,17 +230,13 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
         val server = getServer(cache, serverSettings, clientSettings, statistics, isHandled).start()
 
         if (serverSettings.latestBuild > Constants.CLIENT_BUILD) {
-            if (LOGGER.isWarnEnabled) {
+            LOGGER.warn {
-                LOGGER.warn(
                 "Outdated build detected! Latest: ${serverSettings.latestBuild}, Current: ${Constants.CLIENT_BUILD}"
-                )
             }
         }
 
         state = Running(server, serverSettings)
-        if (LOGGER.isInfoEnabled) {
+        LOGGER.info { "Internal HTTP server was successfully started" }
-            LOGGER.info("Internal HTTP server was successfully started")
-        }
     }
 
     private fun logout() {
@@ -275,18 +255,15 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
             }
         }
 
-        if (LOGGER.isInfoEnabled) {
+        LOGGER.info { "Shutting down HTTP server" }
-            LOGGER.info("Shutting down HTTP server")
-        }
         state.server.stop()
-        if (LOGGER.isInfoEnabled) {
+        LOGGER.info { "Internal HTTP server has shut down" }
-            LOGGER.info("Internal HTTP server has shut down")
+
-        }
         this.state = nextState
     }
 
     fun shutdown() {
-        LOGGER.info("Mangadex@Home Client stopping")
+        LOGGER.info { "Mangadex@Home Client stopping" }
 
         val latch = CountDownLatch(1)
         executorService.schedule({
@@ -310,11 +287,11 @@ class MangaDexClient(private val clientSettings: ClientSettings) {
         try {
             cache.close()
         } catch (e: IOException) {
-            LOGGER.error("Cache failed to close", e)
+            LOGGER.error(e) { "Cache failed to close" }
         }
 
         executorService.shutdown()
-        LOGGER.info("Mangadex@Home Client stopped")
+        LOGGER.info { "Mangadex@Home Client stopped" }
 
         (LoggerFactory.getILoggerFactory() as LoggerContext).stop()
     }

src/main/kotlin/mdnet/base/ServerHandler.kt

@@ -44,9 +44,7 @@ class ServerHandler(private val settings: ClientSettings) {
     private val client = ApacheClient()
 
     fun logoutFromControl(): Boolean {
-        if (LOGGER.isInfoEnabled) {
+        LOGGER.info { "Disconnecting from the control server" }
-            LOGGER.info("Disconnecting from the control server")
-        }
         val params = mapOf<String, Any>(
             "secret" to settings.clientSecret
         )
@@ -79,9 +77,7 @@ class ServerHandler(private val settings: ClientSettings) {
         }
 
     fun loginToControl(): ServerSettings? {
-        if (LOGGER.isInfoEnabled) {
+        LOGGER.info { "Connecting to the control server" }
-            LOGGER.info("Connecting to the control server")
-        }
 
         val request = STRING_ANY_MAP_LENS(getPingParams(), Request(Method.POST, getServerAddress() + "ping"))
         val response = client(request)
@@ -94,9 +90,7 @@ class ServerHandler(private val settings: ClientSettings) {
     }
 
     fun pingControl(old: ServerSettings): ServerSettings? {
-        if (LOGGER.isInfoEnabled) {
+        LOGGER.info { "Pinging the control server" }
-            LOGGER.info("Pinging the control server")
-        }
 
         val request = STRING_ANY_MAP_LENS(getPingParams(old.tls!!.createdAt), Request(Method.POST, getServerAddress() + "ping"))
         val response = client(request)

src/main/kotlin/mdnet/base/data/Token.kt

@@ -1,3 +1,21 @@
+/*
+Mangadex@Home
+Copyright (c) 2020, MangaDex Network
+This file is part of MangaDex@Home.
+
+MangaDex@Home is free software: you can redistribute it and/or modify
+it under the terms of the GNU General Public License as published by
+the Free Software Foundation, either version 3 of the License, or
+(at your option) any later version.
+
+MangaDex@Home is distributed in the hope that it will be useful,
+but WITHOUT ANY WARRANTY; without even the implied warranty of
+MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+GNU General Public License for more details.
+
+You should have received a copy of the GNU General Public License
+along with this MangaDex@Home.  If not, see <http://www.gnu.org/licenses/>.
+ */
 package mdnet.base.data
 
 import com.fasterxml.jackson.databind.PropertyNamingStrategy

src/main/kotlin/mdnet/base/logging.kt

@@ -0,0 +1,54 @@
+package mdnet.base
+
+import org.slf4j.Logger
+
+inline fun Logger.error(msg: () -> String) {
+    if (this.isErrorEnabled) {
+        this.error(msg())
+    }
+}
+inline fun Logger.warn(msg: () -> String) {
+    if (this.isWarnEnabled) {
+        this.warn(msg())
+    }
+}
+inline fun Logger.info(msg: () -> String) {
+    if (this.isInfoEnabled) {
+        this.info(msg())
+    }
+}
+inline fun Logger.debug(msg: () -> String) {
+    if (this.isDebugEnabled) {
+        this.debug(msg())
+    }
+}
+inline fun Logger.trace(msg: () -> String) {
+    if (this.isTraceEnabled) {
+        this.trace(msg())
+    }
+}
+inline fun Logger.error(e: Throwable, msg: () -> String) {
+    if (this.isErrorEnabled) {
+        this.error(msg(), e)
+    }
+}
+inline fun Logger.warn(e: Throwable, msg: () -> String) {
+    if (this.isWarnEnabled) {
+        this.warn(msg(), e)
+    }
+}
+inline fun Logger.info(e: Throwable, msg: () -> String) {
+    if (this.isInfoEnabled) {
+        this.info(msg(), e)
+    }
+}
+inline fun Logger.debug(e: Throwable, msg: () -> String) {
+    if (this.isDebugEnabled) {
+        this.debug(msg(), e)
+    }
+}
+inline fun Logger.trace(e: Throwable, msg: () -> String) {
+    if (this.isTraceEnabled) {
+        this.trace(msg(), e)
+    }
+}

src/main/kotlin/mdnet/base/netty/ApplicationNetty.kt

@@ -47,8 +47,10 @@ import java.util.concurrent.atomic.AtomicReference
 import javax.net.ssl.SSLException
 import mdnet.base.Constants
 import mdnet.base.data.Statistics
+import mdnet.base.info
 import mdnet.base.settings.ClientSettings
 import mdnet.base.settings.TlsCert
+import mdnet.base.trace
 import org.http4k.core.HttpHandler
 import org.http4k.server.Http4kChannelHandler
 import org.http4k.server.Http4kServer
@@ -75,9 +77,7 @@ class Netty(private val tls: TlsCert, private val clientSettings: ClientSettings
         }
 
         override fun start(): Http4kServer = apply {
-            if (LOGGER.isInfoEnabled) {
+            LOGGER.info { "Starting Netty with ${clientSettings.threads} threads" }
-                LOGGER.info("Starting Netty with {} threads", clientSettings.threads)
-            }
 
             val certs = getX509Certs(tls.certificate)
             val sslContext = SslContextBuilder
@@ -107,16 +107,10 @@ class Netty(private val tls: TlsCert, private val clientSettings: ClientSettings
                             ch.pipeline().addLast("handle_ssl", object : ChannelInboundHandlerAdapter() {
                                 override fun exceptionCaught(ctx: ChannelHandlerContext, cause: Throwable) {
                                     if (cause is SSLException || (cause is DecoderException && cause.cause is SSLException)) {
-                                        if (LOGGER.isTraceEnabled) {
+                                        LOGGER.trace { "Ignored invalid SSL connection" }
-                                            LOGGER.trace("Ignored invalid SSL connection")
-                                        }
                                     } else if (cause is IOException || cause is SocketException) {
-                                        if (LOGGER.isInfoEnabled) {
+                                        LOGGER.info { "User (downloader) abruptly closed the connection" }
-                                            LOGGER.info("User (downloader) abruptly closed the connection")
+                                        LOGGER.trace(cause) { "Exception in pipeline" }
-                                        }
-                                        if (LOGGER.isTraceEnabled) {
-                                            LOGGER.trace("Exception in pipeline", cause)
-                                        }
                                     } else if (cause !is ReadTimeoutException && cause !is WriteTimeoutException) {
                                         ctx.fireExceptionCaught(cause)
                                     }

src/main/kotlin/mdnet/base/server/Application.kt

@@ -19,13 +19,19 @@ along with this MangaDex@Home.  If not, see <http://www.gnu.org/licenses/>.
 /* ktlint-disable no-wildcard-imports */
 package mdnet.base.server
 
+import java.net.InetAddress
 import java.util.concurrent.atomic.AtomicBoolean
 import java.util.concurrent.atomic.AtomicReference
 import mdnet.base.data.Statistics
+import mdnet.base.info
 import mdnet.base.netty.Netty
 import mdnet.base.settings.ClientSettings
 import mdnet.base.settings.ServerSettings
 import mdnet.cache.DiskLruCache
+import org.apache.http.client.config.CookieSpecs
+import org.apache.http.client.config.RequestConfig
+import org.apache.http.impl.client.HttpClients
+import org.http4k.client.ApacheClient
 import org.http4k.core.*
 import org.http4k.filter.ServerFilters
 import org.http4k.routing.bind
@@ -39,11 +45,30 @@ private val LOGGER = LoggerFactory.getLogger("Application")
 
 fun getServer(cache: DiskLruCache, serverSettings: ServerSettings, clientSettings: ClientSettings, statistics: AtomicReference<Statistics>, isHandled: AtomicBoolean): Http4kServer {
     val database = Database.connect("jdbc:sqlite:cache/data.db", "org.sqlite.JDBC")
-    val imageServer = ImageServer(cache, statistics, serverSettings, database, clientSettings.clientHostname, isHandled)
+    val client = ApacheClient(responseBodyMode = BodyMode.Stream, client = HttpClients.custom()
+        .disableConnectionState()
+        .setDefaultRequestConfig(
+            RequestConfig.custom()
+                .setCookieSpec(CookieSpecs.IGNORE_COOKIES)
+                .setConnectTimeout(3000)
+                .setSocketTimeout(3000)
+                .setConnectionRequestTimeout(3000)
+                .apply {
+                    if (clientSettings.clientHostname != "0.0.0.0") {
+                        setLocalAddress(InetAddress.getByName(clientSettings.clientHostname))
+                    }
+                }
+                .build())
+        .setMaxConnTotal(3000)
+        .setMaxConnPerRoute(3000)
+        .build())
+
+    val imageServer = ImageServer(cache, database, statistics, serverSettings, client)
 
     return timeRequest()
         .then(catchAllHideDetails())
         .then(ServerFilters.CatchLensFailure)
+        .then(setHandled(isHandled))
         .then(addCommonHeaders())
         .then(
             routes(
@@ -62,6 +87,15 @@ fun getServer(cache: DiskLruCache, serverSettings: ServerSettings, clientSetting
         .asServer(Netty(serverSettings.tls!!, clientSettings, statistics))
 }
 
+fun setHandled(isHandled: AtomicBoolean): Filter {
+    return Filter { next: HttpHandler ->
+        {
+            isHandled.set(true)
+            next(it)
+        }
+    }
+}
+
 fun timeRequest(): Filter {
     return Filter { next: HttpHandler ->
         { request: Request ->
@@ -73,17 +107,14 @@ fun timeRequest(): Filter {
                 }
             }
 
-            if (LOGGER.isInfoEnabled) {
+            LOGGER.info { "Request for $cleanedUri received from ${request.source?.address}" }
-                LOGGER.info("Request for $cleanedUri received from ${request.source?.address}")
-            }
 
             val start = System.currentTimeMillis()
             val response = next(request)
             val latency = System.currentTimeMillis() - start
 
-            if (LOGGER.isInfoEnabled) {
+            LOGGER.info { "Request for $cleanedUri completed (TTFB) in ${latency}ms" }
-                LOGGER.info("Request for $cleanedUri completed (TTFB) in ${latency}ms")
+
-            }
             response.header("X-Time-Taken", latency.toString())
         }
     }

src/main/kotlin/mdnet/base/server/ImageServer.kt

@@ -32,13 +32,11 @@ import java.io.BufferedInputStream
 import java.io.BufferedOutputStream
 import java.io.File
 import java.io.InputStream
-import java.net.InetAddress
 import java.security.MessageDigest
 import java.time.Clock
 import java.time.OffsetDateTime
 import java.util.*
 import java.util.concurrent.Executors
-import java.util.concurrent.atomic.AtomicBoolean
 import java.util.concurrent.atomic.AtomicReference
 import javax.crypto.Cipher
 import javax.crypto.CipherInputStream
@@ -49,13 +47,12 @@ import mdnet.base.data.ImageData
 import mdnet.base.data.ImageDatum
 import mdnet.base.data.Statistics
 import mdnet.base.data.Token
+import mdnet.base.info
 import mdnet.base.settings.ServerSettings
+import mdnet.base.trace
+import mdnet.base.warn
 import mdnet.cache.CachingInputStream
 import mdnet.cache.DiskLruCache
-import org.apache.http.client.config.CookieSpecs
-import org.apache.http.client.config.RequestConfig
-import org.apache.http.impl.client.HttpClients
-import org.http4k.client.ApacheClient
 import org.http4k.core.*
 import org.http4k.filter.CachingFilters
 import org.http4k.filter.CorsPolicy
@@ -66,32 +63,19 @@ import org.jetbrains.exposed.sql.SchemaUtils
 import org.jetbrains.exposed.sql.transactions.transaction
 import org.slf4j.LoggerFactory
 
-private const val THREADS_TO_ALLOCATE = 262144 // 2**18
+class ImageServer(
-
+    private val cache: DiskLruCache,
-class ImageServer(private val cache: DiskLruCache, private val statistics: AtomicReference<Statistics>, private val serverSettings: ServerSettings, private val database: Database, private val clientHostname: String, private val handled: AtomicBoolean) {
+    private val database: Database,
+    private val statistics: AtomicReference<Statistics>,
+    private val serverSettings: ServerSettings,
+    private val client: HttpHandler
+) {
     init {
         transaction(database) {
             SchemaUtils.create(ImageData)
         }
     }
     private val executor = Executors.newCachedThreadPool()
-    private val client = ApacheClient(responseBodyMode = BodyMode.Stream, client = HttpClients.custom()
-        .disableConnectionState()
-        .setDefaultRequestConfig(
-            RequestConfig.custom()
-                .setCookieSpec(CookieSpecs.IGNORE_COOKIES)
-                .setConnectTimeout(3000)
-                .setSocketTimeout(3000)
-                .setConnectionRequestTimeout(3000)
-                .apply {
-                    if (clientHostname != "0.0.0.0") {
-                        setLocalAddress(InetAddress.getByName(clientHostname))
-                    }
-                }
-                .build())
-        .setMaxConnTotal(THREADS_TO_ALLOCATE)
-        .setMaxConnPerRoute(THREADS_TO_ALLOCATE)
-        .build())
 
     fun handler(dataSaver: Boolean, tokenized: Boolean = false): HttpHandler {
         val sodium = LazySodiumJava(SodiumJava())
@@ -115,30 +99,22 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
                                 tokenArr.sliceArray(24 until tokenArr.size), tokenArr.sliceArray(0 until 24), serverSettings.tokenKey
                             )
                         } catch (_: SodiumException) {
-                            if (LOGGER.isInfoEnabled) {
+                            LOGGER.info { "Request for $sanitizedUri rejected for invalid token" }
-                                LOGGER.info("Request for $sanitizedUri rejected for invalid token")
-                            }
                             return@then Response(Status.FORBIDDEN)
                         }
                     )
                 } catch (e: JsonProcessingException) {
-                    if (LOGGER.isInfoEnabled) {
+                    LOGGER.info { "Request for $sanitizedUri rejected for invalid token" }
-                        LOGGER.info("Request for $sanitizedUri rejected for invalid token")
-                    }
                     return@then Response(Status.FORBIDDEN)
                 }
 
                 if (OffsetDateTime.now().isAfter(token.expires)) {
-                    if (LOGGER.isInfoEnabled) {
+                    LOGGER.info { "Request for $sanitizedUri rejected for expired token" }
-                        LOGGER.info("Request for $sanitizedUri rejected for expired token")
-                    }
                     return@then Response(Status.GONE)
                 }
 
                 if (token.hash != chapterHash) {
-                    if (LOGGER.isInfoEnabled) {
+                    LOGGER.info { "Request for $sanitizedUri rejected for inapplicable token" }
-                        LOGGER.info("Request for $sanitizedUri rejected for inapplicable token")
-                    }
                     return@then Response(Status.FORBIDDEN)
                 }
             }
@@ -161,7 +137,6 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
                 }
             }
 
-            handled.set(true)
             if (request.header("Referer")?.startsWith("https://mangadex.org") == false) {
                 snapshot?.close()
                 Response(Status.FORBIDDEN)
@@ -170,10 +145,7 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
             } else {
                 if (snapshot != null) {
                     snapshot.close()
-
+                    LOGGER.warn { "Removing cache file for $sanitizedUri without corresponding DB entry" }
-                    if (LOGGER.isWarnEnabled) {
-                        LOGGER.warn("Removing cache file for $sanitizedUri without corresponding DB entry")
-                    }
                     cache.removeUnsafe(imageId.toCacheId())
                 }
 
@@ -189,9 +161,7 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
                 it.copy(browserCached = it.browserCached + 1)
             }
 
-            if (LOGGER.isInfoEnabled) {
+            LOGGER.info { "Request for $sanitizedUri cached by browser" }
-                LOGGER.info("Request for $sanitizedUri cached by browser")
-            }
 
             val lastModified = imageDatum.lastModified
             snapshot.close()
@@ -203,9 +173,7 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
                 it.copy(cacheHits = it.cacheHits + 1)
             }
 
-            if (LOGGER.isInfoEnabled) {
+            LOGGER.info { "Request for $sanitizedUri hit cache" }
-                LOGGER.info("Request for $sanitizedUri hit cache")
-            }
 
             respondWithImage(
                 CipherInputStream(BufferedInputStream(snapshot.getInputStream(0)), cipher),
@@ -216,9 +184,8 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
     }
 
     private fun Request.handleCacheMiss(sanitizedUri: String, cipher: Cipher, imageId: String, imageDatum: ImageDatum?): Response {
-        if (LOGGER.isInfoEnabled) {
+        LOGGER.info { "Request for $sanitizedUri missed cache" }
-            LOGGER.info("Request for $sanitizedUri missed cache")
+
-        }
         statistics.getAndUpdate {
             it.copy(cacheMisses = it.cacheMisses + 1)
         }
@@ -226,16 +193,13 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
         val mdResponse = client(Request(Method.GET, "${serverSettings.imageServer}$sanitizedUri"))
 
         if (mdResponse.status != Status.OK) {
-            if (LOGGER.isTraceEnabled) {
+            LOGGER.trace { "Upstream query for $sanitizedUri errored with status ${mdResponse.status}" }
-                LOGGER.trace("Upstream query for $sanitizedUri errored with status {}", mdResponse.status)
+
-            }
             mdResponse.close()
             return Response(mdResponse.status)
         }
 
-        if (LOGGER.isTraceEnabled) {
+        LOGGER.trace { "Upstream query for $sanitizedUri succeeded" }
-            LOGGER.trace("Upstream query for $sanitizedUri succeeded")
-        }
 
         val contentType = mdResponse.header("Content-Type")!!
         val contentLength = mdResponse.header("Content-Length")
@@ -246,9 +210,7 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
         // A null editor means that this file is being written to
         // concurrently so we skip the cache process
         return if (editor != null && contentLength != null && lastModified != null) {
-            if (LOGGER.isTraceEnabled) {
+            LOGGER.trace { "Request for $sanitizedUri is being cached and served" }
-                LOGGER.trace("Request for $sanitizedUri is being cached and served")
-            }
 
             if (imageDatum == null) {
                 synchronized(database) {
@@ -267,29 +229,20 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi
             ) {
                 try {
                     if (editor.getLength(0) == contentLength.toLong()) {
-                        if (LOGGER.isInfoEnabled) {
+                        LOGGER.info { "Cache download for $sanitizedUri committed" }
-                            LOGGER.info("Cache download for $sanitizedUri committed")
-                        }
                         editor.commit()
                     } else {
-                        if (LOGGER.isWarnEnabled) {
+                        LOGGER.warn { "Cache download for $sanitizedUri aborted" }
-                            LOGGER.warn("Cache download for $sanitizedUri aborted")
-                        }
                         editor.abort()
                     }
                 } catch (e: Exception) {
-                    if (LOGGER.isWarnEnabled) {
+                    LOGGER.warn(e) { "Cache go/no go for $sanitizedUri failed" }
-                        LOGGER.warn("Cache go/no go for $sanitizedUri failed", e)
-                    }
                 }
             }
             respondWithImage(tee, contentLength, contentType, lastModified, false)
         } else {
             editor?.abort()
-
+            LOGGER.trace { "Request for $sanitizedUri is being served" }
-            if (LOGGER.isTraceEnabled) {
-                LOGGER.trace("Request for $sanitizedUri is being served")
-            }
             respondWithImage(mdResponse.body.stream, contentLength, contentType, lastModified, false)
         }
     }

src/main/kotlin/mdnet/base/server/common.kt

@@ -25,6 +25,7 @@ import java.time.format.DateTimeFormatter
 import java.util.*
 import mdnet.BuildInfo
 import mdnet.base.Constants
+import mdnet.base.warn
 import org.http4k.core.Filter
 import org.http4k.core.HttpHandler
 import org.http4k.core.Request
@@ -51,9 +52,8 @@ fun catchAllHideDetails(): Filter {
             try {
                 next(request)
             } catch (e: Exception) {
-                if (LOGGER.isWarnEnabled) {
+                LOGGER.warn(e) { "Request error detected" }
-                    LOGGER.warn("Request error detected", e)
+
-                }
                 Response(Status.INTERNAL_SERVER_ERROR)
             }
         }