Randomly failed GitHub Actions CI builds caused by not completed MockServer verification

[hnrkdmsk]

Describe the issue Randomly failed GitHub Actions CI builds caused by not completed MockServer verification. Not all expectations are retrieved by MockServer. We use https://github.com/springtainer/springtainer-mockserver to run our MockServer integration tests and after upgrading from version 5.7.1 to 5.10.0 we got this error in multiple projects.

What you are trying to do Version upgrade from 5.7.1 to 5.10.0

MockServer version 5.10.0

To Reproduce It's randomly, so it's hard to describe. It seems you had same issues with the project itself: https://github.com/mock-server/mockserver/commit/f07cb98d11590ae13514fe18bbd424c34261a715 https://github.com/mock-server/mockserver/commit/58028b586d15bc245a5860480aedad31d17b5a04

We use GitHub Actions as CI system. On my local machine I cannot reproduce this. In the CI build it occurs often times.

[jamesdbloom]

Those failures you point out as git commits are not random failures but timing issues that were not understand at the time of making that commit.

Can you please explain what actually error you are getting with some information that could be used to determine how to fix the error, such as logs, or code.

[jamesdbloom]

Additionally you could try using the latest SNAPSHOT version which will be released in the next week, if that doesn't have the issue then you can wait for one week and then upgrade: https://mock-server.com/where/maven_central.html#sonatype_snapshot

[hnrkdmsk]

I get no error message. The problem only occurs in our GitHub Action CI build, where we run following commands:

mvn clean compile test-compile // compile
mvn surefire:test // unit tests
mvn -DskipUTs jacoco:restore-instrumented-classes verify // integration tests - here are the MockServer tests

Out tests are build like this:

    @Test
    public void testHttpRepository()
    {
        mockServerClient.when(request("/some/url").withMethod(POST)
                .withBody("{ \"key\": \"value\" }")
                .withHeader(ACCEPT, APPLICATION_JSON)
                .withHeader(CONTENT_TYPE, APPLICATION_JSON), Times.once())
                        .respond(response()
                                .withStatusCode(HTTP_STATUS_OK)
                                .withHeader(CONTENT_TYPE, APPLICATION_JSON)
                                .withBody("{ \"key\": \"value\" }"));

        var result = repository.get(new SomeDataObject());
        ...
    }

    @After
    @SneakyThrows
    public void doCheckAndCleanupMockServer()
    {
        @SuppressWarnings("resource")
        MockServerClient mockServerClient = getMockServerClient();

        if (mockServerClient.retrieveActiveExpectations(HttpRequest.request()).length > 0)
        {
            printActiveExpectations();
            mockServerClient.reset();
            fail("Active expectations remained (Check log!)");
        }

        mockServerClient.reset();
    }

The error is that not all expectations are retrieved by MockServer in the @After test method process. I don't have any problem with it on my local machine. I think that it has to do with performance or something special on the GitHub Actions Severs? I don't have any public repository for showing.

Or is something wrong in out test?

[jamesdbloom]

Is it possible to test this with the latest SNAPSHOT version to see if the issue still exists. Also there is a UI that shows what is happening internally inside MockServer that could help to diagnose what the issue is. The UI can be reached on http://:/mockserver/dashboard also https is supported. The UI has been significantly improved in the SNAPSHOT version which is pretty only waiting on documentation updates before it'll be released.

[hnrkdmsk]

I will try the latest release and report back later.

[hnrkdmsk]

I've tested the latest release version and have the same issues. The error occurs on several tests and I can't recognize a error log. The error occurs in the @After step of my test. It seems that not all expectations were received. Maybe performance issues with mockserver on docker on the GitHub Actions virtual machine?

[jamesdbloom]

Perhaps there is a race condition, you could try putting a small sleep of a couple of seconds prior to retrieving the expectations. I would initially test this though with a large sleep just to be 100% certain in you understanding it this helps. Such a race condition could be caused by:

