Efficiënt loggen in functionele tests voor Gradle-plugins

Inleiding

Bij het ontwikkelen van een Gradle-plugin zijn functionele tests essentieel om het gedrag van de plugin in een echte Gradle-omgeving te valideren. Echter, een cruciale vraag stelt zich snel:Hoe stel je een effectief logging-systeem op zonder problematische afhankelijkheden te creëren met GradleRunner?

In dit artikel gaan we verkennen :

De problematiek van logging in de functionele tests van Gradle
De architectuur van een robuuste oplossing met SLF4J en Logback
De volledige implementatie met concrete voorbeelden
De goede praktijken en valkuilen om te vermijden

Het probleem : Afhankelijkheid van GradleRunner

Context van pluginontwikkeling

Bij het ontwikkelen van een Gradle-plugin wordt meestal de`GradleRunner`van de Gradle TestKit voor het uitvoeren van testbuilds:

@Test
fun `test my plugin`() {
    val result = GradleRunner.create()
        .withProjectDir(projectDir)
        .withArguments("myTask")
        .build()

    // Comment logger efficacement ici ?
}

Het dilemma van het loggen

Het belangrijkste probleem is als volgt:logging moet niet afhankelijk zijn van een object waarvan de initialisatie onzeker is.

@startuml
!define RECTANGLE class

skinparam backgroundColor #FEFEFE
skinparam componentStyle rectangle

package "Problematische architectuur" {
    RECTANGLE Test {
        + runTest()
    }

    RECTANGLE GradleRunner {
        + build()
        + getLogger() ❌
    }

    RECTANGLE Logger {
        + info()
        + debug()
    }

    Test --> GradleRunner : hangt af van
    Logger ..> GradleRunner : hangt af van ❌
}

note right of Logger
Probleem: De logger is afhankelijk van de GradleRunner die mogelijk niet is geïnitialiseerd
end note

@enduml

De valse goede ideeën

Doe het NIET:

// ❌ MAUVAIS: Tentative d'obtenir un logger du runner
val runner = GradleRunner.create()
val logger = runner.logger // N'existe pas !
// ❌ MAUVAIS: Logger partagé initialisé tardivement
lateinit var logger: Logger
@BeforeEach
fun setup() {
    logger = LoggerFactory.getLogger(...)
}

De oplossing: onafhankelijke logger

Aanbevolen Architectuur

De oplossing bestaat uit het gebruik van een loggervolledig onafhankelijk du GradleRunner, geïnitialiseerd op het niveau van de testklasse.

@startuml
!define RECTANGLE class

skinparam backgroundColor #FEFEFE
skinparam componentStyle rectangle

package "Correcte architectuur" {
    RECTANGLE TestClass {
        + {static} logger: Logger ✓
        + runTest()
    }

    RECTANGLE SLF4J {
        + LoggerFactory
    }

    RECTANGLE GradleRunner {
        + build()
        + forwardOutput()
    }

    RECTANGLE "Console-uitvoer" as Output {
        + captured text
    }

    TestClass --> SLF4J : gebruikt ✓
    TestClass --> GradleRunner : gebruikt
    GradleRunner --> Output : genereert
    TestClass --> Output : analyse
}

note top of TestClass
De logger wordt onafhankelijk van GradleRunner geïnitialiseerd
end note

note bottom of GradleRunner
.forwardOutput() maakt het mogelijk om de uitvoer vast te leggen voor analyse
end note

@enduml

Uitvoeringsstroom

@startuml
!theme plain
skinparam backgroundColor #FEFEFE

participant "JUnit" as junit
participant "TestClass" as test
participant "Logger (SLF4J)" as logger
participant "GradleRunner" as runner
participant "Gradle-build" as gradle

activate junit
junit -> test : load class
activate test

test -> logger : initialize (companion)
activate logger
logger --> test : logger ready ✓
deactivate logger

junit -> test : @BeforeAll
test -> logger : info("Initialisation...")

junit -> test : @BeforeEach
test -> logger : debug("Instellingstest...")

junit -> test : @Test
test -> logger : info("TEST: Bezig...")

test -> runner : create()
activate runner
test -> runner : .forwardOutput()
test -> runner : .withArguments(...)
test -> runner : .build()

runner -> gradle : execute build
activate gradle
gradle --> runner : output text
deactivate gradle

runner --> test : BuildResult + output
deactivate runner

test -> logger : debug("Output analyseren...")
test -> test : analyze output
test -> logger : info("✓ Test geslaagd")

test --> junit : success
deactivate test
deactivate junit

@enduml

Implementatie Volledig

