Output is generated only after running all features

[fslev]

Output is only generated after running all features

Hi,
I am using cucumber-jvm version 4.2.0
When I am running all features via JUnit and Maven, no output with the running scenarios steps is displayed. The features, scenarios and the corresponding steps results are displayed only when all cucumber tests finish.
After changing cucumber-jvm version to 3.0.2, I saw that the output from Cucumber (running features, scenarios and steps) is displayed in real time.

[mpkorstanje]

To resolve this problem the PrettyFormatter should implement the ConcurrentEventListener and be able to handle events from the concurrent execution of pickles (e.g. when using --parallel). See the v4 release announcement for more details.

Please feel free to send PR!

[scormaq]

@mpkorstanje does cucumber-jvm have (or it's in plans to have) integration with logging frameworks like log4j, slf4j etc?

I'm afraid that in case of parallel running cucumber tests, output from pretty formatter will be messed up with logger messages, because for now there no such integration. Example:

• I'm using cucucumber-jvm 4.2.1 + log4j2 + slf4j
• I'm running next feature file with 3 threads in parallel:
   
  

Feature: very first cucumber test

  Scenario: first scenario
    Given I report next in log: 'Hello from 1st scenario'

  Scenario: second scenario
    Given I report next in log: 'Hello from 2nd scenario'

  Scenario: third scenario
    Given I report next in log: 'Hello from 3rd scenario'

  Scenario: fourth scenario
    Given I report next in log: 'Hello from 4th scenario'

1) Here is how my console logs look like when PrettyFormatter implements EventListener

Console output:

> Task :cucumberTests
      17:23:24 [pool-2-thread-3] INFO : Hello from 3rd scenario
      17:23:24 [pool-2-thread-1] INFO : Hello from 1st scenario
      17:23:24 [pool-2-thread-2] INFO : Hello from 2nd scenario
         17:23:25 [pool-2-thread-2] INFO : Hello from 4th scenario
Feature: very first cucumber tests]

  Scenario: first scenario                                # src/test/resources/features/First.feature:4
    Given I report next in log: 'Hello from 1st scenario' # SomeDefs.logSomething(String)

  Scenario: second scenario                               # src/test/resources/features/First.feature:7
    Given I report next in log: 'Hello from 2nd scenario' # SomeDefs.logSomething(String)

  Scenario: third scenario                                # src/test/resources/features/First.feature:10
    Given I report next in log: 'Hello from 3rd scenario' # SomeDefs.logSomething(String)

  Scenario: fourth scenario                               # src/test/resources/features/First.feature:13
    Given I report next in log: 'Hello from 4th scenario' # SomeDefs.logSomething(String)

2) Here is how console logs might look like if PrettyFormatter implement ConcurrentEventListener

Console output:

> Task :cucumberTests
Feature: very first cucumber test

  Scenario: first scenario                                # src/test/resources/features/First.feature:4

  Scenario: second scenario                               # src/test/resources/features/First.feature:7

  Scenario: third scenario                                # src/test/resources/features/First.feature:10
      17:27:49 [pool-2-thread-2] INFO : Hello from 2nd scenario
      17:27:49 [pool-2-thread-3] INFO : Hello from 3rd scenario
      17:27:49 [pool-2-thread-1] INFO : Hello from 1st scenario
    Given I report next in log: 'Hello from 1st scenario' # SomeDefs.logSomething(String)
    Given I report next in log: 'Hello from 2nd scenario' # SomeDefs.logSomething(String)
    Given I report next in log: 'Hello from 3rd scenario' # SomeDefs.logSomething(String)

  Scenario: fourth scenario                               # src/test/resources/features/First.feature:13
      17:27:50 [pool-2-thread-2] INFO : Hello from 4th scenario
    Given I report next in log: 'Hello from 4th scenario' # SomeDefs.logSomething(String)

I copied to my project PrettyFormatter class and made it implement ConcurrentEventListener. Did not help a lot.

3) And actually I would like to see my scenario execution along with its logs, like this:

Console output:

