2.0.11 - Is it possible for the lifecycle events to be synchronous?

[v-mwalk]

In the MSW based test framework we have, the lifecycle events request:start/response:bypass/response/mocked are used for logging; basically request/responses are stringified and then written to files for offline use.

In 1.x.x all worked ok. However, in 2.x.x (2.0.11 currently being used) often the test/s end before the logging has completed.

The reason is that the cloned request and response .text() awaits do not return until AFTER the AUT has completed it's request (MSW has made the mocked response or passthough response got). For the logging to work, based on the lifecycle events, I need to be able to get the request/response details (and so the bodies) before MSW completes. Is this possible?

EG. In the following, I dont see the ... and push until after the AUT completes and gets it's mocked response

(this._mswServerWrapperInstance as MSWUtils).serverInstance.events.on('request:start', async ({request, requestId}) => {
      // Dont log it if it was a request TO Application Under Test
      Log.writeLine(LogLevels.FrameworkInformation, `MSW Request Start (request:start) event caught. If url.host not [localhost:${MSWUtils.autPort}] log in mockedRequests`);
      try {
        const url = new URL(request.url);
        if (url.host != `localhost:${MSWUtils.autPort}`) {
          Log.writeLine(LogLevels.FrameworkDebug,`url.host is [${url.host}] so log in mockedRequests.  Build....`);
          const req = {
            requestId: requestId,
            url: url,
            method: request.method,
            headers: request.headers,
            credentials: request.credentials,
            mode: request.mode,
            cookies: {},
            body: await request.clone().text()
          };
          Log.writeLine(LogLevels.FrameworkDebug,`... and push`);
          MSWUtils.allNonAUTRequests.push(req);
        }
      } catch (err) {
        Log.writeLine(
          LogLevels.Error,
          `Fatal error handing MSW [request:start] and logging request information: ${err}`,
        );
      }
    });

If comment out the await request.clone().text() (and replace with "blah") then all is good; everything works well.

[kettanaito]

Hi, @v-mwalk.

This behavior is correct. Reading the request/response body is an asynchronous action. Even if it takes 0ms, it will always complete on the next tick of the event loop, giving you this out-of-order behavior.

For the logging to work, based on the lifecycle events, I need to be able to get the request/response details (and so the bodies) before MSW completes.

Note that this isn't what life-cycle API is for. It's meant as the means to listen to request/response execution as a side effect. It's correct that those events are emitted after MSW is finished handling respective request/response instances.

Maybe you can tell me more about your requirement? What makes you want this kind of behavior?

[v-mwalk]

Thanks Artem

I'm using the lifecycle events to record requests/responses to the filesystem, either for use by tests or for offline human use. With v1 I'd log all request:start's with their Id's; then on the response events tie-up with the associated requests and log to the file system with the request and response details (file naming based on indexed - for multipe calls to same endpoint - request urls and mocked/passthrough). It would be up to the Test Suites how they use those files; but, it was guaranteed the files would be there at the end of each call to the AUT if the AUT had made requests (responses mocked or bypassed).

The issue is that now, after migration, (actually, for the 'prod' framework I've rolled back to 1.2.5) any tests using the files created by the life cycle events will randomly fail, or test system will prematurely tear down MSW thinking it has competed.

For a functional test automation suite, syncronous execution is important as it allows the test suite to be in full control of everything; enabling coherent logging and 100% repo ability if issues occur etc. I appreciate the Lifecycle events are for 'reading only', but within a test automation suite that 'reading' is part of the test process.

Example test using some actual steps (but is nonsense test!)

  Scenario: An example test
    Given Mock Server Worker is running
    And Application is running
    And A [Server A] listener is on '/path/to/api' and will forward requests to destination
    And A [Server B] listener is on '/some/other/endpoint' and will respond with status '200', json data from mock data file [QT2_offers_lookup/validSinglePlans.json]
    And A [Server C] listener is on '/maybe/another/endpoint' and will respond with status '200', json data '{"Test1:"Value1"}'
    When A 'POST' request is made to [AUT] '/aut/input', json data from test data file [somefile/containingtestdata.json]
    Then '1' intercepted requests were made
    And Response status is '418', json data;
      | JSON-Path  | Compare Types | Expected Value              |
      | statusCode | equals        | 123                         |
      | error      | equals        | "I used to be a teapot"       |
      | message[0] | equals        | "I was changed at some point" |

A mass of helper/framework code underneath, with MSW doing the mock lifting, but as an example; when the step that does the POST to the AUT is complete I want to be 100% sure everything on the test-side is completed so the next step - whatever it is - knows that when it executes all previous test code is completed fully.

As a workaround, I'm looking to see if I can use the active listeners and the onUnhandled event (which the framework already uses to decide if the request can be passed through or if it should be 'lost' with no response - depending on what the respective test wants to do) to see if I can use those to do the logging. I've taken an MSW clone to try and see if a flag could be added to say 'run Async/Synch' but slightly uphill as i'm still coming up to speed on TS/nodejs (I'm C/C++/.NET/Java - but getting there! lol ).