Gradle-afhankelijkheden

Voeg de benodigde afhankelijkheden toe in uw`build.gradle.kts`:

dependencies {
    // Pour les tests fonctionnels
    testImplementation(gradleTestKit())
    testImplementation("org.junit.jupiter:junit-jupiter:5.10.2")

    // Pour le logging
    testImplementation("org.slf4j:slf4j-api:2.0.17")
    testRuntimeOnly("ch.qos.logback:logback-classic:1.4.14")

    // Pour les assertions
    testImplementation("org.assertj:assertj-core:3.27.6")
}

tasks.test {
    useJUnitPlatform()
}

Configuratie Logback

Maak het bestand`src/test/resources/logback-test.xml`:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- Appender console avec format lisible -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <!-- Appender fichier pour conservation -->
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>build/test-results/functional-tests.log</file>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
    </appender>

    <!-- Logger pour vos tests -->
    <logger name="com.cheroliv.bakery" level="DEBUG"/>

    <!-- Réduire le bruit de Gradle -->
    <logger name="org.gradle" level="WARN"/>

    <!-- Configuration racine -->
    <root level="INFO">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="FILE"/>
    </root>
</configuration>

complete testklas

package com.cheroliv.bakery

import org.gradle.testkit.runner.GradleRunner
import org.gradle.testkit.runner.TaskOutcome
import org.junit.jupiter.api.*
import org.junit.jupiter.api.TestInstance.Lifecycle.PER_CLASS
import org.junit.jupiter.api.io.TempDir
import org.slf4j.Logger
import org.slf4j.LoggerFactory
import java.io.File
import kotlin.test.assertEquals
import kotlin.test.assertTrue

@TestInstance(PER_CLASS)
class BakeryPluginFunctionalTest {

    @field:TempDir
    lateinit var projectDir: File

    private val buildFile by lazy { projectDir.resolve("build.gradle.kts") }
    private val settingsFile by lazy { projectDir.resolve("settings.gradle.kts") }

    companion object {
        // ✓ Logger indépendant, initialisé au chargement de la classe
        private val logger: Logger = LoggerFactory.getLogger(
            BakeryPluginFunctionalTest::class.java
        )

        @JvmStatic
        @BeforeAll
        fun globalSetup() {
            logger.info("═".repeat(60))
            logger.info("DÉMARRAGE DE LA SUITE DE TESTS FONCTIONNELS")
            logger.info("═".repeat(60))
        }

        @JvmStatic
        @AfterAll
        fun globalTeardown() {
            logger.info("═".repeat(60))
            logger.info("FIN DE LA SUITE DE TESTS")
            logger.info("═".repeat(60))
        }
    }

    @BeforeEach
    fun setup() {
        logger.info("─".repeat(60))
        logger.info("Préparation de l'environnement de test")
        logger.debug("Répertoire de test: ${projectDir.absolutePath}")

        settingsFile.writeText("""
            rootProject.name = "test-bakery-project"
        """.trimIndent())

        logger.debug("✓ settings.gradle.kts créé")
    }

    @AfterEach
    fun teardown(testInfo: TestInfo) {
        logger.info("✓ Test terminé: ${testInfo.displayName}")
        logger.info("─".repeat(60))
    }

    @Test
    fun `plugin can be applied successfully`() {
        logger.info("TEST: Application du plugin Bakery")

        buildFile.writeText("""
            plugins {
                id("com.cheroliv.bakery")
            }
        """.trimIndent())

        logger.debug("Fichier build.gradle.kts créé")
        logger.debug("Lancement du build Gradle...")

        val startTime = System.currentTimeMillis()

        val result = GradleRunner.create()
            .forwardOutput() // ← Important : capture la sortie
            .withPluginClasspath()
            .withArguments("tasks", "--group=bakery", "--stacktrace")
            .withProjectDir(projectDir)
            .build()

        val duration = System.currentTimeMillis() - startTime
        logger.info("Build terminé en ${duration}ms")

        // Analyse de la sortie
        logger.debug("Analyse de la sortie Gradle...")
        val outputLines = result.output.lines()
        logger.debug("Nombre de lignes capturées: ${outputLines.size}")

        // Validation
        val expectedTasks = listOf("bake", "printConfigPath", "printJBakeClasspath")
        logger.info("Vérification des tâches attendues:")

        expectedTasks.forEach { task ->
            val found = result.output.contains(task)
            logger.debug("  ${if (found) "✓" else "✗"} $task")
            assertTrue(found, "Task '$task' should be available")
        }

        logger.info("✓ Plugin appliqué avec succès - ${expectedTasks.size} tâches trouvées")
    }

