From 9c81c415cdf2f0590906bd981366bebe72d51285 Mon Sep 17 00:00:00 2001 From: carbotaniuman <41451839+carbotaniuman@users.noreply.github.com> Date: Sat, 4 Jul 2020 14:39:11 -0500 Subject: [PATCH] Logging overhauls --- src/main/java/mdnet/cache/DiskLruCache.java | 9 -- .../mdnet/cache/HeaderMismatchException.java | 15 +++ src/main/kotlin/mdnet/base/Constants.kt | 1 - src/main/kotlin/mdnet/base/Main.kt | 13 +- src/main/kotlin/mdnet/base/MangaDexClient.kt | 95 ++++++--------- src/main/kotlin/mdnet/base/ServerHandler.kt | 12 +- src/main/kotlin/mdnet/base/data/Token.kt | 18 +++ src/main/kotlin/mdnet/base/logging.kt | 54 +++++++++ .../mdnet/base/netty/ApplicationNetty.kt | 18 +-- .../kotlin/mdnet/base/server/Application.kt | 45 +++++-- .../kotlin/mdnet/base/server/ImageServer.kt | 111 +++++------------- src/main/kotlin/mdnet/base/server/common.kt | 6 +- 12 files changed, 209 insertions(+), 188 deletions(-) create mode 100644 src/main/kotlin/mdnet/base/logging.kt diff --git a/src/main/java/mdnet/cache/DiskLruCache.java b/src/main/java/mdnet/cache/DiskLruCache.java index 0fcd052..d8c7f03 100644 --- a/src/main/java/mdnet/cache/DiskLruCache.java +++ b/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; } } diff --git a/src/main/java/mdnet/cache/HeaderMismatchException.java b/src/main/java/mdnet/cache/HeaderMismatchException.java index 663cc3b..3ae272c 100644 --- a/src/main/java/mdnet/cache/HeaderMismatchException.java +++ b/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; diff --git a/src/main/kotlin/mdnet/base/Constants.kt b/src/main/kotlin/mdnet/base/Constants.kt index 43105f9..1c6e891 100644 --- a/src/main/kotlin/mdnet/base/Constants.kt +++ b/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 diff --git a/src/main/kotlin/mdnet/base/Main.kt b/src/main/kotlin/mdnet/base/Main.kt index 9308e0d..9c1af90 100644 --- a/src/main/kotlin/mdnet/base/Main.kt +++ b/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("Critical Error", e) - } + LOGGER.error(e) { "Critical Error" } (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) } diff --git a/src/main/kotlin/mdnet/base/MangaDexClient.kt b/src/main/kotlin/mdnet/base/MangaDexClient.kt index 84103c0..4ff553a 100644 --- a/src/main/kotlin/mdnet/base/MangaDexClient.kt +++ b/src/main/kotlin/mdnet/base/MangaDexClient.kt @@ -83,10 +83,10 @@ class MangaDexClient(private val clientSettings: ClientSettings) { statistics.set(JACKSON.readValue(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") - } else { - LOGGER.info("Max tries attempted (${state.counts} out of $timesToWait), shutting down") - } + if (!isHandled.get()) { + LOGGER.info { "No requests received, shutting down" } + } else { + LOGGER.info { "Max tries attempted (${state.counts} out of $timesToWait), shutting down" } } stopServer(state.nextState) state.action() } else -> { - if (LOGGER.isInfoEnabled) { - LOGGER.info( - "Waiting another 15 seconds for graceful shutdown (${state.counts} out of $timesToWait)" - ) + 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( - "Outdated build detected! Latest: ${newSettings.latestBuild}, Current: ${Constants.CLIENT_BUILD}" - ) + 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( - "Outdated build detected! Latest: ${serverSettings.latestBuild}, Current: ${Constants.CLIENT_BUILD}" - ) + 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() } diff --git a/src/main/kotlin/mdnet/base/ServerHandler.kt b/src/main/kotlin/mdnet/base/ServerHandler.kt index a45de66..9fbff3a 100644 --- a/src/main/kotlin/mdnet/base/ServerHandler.kt +++ b/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( "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) diff --git a/src/main/kotlin/mdnet/base/data/Token.kt b/src/main/kotlin/mdnet/base/data/Token.kt index 68ce10d..aa86847 100644 --- a/src/main/kotlin/mdnet/base/data/Token.kt +++ b/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 . + */ package mdnet.base.data import com.fasterxml.jackson.databind.PropertyNamingStrategy diff --git a/src/main/kotlin/mdnet/base/logging.kt b/src/main/kotlin/mdnet/base/logging.kt new file mode 100644 index 0000000..5fa8a80 --- /dev/null +++ b/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) + } +} diff --git a/src/main/kotlin/mdnet/base/netty/ApplicationNetty.kt b/src/main/kotlin/mdnet/base/netty/ApplicationNetty.kt index b1244a1..33c6e25 100644 --- a/src/main/kotlin/mdnet/base/netty/ApplicationNetty.kt +++ b/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 {} threads", clientSettings.threads) - } + LOGGER.info { "Starting Netty with ${clientSettings.threads} 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") - } - if (LOGGER.isTraceEnabled) { - LOGGER.trace("Exception in pipeline", cause) - } + LOGGER.info { "User (downloader) abruptly closed the connection" } + LOGGER.trace(cause) { "Exception in pipeline" } } else if (cause !is ReadTimeoutException && cause !is WriteTimeoutException) { ctx.fireExceptionCaught(cause) } diff --git a/src/main/kotlin/mdnet/base/server/Application.kt b/src/main/kotlin/mdnet/base/server/Application.kt index 4f647af..456128f 100644 --- a/src/main/kotlin/mdnet/base/server/Application.kt +++ b/src/main/kotlin/mdnet/base/server/Application.kt @@ -19,13 +19,19 @@ along with this MangaDex@Home. If not, see . /* 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, 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()) } } diff --git a/src/main/kotlin/mdnet/base/server/ImageServer.kt b/src/main/kotlin/mdnet/base/server/ImageServer.kt index b3db478..b7baf19 100644 --- a/src/main/kotlin/mdnet/base/server/ImageServer.kt +++ b/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, private val statistics: AtomicReference, private val serverSettings: ServerSettings, private val database: Database, private val clientHostname: String, private val handled: AtomicBoolean) { +class ImageServer( + private val cache: DiskLruCache, + private val database: Database, + private val statistics: AtomicReference, + 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() - - if (LOGGER.isWarnEnabled) { - LOGGER.warn("Removing cache file for $sanitizedUri without corresponding DB entry") - } + 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("Cache go/no go for $sanitizedUri failed", e) - } + LOGGER.warn(e) { "Cache go/no go for $sanitizedUri failed" } } } respondWithImage(tee, contentLength, contentType, lastModified, false) } else { editor?.abort() - - if (LOGGER.isTraceEnabled) { - LOGGER.trace("Request for $sanitizedUri is being served") - } + LOGGER.trace { "Request for $sanitizedUri is being served" } respondWithImage(mdResponse.body.stream, contentLength, contentType, lastModified, false) } } @@ -327,13 +280,13 @@ class ImageServer(private val cache: DiskLruCache, private val statistics: Atomi private fun baseHandler(): Filter = CachingFilters.Response.MaxAge(Clock.systemUTC(), Constants.MAX_AGE_CACHE) .then(ServerFilters.Cors( - CorsPolicy( - origins = listOf("https://mangadex.org"), - headers = listOf("*"), - methods = Method.values().toList() + CorsPolicy( + origins = listOf("https://mangadex.org"), + headers = listOf("*"), + methods = Method.values().toList() + ) ) ) - ) .then(Filter { next: HttpHandler -> { request: Request -> val response = next(request) diff --git a/src/main/kotlin/mdnet/base/server/common.kt b/src/main/kotlin/mdnet/base/server/common.kt index 06f8d0f..3bcf24f 100644 --- a/src/main/kotlin/mdnet/base/server/common.kt +++ b/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("Request error detected", e) - } + LOGGER.warn(e) { "Request error detected" } + Response(Status.INTERNAL_SERVER_ERROR) } }