Add logback extensions, coloured output, toggleable logging in IRCClient

.gitignore

@@ -44,6 +44,6 @@ bin/
 ### Mac OS ###
 .DS_Store
 
-src/test/resources/logs/ngircd.log
+src/test/resources/logs/*.log
 !src/test/resources/logs/.gitkeep
 .idea

build.gradle.kts

@@ -19,7 +19,8 @@ dependencies {
     implementation("io.ktor:ktor-network:$ktorVersion")
     implementation("io.ktor:ktor-network-tls:$ktorVersion")
     implementation("io.github.oshai:kotlin-logging-jvm:8.0.4")
-    implementation("ch.qos.logback:logback-classic:1.6.1")
+    implementation("ch.qos.logback:logback-classic:1.6.3")
+    testImplementation("org.jline:jansi-core:4.4.3")
 }
 
 kotlin {
@@ -28,4 +29,6 @@ kotlin {
 
 tasks.test {
     useJUnitPlatform()
+    val logDir = layout.projectDirectory.dir("src/test/resources/logs").toString()
+    systemProperty("TEST_LOG_DIR", logDir)
 }

src/main/kotlin/com/shr4pnel/ferretirc/IrcClient.kt

@@ -1,27 +1,33 @@
 package com.shr4pnel.ferretirc
 
 import com.shr4pnel.ferretirc.irc.Server
-import com.shr4pnel.ferretirc.util.Helpers
 import com.shr4pnel.ferretirc.net.Connection
 import com.shr4pnel.ferretirc.net.messages.ClientMessage
 import com.shr4pnel.ferretirc.net.messages.ServerMessage
+import io.github.oshai.kotlinlogging.KotlinLogging
 import io.github.oshai.kotlinlogging.KotlinLoggingConfiguration
+import io.github.oshai.kotlinlogging.slf4j.logger
 import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.Dispatchers
 import kotlinx.coroutines.SupervisorJob
 import kotlinx.coroutines.cancel
+import org.slf4j.helpers.NOPLogger
 
-class IrcClient(hostname: String, port: Int, enableLogging: Boolean = true) {
+class IrcClient(
+    hostname: String,
+    port: Int,
+    var enableLogging: Boolean = false,
+) {
     init {
         KotlinLoggingConfiguration.logStartupMessage = false
-        Helpers.enableLogging = enableLogging
     }
 
+    private val logger = if (enableLogging) KotlinLogging.logger {} else KotlinLogging.logger(NOPLogger.NOP_LOGGER)
     val scope = CoroutineScope(SupervisorJob() + Dispatchers.IO)
     lateinit var server: Server
 
     @PublishedApi
-    internal val connection = Connection(hostname, port, scope)
+    internal val connection = Connection(hostname, port, scope, enableLogging)
 
     /**
      * Connect to the socket

src/main/kotlin/com/shr4pnel/ferretirc/irc/Server.kt

@@ -2,18 +2,22 @@ package com.shr4pnel.ferretirc.irc
 
 import com.shr4pnel.ferretirc.net.messages.ClientMessage
 import com.shr4pnel.ferretirc.net.messages.ServerMessage
-import kotlinx.coroutines.CoroutineScope
+import io.github.oshai.kotlinlogging.KotlinLogging
+import io.github.oshai.kotlinlogging.slf4j.logger
 import kotlinx.coroutines.channels.Channel
 import kotlinx.coroutines.flow.SharedFlow
 import kotlinx.coroutines.flow.filterIsInstance
 import kotlinx.coroutines.flow.onSubscription
 import kotlinx.coroutines.flow.takeWhile
+import org.slf4j.helpers.NOPLogger
 
 class Server(
     private val msgBuffer: SharedFlow<ServerMessage>,
     private val outgoingMessages: Channel<ClientMessage>,
-    private val scope: CoroutineScope,
+    enableLogging: Boolean = false,
 ) {
+    private val logger = if (enableLogging) KotlinLogging.logger {} else KotlinLogging.logger(NOPLogger.NOP_LOGGER)
+
     lateinit var features: ISupportFeatures
         private set
 
@@ -21,6 +25,7 @@ class Server(
         private set
 
     suspend fun fetchChannels(): Set<IRCChannel> {
+        logger.debug { "Fetching IRC channels" }
         val buffer = mutableSetOf<IRCChannel>()
 
         msgBuffer
@@ -29,7 +34,6 @@ class Server(
             .takeWhile { it !is ServerMessage.Numeric.RPL_LISTEND }
             .filterIsInstance<ServerMessage.Numeric.RPL_LIST>()
             .collect { buffer.add(IRCChannel(it.chanName, it.clientCount, it.topic)) }
-
         channels = buffer.toSortedSet(compareBy { it.chanName })
         return channels
     }

src/main/kotlin/com/shr4pnel/ferretirc/net/Connection.kt

@@ -7,7 +7,12 @@ import io.ktor.network.sockets.aSocket
 import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.Dispatchers
 
-class Connection(val hostname: String, val port: Int, val scope: CoroutineScope) {
+class Connection(
+    val hostname: String,
+    val port: Int,
+    val scope: CoroutineScope,
+    val enableLogging: Boolean = false,
+) {
     private val selectorManager = SelectorManager(Dispatchers.IO)
     private val socketBuilder = aSocket(selectorManager).tcp()
     lateinit var socket: Socket
@@ -16,10 +21,10 @@ class Connection(val hostname: String, val port: Int, val scope: CoroutineScope)
 
     suspend fun connect(): Server {
         socket = socketBuilder.connect(hostname, port)
-        reader = MessageReader(socket, scope)
+        reader = MessageReader(socket, scope, enableLogging)
-        writer = MessageWriter(socket, scope)
+        writer = MessageWriter(socket, scope, enableLogging)
         reader.start()
         writer.start()
-        return Server(reader.sharedMessageBuffer, writer.outgoingMessages, scope)
+        return Server(reader.sharedMessageBuffer, writer.outgoingMessages, enableLogging)
     }
 }

src/main/kotlin/com/shr4pnel/ferretirc/net/MessageParser.kt

@@ -1,15 +1,14 @@
 package com.shr4pnel.ferretirc.net
 
 import com.shr4pnel.ferretirc.net.messages.ServerMessage
-import com.shr4pnel.ferretirc.util.Helpers
 import io.github.oshai.kotlinlogging.KotlinLogging
 import io.github.oshai.kotlinlogging.slf4j.logger
 import kotlinx.coroutines.channels.Channel
 import org.slf4j.helpers.NOPLogger
 
-class MessageParser(val incoming: Channel<String>) {
+class MessageParser(val incoming: Channel<String>, enableLogging: Boolean = false) {
     val incomingParsedMessages = Channel<ServerMessage>()
-    private val logger = if (Helpers.enableLogging) KotlinLogging.logger {} else KotlinLogging.logger(NOPLogger.NOP_LOGGER)
+    private val logger = if (enableLogging) KotlinLogging.logger {} else KotlinLogging.logger(NOPLogger.NOP_LOGGER)
 
     class MessageBuilder {
         private var tags: String? = null
@@ -154,7 +153,7 @@ class MessageParser(val incoming: Channel<String>) {
     suspend fun start() {
         val builder = MessageBuilder()
         for (msg in incoming) {
-            logger.trace { "Receiving: $msg" }
+            logger.debug { "Receiving: $msg" }
             incomingParsedMessages.send(builder.build(msg))
         }
     }

src/main/kotlin/com/shr4pnel/ferretirc/net/MessageReader.kt

@@ -2,7 +2,6 @@ package com.shr4pnel.ferretirc.net
 
 import com.shr4pnel.ferretirc.net.messages.MessageIO
 import com.shr4pnel.ferretirc.net.messages.ServerMessage
-import com.shr4pnel.ferretirc.util.Helpers
 import io.github.oshai.kotlinlogging.KotlinLogging
 import io.github.oshai.kotlinlogging.slf4j.logger
 import io.ktor.network.sockets.Socket
@@ -20,12 +19,12 @@ import org.slf4j.helpers.NOPLogger
 import kotlin.reflect.KClass
 import kotlin.reflect.cast
 
-class MessageReader(socket: Socket, scope: CoroutineScope) : MessageIO(socket, scope) {
+class MessageReader(socket: Socket, scope: CoroutineScope, enableLogging: Boolean = false) : MessageIO(socket, scope) {
     private lateinit var receive: ByteReadChannel
     private val messageBuffer = MutableSharedFlow<ServerMessage>(16, 64)
     val sharedMessageBuffer = messageBuffer.asSharedFlow()
-    val parser = MessageParser(incomingMessages)
+    val parser = MessageParser(incomingMessages, enableLogging)
-    private val logger = if (Helpers.enableLogging) KotlinLogging.logger {} else KotlinLogging.logger(NOPLogger.NOP_LOGGER)
+    private val logger = if (enableLogging) KotlinLogging.logger {} else KotlinLogging.logger(NOPLogger.NOP_LOGGER)
 
     init {
         scope.launch {

src/main/kotlin/com/shr4pnel/ferretirc/net/MessageWriter.kt

@@ -1,7 +1,6 @@
 package com.shr4pnel.ferretirc.net
 
 import com.shr4pnel.ferretirc.net.messages.MessageIO
-import com.shr4pnel.ferretirc.util.Helpers
 import io.github.oshai.kotlinlogging.KotlinLogging
 import io.github.oshai.kotlinlogging.slf4j.logger
 import io.ktor.network.sockets.Socket
@@ -12,9 +11,9 @@ import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.launch
 import org.slf4j.helpers.NOPLogger
 
-class MessageWriter(socket: Socket, scope: CoroutineScope) : MessageIO(socket, scope) {
+class MessageWriter(socket: Socket, scope: CoroutineScope, enableLogging: Boolean = false) : MessageIO(socket, scope) {
     private lateinit var send: ByteWriteChannel
-    private val logger = if (Helpers.enableLogging) KotlinLogging.logger {} else KotlinLogging.logger(NOPLogger.NOP_LOGGER)
+    private val logger = if (enableLogging) KotlinLogging.logger {} else KotlinLogging.logger(NOPLogger.NOP_LOGGER)
 
     override fun start() =
         scope.launch {

src/main/kotlin/com/shr4pnel/ferretirc/util/Helpers.kt

@@ -1,7 +0,0 @@
-package com.shr4pnel.ferretirc.util
-
-class Helpers {
-    companion object LoggingConfig {
-        var enableLogging = true
-    }
-}

src/main/kotlin/com/shr4pnel/ferretirc/util/LogbackHelpers.kt

@@ -0,0 +1,109 @@
+package com.shr4pnel.ferretirc.util
+
+import ch.qos.logback.classic.Level
+import ch.qos.logback.classic.spi.ILoggingEvent
+import ch.qos.logback.core.pattern.CompositeConverter
+import ch.qos.logback.core.pattern.color.BoldWhiteCompositeConverter
+import ch.qos.logback.core.pattern.color.ForegroundCompositeConverterBase
+import ch.qos.logback.core.pattern.color.ANSIConstants as ANSI
+
+private fun center(severity: String, width: Int = 7): String {
+    val pad = width - severity.length
+    if (pad <= 0) return severity
+    val leading = pad / 2
+    return buildString {
+        repeat(leading) { append(" ") }
+        append(severity)
+        repeat(pad - leading) { append(" ") }
+    }
+}
+
+/** 8 bit ANSI codes (logback uses 3/4 bit which isn't always equivalent) */
+object Codes {
+    const val SET_DEFAULT_COLOR = ANSI.ESC_START + ANSI.RESET + ANSI.DEFAULT_FG + ANSI.ESC_END
+    const val FG_START = ANSI.ESC_START + "38;5;"
+    const val FG_BOLD_START = ANSI.ESC_START + ANSI.BOLD + "38;5;"
+    const val BG_START = ANSI.ESC_START + "48;5;"
+    const val RED = "9"
+    const val BLACK = "16"
+    const val GREEN = "22"
+    const val BLUE = "27"
+    const val ORANGE = "202"
+    const val DIMMED_WHITE = "250"
+    const val WHITE = "255"
+    const val UNSET = ""
+}
+
+/**
+ * Interface of HighlightingCompositeConverterExt, used to colour the background and foreground of log messages
+ * depending on their severity.
+ *
+ * Inheritor of ForegroundCompositeConverterBase, the implementation controlling colour-based transformations of
+ * log events
+ *
+ * @see HighlightingCompositeConverterExt
+ * @see CompositeConverter
+ */
+abstract class ForegroundBackgroundCompositeConverter<E : ILoggingEvent> : ForegroundCompositeConverterBase<E>() {
+    override fun transform(event: E, `in`: String) = buildString {
+        val fg = getForegroundColorCode(event)
+        val bg = getBackgroundColourCode(event)
+        val severity = center(`in`.trim())
+        if (fg.isNotEmpty()) {
+            append(Codes.FG_BOLD_START)
+            append(fg)
+            append(ANSI.ESC_END)
+        }
+        if (bg.isNotEmpty()) {
+            append(Codes.BG_START)
+            append(getBackgroundColourCode(event))
+            append(ANSI.ESC_END)
+        }
+        append(severity)
+        append(Codes.SET_DEFAULT_COLOR)
+    }
+
+    abstract fun getBackgroundColourCode(event: ILoggingEvent): String
+}
+
+/**
+ * Converter class extension for control over backgrounds and foregrounds<
+ *
+ * Overrides methods of ForegroundBackgroundCompositeConverter to specify the bg/fg colours depending on severity
+ *
+ * Adapted from [shuwada/logback-custom-color](https://github.com/shuwada/logback-custom-color)
+ */
+class HighlightingCompositeConverterExt : ForegroundBackgroundCompositeConverter<ILoggingEvent>() {
+    override fun getForegroundColorCode(event: ILoggingEvent) = when (event.level) {
+        Level.TRACE -> Codes.WHITE
+        Level.DEBUG -> Codes.WHITE
+        Level.WARN -> Codes.WHITE
+        Level.INFO -> Codes.WHITE
+        Level.ERROR -> Codes.WHITE
+        else -> Codes.UNSET
+    }
+
+    override fun getBackgroundColourCode(event: ILoggingEvent) = when (event.level) {
+        Level.TRACE -> Codes.BLACK
+        Level.DEBUG -> Codes.GREEN
+        Level.WARN -> Codes.ORANGE
+        Level.INFO -> Codes.BLUE
+        Level.ERROR -> Codes.RED
+        else -> Codes.UNSET
+    }
+}
+
+/**
+ * Converter rule which pulls out the last string of the thread split by spaces
+ */
+class ThreadConverter<E> : CompositeConverter<E>() {
+    override fun transform(event: E, `in`: String) = `in`.split(" ").last()
+}
+
+/**
+ * Converter rule which converts text to bold white
+ */
+class BoldWhiteCompositeConverterExt<E> : BoldWhiteCompositeConverter<E>() {
+    override fun transform(event: E, `in`: String) =
+        Codes.FG_BOLD_START + Codes.DIMMED_WHITE + ANSI.ESC_END + `in` + Codes.SET_DEFAULT_COLOR
+}