    @Test
    fun `bake task executes and prints version`() {
        logger.info("TEST: Exécution de la tâche 'bake'")

        buildFile.writeText("""
            plugins {
                id("com.cheroliv.bakery")
            }
        """.trimIndent())

        logger.debug("Exécution de 'gradle bake'...")

        val result = GradleRunner.create()
            .forwardOutput()
            .withPluginClasspath()
            .withArguments("bake", "--info") // --info pour plus de détails
            .withProjectDir(projectDir)
            .build()

        // Extraction d'informations depuis la sortie
        logger.debug("Recherche du message 'Baking site'...")
        val hasBakingMessage = result.output.contains("Baking site with Bakery Plugin!")

        logger.debug("Recherche de la version JBake...")
        val hasVersionMessage = result.output.contains("Using JBake version:")

        // Extraction de la version (si présente)
        val versionRegex = Regex("Using JBake version: (.+)")
        val versionMatch = versionRegex.find(result.output)
        if (versionMatch != null) {
            val version = versionMatch.groupValues[1]
            logger.info("Version JBake détectée: $version")
        }

        // Validation
        assertTrue(hasBakingMessage, "Message 'Baking site' attendu")
        assertTrue(hasVersionMessage, "Message de version attendu")
        assertEquals(TaskOutcome.SUCCESS, result.task(":bake")?.outcome)

        logger.info("✓ Tâche 'bake' exécutée avec succès")
    }

    @Test
    fun `analyze output with structured logging`() {
        logger.info("TEST: Analyse structurée de la sortie")

        buildFile.writeText("""
            plugins {
                id("com.cheroliv.bakery")
            }

            task("diagnostics") {
                doLast {
                    println("[DIAG] Project: ${'$'}{project.name}")
                    println("[DIAG] Build dir: ${'$'}{project.buildDir}")
                    println("[DIAG] Plugin applied: true")

                    val config = configurations.findByName("jbakeRuntime")
                    println("[DIAG] JBake config exists: ${'$'}{config != null}")

                    if (config != null) {
                        println("[DIAG] Dependencies count: ${'$'}{config.dependencies.size}")
                    }
                }
            }
        """.trimIndent())

        logger.debug("Exécution de la tâche diagnostics...")

        val result = GradleRunner.create()
            .forwardOutput()
            .withPluginClasspath()
            .withArguments("diagnostics", "--quiet")
            .withProjectDir(projectDir)
            .build()

        // Analyse structurée
        logger.info("Extraction des informations de diagnostic:")

        val diagLines = result.output.lines()
            .filter { it.startsWith("[DIAG]") }

        logger.debug("Nombre de lignes de diagnostic: ${diagLines.size}")

        diagLines.forEach { line ->
            logger.info("  $line")

            // Analyse spécifique par type de ligne
            when {
                line.contains("Project:") -> {
                    val projectName = line.substringAfter("Project:").trim()
                    logger.debug("    → Nom du projet extrait: '$projectName'")
                }
                line.contains("Dependencies count:") -> {
                    val count = line.substringAfter("count:").trim()
                    logger.debug("    → Nombre de dépendances: $count")
                }
            }
        }

        assertTrue(diagLines.isNotEmpty(), "Des lignes de diagnostic devraient être présentes")
        logger.info("✓ Analyse structurée terminée - ${diagLines.size} lignes analysées")
    }

    @Test
    fun `test with error handling`() {
        logger.info("TEST: Gestion d'erreurs avec logging")

        buildFile.writeText("""
            plugins {
                id("com.cheroliv.bakery")
            }
        """.trimIndent())

        try {
            logger.debug("Tentative d'exécution...")

            val result = GradleRunner.create()
                .forwardOutput()
                .withPluginClasspath()
                .withArguments("printJBakeClasspath")
                .withProjectDir(projectDir)
                .build()

            val outcome = result.task(":printJBakeClasspath")?.outcome
            logger.info("Outcome: $outcome")

            if (outcome == TaskOutcome.SUCCESS) {
                logger.info("✓ Exécution réussie")
            } else {
                logger.warn("⚠ Outcome inattendu: $outcome")
            }

            assertEquals(TaskOutcome.SUCCESS, outcome)

        } catch (e: Exception) {
            logger.error("✗ Échec du test", e)
            logger.error("Type d'exception: ${e.javaClass.simpleName}")
            logger.error("Message: ${e.message}")

            // Log de la stack trace si nécessaire
            if (logger.isDebugEnabled) {
                logger.debug("Stack trace complète:", e)
            }

            throw e
        }
    }
}