> Task :cucumberTests
Feature: very first cucumber test


  Scenario: third scenario                                # src/test/resources/features/First.feature:10
      17:52:54 [pool-2-thread-3] INFO : Hello from 3rd scenario

    Given I report next in log: 'Hello from 3rd scenario' # SomeDefs.logSomething(String)


  Scenario: first scenario                                # src/test/resources/features/First.feature:4
      17:52:54 [pool-2-thread-1] INFO : Hello from 1st scenario

    Given I report next in log: 'Hello from 1st scenario' # SomeDefs.logSomething(String)


  Scenario: second scenario                               # src/test/resources/features/First.feature:7
      17:52:54 [pool-2-thread-2] INFO : Hello from 2nd scenario

    Given I report next in log: 'Hello from 2nd scenario' # SomeDefs.logSomething(String)


  Scenario: fourth scenario                               # src/test/resources/features/First.feature:13
      17:52:55 [pool-2-thread-3] INFO : Hello from 4th scenario

    Given I report next in log: 'Hello from 4th scenario' # SomeDefs.logSomething(String)

Here, my log4j2 logs and PrettyFormatter are not printed immediately as they arrive, but buffered and printed once scenario finished, so I have clear console reporting per scenario.

[mpkorstanje]

does cucumber-jvm have (or it's in plans to have) integration with logging frameworks like log4j, slf4j etc?

Cucumber development is currently primarily driven by community contributions. As such plans exist by the grace of its contributors. I'm currently not aware of prospective contributions in that area.

@mlvandijk had a look at this a while ago but we concluded that in that state of the code base it was not feasible. The current state has been somewhat improved. So it might be worth taking a second look.

As a test framework Cucumber should be relatively dependency free -- lest our dependencies interfere with the system under test. This rules out log4j and slf4j.

It is possible to use use java.util.logging.Logger but I'm concerned about the performance impact of JUL under Java 7. Upgrading Cucumber to Java 8 to facilitate lazy log message creation should be fine though.

I'm afraid that in case of parallel running cucumber tests, output from pretty formatter will be messed up with logger messages, because for now there no such integration.
Here, my log4j2 logs and PrettyFormatter are not printed immediately as they arrive, but buffered and printed once scenario finished, so I have clear console reporting per scenario.

Buffering the the the test case events should be entirely possible. Each TestCaseEvent has a reference to its associated test case and each event listener is synchronized. It does not have to process events concurrently, only test cases.

I'm not sure how you'd make it sync up with the log messages though. How would you propose doing this?

Either way if you get it to work I'd be happy accept the improved formatter as a PR!

[scormaq]

I'm not sure how you'd make it sync up with the log messages though. How would you propose doing this?

I thought about storing cucumber event logs and logger logs into some map (e.g. ConcurrentHashMap) and then printing all collected logs at TestCaseFinished event. Not sure about performance, but it should not affect it a log. At least, for me it's a nice trade off - to have readable console output.

Here is demo project: https://github.com/scormaq/cucumber4-parallel-logger
I did some refactoring with pretty formatter here, with it user can change using pretty plugin to improved log formatter (for log4j2, but it can be extended for other logging frameworks too).

I did not test it for performance or some edge cases, but at first glance it look nice to me. If you think that it is OK, I can propose it to pull request.

[mpkorstanje]

Ah. I see. You're buffering the output of the formatter. Pretty neat. Unfortunately I was expecting the input to be buffered. I'd rather not stack adhoc adapters in the framework itself. It makes the implementation harder to follow.

[TepidDrink]

I am using IntelliJ and running several large feature files.
So with cucumber v4 I have to wait until the whole feature file has been run until I see a hierarchical test output, whereas with v3.0.2 and before I do not.
There is no documentation for the fix and I guess there is none, no mentions of the reasoning behind this change, and it slows me down!
Has anyone got any ideas? I don't want to be running tests in parallel, they are all calling the same api, I just want to see the progress as I'm running the feature file and to have the hierarchical view as follows: Features.Scenarios.Tests.Steps

[mpkorstanje]

IntelliJs "Cucumber for Java" plug-in will have to be updated. You can check https://youtrack.jetbrains.com to see if this issue has been reported yet and vote for it, or create an issue yourself.

Looking at JetBrains/intellij-community@93dbc50 it would appear this should have been fixed in IDEA 191 though.

[fslev]

Hi,
Any feedback about the status of this issue ?
Or is there a workaround to see real-time test status progress via scenario.write() ?
Regards,
Florin

[mpkorstanje]

From the read me:

Please bear in mind that this project is almost entirely developed by volunteers. If you do not provided the implementation yourself (or pay someone to do it for you), the bug might never get fixed. If it is a serious bug, other people than you might care enough to provide a fix.

[MateuszMysliwiec]

I started having the same issue after updating to 4.2.6 versions