src/main/resources/logback-base.xml

@@ -0,0 +1,29 @@
+<included>
+    <import class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"/>
+    <import class="ch.qos.logback.core.ConsoleAppender"/>
+    <import class="ch.qos.logback.core.FileAppender"/>
+    <import class="com.shr4pnel.ferretirc.util.HighlightingCompositeConverterExt"/>
+    <import class="com.shr4pnel.ferretirc.util.ThreadConverter"/>
+    <import class="com.shr4pnel.ferretirc.util.BoldWhiteCompositeConverterExt"/>
+    <import class="ch.qos.logback.classic.filter.ThresholdFilter"/>
+    <!-- https://logback.qos.ch/manual/layouts.html#formatModifiers -->
+    <conversionRule conversionWord="highlightext" class="HighlightingCompositeConverterExt" />
+    <conversionRule conversionWord="boldwhiteext" class="BoldWhiteCompositeConverterExt" />
+    <conversionRule conversionWord="threadconvert" class="ThreadConverter" />
+    <appender name="STDOUT" class="ConsoleAppender">
+        <filter class="ThresholdFilter">
+            <level>${STDOUT_LEVEL:-debug}</level>
+        </filter>
+        <encoder class="PatternLayoutEncoder">
+            <pattern>%d{HH:mm:ss.SSS} %highlightext(%level) %-13.13threadconvert(%t) %-36.36logger %boldwhiteext(%msg) %n</pattern>
+        </encoder>
+    </appender>
+    <appender name="FILE" class="FileAppender">
+        <file>${TEST_LOG_DIR}/libferretirc.log</file>
+        <immediateFlush>true</immediateFlush>
+        <append>false</append>
+        <encoder class="PatternLayoutEncoder">
+            <pattern>%d{HH:mm:ss.SSS} [%.16t/%-5level] %logger %msg%n</pattern>
+        </encoder>
+    </appender>
+</included>

src/main/resources/logback.xml

@@ -2,14 +2,8 @@
 <!DOCTYPE configuration>
 <!-- From https://logback.qos.ch/manual/configuration.html -->
 <configuration>
-    <import class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"/>
+    <include resource="logback-base.xml"/>
-    <import class="ch.qos.logback.core.ConsoleAppender"/>
+    <root level="info">
-    <appender name="STDOUT" class="ConsoleAppender">
-        <encoder class="PatternLayoutEncoder">
-            <pattern>%d{ISO8601} [%5level] %.36logger %msg%n</pattern>
-        </encoder>
-    </appender>
-    <root level="debug">
         <appender-ref ref="STDOUT"/>
     </root>
 </configuration>

src/test/kotlin/com/shr4pnel/ferretirc/IrcClientTest.kt

@@ -4,7 +4,7 @@ import com.shr4pnel.ferretirc.net.messages.ServerMessage
 import io.github.oshai.kotlinlogging.KotlinLogging
 import kotlinx.coroutines.launch
 import kotlinx.coroutines.runBlocking
-import kotlinx.coroutines.withTimeoutOrNull
+import kotlinx.coroutines.test.runTest
 import org.junit.jupiter.api.AfterAll
 import org.junit.jupiter.api.BeforeAll
 import org.junit.jupiter.api.Test