Schema van Multi-niveaus Logging

@startuml
!theme plain
skinparam backgroundColor #FEFEFE

package "Logboekniveaus" {

    rectangle "TRACE" #E8E8E8 {
        note
Zeer fijne uitvoeringsdetails
• Variabele waarden
• Aanroepen van interne methoden
        end note
    }

    rectangle "DEBUG" #D0E8FF {
        note
Debug informatie
• Tussenstappen
• Inhoud van aangemaakte bestanden
• Analyse van de uitvoer Gradle
        end note
    }

    rectangle "INFO" #C8FFC8 {
        note
Belangrijke informatie
• Start/fin van test
• Resultaten van validatie
• Uitvoeringstijd
        end note
    }

    rectangle "WARN" #FFFFC8 {
        note
Waarschuwingen
• Onverwacht gedrag
• Ongebruikelijke resultaten
        end note
    }

    rectangle "ERROR" #FFC8C8 {
        note
Fouten
• Testfouten
• Uitzonderingen
• Stapeltraces
        end note
    }
}

@enduml

Goede praktijken

Aanbevolen logstructuur

@Test
fun `mon test`() {
    // 1. LOG: Début du test
    logger.info("TEST: Description du test")

    // 2. LOG: Préparation
    logger.debug("Préparation des fichiers...")
    buildFile.writeText("...")
    logger.debug("✓ Fichiers préparés")

    // 3. LOG: Exécution
    logger.debug("Lancement du build...")
    val startTime = System.currentTimeMillis()

    val result = GradleRunner.create()
        .forwardOutput()
        .withArguments("task")
        .build()

    val duration = System.currentTimeMillis() - startTime
    logger.info("Build terminé en ${duration}ms")

    // 4. LOG: Analyse
    logger.debug("Analyse des résultats...")
    // ... validations ...

    // 5. LOG: Conclusion
    logger.info("✓ Test réussi")
}

Visuele symbolen voor leesbaarheid

Gebruik Unicode-symbolen om de leesbaarheid van de logboeken te verbeteren:

logger.info("✓ Succès")
logger.info("✗ Échec")
logger.info("⚠ Attention")
logger.info("→ Étape suivante")
logger.info("═".repeat(60)) // Séparateur principal
logger.info("─".repeat(60)) // Séparateur secondaire

Informatie-extractie uit de uitvoer

// Recherche simple
val hasMessage = result.output.contains("Expected message")

// Extraction avec regex
val versionRegex = Regex("Version: (.+)")
val version = versionRegex.find(result.output)?.groupValues?.get(1)

// Filtrage de lignes
val errorLines = result.output.lines()
    .filter { it.contains("ERROR") }

errorLines.forEach { logger.error("Gradle error: $it") }

Vergelijking voor/na

Voor: problematische aanpak

class MyTest {
    lateinit var logger: Logger // ❌ Initialisé tardivement

    @BeforeEach
    fun setup() {
        logger = LoggerFactory.getLogger(...) // ❌ Dépendance
    }

    @Test
    fun test() {
        val runner = GradleRunner.create()
        logger.info("Testing...") // ⚠ Peut échouer
    }
}

Na: Robuuste benadering

class MyTest {
    companion object {
        private val logger = LoggerFactory.getLogger(...) // ✓ Indépendant
    }

    @Test
    fun test() {
        logger.info("TEST: Starting...") // ✓ Toujours disponible

        val result = GradleRunner.create()
            .forwardOutput() // ✓ Capture la sortie
            .build()

        logger.debug("Output: ${result.output}") // ✓ Analyse
    }
}

Samenvattend diagram

@startuml
!theme plain
skinparam backgroundColor #FEFEFE

title Volledige Logstroom in Functionele Tests
actor "Ontwikkelaar" as dev
participant "JUnit" as junit
participant "TestClass" as test
participant "Logger\n(SLF4J)" as logger
participant "Logback" as logback
participant "GradleRunner" as runner
participant "Console/File" as output

dev -> junit : voer de tests uit

activate junit
junit -> test : Laadt de klasse
activate test

test -> logger : initialiseren (companion)
activate logger
logger -> logback : configureren
activate logback
logback --> logger : klaar
deactivate logback
logger --> test : ✓
deactivate logger

== Phase de Setup ==

junit -> test : @BeforeAll
test -> logger : info("Initialisatie")
logger -> output : [INFO] Initialisatie

junit -> test : @BeforeEach
test -> logger : debug("Setup test")
logger -> output : [DEBUG] Test opzetten

