Skip to content

Commit

Permalink
test: print SSR Logs as a context for failed tests to improve trouble…
Browse files Browse the repository at this point in the history 
…shooting of SSR e2e (#19296)

Wrapped each test function inside `it()` within an util function `LogUtils.attachLogsToErrors()`.
Whenever an error happens inside such a function (e.g. due to a failing `expect()`, the Error is intercepted (via try-catch) and the SSR logs are attached to this error's `cause` property. Then the error is re-thrown. Thanks to this, JestJS will report this `cause` along with the main error message.

Btw. made a refactor in various places related to logs:
- removed custom function `expectLogMessages()` and custom matcher `.toContainLogs` with regular `expect(logMessages).toContain()` - to not obfuscate under the hood what is being expected and how
- moved `LogUtils.clearSsrLogFile();` from top-level `beforeEach` to inside the util `SsrUtils.startSsrServer()` - to be less prone to refactoring mistake of re-ordering the execution of those events (i.e. clear log file VS. start new ssr writing to this file)
- created separate functions to get logs:
   - `getRawLogs(): string[]` - gets raw content of the log file (both JSONs and raw strings like 'Node is listening on port 4000'.
   - `getRawLogsPretty(): string[]` - similar as above, but it parses single line JSON strings and pretty-prints them (Note: it's used in `LogUtils.attachLogsToErrors()` for making the logs more readable when we attach them as a context of the error).
   - `getLogsObjects(): object[]` - gets only JSON logs and parses them to JS objects. Raw strings from logs are skipped
   - `getLogsMessages(): string[]` - gets only JSON logs' `message` properties. Raw strings from logs are skipped
   
**QA steps:**
1. Deliberately make one of the tests fail - e.g. change the expected HTTP status from `200` to `123`, e.g. in line 33, in the test `should receive success response with request`
1. Build libs, app and SSR (with localhost backend):
   `npm run build:libs && npm run build && build:ssr:local-http-backend`
2. Run ssr-tests:
   `npm run test:ssr`
3. Verify that the Error message printed by JestJS contains SSR logs as a context:
![image](https://github.com/user-attachments/assets/4c12588b-5ad1-4f99-a56c-67a213ff687b)
![image](https://github.com/user-attachments/assets/d7ae2d01-f853-49b2-8935-3ced99d4b8dd)


fixes https://jira.tools.sap/browse/CXSPA-8564
  • Loading branch information
@Platonn
Platonn authored Sep 27, 2024
1 parent 2979040 commit 2672319
Show file tree
Hide file tree
Showing 5 changed files with 200 additions and 143 deletions.
50 changes: 0 additions & 50 deletions projects/ssr-tests/src/matchers/matchers.ts
View file

This file was deleted.

153 changes: 83 additions & 70 deletions projects/ssr-tests/src/ssr-testing.spec.ts
View file
Original file line number Diff line number Diff line change
@@ -1,11 +1,9 @@
import { TestConfig } from '@spartacus/core';
import { Server } from 'http';
import { expectLogMessages } from './matchers/matchers';
import * as HttpUtils from './utils/http.utils';
import * as LogUtils from './utils/log.utils';
import * as ProxyUtils from './utils/proxy.utils';
import * as SsrUtils from './utils/ssr.utils';

const BACKEND_BASE_URL: string = process.env.CX_BASE_URL || '';

jest.setTimeout(SsrUtils.DEFAULT_SSR_TIMEOUT); // set timeout to at least 1x DEFAULT_SSR_TIMEOUT seconds for each test in this file to increase stability of the tests
Expand All @@ -14,10 +12,6 @@ describe('SSR E2E', () => {
let backendProxy: Server;
const REQUEST_PATH = '/contact'; // path to the page that is less "busy" than the homepage

beforeEach(() => {
LogUtils.clearSsrLogFile();
});

afterEach(async () => {
backendProxy?.close();
await SsrUtils.killSsrServer();
Expand All @@ -29,60 +23,73 @@ describe('SSR E2E', () => {
await SsrUtils.startSsrServer();
});

it('should receive success response with request', async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
});
const response: any = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH,
});
expect(response.statusCode).toEqual(200);
it(
'should receive success response with request',
LogUtils.attachLogsToErrors(async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
});
const response: any = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH,
});
expect(response.statusCode).toEqual(200);

expectLogMessages().toContainLogs([
`Rendering started (${REQUEST_PATH})`,
`Request is waiting for the SSR rendering to complete (${REQUEST_PATH})`,
]);
});
const logsMessages = LogUtils.getLogsMessages();
expect(logsMessages).toContain(`Rendering started (${REQUEST_PATH})`);
expect(logsMessages).toContain(
`Request is waiting for the SSR rendering to complete (${REQUEST_PATH})`
);
})
);

