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

chore: Refactor assertion logging #23354

Merged
merged 12 commits into from
Aug 22, 2022
Merged

Conversation

BlueWinds
Copy link
Contributor

User facing changelog

No change in behavior. Refactoring only.

Additional details

As part of the Detached DOM work, I've run into a lot of issues with the way assertion logging currently works. This PR simplifies our use of the "onBeforeLog" hook, moving the logic for "is this the same log message" into easier to find and understand places.

Steps to test

The automated tests are pretty thorough in this regard. Feel free to play around with any existing project, or especially assertions.cy.ts to verify that nothing has changed.

How has the user experience changed?

PR Tasks

  • Have tests been added/updated?
  • [n/a] Has the original issue (or this PR, if no issue exists) been tagged with a release in ZenHub? (user-facing changes only)
  • [n/a] Has a PR for user-facing changes been opened in cypress-documentation?
  • [n/a] Have API changes been updated in the type definitions?

@cypress-bot
Copy link
Contributor

cypress-bot bot commented Aug 15, 2022

Thanks for taking the time to open a PR!

@@ -790,19 +789,18 @@ describe('src/cy/commands/assertions', () => {
cy.noop({}).should('have.property', 'foo')
})

it('ends and snapshots immediately and sets child', (done) => {
it('snapshots immediately and sets child', (done) => {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This PR does introduce one test change - the assertion log is in a pending state when initially added, and is passed asynchronously as part of the finishAssertions() function, which happens slightly later in the lifecycle of the command.

Other tests verify that it moves from the pending state to resolved before the next command executes - it's just slightly later in resolving the same promise chain than log:added. I don't believe this is a meaningful difference, and so this can remain a chore even though I had to update one test. 🤷‍♀️

@BlueWinds BlueWinds changed the title Issue 7306 refactor assertion logging chore: Refactor assertion logging Aug 15, 2022
@cypress
Copy link

cypress bot commented Aug 16, 2022



Test summary

41474 0 1434 0Flakiness 14


Run details

Project cypress
Status Passed
Commit 4292f80
Started Aug 22, 2022 4:51 PM
Ended Aug 22, 2022 5:06 PM
Duration 15:04 💡
OS Linux Debian - 11.3
Browser Multiple

View run in Cypress Dashboard ➡️


Flakiness

cypress/e2e/commands/net_stubbing.cy.ts Flakiness
1 network stubbing > intercepting request > can delay with deprecated delayMs param
2 network stubbing > intercepting request > can delay with deprecated delayMs param
3 network stubbing > intercepting request > can delay with deprecated delayMs param
4 network stubbing > intercepting request > can delay with deprecated delayMs param
5 ... > with `times` > only uses each handler N times
This comment includes only the first 5 flaky tests. See all 14 flaky tests in the Cypress Dashboard.

This comment has been generated by cypress-bot as a result of this project's GitHub integration settings. You can manage this integration in this project's settings in the Cypress Dashboard

Copy link
Contributor

@lmiller1990 lmiller1990 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All tests pass and I don't see any obvious problems, so looks good. Asked a few questions.

packages/driver/src/cypress/log.ts Show resolved Hide resolved
@lmiller1990
Copy link
Contributor

lmiller1990 commented Aug 16, 2022

Actually, this might be incorrect? I am seeing a lot of red in the command log.

I ran a spec in app - cypress/e2e/cypress-in-cypress-e2e.cy.ts. I ran the first test using .only. I don't see this in develop on the same test. cc @BlueWinds

image

@lmiller1990 lmiller1990 self-requested a review August 16, 2022 01:49
Copy link
Contributor

@lmiller1990 lmiller1990 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Possible regression, going to request changes until we verify it's not a regression.

@BlueWinds
Copy link
Contributor Author

BlueWinds commented Aug 16, 2022

Actually, this might be incorrect? I am seeing a lot of red in the command log.

I ran a spec in app - cypress/e2e/cypress-in-cypress-e2e.cy.ts. I ran the first test using .only. I don't see this in develop on the same test. cc @BlueWinds

Oof, yeah, I see the same. Investigating, will fix and add another driver test once I figure out what's going on here. Wondering if it has to do with cypress-in-cypress.

Fixed, see below.

@BlueWinds
Copy link
Contributor Author

Possible regression, going to request changes until we verify it's not a regression.

Ah, figured it out. .should('not.exist') was getting duplicated when it retried; there's no assertion on the number of logs for any of the not.exist tests.

I've fixed the issue - the 'deduplicate logs' logic just needed to be moved slightly higher in the function - and added an assertion to an existing test to prevent future regressions in the area. See 6849134 for the exact changes, and good catch!

Copy link
Contributor

@lmiller1990 lmiller1990 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Regression was fixed and comments responded too. I am not driver expert yet, so defs need that second 👀 , but seems like things behave the same as they did prior to and after this refactor 👍

Comment on lines 613 to 615
let commandLogId = log.get('commandLogId')

if (commandLogId != null) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logic is specific to commands/asserting.ts and commands are responsible for managing their own logs. Theres no need to move this logic here. This also puts additional attributes on the log that don't seem necessary which are stored on on the runner and the command.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There's a good chance I'll want to end up reusing this in other selectors as part of the Detached DOM work, but I've moved it to asserting.ts for now - you're absolutely right that a comment saying "this is used one place, read about it there" is a code smell.

@BlueWinds BlueWinds force-pushed the issue-7306-refactorAssertionLogging branch from 0a50757 to 443bd53 Compare August 17, 2022 17:23
Copy link
Contributor

@flotwig flotwig left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice!

@BlueWinds
Copy link
Contributor Author

There was a recent merge conflict with develop I had to resolve, took a few commits to get everything cleared up. Should be clean now with all review comments addressed.

Comment on lines -358 to -366
const originalLogSnapshotFn = this.snapshot

this.snapshot = function () {
// restore the original snapshot function
this.snapshot = originalLogSnapshotFn

// call orig fn with next as name
return originalLogSnapshotFn.call(this, options.next)
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We need to maintain this for cross-origin snapshots.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I merged in develop, which included a bunch of cross-origin changes, and fixed several merge conflicts; the tests were initially failing, but after some playing around I got them passing again.

Do you have a specific instance in mind where it's failing to snapshot cross-origin in this branch, so I can add a test?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@emilyrohrbough @BlueWinds I don't believe there is an impact here to cross origin snapshots.

In the case of asking the cross origin spec bridge for a snapshot, this should only happen in the case that something in the primary instance of cypress is requesting a snapshot while a cy.origin block is active or is about to be active, which means it's highly unlikely to be a command asking for the snapshot (ex: XHR's and fetch requests that ask for snapshots as a generated log that aren't direct command invocations). The tests in snapshots.cy.ts should cover this for known cases.

In the case were we DO need to rebind the original snapshot function, this usually happens on interaction events which should almost always be commands. Commands that are run within cy.origin take snapshots within the spec bridge itself, so no asking spec bridges for snapshots should be occuring. This should be covered by the various command tests that assert on consoleProps and other log attributes to verify the snapshot is correct.

Since we don't have tests that verify snapshots interactively (can't leverage the system test and cy-in-cy doesn't support snapshots), I ran this manually to double check and everything looks good from what I can see 😄 .

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for double checking! I'd hate to have accidentally broken something you merged in just a few days ago.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Of course! Honestly wish we had a better way to test snapshots moving forward. Getting snapshot testing into cy-in-cy I think would cover a lot of ground.

@@ -7,6 +7,30 @@ import $errUtils from '../../cypress/error_utils'
const reExistence = /exist/
const reHaveLength = /length/

const onBeforeLog = (log, command, commandLogId) => {
log.set('commandLogId', commandLogId)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Any reason we didn't just provide the log id instead of adding a new attribute on the log?

Copy link
Contributor Author

@BlueWinds BlueWinds Aug 22, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I tried to use the log id initially, but you can't set a log's ID:

    // dont ever allow existing id's to be mutated
    if (this.attributes.id) {
      delete this.obj.id
    }

because the ID is meant to be completely unique - to identify a log instance, across the entire test. Updating it in the log would also require updating the mapping of id -> Log instance that the LogManager maintains, which begins to look like the same level of complexity as having its own attribute.

Also important to note that in the current implementation, the commandLogId isn't globally unique - it's unique (and reproducible) only within the context of a single command. Different instances of .should() can generate the same commandLogId. This isn't a problem in the current implementation, because we only search command.get('logs') for a matching commandLogId.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Basically, this just serves a different purpose than the log's id. It's a bit of state-tracking for an instance of .should().

@BlueWinds BlueWinds merged commit 9ba3ed3 into develop Aug 22, 2022
@BlueWinds BlueWinds deleted the issue-7306-refactorAssertionLogging branch August 22, 2022 17:56
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants