percy / cli

The Percy CLI is used to interact with, and upload snapshots to, percy.io via the command line.
https://docs.percy.io/docs/cli-overview
71 stars 45 forks source link

Percy intermittently hangs indefinitely when trying to establish logger websocket connection #1065

Closed ozyx closed 2 years ago

ozyx commented 2 years ago

The problem

We are running a suite of Percy visual tests using Playwright. As we added more tests, we started noticing tests were intermittently timing out. We traced the issue back to the Percy process hanging indefinitely while trying to establish a websocket connection to a remote logger.

We have tested with and seen the same issue with Percy/cli versions 1.2.1, 1.6.4, 1.7.2, 1.10.0 and 1.10.2. We did notice that we started seeing a marked increase in timeouts as we added more visual tests and snapshots to our suites.

Environment

Details

Debug logs

Below is the stacktrace after aborting a test hanging indefinitely (note that I ran this with the --debug flag):

     20 …› faultManagement.visual.spec.js:71:5 › The Fault Management Plugin Visual Test › ability to acknowledge or shelve
[percy:core:snapshot] --------- (6788ms)
[percy:core:snapshot] Handling snapshot: Selected faults highlight the ability to Acknowledge or Shelve above the fault list (theme: 'espresso') (0ms)
[percy:core:snapshot] - url: http://localhost:8080/#/browse/faults.taxonomy:faultManagement.view?tc.mode=fixed&tc.startBound=1663016803410&tc.endBound=1663018603410&tc.timeSystem=utc&view=faultManagement.view (0ms)
[percy:core:snapshot] - widths: 1024px, 2000px (0ms)
[percy:core:snapshot] - minHeight: 1440px (0ms)
[percy:core:snapshot] - discovery.allowedHostnames: localhost (1ms)
[percy:core:snapshot] - clientInfo: @percy/playwright/1.0.4 (0ms)
[percy:core:snapshot] - environmentInfo: @percy/playwright/1.0.4 (0ms)
[percy:core:snapshot] - domSnapshot: true (0ms)
[percy:core:page] Page created (16ms)
[percy:core:page] Resize page to 1024x1440 @1x (108ms)
[percy:core:page] Navigate to: http://localhost:8080/#/browse/faults.taxonomy:faultManagement.view?tc.mode=fixed&tc.startBound=1663016803410&tc.endBound=1663018603410&tc.timeSystem=utc&view=faultManagement.view (2ms)
[percy:core:discovery] Handling request: http://localhost:8080/ (13ms)
[percy:core:discovery] - Serving root resource (0ms)
[percy:core:discovery] Handling request: http://localhost:8080/dist/espressoTheme.css (89ms)
[percy:core:discovery] - Resource cache hit (1ms)
[percy:core:page] Page navigated (88ms)
[percy:core:network] Wait for 100ms idle (0ms)
[percy:core:page] Resize page to 2000x1440 @1x (100ms)
[percy:core:discovery] Handling request: http://localhost:8080/dist/images/logo-openmct.svg (102ms)
[percy:core:discovery] - Resource cache hit (0ms)
[percy:core:discovery] Handling request: http://localhost:8080/dist/fonts/Open-MCT-Symbols-16px.woff (1ms)
[percy:core:discovery] - Resource cache hit (0ms)
[percy:core:network] Wait for 100ms idle (80ms)
[percy:core] Snapshot taken: Selected faults highlight the ability to Acknowledge or Shelve above the fault list (theme: 'espresso') (111ms)
  ✓  20 …ltManagement.visual.spec.js:71:5 › The Fault Management Plugin Visual Test › ability to acknowledge or shelve (8s)
     21 …Clock.visual.spec.js:42:5 › Visual - Controlled Clock @localStorage › Overlay Plot Loading Indicator @localStorage
^C[percy:core] Stopping percy... (3082623ms)
[percy:core:browser] Closing browser (6ms)
[percy:utils] Unable to connect to remote logger
  ✘  21 [chrome] › controlledClock.visual.spec.js:42:5 › Visual - Controlled Clock @localStorage › Overlay Plot Loading Indicator @localStorage (51m)
    at WebSocket.ws.onclose (/work/node_modules/@percy/sdk-utils/dist/logger.js:136:16)
    at WebSocket.onClose (/work/node_modules/ws/lib/event-target.js:210:18)
    at WebSocket.emit (node:events:513:28)
    at WebSocket.emitClose (/work/node_modules/ws/lib/websocket.js:258:10)
    at Socket.socketOnClose (/work/node_modules/ws/lib/websocket.js:1258:15)
    at Socket.emit (node:events:513:28)
    at TCP.<anonymous> (node:net:757:14)
[percy:playwright] Could not take DOM snapshot "SineWaveInOverlayPlot (theme: 'espresso')"
[percy:playwright] Error: connect ECONNREFUSED 127.0.0.1:5338
    at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1247:16)
[percy:core:browser] Browser closed (338ms)
[percy:core] Build not created (1ms)

Code to reproduce issue

  1. git clone https://github.com/nasa/openmct.git
  2. git checkout percy-cli-timeout
  3. cd openmct
  4. Run docker container simulating our testing environment:

docker run --cpus=2 --rm --network host -v $(pwd):/work/ -w /work/ -it mcr.microsoft.com/playwright:v1.25.2-focal /bin/bash

  1. npm install
  2. npm run test:e2e:visual:debug

Observe that the test run eventually hangs indefinitely.

Robdel12 commented 2 years ago

Hey @ozyx! Thanks for the report. We're currently working on removing the remote logger -- which should totally eliminate this issue.