it('should receive response with 404 when page does not exist', async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
});
const response = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH + 'not-existing-page',
});
expect(response.statusCode).toEqual(404);
});
it(
'should receive response with 404 when page does not exist',
LogUtils.attachLogsToErrors(async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
});
const response = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH + 'not-existing-page',
});
expect(response.statusCode).toEqual(404);
})
);

it('should receive response with status 404 if HTTP error occurred when calling cms/pages API URL', async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
callback: (proxyRes, req) => {
if (req.url?.includes('cms/pages')) {
proxyRes.statusCode = 404;
}
},
});
const response = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH,
});
expect(response.statusCode).toEqual(404);
});
it(
'should receive response with status 404 if HTTP error occurred when calling cms/pages API URL',
LogUtils.attachLogsToErrors(async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
callback: (proxyRes, req) => {
if (req.url?.includes('cms/pages')) {
proxyRes.statusCode = 404;
}
},
});
const response = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH,
});
expect(response.statusCode).toEqual(404);
})
);

it('should receive response with status 500 if HTTP error occurred when calling other than cms/pages API URL', async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
callback: (proxyRes, req) => {
if (req.url?.includes('cms/components')) {
proxyRes.statusCode = 404;
}
},
});
const response = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH,
});
expect(response.statusCode).toEqual(500);
});
it(
'should receive response with status 500 if HTTP error occurred when calling other than cms/pages API URL',
LogUtils.attachLogsToErrors(async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
callback: (proxyRes, req) => {
if (req.url?.includes('cms/components')) {
proxyRes.statusCode = 404;
}
},
});
const response = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH,
});
expect(response.statusCode).toEqual(500);
})
);
});

describe('With caching enabled', () => {
Expand All @@ -92,7 +99,7 @@ describe('SSR E2E', () => {

it(
'should take the response from cache for the next request if previous render succeeded',
async () => {
LogUtils.attachLogsToErrors(async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
});
Expand All @@ -102,23 +109,27 @@ describe('SSR E2E', () => {
});
expect(response.statusCode).toEqual(200);

expectLogMessages().toContainLogs([
`Rendering started (${REQUEST_PATH})`,
`Request is waiting for the SSR rendering to complete (${REQUEST_PATH})`,
]);
const logsMessages = LogUtils.getLogsMessages();
expect(logsMessages).toContain(`Rendering started (${REQUEST_PATH})`);
expect(logsMessages).toContain(
`Request is waiting for the SSR rendering to complete (${REQUEST_PATH})`
);

response = await HttpUtils.sendRequestToSsrServer({
path: REQUEST_PATH,
});
expect(response.statusCode).toEqual(200);
expectLogMessages().toContain(`Render from cache (${REQUEST_PATH})`);
},
const logsMessages2 = LogUtils.getLogsMessages();
expect(logsMessages2).toContain(
`Render from cache (${REQUEST_PATH})`
);
}),
2 * SsrUtils.DEFAULT_SSR_TIMEOUT // increase timeout for this test as it calls the SSR server twice
);

it(
'should render for the next request if previous render failed',
async () => {
LogUtils.attachLogsToErrors(async () => {
backendProxy = await ProxyUtils.startBackendProxyServer({
target: BACKEND_BASE_URL,
callback: (proxyRes, req) => {
Expand All @@ -137,10 +148,11 @@ describe('SSR E2E', () => {
path: REQUEST_PATH,
});
expect(response.statusCode).toEqual(404);
expectLogMessages().not.toContain(
const logsMessages = LogUtils.getLogsMessages();
expect(logsMessages).not.toContain(
`Render from cache (${REQUEST_PATH})`
);
},
}),
2 * SsrUtils.DEFAULT_SSR_TIMEOUT // increase timeout for this test as it calls the SSR server twice
);
});
Expand Down Expand Up @@ -172,10 +184,11 @@ describe('SSR E2E', () => {
});
expect(response.statusCode).toEqual(200);

expectLogMessages().toContainLogs([
`Rendering started (${REQUEST_PATH})`,
`Request is waiting for the SSR rendering to complete (${REQUEST_PATH})`,
]);
const logsMessages = LogUtils.getLogsMessages();
expect(logsMessages).toContain(`Rendering started (${REQUEST_PATH})`);
expect(logsMessages).toContain(
`Request is waiting for the SSR rendering to complete (${REQUEST_PATH})`
);
});

it('should receive response with 200 even when page does not exist', async () => {
Expand Down
Loading

0 comments on commit 2672319

Please sign in to comment.