cypressassertion

Why does Cypress print `cy.log` output later than I would expect?


I am trying to use cy.log to help me understand why a test is failing. Unfortunately I can't seem to get it to log the messages I want. After fiddling around for a bit I resorted to this test:

describe.only("In what order are these messages printed?", () => {
  it("I would expect the LOG to be printed before the EXPECT", () => {
    cy.log("Hello from cy.log");
    expect(1 + 1).to.equal(2);
  });
});

I expect the "Hello" to appear first, but what I get is this:

enter image description here

Moreover, in a failing test, the cy.log does not seem to appear at all, which is unfortunate for me. Again, here is a simple but extreme example.

describe.only("Here is my real problem", () => {
  it("I would expect the LOG to be printed before the test fails", () => {
    cy.log("Hello from cy.log");
    expect(2 + 2).to.equal(42);
  });
});

This produces this:

enter image description here

Is this expected behaviour in Cypress?

If so, I could resort to console.log. Although it is a shame we can't neatly report the log in the main Cypress window itself.

Or have I accidentally set a setting that messes up timing of cy.log?


Solution

  • Cypress uses a queue system, basically anything cy.* is an instruction to add something to the command queue.

    When the test code is run, everything is executed sequentially as per normal javascript, except the command queue is run after the test code has executed.

    You can put synchronous javascript on the queue with cy.then(), and get the log order as per the command queue.

    describe.only("Here is my real problem", () => {
      it("I would expect the LOG to be printed before the test fails", () => {
        cy.log("Hello from cy.log");
        cy.then(() => expect(2 + 2).to.equal(42))
      })
    })