@@ -20,7 +20,7 @@ class IrcClientTest {
 
     companion object {
         lateinit var processes: MutableList<Process>
-        val client = IrcClient("localhost", 6667)
+        val client = IrcClient("localhost", 6667, enableLogging = true)
         private val logger = KotlinLogging.logger {}
 
         @JvmStatic
@@ -42,7 +42,10 @@ class IrcClientTest {
                         ),
                     )
                 client.connect()
-                client.register("shr4p", "Tyler D", "password")
+                client.register("shr4p", "Tyler Fullname", "password")
+                guestUser.connect()
+                guestUser.register("guest", "guest", "pass")
+                client.server
             }
 
         @JvmStatic
@@ -103,10 +106,7 @@ class IrcClientTest {
 
     @Test
     fun messageLands() =
-        runBlocking {
+        runTest {
-            val guestUser = IrcClient("localhost", 6667, false)
-            guestUser.connect()
-            guestUser.register("guest", "guest", "pass")
             val channels = client.server.fetchChannels()
             val message = Message.PrivMsg(channels.first(), "bring me to life")
             guestUser.queueMessage(message)

src/test/resources/logback-test.xml

@@ -0,0 +1,15 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+<!DOCTYPE configuration>
+<!-- From https://logback.qos.ch/manual/configuration.html -->
+<configuration>
+    <import class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"/>
+    <import class="ch.qos.logback.core.ConsoleAppender"/>
+    <include resource="logback-base.xml"/>
+    <logger name="com.shr4pnel" level="trace" additivity="false">
+        <appender-ref ref="STDOUT"/>
+        <appender-ref ref="FILE"/>
+    </logger>
+    <root level="warn">
+        <appender-ref ref="STDOUT"/>
+    </root>
+</configuration>