cypress-io / cypress

Fast, easy and reliable testing for anything that runs in a browser.
https://cypress.io
MIT License
46.72k stars 3.16k forks source link

Cypress run never completes, creates a memory leak. #3915

Closed hdavidzhu closed 5 years ago

hdavidzhu commented 5 years ago

Current behavior:

Our monitoring is detecting that

ffmpeg /var/lever/browser-test-running-listener/services/hire2/cypress/videos/ourTest.coffee.mp4 -f image2pipe -use_wallclock_as_timestamps 1 -i pipe:0 -y -vcodec libx264 -preset ultrafast 

hangs and never resolves.

Over time, one of our parallel test runners gets a memory leak and can't complete new tests.

image

Desired behavior:

Test run should finish, not hang, and not cause a memory leak.

Steps to reproduce: (app code and test code)

Unfortunately, no repro (except for internal code). Guess this means the issue's getting closed? 😢

Versions

Version: Cypress 3.2.0 Operating system: Linux Debian - 8.11 Browser: Electron 59.0.3071.115

brian-mann commented 5 years ago

It's likely not a problem with ffmpeg - you're likely seeing increased memory usage because if a test is hanging and never completing - then the run stays open... which then records more video.

Although it writes ffmpeg frames to a stream that should write to disk immediately, it's not buffered in memory.

Is that graph of the ffmpeg process or the cypress process?

Also tests shouldn't actually just "hang" - eventually something must time out. If you're using AWS codepipeline there's got to be a way to cancel the build after say X minutes of inactivity on stdout or stderr.

Those logs would be helpful here to understand where it's timing out. A test? The same test? Different ones? Multiple specs? A single spec? What happens if you add DEBUG logs? Any clues there? DEBUG=cypress:* cypress run

hdavidzhu commented 5 years ago

Thanks! I'll try:

Is that graph of the ffmpeg process or the cypress process?

It's for the whole test-runner, includiny cypress and ffmpeg.

It is the same test, and it doesn't hang locally. I'll do more logging and see what we come up with.

hdavidzhu commented 5 years ago

I'm getting the following trailing logs:

04-09 11:24:44 -   cypress:server:proxy handling proxied request { 
  url: '/channel/test?token=u5LNlIYO-Gczhjedrk3W4eH9DARzepeCqecQ&a=a3sshqewjqej&OSID=cj0muxr2&OAID=38&VER=8&MODE=init&zx=ngubd5fu67u1&t=1', 
  proxiedUrl: 'https://c-cfc04665-b925-4c55-bb1d-efe543e2cb96.my.website.com/channel/test?token=u5LNlIYO-Gczhjedrk3W4eH9DARzepeCqecQ&a=a3sshqewjqej&OSID=cj0muxr2&OAID=38&VER=8&MODE=init&zx=ngubd5fu67u1&t=1', 
  headers: { 
    host: 'c-cfc04665-b925-4c55-bb1d-efe543e2cb96.my.website.com', 
    connection: 'keep-alive', 
    'user-agent': 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Cypress/3.2.0 Chrome/59.0.3071.115 Electron/1.8.2 Safari/537.36', 
    origin: 'https://my.website.com', 
    accept: '*/*', 
    referer: 'https://my.website.com/interviews', 
    'accept-encoding': 'gzip, deflate', 
    'accept-language': 'en-US', 
    cookie: '_8b866=http://172.18.87.86:11136; connect.sid=s%3ASTdQ2XTTZe5CpFVQ8SBprpkQ6h2EFvXO.YgMKwLmAA0XfxDZvWtxv%2FV7CEGJ64McGuWHVijStxdI; connect.sticky1=s%3ASTdQ2XTTZe5CpFVQ8SBprpkQ6h2EFvXO.YgMKwLmAA0XfxDZvWtxv%2FV7CEGJ64McGuWHVijStxdI; connect.sticky2=a4ffac90-b719-4024-974e-0700963df14d; __cypress.unload=true' }, 
    remoteState: { 
      auth: null, 
      props: { 
        port: '443', 
        tld: 'co', 
        domain: 'mywebsite' 
      }, 
      origin: 'https://my.website.com', 
      strategy: 'http', 
      visiting: false, 
      domainName: 'mywebsite.co', 
      fileServer: null 
    } 
  } +0ms
04-09 11:24:45 -   cypress:server:video capture stderr log { message: 'frame= 5873 fps= 25 q=12.0 size=    1792kB time=00:03:54.36 bitrate=  62.6kbits/s dup=3930 drop=1 speed=1.02x    ' } +558ms
04-09 11:24:45 -   cypress:server:video capture stderr log { message: 'frame= 5888 fps= 25 q=12.0 size=    1792kB time=00:03:54.96 bitrate=  62.5kbits/s dup=3940 drop=1 speed=1.02x    ' } +646ms
04-09 11:24:46 -   cypress:server:timers child sending timer id 550 +10s
04-09 11:24:46 -   cypress:server:video capture stderr log { message: 'frame= 5904 fps= 25 q=12.0 size=    1792kB time=00:03:55.60 bitrate=  62.3kbits/s dup=3951 drop=1 speed=1.02x    ' } +601ms
04-09 11:24:47 -   cypress:server:video capture stderr log { message: 'frame= 5916 fps= 25 q=12.0 size=    1792kB time=00:03:56.08 bitrate=  62.2kbits/s dup=3959 drop=1 speed=1.01x    ' } +499ms
04-09 11:24:46 -   cypress:server:video capture stderr log { message: 'frame= 8303 fps= 25 q=12.0 size=    7424kB time=00:05:31.56 bitrate= 183.4kbits/s dup=5253 drop=0 speed=1.02x    ' } +448ms
04-09 11:24:46 -   cypress:server:video capture stderr log { message: 'frame= 8316 fps= 25 q=12.0 size=    7424kB time=00:05:32.08 bitrate= 183.1kbits/s dup=5262 drop=0 speed=1.02x    ' } +501ms
04-09 11:24:47 -   cypress:server:video capture stderr log { message: 'frame= 8331 fps= 25 q=12.0 size=    7424kB time=00:05:32.68 bitrate= 182.8kbits/s dup=5272 drop=0 speed=1.02x    ' } +650ms
04-09 11:24:47 -   cypress:server:video capture stderr log { message: 'frame= 8343 fps= 25 q=12.0 size=    7424kB time=00:05:33.16 bitrate= 182.5kbits/s dup=5280 drop=0 speed=1.02x    ' } +499ms
04-09 11:24:48 -   cypress:server:video capture stderr log { message: 'frame= 8359 fps= 25 q=12.0 size=    7424kB time=00:05:33.80 bitrate= 182.2kbits/s dup=5291 drop=0 speed=1.02x    ' } +601ms
04-09 11:24:49 -   cypress:server:video capture stderr log { message: 'frame= 8374 fps= 25 q=12.0 size=    7424kB time=00:05:34.40 bitrate= 181.9kbits/s dup=5301 drop=0 speed=1.02x    ' } +650ms
04-09 11:24:49 -   cypress:server:video capture stderr log { message: 'frame= 8391 fps= 25 q=12.0 size=    7424kB time=00:05:35.08 bitrate= 181.5kbits/s dup=5313 drop=0 speed=1.02x    ' } +600ms
04-09 11:24:50 -   cypress:server:video capture stderr log { message: 'frame= 8406 fps= 25 q=12.0 size=    7424kB time=00:05:35.68 bitrate= 181.2kbits/s dup=5323 drop=0 speed=1.02x    ' } +650ms
04-09 11:24:50 -   cypress:server:video capture stderr log { message: 'frame= 8418 fps= 25 q=12.0 size=    7424kB time=00:05:36.16 bitrate= 180.9kbits/s dup=5331 drop=0 speed=1.02x    ' } +499ms
04-09 11:24:51 -   cypress:server:timers child sending timer id 257 +10s