== Phase de Test ==

junit -> test : @Test
test -> logger : info("TEST: Starten")
logger -> output : [INFO] TEST: Starten

test -> runner : create()
activate runner

test -> runner : .forwardOutput()
test -> runner : .build()

runner -> runner : uitvoeren Gradle
runner --> test : BuildResult
deactivate runner

test -> logger : debug("Uitvoer analyseren")
logger -> output : [DEBUG] Analyseren van output

test -> test : beweringen
test -> logger : info("✓ Test geslaagd")
logger -> output : [INFO] ✓ Test geslaagd

== Phase de Cleanup ==

junit -> test : @AfterEach
test -> logger : debug("Opschonen")
logger -> output : [DEBUG] Opschonen

junit -> test : @AfterAll
test -> logger : info("Einde van de tests")
logger -> output : [INFO] Einde van de testen

test --> junit : ✓ alle tests zijn geslaagd
deactivate test
deactivate junit

dev <-- junit : testrapport

@enduml

Te vermijden valkuilen

❌ valstrik #1: vergeten `.forwardOutput()

// MAUVAIS: La sortie Gradle n'est pas capturée
val result = GradleRunner.create()
    .withArguments("task")
    .build()

// result.output sera vide !

// BON: La sortie est capturée
val result = GradleRunner.create()
    .forwardOutput() // ✓
    .withArguments("task")
    .build()

❌ valstrik n°2 : Logger niet geïnitialiseerd

// MAUVAIS
class Test {
    lateinit var logger: Logger // Peut ne pas être initialisé
}

// BON
class Test {
    companion object {
        private val logger = LoggerFactory.getLogger(...) // Toujours initialisé
    }
}

❌ Valkuil nr. 3: Overmatig loggen

// MAUVAIS: Trop de logs DEBUG en production
logger.debug("Variable a = $a")
logger.debug("Variable b = $b")
logger.debug("Variable c = $c")
// ... 100 lignes de logs

// BON: Logging ciblé
logger.info("Traitement de ${items.size} éléments")
logger.debug("Détails: ${items.take(5)}...") // Échantillon seulement

Resultaten en Metriek

Met deze aanpak krijgt u :

metrisch	Voor	Na
Regels van code	~50 regels	~80 lijnen (+60%)
debugtijd	~30 min	~5 min (-83%)
Fouten gedetecteerd	Basis	gedetailleerd
onderhoud	Moeilijk	simpel
Onafhankelijkheid	❌ Gekoppeld	✓ Onafhankelijk

metrisch

Voor

Regels van code

~50 regels

~80 lijnen (+60%)

debugtijd

~30 min

~5 min (-83%)

Fouten gedetecteerd

Basis

gedetailleerd

onderhoud

Moeilijk

simpel

Onafhankelijkheid

❌ Gekoppeld

✓ Onafhankelijk

Conclusie

Het opzetten van een robuust logging-systeem in de functionele tests van Gradle-plugins berust op een eenvoudig principe :de onafhankelijkheid.

Belangrijkste punten om te onthouden:

Onafhankelijke logger: Geïnitialiseerd in een`companion object`
SLF4J + Logback: Geteste en configureerbare stack
.forwardOutput(): Opname van de Gradle-uitvoer
Gestructureerde logging: INFO voor de stappen, DEBUG voor de details
Uitvoeranalyse: Extractie van informatie sinds`result.output`

Deze aanpak garandeert testsonderhoudbaar, debuggbare et robuust, terwijl de solide ontwerpprincipes worden gerespecteerd

bronnen

Verder Gaan

In een volgend artikel zullen we verkennen:

Continue integratie met gestructureerde logging
De HTML-testrapporten met ingebouwde logs
Geavanceerd debuggen met JVM attach
De prestaties en optimalisaties van logging

Dit artikel maakt deel uit van de serie "Ontwikkeling van Gradle-plugins" op mijn technische blog.

Gerelateerde artikelen

HyperFrames-Gradle : AsciiDoc omzetten naar een MP4-video
31 May 2026

Audit van mijn LLM‑consumptie : SQLite, OpenCode, Ollama Cloud, en waarom mijn pro‑abonnement de wereldwijde markt opschudt
18 May 2026

De architectuur « Onafhankelijke plugin + consumentenroot »: Waarom worden mijn Gradle-builds geduplicerd?
14 May 2026

De Knowledge Graph als aanbevelingsmotor : hoe ik de chronologische gerelateerde artikelen heb doodgemaakt
12 May 2026

Schakel JavaScript in om de commentaren aangedreven door Disqus.