[kettanaito]

Would awaiting the life-cycle event listeners help? If I understand the problem, the test finishes while your framework still handles writing the request/response data to disk. If that's the case, you should properly await the response:* event before marking the test as finished (tests should de-facto depend on your framework to eliminate any race conditions).

const responseReceived = new DeferredPromise()

// Should also handle "response:bypass" events!
server.events.on('response:mocked', async ({ response }) => {
  const body = await response.text()
  responseReceived.resolve(body)
})

return responseReceived

I'm using DeferredPromise here.

Wrap this in a function and await it before completing the test. Let me know if this helps.

[v-mwalk]

Hi @kettanaito
Many many apologies for not replying sooner - BAU work got in the way :-)

For the Framework using MSW, I've actually gone back to using MSW 1.3.2. I did try a number of fixes to work around the async working of the events but because it is in-built with MSW I cannot make it synchronous. When I get time, I may well look at the MSW code to see if it is possible to have a switch to say async/sync.

Although I am only using the event listeners for logging purposes, because a test can reach the end (and so start on the next) before the event support code completes it starts getting very complicated. For a Functional Test Suite (wereby all connections are mocked - using MSW) it really needs everything within the test suite to be synchronous - not only for logging (out-of-order log information) but also for the Test Runner and test sanity (IE. 100% sure of the sequence of operation for repro reasons).

With the solutions I tried (including yours) the issue I had was that I could not be sure the AUT would make a request - there could be a defect in the AUT that which meant an intercepted request was NOT made. And that was the key breaker for me; as the test-suite I can make no assumptions about the health/functionality of the AUT the test suite is testing (and MSW mocking calls from). When I make an API call to the AUT, when it returns I need to be 100% sure everything (test-side) has completed - the AUT may do stuff out-of-process which test/s are built to handle/validate (as an example, one of the AUTs here has a 'health ping' that happens every 30 seconds - which I can automatically handle and/or test). But for the test suite, it really has to be syncronous for a given test...

I hope I've not waffled for too long lol; I just wanted to try and explain the reason for the synchronous need (as in 'normal' applications, async operation is a great bonus!) and my jump back to 1.3.2...

[kettanaito]

There's not much we can/should do about this. Reading the request body stream is async so you must await that in your tests/tooling. Most test frameworks work nicely with awaiting promises both in the tests and in the setup hooks so you should utilize those (forcing a synchronous nature of a test that operates on asynchronous resources like requests and responses isn't a good idea).

[v-mwalk]

I'm not forcing sync on async and yes, when i'm reading the request body etc then i am awaiting etc. All that works nicely. The issue is the event firing which in v2.0.0 has gone async - worked well in <2.0.0 where it was syncronous - when the AUT response was received , the test suite was sure all activity was over and complete. However, in v2+ that is not the case, the event may not have fired, happening sometime after. Lol - probably not explaining it well. I'll try and get some time to knock up a quick n simple example. It is not a big deal as <v2.0.0 is actually working well - with iNest AUTs..

…

On Mon, 29 Jan 2024, 21:11 Artem Zakharchenko, ***@***.***> wrote: There's not much we can/should do about this. Reading the request body stream is async so you must await that in your tests/tooling. Most test frameworks work nicely with awaiting promises both in the tests and in the setup hooks so you should utilize those (forcing a synchronous nature of a test that operates on asynchronous resources like requests and responses isn't a good idea). — Reply to this email directly, view it on GitHub <#1927 (reply in thread)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ADAIJVULDTRYVSUYTKASGD3YQ57W7AVCNFSM6AAAAABATX2DX6VHI2DSMVQWIX3LMV43SRDJONRXK43TNFXW4Q3PNVWWK3TUHM4DEOBQGY4DS> . You are receiving this because you were mentioned.Message ID: ***@***.***>