Duplicate logging when running with cucumber

[aybartsch]

What happened?

When running tests with IntelliJ or Gradle runner the logging is kind of duplicated. The above logging block is written when the test is actually running whereas the below logging block is written after the test has been finished. The duplicate log entries were written every 0.5 seconds but there was no chromedriver running anymore.

11:19:53.284 [main] INFO  CustomDriver: WebDriver URL is not defined. Assuming local execution. Using driver type: CHROME
  Gegeben sei der Anwender loggt sich erfolgreich ein und befindet sich auf der Startseite des NVZ. # com.westernacher.nvz.e2e.steps.common.login.LoginSteps.givenTheLoginIsSuccessfulAndTheStartPageIsShown()
  Wenn der Anwender die Seite zum Suchen einer Amtstätigkeit öffnet,                                # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsOpeningTheNotarySearchPage()
  Dann wird die Seite 'Daten der Amtstätigkeit einsehen und bearbeiten' angezeigt.                  # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheNotarySearchPageIsShown()
  Wenn der Anwender die einfache Suche zur Suche nach einer Amtstätigkeit verwendet,                # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsSearchingForNotaryUsingTheSimpleSearch()
  Dann kann die Amtstätigkeit mit der einfachen Suche gefunden und angezeigt werden.                # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheUserIsFindingTheNotaryUsingTheSimpleSearch()
  Wenn der Anwender die Amtstätigkeit auswählt,                                                     # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsSelectingNotary()
  Dann wird der Knopf 'Details anzeigen' für die Amtstätigkeit aktiviert.                           # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheButtonShowDetailsIsEnabled()
  Wenn der Anwender auf 'Details anzeigen' für die Amtstätigkeit klickt,                            # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsOpeningNotaryDetails()
  Dann wird die Seite 'Person' der Amtstätigkeit geöffnet.                                          # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheNotaryPersonEditPageIsShown()
  Wenn der Anwender die Daten der Person der Amtstätigkeit ändert und speichert,                    # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsChangingNotaryPersonData()
  Dann werden die Daten der Person der Amtstätigkeit gespeichert und angezeigt.                     # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenNotaryPersonDataIsChanged()
  Wenn der Anwender die Seite 'Amtstätigkeit' öffnet,                                               # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsOpeningNotaryEditPage()
  Dann wird die Seite 'Amtstätigkeit' angezeigt.                                                    # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheNotaryEditPageIsShown()
  Wenn der Anwender die Daten der Amtstätigkeit ändert und speichert,                               # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsChangingNotaryData()
  Dann werden die geänderten Daten der Amtstätigkeit gespeichert und angezeigt.                     # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenNotaryDataIsChanged()
  Wenn der Anwender die Daten der Geschäftsstelle ändert und speichert,                             # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsChangingMainOfficeData()
  Und wenn der Anwender eine Adresse aus der Liste auswählt und bestätigt,                          # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsSelectingAndConfirmingAnAddressFromTheList()
  Und wenn der Anwender die Geo-Daten einträgt und bestätigt,                                       # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsAddingAndSavingGeoData()
  Dann werden die geänderten Daten der Geschäftsstelle gespeichert und angezeigt.                   # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenMainOfficeDataIsChanged()
  Wenn der Anwender die Sprachen ändert und speichert,                                              # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsChangingLanguagesData()
  Dann werden die geänderten Sprachen gespeichert und angezeigt.                                    # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenLanguagesDataIsChanged()
  Wenn der Anwender eine neue Geschäftsstelle hinzufügt,                                            # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsAddingNewOffice()
  Und wenn der Anwender eine Adresse aus der Liste auswählt und bestätigt,                          # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsSelectingAndConfirmingAnAddressFromTheList()
  Dann wird die neue Geschäftsstelle gespeichert und angezeigt.                                     # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheOfficeHasBeenAdded()
  Wenn der Anwender eine vorläufige Amtsenthebung hinzufügt und bestätigt,                          # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsAddingTmpOfficeRmData()
  Dann wird die vorläufige Amtsenthebung gespeichert und angezeigt.                                 # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheTmpOfficeRmDataHasBeenAdded()
  Wenn der Anwender eine Ausnahmebewilligung hinzufügt und bestätigt,                               # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsAddingTmpOfficePauseData()
  Dann wird die Ausnahmebewilligung gespeichert und angezeigt.                                      # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheTmpOfficePauseDataHasBeenAdded()
  Wenn der Anwender die Seite 'Bemerkungen' der Amtstätigkeit öffnet,                               # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsOpeningNotaryCommentsPage()
  Dann wird die Seite 'Bemerkungen' der Amtstätigkeit angezeigt.                                    # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenNotaryCommentsPageIsShown()
  Wenn der Anwender den Kommentar ändert und die Änderung bestätigt,                                # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsAddingComment()
  Dann wird der Kommentar gespeichert und die Änderung angezeigt.                                   # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheCommentHasBeenAdded()
  Wenn der Anwender die Seite 'Sozietät' der Amtstätigkeit öffnet,                                  # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsOpeningNotaryJointPracticeEditPage()
  Dann wird die Seite 'Sozietät' der Amtstätigkeit angezeigt.                                       # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenNotaryJointPracticeEditPageIsShown()
  Wenn der Anwender die Daten der Sozietät hinzufügt und speichert,                                 # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.whenTheUserIsAddingJointPracticeData()
  Dann werden die Daten der Sozietät gespeichert und angezeigt.                                     # com.westernacher.nvz.e2e.steps.notary.edit.NotaryEditSteps.thenTheJointPracticeDataHasBeenAdded()