Our app uses continuous 20s long-polling, and it could be that the long-polling is confusing Cypress's proxy layer, never resolving a test.

For now, I'll try to terminate any new requests at the end of a test to see if that helps.

pratik-domain commented 5 years ago

I am having the same issue. Tests are running every evening and some days all the tests in the suite runs, other days only a few tests run. We are also trying to figure out the reason.

cypress:server:server Got CONNECT request from pixel.rubiconproject.com:443
cypress:https-proxy Writing socket connection headers for URL: pixel.rubiconproject.com:443
cypress:server:cors Parsed URL { 
  port: '443', 
  tld: 'com', 
  domain: 'rubiconproject' 
  }
cypress:server:server HTTPS request does not match URL: https://pixel.rubiconproject.com:443 with props: { port: '443', tld: 'com.au', domain: 'domain' }
cypress:server:server HTTPS request https://pixel.rubiconproject.com:443 matches blacklist? undefined
cypress:https-proxy Making direct connection to pixel.rubiconproject.com:443
cypress:server:video capture stderr log { 
  message: '    Last message repeated 1 times' 
}
cypress:server:video capture stderr log { 
  message: 'frame=  128 fps= 48 q=17.0 size=     512kB time=00:00:04.56 bitrate= 919.9kbits/s dup=52 drop=0 speed=1.71x    ' 
}
cypress:server:server Got CONNECT request from beacon.krxd.net:443
cypress:https-proxy Writing socket connection headers for URL: beacon.krxd.net:443
cypress:server:cors Parsed URL { 
  port: '443', 
  tld: 'net', 
  domain: 'krxd' 
}
cypress:server:server HTTPS request does not match URL: https://beacon.krxd.net:443 with props: { port: '443', tld: 'com.au', domain: 'domain' }
cypress:server:server HTTPS request https://beacon.krxd.net:443 matches blacklist? undefined
cypress:https-proxy Making direct connection to beacon.krxd.net:443
cypress:server:server Got CONNECT request from pixel.rubiconproject.com:443
cypress:https-proxy Writing socket connection headers for URL: pixel.rubiconproject.com:443
cypress:server:cors Parsed URL { 
  port: '443', 
  tld: 'com', 
  domain: 'rubiconproject' 
}
cypress:server:server HTTPS request does not match URL: https://pixel.rubiconproject.com:443 with props: { port: '443', tld: 'com.au', domain: 'domain' }
cypress:server:server HTTPS request https://pixel.rubiconproject.com:443 matches blacklist? undefined
cypress:https-proxy Making direct connection to pixel.rubiconproject.com:443
cypress:server:video capture stderr log { 
  message: 'frame=  142 fps= 44 q=15.0 size=     512kB time=00:00:05.12 bitrate= 819.3kbits/s dup=54 drop=0 speed=1.59x    ' 
}
cypress:server:timers child sending timer id 3
...
cypress:server:timers child sending timer id 5
...
cypress:server:timers child sending timer id 129
cypress:cli Stopping XVFB

Below are the screen shots. In both the cases build pass?

master__349__Jenkins_ master__351__Jenkins_

Thanks for your help. Pratik

jennifer-shehane commented 5 years ago

Unfortunately we'll have to close this issue if no reproducible example is provided. Can anyone provide a way to reproduce this? We need test code that we can run and see this hanging behavior ourselves.

hdavidzhu commented 5 years ago

@jennifer-shehane Thanks to your help (outside of this Github issue), we determined that this is related to an existing Electron issue that prevents Cypress from tearing it down (due to beforeunload).

We switched to Chrome in Cypress v3.3.1 and the issue has gone away 🎉 Although we sacrifice video recordings, I imagine the Electron-related issue would be resolved sometime soon when their patch comes out:

https://github.com/cypress-io/cypress/issues/796 https://github.com/electron/electron/issues/17364