archfz/cypress-terminal-report

When enableExtendedCollector and logToFilesOnAfterRun are set, the file write preprocessor is called twice, resulting in only the after-all hook being logged

Rikkun-1 opened this issue · 4 comments

Rikkun-1 commented

I need to log both beforeAll and afterAll hooks.
Because of this I am using enableExtendedCollector option.

My support file looks like this:

require('cypress-terminal-report/src/installLogsCollector')({
  enableExtendedCollector: true,
});

This allows me to log beforeAll and afterAll hook if it's not last after hook.

To log last afterAll hook I have to use logToFilesOnAfterRun option like this:

require('cypress-terminal-report/src/installLogsPrinter')(on, {
  printLogsToConsole: 'onFail',
  printLogsToFile: 'always',
  commandTrimLength: 10000,
  defaultTrimLength: 10000,
  logToFilesOnAfterRun: true,
  outputRoot: config.projectRoot + `/cypress/results/commandLog/`,
  specRoot: 'cypress/e2e',
  outputTarget: {
    [`spec|log`]: 'txt'
  }
})

But if you use logToFilesOnAfterRun option it will remove file, create it again and log only afterAll because this line is called twice https://github.com/archfz/cypress-terminal-report/blob/master/src/outputProcessor/BaseOutputProcessor.js#L27.

First time from afterAll hook and second time from after:run.

I was able to solve this problem by writing custom output log processor that almost same as TextOutputProcessor https://github.com/archfz/cypress-terminal-report/blob/master/src/outputProcessor/TextOutputProcessor.js

The only difference is that it tracks what specs were written by itself instead of relying on specChunksWritten from BaseOutputProcessor that will be flushed.

const CONSTANTS = require('cypress-terminal-report/src/constants');
const PADDING = '    ';
const PADDING_LOGS = `${PADDING}`.repeat(6);
const { EOL } = require('os');

const severityToFont = {
  [CONSTANTS.SEVERITY.ERROR]: 'ERROR',
  [CONSTANTS.SEVERITY.WARNING]: 'WARN',
  [CONSTANTS.SEVERITY.SUCCESS]: 'OK',
}

function padTypeText(text) {
  return Array(Math.max(PADDING_LOGS.length - text.length + 1, 0)).join(' ')
    + text;
}

const prevTexts = {};

function writeExtendedLog(allMessages) {
  Object.entries(allMessages).forEach(([spec, tests]) => {
    this.chunkSeparator = EOL + EOL;

    // don't write header if we want to append to file
    let text = prevTexts[spec] ? '' : `${spec}:${EOL}`;
    Object.entries(tests).forEach(([test, messages]) => {
      text += `${PADDING}${test}${EOL}`;
      messages.forEach(([type, message, severity]) => {
        text += (padTypeText(`${type} (${severityToFont[severity]}): `) +
          message.replace(/\n/g, `${EOL}${PADDING_LOGS}`) + EOL).replace(/\s+\n/, '\n');
      }); 
      text += EOL;
    });

    // append new text previously written and write new text as a whole(remember that deleted between afterAll and after:run)
    text = prevTexts[spec] ? prevTexts[spec] + text : text;
    this.writeSpecChunk(spec, text);
    prevTexts[spec] = text;
  })
}

module.exports = {
  writeExtendedLog,
}
 outputTarget: {
    [`spec|log`]: writeExtendedLog
  }

This custom logger solves my problem but it looks kinda hacky.

I guess that's a bug because I think that nobody would expect to get only afterAll hook when he uses logToFilesOnAfterRun option.

