Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
Rikkun-1 opened this issue May 23, 2023 · 4 comments
Labels
bug Something isn't working

Comments

@Rikkun-1
Copy link

Rikkun-1 commented May 23, 2023

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 archfz added the bug Something isn't working label May 27, 2023
@archfz
Copy link
Owner

archfz commented May 27, 2023

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?

@Rikkun-1
Copy link
Author

Rikkun-1 commented May 27, 2023

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
Copy link
Owner

archfz commented May 27, 2023

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.

@archfz archfz closed this as completed May 27, 2023
@archfz
Copy link
Owner

archfz commented May 27, 2023

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants