Hard bug fixed by a simple fix
Tags: opensource
Published: 2022-04-18 03:16:07

Opened my [Pull request](https://github.com/Seneca-CDOT/telescope/pull/3307) on adding best practices for the SSO services. The e2e test was failing in the pipeline, despised testing locally. 
On the CI, the test case was only failing on Chromium.
```
FAIL browser: chromium src/api/sso/test/e2e/auth-flows.test.js (28.142 s)
  Authentication Flows
    ✕ Login flow preserves state param (25222 ms)
```
First, some of my reviewers are using Mac M1  (ARM architecture), they were not able to build the image properly since the node-alpine version because it was missing some build-in package to build the image. I had to use a bigger node version. 
After pushing those changes, [@humphd](https://github.com/humphd) helped me to debug, this issue wasn't able to be producible locally.

I started to run on different environment, and this is the result showed below:
**Windows 11 pro 21H2** - test case pass. (by @Kevan-Y )
**Windows 11 pro 21H2 on WSL2 Ubuntu-20.04** - test case pass  (by @Kevan-Y )
**Amazon Linux 2 AMI (HVM) - Kernel 5.10 (ami-0c02fb55956c7d316 (64-bit x86)) - t2.large** - test case pass  (by @Kevan-Y )
**MacOS M1** -  test case pass (by @humphd)

It wasn't looking good. This makes debugging hard since it's only happening on CI.

I started to increase the timeout of the test case to 30000ms
```js
it('Login flow preserves state param', async () => {
    const { state } = await login(page, 'user1', 'user1pass');
    // Expect the state to match what we sent originally (see index.html <a>)
    expect(state).toEqual('abc123');
  }, 30000);
```
Despite increasing timeout it was failing. 

Possibility due to some other container such as elastic search, it crashed, since that container had some issue with the memory not enough allocated. I increased the memory in the docker-compose file.
```yml
  elasticsearch:
    environment:
      # Limit the initial heap size. By default it will use 1/4 of available RAM
      - 'ES_JAVA_OPTS=-Xms512m -Xmx512m'
```
After pushing these changes, the CI pipeline was still failing.

I decided to skip all the e2e test cases and only run `Login flow preserves state param` of `src/api/sso/test/e2e/auth-flows.test.js ` for the purpose of debugging and also turn on `LOG_LEVEL` to `debug`.
I pushed those changes, but it wasn't helping. They were 0 logs that helped to identify which place it when wrong. So I switch to the basic way of debugging. "Put console.log on each line"

In `src\api\sso\test\e2e\auth-flows.test.js`
```js
 it('Login flow preserves state param', async () => {
    console.log('Start test case by await login');
    const { state } = await login(page, 'user1', 'user1pass');
    console.log('Done await login', state);

    // Expect the state to match what we sent originally (see index.html <a>)
    expect(state).toEqual('abc123');
  }, 30000);
```
In `src\api\sso\test\e2e\browser-util.js`
```js
const login = async (page, username, password) => {
  console.log('Start login and wait for page');
  // Click login button and then wait for the login page to load
  await Promise.all([
    page.waitForNavigation({
      url: /simplesaml\/module\.php\/core\/loginuserpass\.php/,
      waitUtil: 'networkidle',
    }),
    page.click('#login'),
  ]);
  console.log('after click login');

  console.log('click input[name="username"]');
  // Fill the login form, star with username
  await page.click('input[name="username"]');
  console.log('after click input[name="username"]');

  console.log('fill input[name="username"]');
  await page.fill('input[name="username"]', username);
  console.log('after fill input[name="username"]');

  // Now enter the password
  console.log('click input[name="password"]');
  await page.click('input[name="password"]');
  console.log('after click input[name="password"]');

  console.log('fill input[name="password"]');
  await page.fill('input[name="password"]', password);
  console.log('after fill input[name="password"]');

  console.log('wait for the new page to load');
  // Click login button and then wait for the new page to load
  await Promise.all([
    page.waitForNavigation({
      url: /^http:\/\/localhost:\d+\/auth\.html\?access_token=[^&]+&state=/,
      waitUtil: 'load',
    }),
    page.click('text=/.*Login.*/'),
  ]);

  // The token and state will get returned on the query string
  return getTokenAndState(page);
};
```
After pushing this change, I finally got some good debug result. The test case was timing out in 
```js
await Promise.all([
    page.waitForNavigation({
      url: /simplesaml\/module\.php\/core\/loginuserpass\.php/,
      waitUtil: 'networkidle',
    }),
    page.click('#login'),
  ]);
```
One possible issue mentioned by [@Humphd](https://github.com/humphd), the event was sitting on that page for some reason and never navigates.
Instead of `waitUtil: 'networkidle'`, we change to `waitUtil: 'load'`. [see reference](https://playwright.dev/docs/api/class-page#page-wait-for-navigation)
Even with that, it didn't work. But the ultimate fix was to try to update from version `1.19.2` to `1.20.2` of `playwright` which might potentially fix it.
It was the right solution, just an update of the dependencies, and everything works fine.

Spend a couple of days trying to debug this, and the fix was just a dependency update. It was a good experience, in the end. Sometimes we have to wait for the upstream to fix for us.