cypress/e2e/Test.spec.js:
    [[ after all #1 ]]
        cy:log (K): Tests passed. Disposing HAR
        cy:command (K): task	disposeHar

That's an edge case to log the very last afterAll but It would be cool if it worked reliably out of the box.

Thanks for attention in advance :)

archfz commented

This seems strange. I have tried to reproduce the issue but could not. I think I know where the issue might be and will apply a theoretical fix, but would like you to help me reproduce it so I can write a test for it.

Ran cypress with only one spec and your settings, using this test:

describe('All hooks.', function () {
  before(function () {
    cy.log('from before');
  });
  beforeEach(function () {
    cy.log('from beforeEach');
  });
  it('passed it', function () {
    cy.log('from it');
  });
  it('passed it 2', function () {
    cy.log('from it 2');
  });
  afterEach(function () {
    cy.log('from afterEach');
  });
  after(function () {
    // cy.get('from after', {timeout: 0});
    cy.log('from after');
  });
  after(function () {
    cy.log('from after 2');
  });
});

This works correctly all the time. The weird thing is that logToFilesOnAfterRun was added to support fail-fast plugin. So there should be no relation to after all hooks not being logged with extended collector. In fact if I remove the logToFilesOnAfterRun option, the output files are still generated correctly with the after all in them. Are you using fail-fast? I feel like there something more specific going on with your setup. What version of cypress are you running?

  • 👍1
Rikkun-1 commented

Thanks for response.
I am not using fail-fast.
I am using cypress v12.11.0.

Your example works fine for me.

I ran:

describe('All hooks.', function () {
  before(function () {
    cy.log('from before');
  });
  beforeEach(function () {
    cy.log('from beforeEach');
  });
  it('passed it', function () {
    cy.log('from it');
  });
  it('passed it 2', function () {
    cy.log('from it 2');
  });
  afterEach(function () {
    cy.log('from afterEach');
  });
  after(function () {
    // cy.get('from after', {timeout: 0});
    cy.log('from after');
  });
  after(function () {
    cy.log('from after 2');
  });
});

And got following as expected.

cypress/e2e/Test.spec.js:
    All hooks. -> [[ before all #1 ]]
            cy:log (K): from before

    All hooks. -> passed it
            cy:log (K): from beforeEach
            cy:log (K): from it
            cy:log (K): from afterEach

    All hooks. -> passed it 2
            cy:log (K): from beforeEach
            cy:log (K): from it 2
            cy:log (K): from afterEach

    All hooks. -> [[ after all #1 ]]
            cy:log (K): from after

    All hooks. -> [[ after all #2 ]]
            cy:log (K): from after 2

But if I add global afterAll like this:

describe('All hooks.', function () {
  before(function () {
    cy.log('from before');
  });
  beforeEach(function () {
    cy.log('from beforeEach');
  });
  it('passed it', function () {
    cy.log('from it');
  });
  it('passed it 2', function () {
    cy.log('from it 2');
  });
  afterEach(function () {
    cy.log('from afterEach');
  });
  after(function () {
    cy.log('from after');
  });
  after(function () {
    cy.log('from after 2');
  });
});

+ after(function() {
+   cy.log('Global after hook')
+ });

I will get only global hook if logToFilesOnAfterRun: true:

cypress/e2e/Test.spec.js:
    [[ after all #2 ]]
            cy:log (K): Global after hook

And everything else except global hook if logToFilesOnAfterRun: false:

cypress/e2e/Test.spec.js:
    All hooks. -> [[ before all #1 ]]
            cy:log (K): from before

    All hooks. -> passed it
            cy:log (K): from beforeEach
            cy:log (K): from it
            cy:log (K): from afterEach

    All hooks. -> passed it 2
            cy:log (K): from beforeEach
            cy:log (K): from it 2
            cy:log (K): from afterEach

    All hooks. -> [[ after all #1 ]]
            cy:log (K): from after

    All hooks. -> [[ after all #2 ]]
            cy:log (K): from after 2

I expect to see both suite and global hooks to be logged:

cypress/e2e/Test.spec.js:
    All hooks. -> [[ before all #1 ]]
            cy:log (K): from before

    All hooks. -> passed it
            cy:log (K): from beforeEach
            cy:log (K): from it
            cy:log (K): from afterEach

    All hooks. -> passed it 2
            cy:log (K): from beforeEach
            cy:log (K): from it 2
            cy:log (K): from afterEach

    All hooks. -> [[ after all #1 ]]
            cy:log (K): from after

    All hooks. -> [[ after all #2 ]]
            cy:log (K): from after 2

    [[ after all #2 ]]
            cy:log (K): Global after hook
archfz commented

Released fix in 5.2.0. Custom processor is not needed. However there is a cavet, you will need to register your after hook before the plugin support install. See README note, in the last part of the section.

  • ❤️1
archfz commented

Besides this be careful with that custom output processor as it accumulates memory usage, so in a sens it has memory leaks.