• Test code or code that the test code is calling that continues to run after the test is complete. This is a fairly common problem and would be possible if you have any asynchronous or multithread processing in your test code or the code your test is calling and there are any mistakes in the way futures / singles etc that are used. If this is the case the number of expectations you see would be random depending on how fast the asynchronous code executes in comparison to how fast you're @After method is called. The differences between these two things would also likely be different between your local machine and github actions.
• The MockServer event log uses the disruptor pattern and therefore log events are processed asynchronously, however this seems unlikely because retrieve expectation requests are processed by pushing an event into the event log and so should be guaranteed to be correct w.r.t to the events log.

The logs should show you what the problem is, especially if you again put a sleep after retrieving the expectations and see what processing is happening after this. I would strongly suspect there is some additional processing happening after you have retrieve the expectations causing the the race condition and therefore this random behaviour.

[TheReprator]

Hi Mate, i am also facing the same issue my android ui test are failing randomly.

Workflow Success: https://github.com/TheReprator/Wipro/runs/2911975969?check_suite_focus=true

Workflow Fail: https://github.com/TheReprator/Wipro/runs/2911975942?check_suite_focus=true

Repo: https://github.com/TheReprator/Wipro Branch: codeCoverage workflow: push.yml

Looking forward for a solution.

Regards, Vikram Singh

[pawelszczesny-fortum]

Hey, I've the same problem while using mockserver-junit-jupiter:5.11.2. Tests randomly failing on github actions. Locally and in Jenkins always success.

[hnrkdmsk]

Hello, our fix was to put a simple Thread.sleep(10) before the retrieveActiveExpectations check. We have a global @AfterEach-method to check if all Mock Server requests are retrieved and checked.

@jamesdbloom In the @AfterEach-method are no more actions implemented, so I don't think it has to do with it.

Here some code: @AfterEach-Method

    @SneakyThrows
    @AfterEach
    public void checkAndCleanupMockServer()
    {
        Thread.sleep(10); // NOSONAR: to handle race conditions (see: https://github.com/mock-server/mockserver/issues/807)

        doCheckAndCleanupMockServer();
    }

doCheckAndCleanupMockServer()

   /**
     * Checks for active expectations
     * <p>
     * In case of active expectations all information will be printed to System:out and the mockserver-config will be cleared to start the next fresh test.
     */
    @SuppressWarnings("resource")
    default void doCheckAndCleanupMockServer()
    {
        MockServerClient mockServerClient = getMockServerClient();

        if (mockServerClient.retrieveActiveExpectations(HttpRequest.request()).length > 0)
        {
            printActiveExpectations();
            mockServerClient.reset();
            fail("Active expectations remained (Check log!)");
        }

        mockServerClient.reset();
    }

    /**
     * Prints active expectations and logs to System:out
     */
    @SuppressWarnings("resource")
    default void printActiveExpectations()
    {
        System.out.println("\u001B[31m" + "=== retrieveRecordedRequests ===" + "\u001B[0m"); // NOSONAR
        Arrays.asList(getMockServerClient().retrieveRecordedRequests(null)).forEach(System.out::println); // NOSONAR
        System.out.println("\u001B[31m" + "=== retrieveActiveExpectations ===" + "\u001B[0m"); // NOSONAR
        Arrays.asList(getMockServerClient().retrieveActiveExpectations(null)).forEach(System.out::println); // NOSONAR
    }

Greetings!

[jamesdbloom]

I think I have at last found the problem. Some time expectations that are no longer active are not yet removed from the list of expectations if some requests are in-flight for that expectation. These are then remove when the next request is attempted to be matched. However, these non-active expectations were previously returned on the retrieve call. I've now filtered these out which I believe should fix you problem. I'll try to do a SNAPSHOT release short so you should be able to test that (or wait for the next full release).

I'm going to close this issue because I believe it is now fixed but if you disagree please comment here or open a new issue.