11:19:42.482 [main] INFO  : 

-------------------------------------------------------------------------------------
     _______. _______ .______       _______ .__   __.  __  .___________.____    ____ 
    /       ||   ____||   _  \     |   ____||  \ |  | |  | |           |\   \  /   / 
   |   (----`|  |__   |  |_)  |    |  |__   |   \|  | |  | `---|  |----` \   \/   /  
    \   \    |   __|  |      /     |   __|  |  . `  | |  |     |  |       \_    _/   
.----)   |   |  |____ |  |\  \----.|  |____ |  |\   | |  |     |  |         |  |     
|_______/    |_______|| _| `._____||_______||__| \__| |__|     |__|         |__|    
                                                                                     
 News and tutorials at https://serenity-bdd.info                                     
 Documentation at https://serenity-bdd.github.io                                     
 Test Automation Training and Coaching: https://www.serenity-dojo.com                
 Commercial Support: https://www.serenity-dojo.com/serenity-bdd-enterprise-support   
 Join the Serenity Community on Gitter: https://gitter.im/serenity-bdd/serenity-core 
-------------------------------------------------------------------------------------

11:19:42.497 [main] INFO  : Test Suite Started: Amtstätigkeit
11:21:07.480 [main] INFO  : 
  _____   ___   ___   _____     ___   _____     _     ___   _____   ___   ___  
 |_   _| | __| / __| |_   _|   / __| |_   _|   /_\   | _ \ |_   _| | __| |   \ 
   | |   | _|  \__ \   | |     \__ \   | |    / _ \  |   /   | |   | _|  | |) |
   |_|   |___| |___/   |_|     |___/   |_|   /_/ \_\ |_|_\   |_|   |___| |___/ 

Dem Anwender sollte es möglich sein, eine Amtstätigkeit zu ändern.(amtstätigkeit;dem-anwender-sollte-es-möglich-sein--eine-amtstätigkeit-zu-ändern.)
--------------------------------------------------------------------------------
11:21:07.491 [main] INFO  : |-- Gegeben sei der Anwender loggt sich erfolgreich ein und befindet sich auf der Startseite des NVZ.
11:21:08.999 [main] INFO  : |-- Wenn der Anwender die Seite zum Suchen einer Amtstätigkeit öffnet,
11:21:10.505 [main] INFO  : |-- Dann wird die Seite 'Daten der Amtstätigkeit einsehen und bearbeiten' angezeigt.
11:21:12.008 [main] INFO  : |-- Wenn der Anwender die einfache Suche zur Suche nach einer Amtstätigkeit verwendet,
11:21:13.515 [main] INFO  : |-- Dann kann die Amtstätigkeit mit der einfachen Suche gefunden und angezeigt werden.
11:21:15.019 [main] INFO  : |-- Wenn der Anwender die Amtstätigkeit auswählt,
11:21:16.526 [main] INFO  : |-- Dann wird der Knopf 'Details anzeigen' für die Amtstätigkeit aktiviert.
11:21:18.030 [main] INFO  : |-- Wenn der Anwender auf 'Details anzeigen' für die Amtstätigkeit klickt,
11:21:19.534 [main] INFO  : |-- Dann wird die Seite 'Person' der Amtstätigkeit geöffnet.
11:21:21.035 [main] INFO  : |-- Wenn der Anwender die Daten der Person der Amtstätigkeit ändert und speichert,
11:21:22.540 [main] INFO  : |-- Dann werden die Daten der Person der Amtstätigkeit gespeichert und angezeigt.
11:21:24.042 [main] INFO  : |-- Wenn der Anwender die Seite 'Amtstätigkeit' öffnet,
11:21:25.545 [main] INFO  : |-- Dann wird die Seite 'Amtstätigkeit' angezeigt.
11:21:27.049 [main] INFO  : |-- Wenn der Anwender die Daten der Amtstätigkeit ändert und speichert,
11:21:28.552 [main] INFO  : |-- Dann werden die geänderten Daten der Amtstätigkeit gespeichert und angezeigt.
11:21:30.054 [main] INFO  : |-- Wenn der Anwender die Daten der Geschäftsstelle ändert und speichert,
11:21:31.558 [main] INFO  : |-- Und wenn der Anwender eine Adresse aus der Liste auswählt und bestätigt,
11:21:33.063 [main] INFO  : |-- Und wenn der Anwender die Geo-Daten einträgt und bestätigt,
11:21:34.566 [main] INFO  : |-- Dann werden die geänderten Daten der Geschäftsstelle gespeichert und angezeigt.
11:21:36.068 [main] INFO  : |-- Wenn der Anwender die Sprachen ändert und speichert,
11:21:37.573 [main] INFO  : |-- Dann werden die geänderten Sprachen gespeichert und angezeigt.
11:21:39.077 [main] INFO  : |-- Wenn der Anwender eine neue Geschäftsstelle hinzufügt,
11:21:40.580 [main] INFO  : |-- Und wenn der Anwender eine Adresse aus der Liste auswählt und bestätigt,
11:21:42.083 [main] INFO  : |-- Dann wird die neue Geschäftsstelle gespeichert und angezeigt.
11:21:43.585 [main] INFO  : |-- Wenn der Anwender eine vorläufige Amtsenthebung hinzufügt und bestätigt,
11:21:45.088 [main] INFO  : |-- Dann wird die vorläufige Amtsenthebung gespeichert und angezeigt.
11:21:46.593 [main] INFO  : |-- Wenn der Anwender eine Ausnahmebewilligung hinzufügt und bestätigt,
11:21:48.098 [main] INFO  : |-- Dann wird die Ausnahmebewilligung gespeichert und angezeigt.
11:21:49.603 [main] INFO  : |-- Wenn der Anwender die Seite 'Bemerkungen' der Amtstätigkeit öffnet,
11:21:51.109 [main] INFO  : |-- Dann wird die Seite 'Bemerkungen' der Amtstätigkeit angezeigt.
11:21:52.616 [main] INFO  : |-- Wenn der Anwender den Kommentar ändert und die Änderung bestätigt,
11:21:54.118 [main] INFO  : |-- Dann wird der Kommentar gespeichert und die Änderung angezeigt.
11:21:55.623 [main] INFO  : |-- Wenn der Anwender die Seite 'Sozietät' der Amtstätigkeit öffnet,
11:21:57.129 [main] INFO  : |-- Dann wird die Seite 'Sozietät' der Amtstätigkeit angezeigt.
11:21:58.634 [main] INFO  : |-- Wenn der Anwender die Daten der Sozietät hinzufügt und speichert,
11:22:00.136 [main] INFO  : |-- Dann werden die Daten der Sozietät gespeichert und angezeigt.
11:22:01.640 [main] INFO  : 
  _____   ___   ___   _____     ___     _     ___   ___   ___   ___  
 |_   _| | __| / __| |_   _|   | _ \   /_\   / __| / __| | __| |   \ 
   | |   | _|  \__ \   | |     |  _/  / _ \  \__ \ \__ \ | _|  | |) |
   |_|   |___| |___/   |_|     |_|   /_/ \_\ |___/ |___/ |___| |___/ 

Dem Anwender sollte es möglich sein, eine Amtstätigkeit zu ändern.
----------------------------------------------------------------------

Process finished with exit code 0

What did you expect to happen?

There should only one logging of test execution. When the test has passed the logging should be finished, too.

Serenity BDD version

4.0.15

JDK version

11.0.21

Execution environment

macOS Ventura 13.6.3
Chrome 120.0.6099.216

How to reproduce the bug.

Run a test class configured like below with Gradle or IntelliJ runner and verify the logging.

package com.westernacher.nvz.e2e.tests.serenity.notary.edit;

import com.westernacher.nvz.e2e.tests.serenity.BaseTest;
import org.junit.platform.suite.api.ConfigurationParameter;
import org.junit.platform.suite.api.IncludeEngines;
import org.junit.platform.suite.api.SelectClasspathResource;
import org.junit.platform.suite.api.Suite;

import static io.cucumber.core.options.Constants.GLUE_PROPERTY_NAME;
import static io.cucumber.core.options.Constants.PLUGIN_PROPERTY_NAME;

@Suite
@IncludeEngines("cucumber")
@SelectClasspathResource("/features/notary/edit/NotaryEdit.feature")
@ConfigurationParameter(key = PLUGIN_PROPERTY_NAME,
        value = "io.cucumber.core.plugin.SerenityReporterParallel,pretty")
@ConfigurationParameter(key = GLUE_PROPERTY_NAME,
        value = "com.westernacher.nvz.e2e.steps.common.login," +
                "com.westernacher.nvz.e2e.steps.notary.edit")
public class NotaryEditTest extends BaseTest {
}

How can we make it happen?

Add it to the Serenity BDD backlog and wait for a volunteer to pick it up

[wakaleo]

This can happen if you have defined Cucumber reporting plugins in more than one place (e.g. in the annotations and in the junit-platform.properties file). It's a Cucumber configuration issue, unrelated to Serenity.

[aybartsch]

@wakaleo Thanks for answering. I don't have any "junit-platform.properties" within my project. Instead I have removed "cucumber.properties" located under resources but this could not solved the problem. Could you please point me to the cucumber configuration issue?

I have performed some test runs with different annotations but it looks like a serenity issue to me:

SerenityReporterParallel + pretty

1. Chromedriver running --> Cucumber logging
2. Chromedriver finished --> Serenity logging

SerenityReporterParallel

1. Chromedriver running --> No logging
2. Chromedriver finished --> Serenity logging

pretty

1. Chromedriver running --> Cucumber logging
2. Chromedriver finished --> No logging

The serenity logging always starts when the test execution has been finished.

[wakaleo]

It's not a Serenity issue (Serenity doesn't log the Cucumber steps). I'd have to see your project, but I presume there must be somewhere else where the Cucumber logs are being configured?

[aybartsch]

@wakaleo I could solving the issue by replacing SerenityReporterParallel with SerenityReporter and removing pretty printer:

@Suite
@IncludeEngines("cucumber")
@SelectClasspathResource("/features/common/login/Login.feature")
@ConfigurationParameter(key = PLUGIN_PROPERTY_NAME,
        value = "io.cucumber.core.plugin.SerenityReporter")
@ConfigurationParameter(key = GLUE_PROPERTY_NAME,
        value = "com.westernacher.nvz.e2e.steps.common.login")
public class LoginTest extends BaseTest {
}

Thus, in my humble opinion it was caused by Serenity's parallel reporter. Closing this issue.