Fix logging in tests

This commit is contained in:
eikek
2022-02-19 23:33:01 +01:00
parent 8b42708db2
commit 9eb9497675
28 changed files with 130 additions and 76 deletions

View File

@ -453,7 +453,7 @@ val store = project
.in(file("modules/store")) .in(file("modules/store"))
.disablePlugins(RevolverPlugin) .disablePlugins(RevolverPlugin)
.settings(sharedSettings) .settings(sharedSettings)
.withTestSettings .withTestSettingsDependsOn(loggingScribe)
.settings( .settings(
name := "docspell-store", name := "docspell-store",
libraryDependencies ++= libraryDependencies ++=
@ -523,7 +523,7 @@ val extract = project
.in(file("modules/extract")) .in(file("modules/extract"))
.disablePlugins(RevolverPlugin) .disablePlugins(RevolverPlugin)
.settings(sharedSettings) .settings(sharedSettings)
.withTestSettings .withTestSettingsDependsOn(loggingScribe)
.settings( .settings(
name := "docspell-extract", name := "docspell-extract",
libraryDependencies ++= libraryDependencies ++=
@ -539,7 +539,7 @@ val convert = project
.in(file("modules/convert")) .in(file("modules/convert"))
.disablePlugins(RevolverPlugin) .disablePlugins(RevolverPlugin)
.settings(sharedSettings) .settings(sharedSettings)
.withTestSettings .withTestSettingsDependsOn(loggingScribe)
.settings( .settings(
name := "docspell-convert", name := "docspell-convert",
libraryDependencies ++= libraryDependencies ++=
@ -554,7 +554,7 @@ val analysis = project
.disablePlugins(RevolverPlugin) .disablePlugins(RevolverPlugin)
.enablePlugins(NerModelsPlugin) .enablePlugins(NerModelsPlugin)
.settings(sharedSettings) .settings(sharedSettings)
.withTestSettings .withTestSettingsDependsOn(loggingScribe)
.settings(NerModelsPlugin.nerClassifierSettings) .settings(NerModelsPlugin.nerClassifierSettings)
.settings( .settings(
name := "docspell-analysis", name := "docspell-analysis",

View File

@ -17,10 +17,11 @@ import fs2.io.file.Files
import docspell.analysis.classifier.TextClassifier.Data import docspell.analysis.classifier.TextClassifier.Data
import docspell.common._ import docspell.common._
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class StanfordTextClassifierSuite extends FunSuite { class StanfordTextClassifierSuite extends FunSuite with TestLoggingConfig {
val logger = docspell.logging.getLogger[IO] val logger = docspell.logging.getLogger[IO]
test("learn from data") { test("learn from data") {

View File

@ -10,10 +10,11 @@ import docspell.analysis.Env
import docspell.common.Language.NLPLanguage import docspell.common.Language.NLPLanguage
import docspell.common._ import docspell.common._
import docspell.files.TestFiles import docspell.files.TestFiles
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class BaseCRFAnnotatorSuite extends FunSuite { class BaseCRFAnnotatorSuite extends FunSuite with TestLoggingConfig {
def annotate(language: NLPLanguage): String => Vector[NerLabel] = def annotate(language: NLPLanguage): String => Vector[NerLabel] =
BasicCRFAnnotator.nerAnnotate(BasicCRFAnnotator.Cache.getAnnotator(language)) BasicCRFAnnotator.nerAnnotate(BasicCRFAnnotator.Cache.getAnnotator(language))

View File

@ -14,11 +14,12 @@ import cats.effect.unsafe.implicits.global
import docspell.analysis.Env import docspell.analysis.Env
import docspell.common._ import docspell.common._
import docspell.files.TestFiles import docspell.files.TestFiles
import docspell.logging.TestLoggingConfig
import edu.stanford.nlp.pipeline.StanfordCoreNLP import edu.stanford.nlp.pipeline.StanfordCoreNLP
import munit._ import munit._
class StanfordNerAnnotatorSuite extends FunSuite { class StanfordNerAnnotatorSuite extends FunSuite with TestLoggingConfig {
lazy val germanClassifier = lazy val germanClassifier =
new StanfordCoreNLP(Properties.nerGerman(None, false)) new StanfordCoreNLP(Properties.nerGerman(None, false))
lazy val englishClassifier = lazy val englishClassifier =

View File

@ -20,13 +20,13 @@ import docspell.convert.extern.OcrMyPdfConfig
import docspell.convert.extern.{TesseractConfig, UnoconvConfig, WkHtmlPdfConfig} import docspell.convert.extern.{TesseractConfig, UnoconvConfig, WkHtmlPdfConfig}
import docspell.convert.flexmark.MarkdownConfig import docspell.convert.flexmark.MarkdownConfig
import docspell.files.ExampleFiles import docspell.files.ExampleFiles
import docspell.logging.{Level, Logger} import docspell.logging.TestLoggingConfig
import munit._ import munit._
class ConversionTest extends FunSuite with FileChecks { class ConversionTest extends FunSuite with FileChecks with TestLoggingConfig {
val logger = Logger.simpleF[IO](System.err, Level.Info) val logger = docspell.logging.getLogger[IO]
val target = File.path(Paths.get("target")) val target = File.path(Paths.get("target"))
val convertConfig = ConvertConfig( val convertConfig = ConvertConfig(

View File

@ -11,12 +11,15 @@ import fs2.Stream
import docspell.common._ import docspell.common._
import docspell.files.ExampleFiles import docspell.files.ExampleFiles
import docspell.logging.{Level, Logger} import docspell.logging.{Logger, TestLoggingConfig}
import munit.CatsEffectSuite import munit.CatsEffectSuite
class RemovePdfEncryptionTest extends CatsEffectSuite with FileChecks { class RemovePdfEncryptionTest
val logger: Logger[IO] = Logger.simpleF[IO](System.err, Level.Info) extends CatsEffectSuite
with FileChecks
with TestLoggingConfig {
val logger: Logger[IO] = docspell.logging.getLogger[IO]
private val protectedPdf = private val protectedPdf =
ExampleFiles.secured_protected_test123_pdf.readURL[IO](16 * 1024) ExampleFiles.secured_protected_test123_pdf.readURL[IO](16 * 1024)

View File

@ -16,13 +16,13 @@ import fs2.io.file.Path
import docspell.common._ import docspell.common._
import docspell.convert._ import docspell.convert._
import docspell.files.ExampleFiles import docspell.files.ExampleFiles
import docspell.logging.{Level, Logger} import docspell.logging.TestLoggingConfig
import munit._ import munit._
class ExternConvTest extends FunSuite with FileChecks { class ExternConvTest extends FunSuite with FileChecks with TestLoggingConfig {
val utf8 = StandardCharsets.UTF_8 val utf8 = StandardCharsets.UTF_8
val logger = Logger.simpleF[IO](System.err, Level.Info) val logger = docspell.logging.getLogger[IO]
val target = File.path(Paths.get("target")) val target = File.path(Paths.get("target"))
test("convert html to pdf") { test("convert html to pdf") {

View File

@ -10,10 +10,11 @@ import cats.effect.IO
import cats.effect.unsafe.implicits.global import cats.effect.unsafe.implicits.global
import docspell.files.TestFiles import docspell.files.TestFiles
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class TextExtractionSuite extends FunSuite { class TextExtractionSuite extends FunSuite with TestLoggingConfig {
import TestFiles._ import TestFiles._
val logger = docspell.logging.getLogger[IO] val logger = docspell.logging.getLogger[IO]

View File

@ -10,10 +10,11 @@ import cats.effect._
import cats.effect.unsafe.implicits.global import cats.effect.unsafe.implicits.global
import docspell.files.ExampleFiles import docspell.files.ExampleFiles
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class OdfExtractTest extends FunSuite { class OdfExtractTest extends FunSuite with TestLoggingConfig {
val files = List( val files = List(
ExampleFiles.examples_sample_odt -> 6367, ExampleFiles.examples_sample_odt -> 6367,

View File

@ -6,9 +6,11 @@
package docspell.extract.pdfbox package docspell.extract.pdfbox
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class PdfMetaDataTest extends FunSuite { class PdfMetaDataTest extends FunSuite with TestLoggingConfig {
test("split keywords on comma") { test("split keywords on comma") {
val md = PdfMetaData.empty.copy(keywords = Some("a,b, c")) val md = PdfMetaData.empty.copy(keywords = Some("a,b, c"))

View File

@ -10,10 +10,11 @@ import cats.effect._
import cats.effect.unsafe.implicits.global import cats.effect.unsafe.implicits.global
import docspell.files.{ExampleFiles, TestFiles} import docspell.files.{ExampleFiles, TestFiles}
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class PdfboxExtractTest extends FunSuite { class PdfboxExtractTest extends FunSuite with TestLoggingConfig {
val textPDFs = List( val textPDFs = List(
ExampleFiles.letter_de_pdf -> TestFiles.letterDEText, ExampleFiles.letter_de_pdf -> TestFiles.letterDEText,

View File

@ -13,10 +13,11 @@ import fs2.io.file.Files
import fs2.io.file.Path import fs2.io.file.Path
import docspell.files.ExampleFiles import docspell.files.ExampleFiles
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class PdfboxPreviewTest extends FunSuite { class PdfboxPreviewTest extends FunSuite with TestLoggingConfig {
val testPDFs = List( val testPDFs = List(
ExampleFiles.letter_de_pdf -> "7d98be75b239816d6c751b3f3c56118ebf1a4632c43baf35a68a662f9d595ab8", ExampleFiles.letter_de_pdf -> "7d98be75b239816d6c751b3f3c56118ebf1a4632c43baf35a68a662f9d595ab8",

View File

@ -11,10 +11,11 @@ import cats.effect.unsafe.implicits.global
import docspell.common.MimeTypeHint import docspell.common.MimeTypeHint
import docspell.files.ExampleFiles import docspell.files.ExampleFiles
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class PoiExtractTest extends FunSuite { class PoiExtractTest extends FunSuite with TestLoggingConfig {
val officeFiles = List( val officeFiles = List(
ExampleFiles.examples_sample_doc -> 6241, ExampleFiles.examples_sample_doc -> 6241,

View File

@ -7,10 +7,11 @@
package docspell.extract.rtf package docspell.extract.rtf
import docspell.files.ExampleFiles import docspell.files.ExampleFiles
import docspell.logging.TestLoggingConfig
import munit._ import munit._
class RtfExtractTest extends FunSuite { class RtfExtractTest extends FunSuite with TestLoggingConfig {
test("extract text from rtf using java input-stream") { test("extract text from rtf using java input-stream") {
val file = ExampleFiles.examples_sample_rtf val file = ExampleFiles.examples_sample_rtf

View File

@ -11,6 +11,7 @@ import cats.implicits._
import fs2.Pipe import fs2.Pipe
import docspell.common._ import docspell.common._
import docspell.logging
import docspell.store.Store import docspell.store.Store
import docspell.store.records.RJobLog import docspell.store.records.RJobLog
@ -29,19 +30,22 @@ object LogSink {
def logInternal[F[_]: Sync](e: LogEvent): F[Unit] = { def logInternal[F[_]: Sync](e: LogEvent): F[Unit] = {
val logger = docspell.logging.getLogger[F] val logger = docspell.logging.getLogger[F]
val addData: logging.LogEvent => logging.LogEvent =
_.data("jobId", e.jobId).data("jobInfo", e.jobInfo)
e.level match { e.level match {
case LogLevel.Info => case LogLevel.Info =>
logger.info(e.logLine) logger.infoWith(e.logLine)(addData)
case LogLevel.Debug => case LogLevel.Debug =>
logger.debug(e.logLine) logger.debugWith(e.logLine)(addData)
case LogLevel.Warn => case LogLevel.Warn =>
logger.warn(e.logLine) logger.warnWith(e.logLine)(addData)
case LogLevel.Error => case LogLevel.Error =>
e.ex match { e.ex match {
case Some(exc) => case Some(exc) =>
logger.error(exc)(e.logLine) logger.errorWith(e.logLine)(addData.andThen(_.addError(exc)))
case None => case None =>
logger.error(e.logLine) logger.errorWith(e.logLine)(addData)
} }
} }
} }

View File

@ -163,4 +163,7 @@ object Logger {
val asUnsafe = simple(ps, minimumLevel) val asUnsafe = simple(ps, minimumLevel)
} }
def simpleDefault[F[_]: Sync](minimumLevel: Level = Level.Info): Logger[F] =
simpleF[F](System.err, minimumLevel)
} }

View File

@ -8,21 +8,37 @@ package docspell.logging.impl
import cats.effect.Sync import cats.effect.Sync
import docspell.logging.LogConfig
import docspell.logging.LogConfig.Format import docspell.logging.LogConfig.Format
import docspell.logging.{Level, LogConfig}
import scribe.format.Formatter import scribe.format.Formatter
import scribe.jul.JULHandler import scribe.jul.JULHandler
import scribe.writer.ConsoleWriter import scribe.writer.ConsoleWriter
object ScribeConfigure { object ScribeConfigure {
private[this] val docspellRootVerbose = "DOCSPELL_ROOT_LOGGER_LEVEL"
def configure[F[_]: Sync](cfg: LogConfig): F[Unit] = def configure[F[_]: Sync](cfg: LogConfig): F[Unit] =
Sync[F].delay { Sync[F].delay {
replaceJUL() replaceJUL()
unsafeConfigure(scribe.Logger.root, cfg) val docspellLogger = scribe.Logger("docspell")
unsafeConfigure(scribe.Logger.root, cfg.copy(minimumLevel = getRootMinimumLevel))
unsafeConfigure(docspellLogger, cfg)
} }
private[this] def getRootMinimumLevel: Level =
Option(System.getenv(docspellRootVerbose))
.map(Level.fromString)
.flatMap {
case Right(level) => Some(level)
case Left(err) =>
scribe.warn(
s"Environment variable '$docspellRootVerbose' has invalid value: $err"
)
None
}
.getOrElse(Level.Error)
def unsafeConfigure(logger: scribe.Logger, cfg: LogConfig): Unit = { def unsafeConfigure(logger: scribe.Logger, cfg: LogConfig): Unit = {
val mods = List[scribe.Logger => scribe.Logger]( val mods = List[scribe.Logger => scribe.Logger](
_.clearHandlers(), _.clearHandlers(),
@ -45,7 +61,7 @@ object ScribeConfigure {
() ()
} }
def replaceJUL(): Unit = { private def replaceJUL(): Unit = {
scribe.Logger.system // just to load effects in Logger singleton scribe.Logger.system // just to load effects in Logger singleton
val julRoot = java.util.logging.LogManager.getLogManager.getLogger("") val julRoot = java.util.logging.LogManager.getLogManager.getLogger("")
julRoot.getHandlers.foreach(julRoot.removeHandler) julRoot.getHandlers.foreach(julRoot.removeHandler)

View File

@ -0,0 +1,26 @@
/*
* Copyright 2020 Eike K. & Contributors
*
* SPDX-License-Identifier: AGPL-3.0-or-later
*/
package docspell.logging
import docspell.logging.impl.ScribeConfigure
import munit.Suite
trait TestLoggingConfig extends Suite {
def docspellLogConfig: LogConfig = LogConfig(Level.Warn, LogConfig.Format.Fancy)
def rootMinimumLevel: Level = Level.Error
override def beforeAll(): Unit = {
super.beforeAll()
val docspellLogger = scribe.Logger("docspell")
ScribeConfigure.unsafeConfigure(docspellLogger, docspellLogConfig)
val rootCfg = docspellLogConfig.copy(minimumLevel = rootMinimumLevel)
ScribeConfigure.unsafeConfigure(scribe.Logger.root, rootCfg)
()
}
}

View File

@ -46,7 +46,7 @@ trait Fixtures extends HttpClientOps { self: CatsEffectSuite =>
} }
object Fixtures { object Fixtures {
private val loggerIO: Logger[IO] = docspell.logging.getLogger[IO] private val loggerIO: Logger[IO] = Logger.simpleDefault[IO]()
final case class Env(store: Store[IO], cfg: PubSubConfig) { final case class Env(store: Store[IO], cfg: PubSubConfig) {
def pubSub: Resource[IO, NaivePubSub[IO]] = { def pubSub: Resource[IO, NaivePubSub[IO]] = {

View File

@ -9,6 +9,7 @@ package docspell.pubsub.naive
import cats.effect._ import cats.effect._
import docspell.common._ import docspell.common._
import docspell.logging.Logger
import docspell.pubsub.api._ import docspell.pubsub.api._
import io.circe.Encoder import io.circe.Encoder
@ -55,5 +56,5 @@ trait HttpClientOps {
} }
object HttpClientOps { object HttpClientOps {
private val logger = docspell.logging.getLogger[IO] private val logger = Logger.simpleDefault[IO]()
} }

View File

@ -12,13 +12,14 @@ import cats.effect._
import cats.implicits._ import cats.implicits._
import fs2.concurrent.SignallingRef import fs2.concurrent.SignallingRef
import docspell.logging.{Logger, TestLoggingConfig}
import docspell.pubsub.api._ import docspell.pubsub.api._
import docspell.pubsub.naive.Topics._ import docspell.pubsub.naive.Topics._
import munit.CatsEffectSuite import munit.CatsEffectSuite
class NaivePubSubTest extends CatsEffectSuite with Fixtures { class NaivePubSubTest extends CatsEffectSuite with Fixtures with TestLoggingConfig {
private[this] val logger = docspell.logging.getLogger[IO] private[this] val logger = Logger.simpleDefault[IO]()
def subscribe[A](ps: PubSubT[IO], topic: TypedTopic[A]) = def subscribe[A](ps: PubSubT[IO], topic: TypedTopic[A]) =
for { for {

View File

@ -9,11 +9,12 @@ package docspell.store.migrate
import cats.effect.IO import cats.effect.IO
import cats.effect.unsafe.implicits._ import cats.effect.unsafe.implicits._
import docspell.logging.TestLoggingConfig
import docspell.store.StoreFixture import docspell.store.StoreFixture
import munit.FunSuite import munit.FunSuite
class H2MigrateTest extends FunSuite { class H2MigrateTest extends FunSuite with TestLoggingConfig {
test("h2 empty schema migration") { test("h2 empty schema migration") {
val jdbc = StoreFixture.memoryDB("h2test") val jdbc = StoreFixture.memoryDB("h2test")

View File

@ -10,6 +10,7 @@ import cats.effect._
import cats.effect.unsafe.implicits._ import cats.effect.unsafe.implicits._
import docspell.common.LenientUri import docspell.common.LenientUri
import docspell.logging.TestLoggingConfig
import docspell.store.JdbcConfig import docspell.store.JdbcConfig
import com.dimafeng.testcontainers.MariaDBContainer import com.dimafeng.testcontainers.MariaDBContainer
@ -17,7 +18,10 @@ import com.dimafeng.testcontainers.munit.TestContainerForAll
import munit._ import munit._
import org.testcontainers.utility.DockerImageName import org.testcontainers.utility.DockerImageName
class MariaDbMigrateTest extends FunSuite with TestContainerForAll { class MariaDbMigrateTest
extends FunSuite
with TestContainerForAll
with TestLoggingConfig {
override val containerDef: MariaDBContainer.Def = override val containerDef: MariaDBContainer.Def =
MariaDBContainer.Def(DockerImageName.parse("mariadb:10.5")) MariaDBContainer.Def(DockerImageName.parse("mariadb:10.5"))

View File

@ -10,6 +10,7 @@ import cats.effect._
import cats.effect.unsafe.implicits._ import cats.effect.unsafe.implicits._
import docspell.common.LenientUri import docspell.common.LenientUri
import docspell.logging.TestLoggingConfig
import docspell.store.JdbcConfig import docspell.store.JdbcConfig
import com.dimafeng.testcontainers.PostgreSQLContainer import com.dimafeng.testcontainers.PostgreSQLContainer
@ -17,7 +18,10 @@ import com.dimafeng.testcontainers.munit.TestContainerForAll
import munit._ import munit._
import org.testcontainers.utility.DockerImageName import org.testcontainers.utility.DockerImageName
class PostgresqlMigrateTest extends FunSuite with TestContainerForAll { class PostgresqlMigrateTest
extends FunSuite
with TestContainerForAll
with TestLoggingConfig {
override val containerDef: PostgreSQLContainer.Def = override val containerDef: PostgreSQLContainer.Def =
PostgreSQLContainer.Def(DockerImageName.parse("postgres:13")) PostgreSQLContainer.Def(DockerImageName.parse("postgres:13"))

View File

@ -6,12 +6,13 @@
package docspell.store.qb package docspell.store.qb
import docspell.logging.TestLoggingConfig
import docspell.store.qb.DSL._ import docspell.store.qb.DSL._
import docspell.store.qb.model._ import docspell.store.qb.model._
import munit._ import munit._
class QueryBuilderTest extends FunSuite { class QueryBuilderTest extends FunSuite with TestLoggingConfig {
test("simple") { test("simple") {
val c = CourseRecord.as("c") val c = CourseRecord.as("c")

View File

@ -6,13 +6,14 @@
package docspell.store.qb.impl package docspell.store.qb.impl
import docspell.logging.TestLoggingConfig
import docspell.store.qb.DSL._ import docspell.store.qb.DSL._
import docspell.store.qb._ import docspell.store.qb._
import docspell.store.qb.model._ import docspell.store.qb.model._
import munit._ import munit._
class SelectBuilderTest extends FunSuite { class SelectBuilderTest extends FunSuite with TestLoggingConfig {
test("basic fragment") { test("basic fragment") {
val c = CourseRecord.as("c") val c = CourseRecord.as("c")

View File

@ -12,6 +12,7 @@ import java.util.concurrent.atomic.AtomicLong
import cats.implicits._ import cats.implicits._
import docspell.common._ import docspell.common._
import docspell.logging.TestLoggingConfig
import docspell.store.StoreFixture import docspell.store.StoreFixture
import docspell.store.records.RJob import docspell.store.records.RJob
import docspell.store.records.RJobGroupUse import docspell.store.records.RJobGroupUse
@ -19,7 +20,7 @@ import docspell.store.records.RJobGroupUse
import doobie.implicits._ import doobie.implicits._
import munit._ import munit._
class QJobTest extends CatsEffectSuite with StoreFixture { class QJobTest extends CatsEffectSuite with StoreFixture with TestLoggingConfig {
private[this] val c = new AtomicLong(0) private[this] val c = new AtomicLong(0)
private val worker = Ident.unsafe("joex1") private val worker = Ident.unsafe("joex1")

View File

@ -604,41 +604,18 @@ Please have a look at the corresponding [section](@/docs/configure/_index.md#mem
# Logging # Logging
By default, docspell logs to stdout. This works well, when managed by By default, docspell logs to stdout. This works well, when managed by
systemd or other inits. Logging is done by systemd or other inits. Logging can be configured in the configuration
[logback](https://logback.qos.ch/). Please refer to its documentation file or via environment variables. There are only two settings:
for how to configure logging.
If you created your logback config file, it can be added as argument - `minimum-level` specifies the log level to control the verbosity.
to the executable using this syntax: Levels are ordered from: *Trace*, *Debug*, *Info*, *Warn* and
*Error*
``` bash - `format` this defines how the logs are formatted. There are two
/path/to/docspell -Dlogback.configurationFile=/path/to/your/logging-config-file formats for humans: *Plain* and *Fancy*. And two more suited for
``` machine consumption: *Json* and *Logfmt*. The *Json* format contains
all details, while the others may omit some for readability
To get started, the default config looks like this:
``` xml
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<withJansi>true</withJansi>
<encoder>
<pattern>[%thread] %highlight(%-5level) %cyan(%logger{15}) - %msg %n</pattern>
</encoder>
</appender>
<logger name="docspell" level="debug" />
<root level="INFO">
<appender-ref ref="STDOUT" />
</root>
</configuration>
```
The `<root level="INFO">` means, that only log statements with level
"INFO" will be printed. But the `<logger name="docspell"
level="debug">` above says, that for loggers with name "docspell"
statements with level "DEBUG" will be printed, too.
These settings are the same for joex and the restserver component.
# Default Config # Default Config
## Rest Server ## Rest Server