From 3d822201c4b585c20132285be33226a3bd17d0ca Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 3 Jun 2019 13:03:44 -0400 Subject: [PATCH 01/27] add tests for getAddress on localhost --- .../network/test/integration/connect_spec.ts | 51 +++++++++++++++++++ packages/network/test/mocha.opts | 1 + packages/network/test/unit/agent_spec.ts | 1 - 3 files changed, 52 insertions(+), 1 deletion(-) create mode 100644 packages/network/test/integration/connect_spec.ts diff --git a/packages/network/test/integration/connect_spec.ts b/packages/network/test/integration/connect_spec.ts new file mode 100644 index 000000000000..5601e357134d --- /dev/null +++ b/packages/network/test/integration/connect_spec.ts @@ -0,0 +1,51 @@ +import _ from 'lodash' +import Bluebird from 'bluebird' +import chai from 'chai' +import net from 'net' +import sinonChai from 'sinon-chai' +import * as connect from '../../lib/connect' + +const expect = chai.expect +chai.use(sinonChai) + +describe('lib/connect', function() { + context('.getAddress', function() { + it('resolves localhost on 127.0.0.1 immediately', function() { + this.timeout(50) + + const server = net.createServer(_.partialRight(_.invoke, 'close')) + + return Bluebird.fromCallback(cb => { + server.listen(0, '127.0.0.1', cb) + }) + .then(() => { + return connect.getAddress(server.address().port, 'localhost') + }) + .then((address) => { + expect(address).to.deep.eq({ + family: 4, + address: '127.0.0.1' + }) + }) + }) + + it('resolves localhost on ::1 immediately', function() { + this.timeout(50) + + const server = net.createServer(_.partialRight(_.invoke, 'close')) + + return Bluebird.fromCallback(cb => { + server.listen(0, '::1', cb) + }) + .then(() => { + return connect.getAddress(server.address().port, 'localhost') + }) + .then((address) => { + expect(address).to.deep.eq({ + family: 6, + address: '::1' + }) + }) + }) + }) +}) diff --git a/packages/network/test/mocha.opts b/packages/network/test/mocha.opts index 3622a281707e..7ef9f2476490 100644 --- a/packages/network/test/mocha.opts +++ b/packages/network/test/mocha.opts @@ -1,4 +1,5 @@ test/unit +test/integration --compilers ts:@packages/ts/register --timeout 10000 --recursive diff --git a/packages/network/test/unit/agent_spec.ts b/packages/network/test/unit/agent_spec.ts index 687c53d1f398..5fe314b3da25 100644 --- a/packages/network/test/unit/agent_spec.ts +++ b/packages/network/test/unit/agent_spec.ts @@ -1,6 +1,5 @@ import Bluebird from 'bluebird' import chai from 'chai' -import { EventEmitter } from 'events' import http from 'http' import https from 'https' import net from 'net' From 925efeb500222d940689538d8da4ee1c9c519c0e Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 3 Jun 2019 16:09:00 -0400 Subject: [PATCH 02/27] add test for visit resolving quickly --- .../cypress/integration/commands/navigation_spec.coffee | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/packages/driver/test/cypress/integration/commands/navigation_spec.coffee b/packages/driver/test/cypress/integration/commands/navigation_spec.coffee index f1c9d0a08048..bf7d71857024 100644 --- a/packages/driver/test/cypress/integration/commands/navigation_spec.coffee +++ b/packages/driver/test/cypress/integration/commands/navigation_spec.coffee @@ -605,6 +605,12 @@ describe "src/cy/commands/navigation", -> }) cy.contains('"user-agent":"something special"') + it "completes immediately on localhost", -> + cy.visit({ + url: '/dump-method' + timeout: 50 + }) + describe "can send a POST request", -> it "automatically urlencoded using an object body", -> cy.visit("http://localhost:3500/post-only", { From 5f678a2c191d51144135fcd8d68b51f4801636cd Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 4 Jun 2019 16:20:03 -0400 Subject: [PATCH 03/27] add debug logs to network --- packages/network/lib/agent.ts | 4 +++- packages/network/lib/connect.ts | 6 ++++++ 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/packages/network/lib/agent.ts b/packages/network/lib/agent.ts index 8c841ef5c11e..92f0292e4c81 100644 --- a/packages/network/lib/agent.ts +++ b/packages/network/lib/agent.ts @@ -156,11 +156,13 @@ export class CombinedAgent { } } - debug(`addRequest called for ${options.href}`) + debug('addRequest called %o', { isHttps, ..._.pick(options, 'href') }) return getFirstWorkingFamily(options, this.familyCache, (family: net.family) => { options.family = family + debug('got family %o', _.pick(options, 'family', 'href')) + if (isHttps) { return this.httpsAgent.addRequest(req, options) } diff --git a/packages/network/lib/connect.ts b/packages/network/lib/connect.ts index 4875314422c9..0d580ef1bf3a 100644 --- a/packages/network/lib/connect.ts +++ b/packages/network/lib/connect.ts @@ -22,6 +22,8 @@ export function byPortAndAddress (port: number, address: net.Address) { } export function getAddress (port: number, hostname: string) { + debug('beginning getAddress %o', { hostname, port }) + const fn = byPortAndAddress.bind({}, port) // promisify at the very last second which enables us to @@ -35,9 +37,13 @@ export function getAddress (port: number, hostname: string) { // @ts-ignore return lookupAsync(hostname, { all: true }) .then((addresses: net.Address[]) => { + debug('got addresses %o', { hostname, port, addresses }) // convert to an array if string return Array.prototype.concat.call(addresses).map(fn) }) + .tapCatch((err) => { + debug('error getting address', { hostname, port, err }) + }) .any() } From 768381b1c2a834a2f038bfcb78c3abcfc99b8b25 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 4 Jun 2019 16:29:55 -0400 Subject: [PATCH 04/27] network: override addRequest in HttpAgent, not createSocket --- packages/network/lib/agent.ts | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/packages/network/lib/agent.ts b/packages/network/lib/agent.ts index 92f0292e4c81..0173023feb5a 100644 --- a/packages/network/lib/agent.ts +++ b/packages/network/lib/agent.ts @@ -138,6 +138,7 @@ export class CombinedAgent { } // called by Node.js whenever a new request is made internally + // TODO: need to support legacy invocation? https://github.com/nodejs/node/blob/cb68c04ce1bc4534b2d92bc7319c6ff6dda0180d/lib/_http_agent.js#L148-L155 addRequest(req: http.ClientRequest, options: http.RequestOptions) { const isHttps = isRequestHttps(options) @@ -182,22 +183,22 @@ class HttpAgent extends http.Agent { this.httpsAgent = new https.Agent({ keepAlive: true }) } - createSocket (req: http.ClientRequest, options: http.RequestOptions, cb: http.SocketCallback) { + addRequest (req: http.ClientRequest, options: http.RequestOptions) { if (process.env.HTTP_PROXY) { const proxy = getProxyForUrl(options.href) if (proxy) { options.proxy = proxy - return this._createProxiedSocket(req, options, cb) + this._addProxiedRequest(req, options) } } - super.createSocket(req, options, cb) + super.addRequest(req, options) } - _createProxiedSocket (req: http.ClientRequest, options: RequestOptionsWithProxy, cb: http.SocketCallback) { - debug(`Creating proxied socket for ${options.href} through ${options.proxy}`) + _addProxiedRequest (req: http.ClientRequest, options: RequestOptionsWithProxy) { + debug(`Creating proxied request for ${options.href} through ${options.proxy}`) const proxy = url.parse(options.proxy) @@ -228,7 +229,7 @@ class HttpAgent extends http.Agent { return this.httpsAgent.addRequest(req, options) } - super.createSocket(req, options, cb) + super.addRequest(req, options) } } From 79edfa56242c45de37fa996270c972ad266152fb Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Wed, 5 Jun 2019 10:21:11 -0400 Subject: [PATCH 05/27] don't need to add connection: keep-alive to all responses https://github.com/cypress-io/cypress/pull/4385#issuecomment-499103484 --- packages/server/lib/request.coffee | 5 ----- 1 file changed, 5 deletions(-) diff --git a/packages/server/lib/request.coffee b/packages/server/lib/request.coffee index 161640ec9e02..6842f3024660 100644 --- a/packages/server/lib/request.coffee +++ b/packages/server/lib/request.coffee @@ -441,11 +441,6 @@ module.exports = (options = {}) -> defaults = { timeout: options.timeout agent: agent - ## send keep-alive with requests since Chrome won't send it in proxy mode - ## https://github.com/cypress-io/cypress/pull/3531#issuecomment-476269041 - headers: { - "Connection": "keep-alive" - } proxy: null ## upstream proxying is handled by CombinedAgent } From 6083e1e5bee76db32bfe4caa84609ef85ac34baf Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Wed, 5 Jun 2019 12:39:20 -0400 Subject: [PATCH 06/27] test that visit finishes quickly --- .../commands/navigation_spec.coffee | 22 ++++++++++++++----- packages/driver/test/support/server.coffee | 6 +++++ 2 files changed, 23 insertions(+), 5 deletions(-) diff --git a/packages/driver/test/cypress/integration/commands/navigation_spec.coffee b/packages/driver/test/cypress/integration/commands/navigation_spec.coffee index bf7d71857024..77b975a54ce7 100644 --- a/packages/driver/test/cypress/integration/commands/navigation_spec.coffee +++ b/packages/driver/test/cypress/integration/commands/navigation_spec.coffee @@ -605,11 +605,23 @@ describe "src/cy/commands/navigation", -> }) cy.contains('"user-agent":"something special"') - it "completes immediately on localhost", -> - cy.visit({ - url: '/dump-method' - timeout: 50 - }) + ## https://github.com/cypress-io/cypress/issues/4313 + it "normally finishes in less than 500ms on localhost with connection: close", -> + _.times 100, -> + t = undefined + + cy.wrap({ + startTimer: -> + t = setTimeout -> + throw new Error('took too long') + , 500 + }, { log: false }) + .invoke('startTimer') + .visit('/close-connection') + .then -> + clearTimeout(t) + + cy.wrap -> describe "can send a POST request", -> it "automatically urlencoded using an object body", -> diff --git a/packages/driver/test/support/server.coffee b/packages/driver/test/support/server.coffee index a71def2745b1..cc1c2f5096e6 100644 --- a/packages/driver/test/support/server.coffee +++ b/packages/driver/test/support/server.coffee @@ -36,6 +36,12 @@ niv.install("react-dom@15.6.1") app.head "/", (req, res) -> res.sendStatus(200) + app.get "/close-connection", (req, res) -> + res.set('Connection', 'close') + .type('html') + .send('hello') + .close() + app.get "/timeout", (req, res) -> Promise .delay(req.query.ms ? 0) From 600c9c21e62de8b4de09e27042bb4b391ad0e0ec Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Wed, 5 Jun 2019 12:40:04 -0400 Subject: [PATCH 07/27] do not forward connection header --- packages/server/lib/controllers/proxy.coffee | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/server/lib/controllers/proxy.coffee b/packages/server/lib/controllers/proxy.coffee index c355878686f4..7e2d6c972aaa 100644 --- a/packages/server/lib/controllers/proxy.coffee +++ b/packages/server/lib/controllers/proxy.coffee @@ -348,7 +348,7 @@ module.exports = { return if res.headersSent ## omit problematic headers - headers = _.omit incomingRes.headers, "set-cookie", "x-frame-options", "content-length", "content-security-policy" + headers = _.omit incomingRes.headers, "set-cookie", "x-frame-options", "content-length", "content-security-policy", "connection" ## do not cache when we inject content into responses ## later on we should switch to an etag system so we dont From 108d6b623853ab0d28dda3371feda717293135c0 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 10 Jun 2019 14:10:58 -0400 Subject: [PATCH 08/27] add tests to help reproduce --- .../driver/src/cy/commands/navigation.coffee | 13 ++++++---- .../commands/navigation_spec.coffee | 19 ++++++-------- packages/driver/test/support/server.coffee | 4 +-- packages/server/lib/server.coffee | 11 ++++++++ packages/server/test/e2e/6_visit_spec.coffee | 25 +++++++++++++++++++ .../integration/fast_visit_spec.coffee | 14 +++++++++++ 6 files changed, 66 insertions(+), 20 deletions(-) create mode 100644 packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee diff --git a/packages/driver/src/cy/commands/navigation.coffee b/packages/driver/src/cy/commands/navigation.coffee index 3658b8453f89..620a8fbf3478 100644 --- a/packages/driver/src/cy/commands/navigation.coffee +++ b/packages/driver/src/cy/commands/navigation.coffee @@ -577,7 +577,7 @@ module.exports = (Commands, Cypress, cy, state, config) -> $utils.iframeSrc($autIframe, url) - onLoad = ({runOnLoadCallback}) -> + onLoad = ({runOnLoadCallback, totalTime}) -> ## reset window on load win = state("window") @@ -585,7 +585,11 @@ module.exports = (Commands, Cypress, cy, state, config) -> if runOnLoadCallback isnt false options.onLoad?.call(runnable.ctx, win) - options._log.set({url: url}) if options._log + if options._log + options._log.set({ + url + totalTime + }) return Promise.resolve(win) @@ -680,7 +684,8 @@ module.exports = (Commands, Cypress, cy, state, config) -> url = $Location.fullyQualifyUrl(url) changeIframeSrc(url, "window:load") - .then(onLoad) + .then -> + onLoad(resp) else ## if we've already visited a new superDomain ## then die else we'd be in a terrible endless loop @@ -784,8 +789,6 @@ module.exports = (Commands, Cypress, cy, state, config) -> go() visit() - .then -> - state("window") .timeout(options.timeout, "visit") .catch Promise.TimeoutError, (err) => timedOutWaitingForPageLoad(options.timeout, options._log) diff --git a/packages/driver/test/cypress/integration/commands/navigation_spec.coffee b/packages/driver/test/cypress/integration/commands/navigation_spec.coffee index 77b975a54ce7..2792cbb781d3 100644 --- a/packages/driver/test/cypress/integration/commands/navigation_spec.coffee +++ b/packages/driver/test/cypress/integration/commands/navigation_spec.coffee @@ -607,19 +607,14 @@ describe "src/cy/commands/navigation", -> ## https://github.com/cypress-io/cypress/issues/4313 it "normally finishes in less than 500ms on localhost with connection: close", -> + cy.on "log:added", (attrs, log) => + if attrs.name is "visit" + @lastLog = log + _.times 100, -> - t = undefined - - cy.wrap({ - startTimer: -> - t = setTimeout -> - throw new Error('took too long') - , 500 - }, { log: false }) - .invoke('startTimer') - .visit('/close-connection') - .then -> - clearTimeout(t) + cy.visit('/dump-method') + .then () -> + expect(@lastLog.get("totalTime")).to.be.lte(2000) cy.wrap -> diff --git a/packages/driver/test/support/server.coffee b/packages/driver/test/support/server.coffee index cc1c2f5096e6..4dfdbf99dda9 100644 --- a/packages/driver/test/support/server.coffee +++ b/packages/driver/test/support/server.coffee @@ -37,10 +37,8 @@ niv.install("react-dom@15.6.1") res.sendStatus(200) app.get "/close-connection", (req, res) -> - res.set('Connection', 'close') - .type('html') + res.type('html') .send('hello') - .close() app.get "/timeout", (req, res) -> Promise diff --git a/packages/server/lib/server.coffee b/packages/server/lib/server.coffee index 760686cff864..bfbba674dbe8 100644 --- a/packages/server/lib/server.coffee +++ b/packages/server/lib/server.coffee @@ -311,12 +311,15 @@ class Server @_request.sendPromise(headers, automationRequest, options) _onResolveUrl: (urlStr, headers, automationRequest, options = {}) -> + console.log('***************************************\n') debug("resolving visit %o", { url: urlStr headers options }) + startTime = new Date() + ## if we have an existing url resolver ## in flight then cancel it if @_urlResolver @@ -390,8 +393,14 @@ class Server reject(err) onReqStreamReady = (str) => + debug('onReqStreamReady') reqStream = str + require('debug')('cypress:server:server2')('lkasjflksadf %o', { + foo: process, + process + }) + str .on("error", onReqError) .on "response", (incomingRes) => @@ -452,6 +461,8 @@ class Server ## connection hangs before receiving a body. debug("resolve:url response ended, setting buffer %o", { newUrl, details }) + details.totalTime = new Date() - startTime + ## TODO: think about moving this logic back into the ## frontend so that the driver can be in control of ## when the server should cache the request buffer diff --git a/packages/server/test/e2e/6_visit_spec.coffee b/packages/server/test/e2e/6_visit_spec.coffee index d9ddb00de35d..df34623396c3 100644 --- a/packages/server/test/e2e/6_visit_spec.coffee +++ b/packages/server/test/e2e/6_visit_spec.coffee @@ -150,3 +150,28 @@ describe "e2e visit", -> snapshot: true expectedExitCode: 2 }) + + context "resolves visits quickly", -> + e2e.setup({ + servers: { + port: 3434 + onServer: (app) -> + app.get '/foo', (req, res) -> + res + # .set('connection', 'close') + .type('html').send('hi') + } + settings: { + baseUrl: 'http://localhost:3434' + } + }) + + it "in normal network conditions", -> + e2e.exec(@, { + spec: "fast_visit_spec.coffee" + snapshot: false + expectedExitCode: 0 + # browser: 'chrome' + headed: true + exit: false + }) diff --git a/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee b/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee new file mode 100644 index 000000000000..9a6dfe652b22 --- /dev/null +++ b/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee @@ -0,0 +1,14 @@ +beforeEach -> + cy.on "log:added", (attrs, log) => + if attrs.name is "visit" + @lastLog = log + + return null + +it "normally finishes in less than 500ms on localhost with connection: close", -> + Cypress._.times 100, -> + cy.visit('/foo') + .then -> + expect(@lastLog.get("totalTime")).to.be.lte(2000) + + return undefined From 625d4ecc55e1c3b704047ddc888c4cf359dee2fe Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 10 Jun 2019 14:52:04 -0400 Subject: [PATCH 09/27] cleanup --- packages/server/lib/server.coffee | 7 ------- 1 file changed, 7 deletions(-) diff --git a/packages/server/lib/server.coffee b/packages/server/lib/server.coffee index bfbba674dbe8..99744679ceba 100644 --- a/packages/server/lib/server.coffee +++ b/packages/server/lib/server.coffee @@ -311,7 +311,6 @@ class Server @_request.sendPromise(headers, automationRequest, options) _onResolveUrl: (urlStr, headers, automationRequest, options = {}) -> - console.log('***************************************\n') debug("resolving visit %o", { url: urlStr headers @@ -393,14 +392,8 @@ class Server reject(err) onReqStreamReady = (str) => - debug('onReqStreamReady') reqStream = str - require('debug')('cypress:server:server2')('lkasjflksadf %o', { - foo: process, - process - }) - str .on("error", onReqError) .on "response", (incomingRes) => From 5d67a97ca2f348d53e27f3d8db6fd5cc0a46de5f Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 10 Jun 2019 15:10:06 -0400 Subject: [PATCH 10/27] still send keep-alive --- packages/server/lib/request.coffee | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/packages/server/lib/request.coffee b/packages/server/lib/request.coffee index 6842f3024660..161640ec9e02 100644 --- a/packages/server/lib/request.coffee +++ b/packages/server/lib/request.coffee @@ -441,6 +441,11 @@ module.exports = (options = {}) -> defaults = { timeout: options.timeout agent: agent + ## send keep-alive with requests since Chrome won't send it in proxy mode + ## https://github.com/cypress-io/cypress/pull/3531#issuecomment-476269041 + headers: { + "Connection": "keep-alive" + } proxy: null ## upstream proxying is handled by CombinedAgent } From 07a82583f8ab6dffa52101adfa9fbc140bf1a45a Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 10 Jun 2019 15:15:08 -0400 Subject: [PATCH 11/27] update tests --- .../network/test/integration/connect_spec.ts | 4 +- .../test/integration/server_spec.coffee | 67 ++++++++++--------- 2 files changed, 39 insertions(+), 32 deletions(-) diff --git a/packages/network/test/integration/connect_spec.ts b/packages/network/test/integration/connect_spec.ts index 5601e357134d..cd85b5c6dbf6 100644 --- a/packages/network/test/integration/connect_spec.ts +++ b/packages/network/test/integration/connect_spec.ts @@ -29,7 +29,9 @@ describe('lib/connect', function() { }) }) - it('resolves localhost on ::1 immediately', function() { + // Error: listen EADDRNOTAVAIL ::1 + // TODO: add an ipv6 lo if to the docker container + it.skip('resolves localhost on ::1 immediately', function() { this.timeout(50) const server = net.createServer(_.partialRight(_.invoke, 'close')) diff --git a/packages/server/test/integration/server_spec.coffee b/packages/server/test/integration/server_spec.coffee index 07538845f833..cffe3271e46e 100644 --- a/packages/server/test/integration/server_spec.coffee +++ b/packages/server/test/integration/server_spec.coffee @@ -13,6 +13,11 @@ Fixtures = require("#{root}test/support/helpers/fixtures") s3StaticHtmlUrl = "https://s3.amazonaws.com/static.cypress.io/cypress-project-internal-test-assets/index.html" +expectToEqDetails = (actual, expected) -> + actual = _.omit(actual, 'totalTime') + + expect(actual).to.deep.eq(expected) + describe "Server", -> beforeEach -> sinon.stub(Server.prototype, "reset") @@ -116,7 +121,7 @@ describe "Server", -> it "can serve static assets", -> @server._onResolveUrl("/index.html", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -142,7 +147,7 @@ describe "Server", -> it "sends back the content type", -> @server._onResolveUrl("/assets/foo.json", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: false contentType: "application/json" @@ -160,7 +165,7 @@ describe "Server", -> @server._onResolveUrl("/index.html", {}, @automationRequest) .then (obj = {}) => - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -177,7 +182,7 @@ describe "Server", -> .then => @server._onResolveUrl("/index.html", {}, @automationRequest) .then (obj = {}) => - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -203,7 +208,7 @@ describe "Server", -> it "can follow static file redirects", -> @server._onResolveUrl("/sub", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -233,7 +238,7 @@ describe "Server", -> it "gracefully handles 404", -> @server._onResolveUrl("/does-not-exist", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: false isHtml: false contentType: undefined @@ -256,7 +261,7 @@ describe "Server", -> it "handles urls with hashes", -> @server._onResolveUrl("/index.html#/foo/bar", {}, @automationRequest) .then (obj = {}) => - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -322,7 +327,7 @@ describe "Server", -> ## fire the 2nd request now that the first one has had some time to reach out @server._onResolveUrl("http://localhost:#{@httpPort}/#{path}/100", {}, @automationRequest) .then (obj) => - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -360,7 +365,7 @@ describe "Server", -> @server._onResolveUrl("http://getbootstrap.com/", headers, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -389,7 +394,7 @@ describe "Server", -> @server._onResolveUrl("http://getbootstrap.com/user.json", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: false contentType: "application/json" @@ -420,7 +425,7 @@ describe "Server", -> @server._onResolveUrl("http://espn.com/", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -477,7 +482,7 @@ describe "Server", -> @server._onResolveUrl("http://espn.com/", {}, @automationRequest) .then (obj = {}) => - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -496,7 +501,7 @@ describe "Server", -> .then => @server._onResolveUrl("http://espn.com/", {}, @automationRequest) .then (obj = {}) => - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -544,7 +549,7 @@ describe "Server", -> @server._onResolveUrl("http://espn.com/", {}, @automationRequest) .then (obj = {}) => - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: false isHtml: false contentType: undefined @@ -558,7 +563,7 @@ describe "Server", -> @server._onResolveUrl("http://espn.com/", {}, @automationRequest) .then (obj = {}) => - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -590,7 +595,7 @@ describe "Server", -> @server._onResolveUrl("http://mlb.com/", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: false isHtml: true contentType: "text/html" @@ -619,7 +624,7 @@ describe "Server", -> @server._onResolveUrl("http://getbootstrap.com/#/foo", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -655,7 +660,7 @@ describe "Server", -> @server._onResolveUrl("http://google.com/foo", headers, @automationRequest, { failOnStatusCode: false }) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -705,7 +710,7 @@ describe "Server", -> @server._onResolveUrl("http://google.com/index", headers, @automationRequest, { auth }) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -756,7 +761,7 @@ describe "Server", -> @server._onResolveUrl("/index.html", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -775,7 +780,7 @@ describe "Server", -> .then => @server._onResolveUrl("http://www.google.com/", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -807,7 +812,7 @@ describe "Server", -> .then => @server._onResolveUrl("/index.html", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -847,7 +852,7 @@ describe "Server", -> @server._onResolveUrl("http://www.google.com/", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -882,7 +887,7 @@ describe "Server", -> .then => @server._onResolveUrl("/index.html", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -914,7 +919,7 @@ describe "Server", -> .then => @server._onResolveUrl("http://www.google.com/", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -952,7 +957,7 @@ describe "Server", -> @server._onResolveUrl("https://www.foobar.com:8443/", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -987,7 +992,7 @@ describe "Server", -> .then => @server._onResolveUrl("/index.html", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -1019,7 +1024,7 @@ describe "Server", -> .then => @server._onResolveUrl("https://www.foobar.com:8443/", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -1057,7 +1062,7 @@ describe "Server", -> @server._onResolveUrl(s3StaticHtmlUrl, {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -1101,7 +1106,7 @@ describe "Server", -> .then => @server._onResolveUrl("/index.html", {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" @@ -1133,7 +1138,7 @@ describe "Server", -> .then => @server._onResolveUrl(s3StaticHtmlUrl, {}, @automationRequest) .then (obj = {}) -> - expect(obj).to.deep.eq({ + expectToEqDetails(obj, { isOkStatusCode: true isHtml: true contentType: "text/html" From b9d65a4e5ceefae0118e7c3fb6b55ccd279a125f Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 10 Jun 2019 15:26:59 -0400 Subject: [PATCH 12/27] remove timers --- packages/server/index.js | 6 - packages/server/lib/plugins/child/index.js | 5 - packages/server/test/unit/timers_spec.coffee | 112 ------------- packages/server/timers/child.js | 22 --- packages/server/timers/parent.js | 166 ------------------- 5 files changed, 311 deletions(-) delete mode 100644 packages/server/test/unit/timers_spec.coffee delete mode 100644 packages/server/timers/child.js delete mode 100644 packages/server/timers/parent.js diff --git a/packages/server/index.js b/packages/server/index.js index 283e80622b28..5eb0509688fd 100644 --- a/packages/server/index.js +++ b/packages/server/index.js @@ -1,12 +1,6 @@ // override tty if we're being forced to require('./lib/util/tty').override() -// if we are running in electron -// we must hack around busted timers -if (process.versions.electron) { - require('./timers/parent').fix() -} - if (process.env.CY_NET_PROFILE && process.env.CYPRESS_ENV) { const netProfiler = require('./lib/util/net_profiler')() diff --git a/packages/server/lib/plugins/child/index.js b/packages/server/lib/plugins/child/index.js index 6de9649b0b4d..34b755b7e6f1 100644 --- a/packages/server/lib/plugins/child/index.js +++ b/packages/server/lib/plugins/child/index.js @@ -1,8 +1,3 @@ -// if we are running in electron -// we must hack around busted timers -if (process.versions.electron) { - require('../../timers/parent').fix() -} require('graceful-fs').gracefulify(require('fs')) require('@packages/coffee/register') require && require.extensions && delete require.extensions['.litcoffee'] diff --git a/packages/server/test/unit/timers_spec.coffee b/packages/server/test/unit/timers_spec.coffee deleted file mode 100644 index a3a93bf88db2..000000000000 --- a/packages/server/test/unit/timers_spec.coffee +++ /dev/null @@ -1,112 +0,0 @@ -require("../spec_helper") - -_ = require("lodash") - -parent = require("#{root}timers/parent") - -describe "timers/parent", -> - context ".fix", -> - beforeEach -> - parent.restore() - @timer = parent.fix() - - describe "setTimeout", -> - it "returns timer object", (done) -> - obj = setTimeout(done, 10) - - expect(obj.id).to.eq(1) - expect(obj.ref).to.be.a("function") - expect(obj.unref).to.be.a("function") - - it "increments timer id", (done) -> - fn = _.after(2, done) - - obj1 = setTimeout(fn, 10) - obj2 = setTimeout(fn, 10) - - expect(obj2.id).to.eq(2) - - it "slices out of queue once cb is invoked", (done) -> - fn = => - expect(@timer.queue).to.deep.eq({}) - done() - - setTimeout(fn, 10) - - expect(@timer.queue[1].cb).to.eq(fn) - - describe "clearTimeout", -> - it "does not explode when passing null", -> - clearTimeout(null) - - it "can clear the timeout and prevent the cb from being invoked", (done) -> - fn = => - done(new Error("should not have been invoked")) - - timer = setTimeout(fn, 10) - - expect(@timer.queue[1].cb).to.eq(fn) - - clearTimeout(timer) - - expect(@timer.queue).to.deep.eq({}) - - setTimeout -> - done() - , 20 - - describe "setInterval", -> - it "returns timer object", (done) -> - obj = setInterval -> - clearInterval(obj) - - done() - , 10 - - expect(obj.id).to.eq(1) - expect(obj.ref).to.be.a("function") - expect(obj.unref).to.be.a("function") - - it "increments timer id", (done) -> - fn = _.after 2, -> - clearInterval(obj1) - clearInterval(obj2) - done() - - obj1 = setInterval(fn, 10) - obj2 = setInterval(fn, 10000) - - expect(obj2.id).to.eq(2) - - it "continuously polls until cleared", (done) -> - poller = _.after 3, => - clearInterval(t) - - setTimeout -> - expect(fn).to.be.calledThrice - done() - , 100 - - fn = sinon.spy(poller) - - t = setInterval(fn, 10) - - describe "clearInterval", -> - it "does not explode when passing null", -> - clearInterval(null) - - it "can clear the interval and prevent the cb from being invoked", (done) -> - fn = => - done(new Error("should not have been invoked")) - - timer = setInterval(fn, 10) - - expect(@timer.queue[1].cb).to.exist - - clearInterval(timer) - - expect(@timer.queue).to.deep.eq({}) - - setTimeout -> - done() - , 20 diff --git a/packages/server/timers/child.js b/packages/server/timers/child.js deleted file mode 100644 index f57b0d5a64d5..000000000000 --- a/packages/server/timers/child.js +++ /dev/null @@ -1,22 +0,0 @@ -const log = require('debug')('cypress:server:timers') - -process.on('message', (obj = {}) => { - const { id, ms } = obj - - log('child received timer id %d', id) - - setTimeout(() => { - try { - log('child sending timer id %d', id) - - // process.send could throw if - // parent process has already exited - process.send({ - id, - ms, - }) - } catch (err) { - // eslint-disable no-empty - } - }, ms) -}) diff --git a/packages/server/timers/parent.js b/packages/server/timers/parent.js deleted file mode 100644 index bd44be74672e..000000000000 --- a/packages/server/timers/parent.js +++ /dev/null @@ -1,166 +0,0 @@ -// electron has completely busted timers resulting in -// all kinds of bizarre timeouts and unresponsive UI -// https://github.com/electron/electron/issues/7079 -// -// this fixes this problem by replacing all the global -// timers and implementing a lightweight queuing mechanism -// involving a forked process - -const cp = require('child_process') -const path = require('path') -const log = require('debug')('cypress:server:timers') - -const st = global.setTimeout -const si = global.setInterval -const ct = global.clearTimeout -const ci = global.clearInterval - -let child = null - -function noop () {} - -function restore () { - // restore - global.setTimeout = st - global.setInterval = si - global.clearTimeout = ct - global.clearInterval = ci - - if (child) { - child.kill() - } - - child = null -} - -function fix () { - const queue = {} - let idCounter = 0 - - function sendAndQueue (id, cb, ms, args) { - // const started = Date.now() - log('queuing timer id %d after %d ms', id, ms) - - queue[id] = { - // started, - args, - ms, - cb, - } - - child.send({ - id, - ms, - }) - - // return the timer object - return { - id, - ref: noop, - unref: noop, - } - } - - function clear (id) { - log('clearing timer id %d from queue %o', id, queue) - - delete queue[id] - } - - // fork the child process - let child = cp.fork(path.join(__dirname, 'child.js'), [], { - stdio: 'inherit', - }) - .on('message', (obj = {}) => { - const { id } = obj - - const msg = queue[id] - - // if we didn't get a msg - // that means we must have - // cleared the timeout already - if (!msg) { - return - } - - const { cb, args } = msg - - clear(id) - - cb(...args) - }) - - // In linux apparently the child process is never - // exiting which causes cypress to hang indefinitely. - // It would **SEEM** as if we... - // 1. dont need to manually kill our child process - // because it should naturally exit. - // (but of course it doesn't in linux) - // 2. use our restore function already defined above. - // however when using the restore function above - // the 'child' reference is null. how is it null? - // it makes no sense. there must be a rip in the - // space time continuum, obviously. that or the - // child reference as the rest of the matter of - // the universe has succumbed to entropy. - process.on('exit', () => { - child && child.kill() - - restore() - }) - - global.setTimeout = function (cb, ms, ...args) { - idCounter += 1 - - return sendAndQueue(idCounter, cb, ms, args) - } - - global.clearTimeout = function (timer) { - if (!timer) { - return - } - - // return undefined per the spec - clear(timer.id) - } - - global.clearInterval = function (timer) { - if (!timer) { - return - } - - // return undefined per the spec - clear(timer.id) - } - - global.setInterval = function (fn, ms, ...args) { - const permId = idCounter += 1 - - function cb () { - // we want to immediately poll again - // because our permId was just cleared - // from the queue stack - poll() - - fn() - } - - function poll () { - return sendAndQueue(permId, cb, ms, args) - } - - return poll() - } - - return { - child, - - queue, - } -} - -module.exports = { - restore, - - fix, -} From 208775a438bed2fdf31b87c789bb16cd49051e3e Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 10 Jun 2019 15:57:02 -0400 Subject: [PATCH 13/27] add snapshots to e2e test --- .../__snapshots__/6_visit_spec.coffee.js | 120 ++++++++++++++++++ packages/server/test/e2e/6_visit_spec.coffee | 25 +++- .../integration/fast_visit_spec.coffee | 14 +- 3 files changed, 149 insertions(+), 10 deletions(-) diff --git a/packages/server/__snapshots__/6_visit_spec.coffee.js b/packages/server/__snapshots__/6_visit_spec.coffee.js index 30aa55b179e5..2931715f822b 100644 --- a/packages/server/__snapshots__/6_visit_spec.coffee.js +++ b/packages/server/__snapshots__/6_visit_spec.coffee.js @@ -819,3 +819,123 @@ Error: ESOCKETTIMEDOUT ` + +exports['e2e visit resolves visits quickly in chrome (headed) 1'] = ` + +==================================================================================================== + + (Run Starting) + + ┌────────────────────────────────────────────────────────────────────────────────────────────────┐ + │ Cypress: 1.2.3 │ + │ Browser: FooBrowser 88 │ + │ Specs: 1 found (fast_visit_spec.coffee) │ + │ Searched: cypress/integration/fast_visit_spec.coffee │ + └────────────────────────────────────────────────────────────────────────────────────────────────┘ + + +──────────────────────────────────────────────────────────────────────────────────────────────────── + + Running: fast_visit_spec.coffee... (1 of 1) + +Warning: Cypress can only record videos when using the built in 'electron' browser. + +You have set the browser to: 'chrome' + +A video will not be recorded when using this browser. + + + ✓ normally finishes in less than XX:XX on localhost with connection: keep-alive + ✓ normally finishes in less than XX:XX on localhost with connection: close + + 2 passing + + + (Results) + + ┌──────────────────────────────────────┐ + │ Tests: 2 │ + │ Passing: 2 │ + │ Failing: 0 │ + │ Pending: 0 │ + │ Skipped: 0 │ + │ Screenshots: 0 │ + │ Video: false │ + │ Duration: X seconds │ + │ Spec Ran: fast_visit_spec.coffee │ + └──────────────────────────────────────┘ + + +==================================================================================================== + + (Run Finished) + + + Spec Tests Passing Failing Pending Skipped + ┌────────────────────────────────────────────────────────────────────────────────────────────────┐ + │ ✔ fast_visit_spec.coffee XX:XX 2 2 - - - │ + └────────────────────────────────────────────────────────────────────────────────────────────────┘ + All specs passed! XX:XX 2 2 - - - + + +` + +exports['e2e visit resolves visits quickly in electron (headless) 1'] = ` + +==================================================================================================== + + (Run Starting) + + ┌────────────────────────────────────────────────────────────────────────────────────────────────┐ + │ Cypress: 1.2.3 │ + │ Browser: FooBrowser 88 │ + │ Specs: 1 found (fast_visit_spec.coffee) │ + │ Searched: cypress/integration/fast_visit_spec.coffee │ + └────────────────────────────────────────────────────────────────────────────────────────────────┘ + + +──────────────────────────────────────────────────────────────────────────────────────────────────── + + Running: fast_visit_spec.coffee... (1 of 1) + + + ✓ normally finishes in less than XX:XX on localhost with connection: keep-alive + ✓ normally finishes in less than XX:XX on localhost with connection: close + + 2 passing + + + (Results) + + ┌──────────────────────────────────────┐ + │ Tests: 2 │ + │ Passing: 2 │ + │ Failing: 0 │ + │ Pending: 0 │ + │ Skipped: 0 │ + │ Screenshots: 0 │ + │ Video: true │ + │ Duration: X seconds │ + │ Spec Ran: fast_visit_spec.coffee │ + └──────────────────────────────────────┘ + + + (Video) + + - Started processing: Compressing to 32 CRF + - Finished processing: /foo/bar/.projects/e2e/cypress/videos/abc123.mp4 (X seconds) + + +==================================================================================================== + + (Run Finished) + + + Spec Tests Passing Failing Pending Skipped + ┌────────────────────────────────────────────────────────────────────────────────────────────────┐ + │ ✔ fast_visit_spec.coffee XX:XX 2 2 - - - │ + └────────────────────────────────────────────────────────────────────────────────────────────────┘ + All specs passed! XX:XX 2 2 - - - + + +` diff --git a/packages/server/test/e2e/6_visit_spec.coffee b/packages/server/test/e2e/6_visit_spec.coffee index df34623396c3..1043ab617f13 100644 --- a/packages/server/test/e2e/6_visit_spec.coffee +++ b/packages/server/test/e2e/6_visit_spec.coffee @@ -151,14 +151,19 @@ describe "e2e visit", -> expectedExitCode: 2 }) + ## https://github.com/cypress-io/cypress/issues/4313 context "resolves visits quickly", -> e2e.setup({ servers: { port: 3434 onServer: (app) -> - app.get '/foo', (req, res) -> + app.get '/keepalive', (req, res) -> res - # .set('connection', 'close') + .type('html').send('hi') + + app.get '/close', (req, res) -> + res + .set('connection', 'close') .type('html').send('hi') } settings: { @@ -166,12 +171,18 @@ describe "e2e visit", -> } }) - it "in normal network conditions", -> + it "in chrome (headed)", -> + e2e.exec(@, { + spec: "fast_visit_spec.coffee" + snapshot: true + expectedExitCode: 0 + browser: 'chrome' + }) + + it "in electron (headless)", -> e2e.exec(@, { spec: "fast_visit_spec.coffee" - snapshot: false + snapshot: true expectedExitCode: 0 - # browser: 'chrome' - headed: true - exit: false + browser: 'electron' }) diff --git a/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee b/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee index 9a6dfe652b22..64e202a6b45e 100644 --- a/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee +++ b/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee @@ -5,10 +5,18 @@ beforeEach -> return null -it "normally finishes in less than 500ms on localhost with connection: close", -> +it "normally finishes in less than 1000ms on localhost with connection: keep-alive", -> Cypress._.times 100, -> - cy.visit('/foo') + cy.visit('/keepalive') .then -> - expect(@lastLog.get("totalTime")).to.be.lte(2000) + expect(@lastLog.get("totalTime")).to.be.lte(1000) + + return undefined + +it "normally finishes in less than 1000ms on localhost with connection: close", -> + Cypress._.times 100, -> + cy.visit('/close') + .then -> + expect(@lastLog.get("totalTime")).to.be.lte(1000) return undefined From ebe4310185b0e678ce6a47474818d815768d1fb6 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 10 Jun 2019 15:57:13 -0400 Subject: [PATCH 14/27] remove tests for debugging --- .../integration/commands/navigation_spec.coffee | 13 ------------- packages/driver/test/support/server.coffee | 4 ---- 2 files changed, 17 deletions(-) diff --git a/packages/driver/test/cypress/integration/commands/navigation_spec.coffee b/packages/driver/test/cypress/integration/commands/navigation_spec.coffee index 2792cbb781d3..f1c9d0a08048 100644 --- a/packages/driver/test/cypress/integration/commands/navigation_spec.coffee +++ b/packages/driver/test/cypress/integration/commands/navigation_spec.coffee @@ -605,19 +605,6 @@ describe "src/cy/commands/navigation", -> }) cy.contains('"user-agent":"something special"') - ## https://github.com/cypress-io/cypress/issues/4313 - it "normally finishes in less than 500ms on localhost with connection: close", -> - cy.on "log:added", (attrs, log) => - if attrs.name is "visit" - @lastLog = log - - _.times 100, -> - cy.visit('/dump-method') - .then () -> - expect(@lastLog.get("totalTime")).to.be.lte(2000) - - cy.wrap -> - describe "can send a POST request", -> it "automatically urlencoded using an object body", -> cy.visit("http://localhost:3500/post-only", { diff --git a/packages/driver/test/support/server.coffee b/packages/driver/test/support/server.coffee index 4dfdbf99dda9..a71def2745b1 100644 --- a/packages/driver/test/support/server.coffee +++ b/packages/driver/test/support/server.coffee @@ -36,10 +36,6 @@ niv.install("react-dom@15.6.1") app.head "/", (req, res) -> res.sendStatus(200) - app.get "/close-connection", (req, res) -> - res.type('html') - .send('hello') - app.get "/timeout", (req, res) -> Promise .delay(req.query.ms ? 0) From 9c8337e4339ee863b0a19c2e267d1e5a0ca34f6d Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 10 Jun 2019 16:52:41 -0400 Subject: [PATCH 15/27] try making console writes async --- packages/server/index.js | 2 ++ packages/server/lib/util/stdio.js | 41 +++++++++++++++++++++++++++++++ 2 files changed, 43 insertions(+) create mode 100644 packages/server/lib/util/stdio.js diff --git a/packages/server/index.js b/packages/server/index.js index 5eb0509688fd..f0939077dc10 100644 --- a/packages/server/index.js +++ b/packages/server/index.js @@ -1,3 +1,5 @@ +require('./lib/util/stdio').makeAsync() + // override tty if we're being forced to require('./lib/util/tty').override() diff --git a/packages/server/lib/util/stdio.js b/packages/server/lib/util/stdio.js new file mode 100644 index 000000000000..a90cd74804d3 --- /dev/null +++ b/packages/server/lib/util/stdio.js @@ -0,0 +1,41 @@ +const _ = require('lodash') +const fs = require('fs') +const tty = require('tty') + +function writeThruAsync (fd) { + return function write (chunk, enc, cb) { + fs.write(fd, chunk, null, enc, cb || _.noop) + } +} + +/** + * Make stdout and stderr consistently act as asynchronous writes, not synchronous. + * Synchronous writes can block the execution of things we actually care about. + * + * https://github.com/cypress-io/cypress/pull/4385#issuecomment-500543325 + * https://nodejs.org/api/process.html#process_a_note_on_process_i_o + */ +function makeAsync () { + if (process.env.DISABLE_ASYNC_STDIO) { + return + } + + if (process.platform === 'win32') { + // TTYs are asynchronous on Windows + return + } + + [ + [1, process.stdout], + [2, process.stderr], + ].map(([fd, str]) => { + if (tty.isatty(fd)) { + // TTYs are synchronous on POSIX, make it async + str.write = writeThruAsync(fd) + } + }) +} + +module.exports = { + makeAsync, +} From 93f15fcb172b75f53ea370f16bd6634bebb1c0d0 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 11:48:06 -0400 Subject: [PATCH 16/27] Revert "remove timers" This reverts commit b9d65a4e5ceefae0118e7c3fb6b55ccd279a125f. --- packages/server/index.js | 6 + packages/server/lib/plugins/child/index.js | 5 + packages/server/test/unit/timers_spec.coffee | 112 +++++++++++++ packages/server/timers/child.js | 22 +++ packages/server/timers/parent.js | 166 +++++++++++++++++++ 5 files changed, 311 insertions(+) create mode 100644 packages/server/test/unit/timers_spec.coffee create mode 100644 packages/server/timers/child.js create mode 100644 packages/server/timers/parent.js diff --git a/packages/server/index.js b/packages/server/index.js index f0939077dc10..b6bb16cc2dda 100644 --- a/packages/server/index.js +++ b/packages/server/index.js @@ -3,6 +3,12 @@ require('./lib/util/stdio').makeAsync() // override tty if we're being forced to require('./lib/util/tty').override() +// if we are running in electron +// we must hack around busted timers +if (process.versions.electron) { + require('./timers/parent').fix() +} + if (process.env.CY_NET_PROFILE && process.env.CYPRESS_ENV) { const netProfiler = require('./lib/util/net_profiler')() diff --git a/packages/server/lib/plugins/child/index.js b/packages/server/lib/plugins/child/index.js index 34b755b7e6f1..6de9649b0b4d 100644 --- a/packages/server/lib/plugins/child/index.js +++ b/packages/server/lib/plugins/child/index.js @@ -1,3 +1,8 @@ +// if we are running in electron +// we must hack around busted timers +if (process.versions.electron) { + require('../../timers/parent').fix() +} require('graceful-fs').gracefulify(require('fs')) require('@packages/coffee/register') require && require.extensions && delete require.extensions['.litcoffee'] diff --git a/packages/server/test/unit/timers_spec.coffee b/packages/server/test/unit/timers_spec.coffee new file mode 100644 index 000000000000..a3a93bf88db2 --- /dev/null +++ b/packages/server/test/unit/timers_spec.coffee @@ -0,0 +1,112 @@ +require("../spec_helper") + +_ = require("lodash") + +parent = require("#{root}timers/parent") + +describe "timers/parent", -> + context ".fix", -> + beforeEach -> + parent.restore() + @timer = parent.fix() + + describe "setTimeout", -> + it "returns timer object", (done) -> + obj = setTimeout(done, 10) + + expect(obj.id).to.eq(1) + expect(obj.ref).to.be.a("function") + expect(obj.unref).to.be.a("function") + + it "increments timer id", (done) -> + fn = _.after(2, done) + + obj1 = setTimeout(fn, 10) + obj2 = setTimeout(fn, 10) + + expect(obj2.id).to.eq(2) + + it "slices out of queue once cb is invoked", (done) -> + fn = => + expect(@timer.queue).to.deep.eq({}) + done() + + setTimeout(fn, 10) + + expect(@timer.queue[1].cb).to.eq(fn) + + describe "clearTimeout", -> + it "does not explode when passing null", -> + clearTimeout(null) + + it "can clear the timeout and prevent the cb from being invoked", (done) -> + fn = => + done(new Error("should not have been invoked")) + + timer = setTimeout(fn, 10) + + expect(@timer.queue[1].cb).to.eq(fn) + + clearTimeout(timer) + + expect(@timer.queue).to.deep.eq({}) + + setTimeout -> + done() + , 20 + + describe "setInterval", -> + it "returns timer object", (done) -> + obj = setInterval -> + clearInterval(obj) + + done() + , 10 + + expect(obj.id).to.eq(1) + expect(obj.ref).to.be.a("function") + expect(obj.unref).to.be.a("function") + + it "increments timer id", (done) -> + fn = _.after 2, -> + clearInterval(obj1) + clearInterval(obj2) + done() + + obj1 = setInterval(fn, 10) + obj2 = setInterval(fn, 10000) + + expect(obj2.id).to.eq(2) + + it "continuously polls until cleared", (done) -> + poller = _.after 3, => + clearInterval(t) + + setTimeout -> + expect(fn).to.be.calledThrice + done() + , 100 + + fn = sinon.spy(poller) + + t = setInterval(fn, 10) + + describe "clearInterval", -> + it "does not explode when passing null", -> + clearInterval(null) + + it "can clear the interval and prevent the cb from being invoked", (done) -> + fn = => + done(new Error("should not have been invoked")) + + timer = setInterval(fn, 10) + + expect(@timer.queue[1].cb).to.exist + + clearInterval(timer) + + expect(@timer.queue).to.deep.eq({}) + + setTimeout -> + done() + , 20 diff --git a/packages/server/timers/child.js b/packages/server/timers/child.js new file mode 100644 index 000000000000..f57b0d5a64d5 --- /dev/null +++ b/packages/server/timers/child.js @@ -0,0 +1,22 @@ +const log = require('debug')('cypress:server:timers') + +process.on('message', (obj = {}) => { + const { id, ms } = obj + + log('child received timer id %d', id) + + setTimeout(() => { + try { + log('child sending timer id %d', id) + + // process.send could throw if + // parent process has already exited + process.send({ + id, + ms, + }) + } catch (err) { + // eslint-disable no-empty + } + }, ms) +}) diff --git a/packages/server/timers/parent.js b/packages/server/timers/parent.js new file mode 100644 index 000000000000..bd44be74672e --- /dev/null +++ b/packages/server/timers/parent.js @@ -0,0 +1,166 @@ +// electron has completely busted timers resulting in +// all kinds of bizarre timeouts and unresponsive UI +// https://github.com/electron/electron/issues/7079 +// +// this fixes this problem by replacing all the global +// timers and implementing a lightweight queuing mechanism +// involving a forked process + +const cp = require('child_process') +const path = require('path') +const log = require('debug')('cypress:server:timers') + +const st = global.setTimeout +const si = global.setInterval +const ct = global.clearTimeout +const ci = global.clearInterval + +let child = null + +function noop () {} + +function restore () { + // restore + global.setTimeout = st + global.setInterval = si + global.clearTimeout = ct + global.clearInterval = ci + + if (child) { + child.kill() + } + + child = null +} + +function fix () { + const queue = {} + let idCounter = 0 + + function sendAndQueue (id, cb, ms, args) { + // const started = Date.now() + log('queuing timer id %d after %d ms', id, ms) + + queue[id] = { + // started, + args, + ms, + cb, + } + + child.send({ + id, + ms, + }) + + // return the timer object + return { + id, + ref: noop, + unref: noop, + } + } + + function clear (id) { + log('clearing timer id %d from queue %o', id, queue) + + delete queue[id] + } + + // fork the child process + let child = cp.fork(path.join(__dirname, 'child.js'), [], { + stdio: 'inherit', + }) + .on('message', (obj = {}) => { + const { id } = obj + + const msg = queue[id] + + // if we didn't get a msg + // that means we must have + // cleared the timeout already + if (!msg) { + return + } + + const { cb, args } = msg + + clear(id) + + cb(...args) + }) + + // In linux apparently the child process is never + // exiting which causes cypress to hang indefinitely. + // It would **SEEM** as if we... + // 1. dont need to manually kill our child process + // because it should naturally exit. + // (but of course it doesn't in linux) + // 2. use our restore function already defined above. + // however when using the restore function above + // the 'child' reference is null. how is it null? + // it makes no sense. there must be a rip in the + // space time continuum, obviously. that or the + // child reference as the rest of the matter of + // the universe has succumbed to entropy. + process.on('exit', () => { + child && child.kill() + + restore() + }) + + global.setTimeout = function (cb, ms, ...args) { + idCounter += 1 + + return sendAndQueue(idCounter, cb, ms, args) + } + + global.clearTimeout = function (timer) { + if (!timer) { + return + } + + // return undefined per the spec + clear(timer.id) + } + + global.clearInterval = function (timer) { + if (!timer) { + return + } + + // return undefined per the spec + clear(timer.id) + } + + global.setInterval = function (fn, ms, ...args) { + const permId = idCounter += 1 + + function cb () { + // we want to immediately poll again + // because our permId was just cleared + // from the queue stack + poll() + + fn() + } + + function poll () { + return sendAndQueue(permId, cb, ms, args) + } + + return poll() + } + + return { + child, + + queue, + } +} + +module.exports = { + restore, + + fix, +} From aee8a7271de363c4303ecda3c1f159a5fefbf9f3 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 12:17:52 -0400 Subject: [PATCH 17/27] allow DEBUG_COLORS to be passed in an e2e test --- packages/server/test/support/helpers/e2e.coffee | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/server/test/support/helpers/e2e.coffee b/packages/server/test/support/helpers/e2e.coffee index c61a68daad54..1118defcdfa2 100644 --- a/packages/server/test/support/helpers/e2e.coffee +++ b/packages/server/test/support/helpers/e2e.coffee @@ -356,14 +356,14 @@ module.exports = { env: _.chain(process.env) .omit("CYPRESS_DEBUG") .extend({ - DEBUG_COLORS: "1" - ## FYI: color will already be disabled ## because we are piping the child process COLUMNS: 100 LINES: 24 }) .defaults({ + DEBUG_COLORS: "1" + ## prevent any Compression progress ## messages from showing up VIDEO_COMPRESSION_THROTTLE: 120000 From c51b3957e237c8970390dfec897753ada3702faa Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 12:22:38 -0400 Subject: [PATCH 18/27] try: using system node for the timers, setting up our own IPC --- packages/server/timers/child.js | 30 ++++++++++++----- packages/server/timers/parent.js | 58 +++++++++++++++++++++++--------- 2 files changed, 65 insertions(+), 23 deletions(-) diff --git a/packages/server/timers/child.js b/packages/server/timers/child.js index f57b0d5a64d5..65a2cc14d6b3 100644 --- a/packages/server/timers/child.js +++ b/packages/server/timers/child.js @@ -1,20 +1,34 @@ -const log = require('debug')('cypress:server:timers') +const debug = require('debug')('cypress:server:timers:child') +const net = require('net') + +const ipcPath = process.argv.pop() + +const sock = net.createConnection({ + path: ipcPath, +}, () => { + debug('connected to %o', { ipcPath }) +}) + +sock.on('data', (obj = {}) => { + debug('received %o', obj) + obj = JSON.parse(obj.toString()) -process.on('message', (obj = {}) => { const { id, ms } = obj - log('child received timer id %d', id) + debug('child received timer id %d', id) setTimeout(() => { try { - log('child sending timer id %d', id) - - // process.send could throw if - // parent process has already exited - process.send({ + const outObj = JSON.stringify({ id, ms, }) + + debug('child sending timer id %d %o', id, outObj) + + // process.send could throw if + // parent process has already exited + sock.write(outObj) } catch (err) { // eslint-disable no-empty } diff --git a/packages/server/timers/parent.js b/packages/server/timers/parent.js index bd44be74672e..9726c25a3aa3 100644 --- a/packages/server/timers/parent.js +++ b/packages/server/timers/parent.js @@ -8,7 +8,9 @@ const cp = require('child_process') const path = require('path') -const log = require('debug')('cypress:server:timers') +const debug = require('debug')('cypress:server:timers:parent') +const net = require('net') +const os = require('os') const st = global.setTimeout const si = global.setInterval @@ -39,7 +41,7 @@ function fix () { function sendAndQueue (id, cb, ms, args) { // const started = Date.now() - log('queuing timer id %d after %d ms', id, ms) + debug('queuing timer id %d after %d ms', id, ms) queue[id] = { // started, @@ -62,32 +64,58 @@ function fix () { } function clear (id) { - log('clearing timer id %d from queue %o', id, queue) + debug('clearing timer id %d from queue %o', id, queue) delete queue[id] } // fork the child process - let child = cp.fork(path.join(__dirname, 'child.js'), [], { + let ipc = net.createServer() + const ipcPath = path.join(os.tmpdir(), `cy-timers-${Math.random().toString()}`) + + debug('listening on %o', { ipcPath }) + + let child = cp.spawn('node', [ + path.join(__dirname, 'child.js'), + ipcPath, + ], { stdio: 'inherit', }) - .on('message', (obj = {}) => { - const { id } = obj - const msg = queue[id] + ipc.listen({ + path: ipcPath, + }) - // if we didn't get a msg - // that means we must have - // cleared the timeout already - if (!msg) { - return + ipc.on('connection', (sock) => { + debug('connection received') + child.send = (obj) => { + obj = JSON.stringify(obj) + debug('sending %o', { obj }) + + return sock.write(obj) } - const { cb, args } = msg + sock.on('data', (obj = '{}') => { + debug('received %o', { obj: obj.toString() }) + obj = JSON.parse(obj.toString()) - clear(id) + const { id } = obj - cb(...args) + const msg = queue[id] + + // if we didn't get a msg + // that means we must have + // cleared the timeout already + if (!msg) { + return + } + + const { cb, args } = msg + + clear(id) + + cb(...args) + }) }) // In linux apparently the child process is never From d507f52ed01e40e6a6897c0d9d5300d270053aec Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 12:22:42 -0400 Subject: [PATCH 19/27] Revert "try: using system node for the timers, setting up our own IPC" This reverts commit c51b3957e237c8970390dfec897753ada3702faa. --- packages/server/timers/child.js | 30 +++++------------ packages/server/timers/parent.js | 58 +++++++++----------------------- 2 files changed, 23 insertions(+), 65 deletions(-) diff --git a/packages/server/timers/child.js b/packages/server/timers/child.js index 65a2cc14d6b3..f57b0d5a64d5 100644 --- a/packages/server/timers/child.js +++ b/packages/server/timers/child.js @@ -1,34 +1,20 @@ -const debug = require('debug')('cypress:server:timers:child') -const net = require('net') - -const ipcPath = process.argv.pop() - -const sock = net.createConnection({ - path: ipcPath, -}, () => { - debug('connected to %o', { ipcPath }) -}) - -sock.on('data', (obj = {}) => { - debug('received %o', obj) - obj = JSON.parse(obj.toString()) +const log = require('debug')('cypress:server:timers') +process.on('message', (obj = {}) => { const { id, ms } = obj - debug('child received timer id %d', id) + log('child received timer id %d', id) setTimeout(() => { try { - const outObj = JSON.stringify({ - id, - ms, - }) - - debug('child sending timer id %d %o', id, outObj) + log('child sending timer id %d', id) // process.send could throw if // parent process has already exited - sock.write(outObj) + process.send({ + id, + ms, + }) } catch (err) { // eslint-disable no-empty } diff --git a/packages/server/timers/parent.js b/packages/server/timers/parent.js index 9726c25a3aa3..bd44be74672e 100644 --- a/packages/server/timers/parent.js +++ b/packages/server/timers/parent.js @@ -8,9 +8,7 @@ const cp = require('child_process') const path = require('path') -const debug = require('debug')('cypress:server:timers:parent') -const net = require('net') -const os = require('os') +const log = require('debug')('cypress:server:timers') const st = global.setTimeout const si = global.setInterval @@ -41,7 +39,7 @@ function fix () { function sendAndQueue (id, cb, ms, args) { // const started = Date.now() - debug('queuing timer id %d after %d ms', id, ms) + log('queuing timer id %d after %d ms', id, ms) queue[id] = { // started, @@ -64,58 +62,32 @@ function fix () { } function clear (id) { - debug('clearing timer id %d from queue %o', id, queue) + log('clearing timer id %d from queue %o', id, queue) delete queue[id] } // fork the child process - let ipc = net.createServer() - const ipcPath = path.join(os.tmpdir(), `cy-timers-${Math.random().toString()}`) - - debug('listening on %o', { ipcPath }) - - let child = cp.spawn('node', [ - path.join(__dirname, 'child.js'), - ipcPath, - ], { + let child = cp.fork(path.join(__dirname, 'child.js'), [], { stdio: 'inherit', }) + .on('message', (obj = {}) => { + const { id } = obj - ipc.listen({ - path: ipcPath, - }) + const msg = queue[id] - ipc.on('connection', (sock) => { - debug('connection received') - child.send = (obj) => { - obj = JSON.stringify(obj) - debug('sending %o', { obj }) - - return sock.write(obj) + // if we didn't get a msg + // that means we must have + // cleared the timeout already + if (!msg) { + return } - sock.on('data', (obj = '{}') => { - debug('received %o', { obj: obj.toString() }) - obj = JSON.parse(obj.toString()) + const { cb, args } = msg - const { id } = obj + clear(id) - const msg = queue[id] - - // if we didn't get a msg - // that means we must have - // cleared the timeout already - if (!msg) { - return - } - - const { cb, args } = msg - - clear(id) - - cb(...args) - }) + cb(...args) }) // In linux apparently the child process is never From 1b14a1b8550939129e000040e87381311dfc37a1 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 12:25:53 -0400 Subject: [PATCH 20/27] put the interesting test first --- .../e2e/cypress/integration/fast_visit_spec.coffee | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee b/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee index 64e202a6b45e..8cd449f4b267 100644 --- a/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee +++ b/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee @@ -5,17 +5,17 @@ beforeEach -> return null -it "normally finishes in less than 1000ms on localhost with connection: keep-alive", -> +it "normally finishes in less than 1000ms on localhost with connection: close", -> Cypress._.times 100, -> - cy.visit('/keepalive') + cy.visit('/close') .then -> expect(@lastLog.get("totalTime")).to.be.lte(1000) return undefined -it "normally finishes in less than 1000ms on localhost with connection: close", -> +it "normally finishes in less than 1000ms on localhost with connection: keep-alive", -> Cypress._.times 100, -> - cy.visit('/close') + cy.visit('/keepalive') .then -> expect(@lastLog.get("totalTime")).to.be.lte(1000) From 8b82f0eeb30eec98288308b30b9cf19e3fb595a8 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 12:44:34 -0400 Subject: [PATCH 21/27] use electron-mocha to run tests in electron --- packages/server/package.json | 1 + packages/server/test/scripts/run.js | 6 +++--- packages/server/test/unit/timers_spec.coffee | 3 +++ 3 files changed, 7 insertions(+), 3 deletions(-) diff --git a/packages/server/package.json b/packages/server/package.json index 170d3b842637..d03606b551d5 100644 --- a/packages/server/package.json +++ b/packages/server/package.json @@ -67,6 +67,7 @@ "console-table-printer": "1.0.0-beta12", "cors": "2.8.5", "coveralls": "2.13.3", + "electron-mocha": "^8.0.2", "electron-osx-sign": "0.4.11", "eol": "0.9.1", "eventsource": "1.0.7", diff --git a/packages/server/test/scripts/run.js b/packages/server/test/scripts/run.js index c804473db0bd..bf644f5c2600 100644 --- a/packages/server/test/scripts/run.js +++ b/packages/server/test/scripts/run.js @@ -65,7 +65,7 @@ if (options['inspect-brk']) { } commandAndArguments.args.push( - 'node_modules/.bin/_mocha', + 'node_modules/.bin/electron-mocha', run ) @@ -80,8 +80,8 @@ commandAndArguments.args.push( '--timeout', options['inspect-brk'] ? '40000000' : '10000', '--recursive', - '--compilers', - 'ts:@packages/ts/register,coffee:@packages/coffee/register', + '--require-main', + '@packages/ts/register,@packages/coffee/register', '--reporter', 'mocha-multi-reporters', '--reporter-options', diff --git a/packages/server/test/unit/timers_spec.coffee b/packages/server/test/unit/timers_spec.coffee index a3a93bf88db2..bc088f0fd307 100644 --- a/packages/server/test/unit/timers_spec.coffee +++ b/packages/server/test/unit/timers_spec.coffee @@ -5,6 +5,9 @@ _ = require("lodash") parent = require("#{root}timers/parent") describe "timers/parent", -> + it "tests should be running in electron", -> + expect(process.versions.electron).to.not.be.undefined + context ".fix", -> beforeEach -> parent.restore() From ae439aa61b60169d2018d7f202ca5bdc8e548aa7 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 12:47:38 -0400 Subject: [PATCH 22/27] Revert "use electron-mocha to run tests in electron" This reverts commit 8b82f0eeb30eec98288308b30b9cf19e3fb595a8. --- packages/server/package.json | 1 - packages/server/test/scripts/run.js | 6 +++--- packages/server/test/unit/timers_spec.coffee | 3 --- 3 files changed, 3 insertions(+), 7 deletions(-) diff --git a/packages/server/package.json b/packages/server/package.json index d03606b551d5..170d3b842637 100644 --- a/packages/server/package.json +++ b/packages/server/package.json @@ -67,7 +67,6 @@ "console-table-printer": "1.0.0-beta12", "cors": "2.8.5", "coveralls": "2.13.3", - "electron-mocha": "^8.0.2", "electron-osx-sign": "0.4.11", "eol": "0.9.1", "eventsource": "1.0.7", diff --git a/packages/server/test/scripts/run.js b/packages/server/test/scripts/run.js index bf644f5c2600..c804473db0bd 100644 --- a/packages/server/test/scripts/run.js +++ b/packages/server/test/scripts/run.js @@ -65,7 +65,7 @@ if (options['inspect-brk']) { } commandAndArguments.args.push( - 'node_modules/.bin/electron-mocha', + 'node_modules/.bin/_mocha', run ) @@ -80,8 +80,8 @@ commandAndArguments.args.push( '--timeout', options['inspect-brk'] ? '40000000' : '10000', '--recursive', - '--require-main', - '@packages/ts/register,@packages/coffee/register', + '--compilers', + 'ts:@packages/ts/register,coffee:@packages/coffee/register', '--reporter', 'mocha-multi-reporters', '--reporter-options', diff --git a/packages/server/test/unit/timers_spec.coffee b/packages/server/test/unit/timers_spec.coffee index bc088f0fd307..a3a93bf88db2 100644 --- a/packages/server/test/unit/timers_spec.coffee +++ b/packages/server/test/unit/timers_spec.coffee @@ -5,9 +5,6 @@ _ = require("lodash") parent = require("#{root}timers/parent") describe "timers/parent", -> - it "tests should be running in electron", -> - expect(process.versions.electron).to.not.be.undefined - context ".fix", -> beforeEach -> parent.restore() From 890e38a717fe7bd5915209e182a9156a8bb2b8ce Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 12:51:02 -0400 Subject: [PATCH 23/27] support legacy addRequest invocation --- packages/network/lib/agent.ts | 16 +++++++++++++--- 1 file changed, 13 insertions(+), 3 deletions(-) diff --git a/packages/network/lib/agent.ts b/packages/network/lib/agent.ts index 0173023feb5a..ebc099762df9 100644 --- a/packages/network/lib/agent.ts +++ b/packages/network/lib/agent.ts @@ -138,8 +138,18 @@ export class CombinedAgent { } // called by Node.js whenever a new request is made internally - // TODO: need to support legacy invocation? https://github.com/nodejs/node/blob/cb68c04ce1bc4534b2d92bc7319c6ff6dda0180d/lib/_http_agent.js#L148-L155 - addRequest(req: http.ClientRequest, options: http.RequestOptions) { + addRequest(req: http.ClientRequest, options: http.RequestOptions, port?: number, localAddress?: string) { + // Legacy API: addRequest(req, host, port, localAddress) + // https://github.com/nodejs/node/blob/cb68c04ce1bc4534b2d92bc7319c6ff6dda0180d/lib/_http_agent.js#L148-L155 + if (typeof options === 'string') { + // @ts-ignore + options = { + host: options, + port: port!, + localAddress + } + } + const isHttps = isRequestHttps(options) if (!options.href) { @@ -190,7 +200,7 @@ class HttpAgent extends http.Agent { if (proxy) { options.proxy = proxy - this._addProxiedRequest(req, options) + return this._addProxiedRequest(req, options) } } From 3f077f827dd62ff6c920f42d1baec6715280e4c4 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 13:16:45 -0400 Subject: [PATCH 24/27] Revert "Revert "remove timers"" This reverts commit 93f15fcb172b75f53ea370f16bd6634bebb1c0d0. --- packages/server/index.js | 6 - packages/server/lib/plugins/child/index.js | 5 - packages/server/test/unit/timers_spec.coffee | 112 ------------- packages/server/timers/child.js | 22 --- packages/server/timers/parent.js | 166 ------------------- 5 files changed, 311 deletions(-) delete mode 100644 packages/server/test/unit/timers_spec.coffee delete mode 100644 packages/server/timers/child.js delete mode 100644 packages/server/timers/parent.js diff --git a/packages/server/index.js b/packages/server/index.js index b6bb16cc2dda..f0939077dc10 100644 --- a/packages/server/index.js +++ b/packages/server/index.js @@ -3,12 +3,6 @@ require('./lib/util/stdio').makeAsync() // override tty if we're being forced to require('./lib/util/tty').override() -// if we are running in electron -// we must hack around busted timers -if (process.versions.electron) { - require('./timers/parent').fix() -} - if (process.env.CY_NET_PROFILE && process.env.CYPRESS_ENV) { const netProfiler = require('./lib/util/net_profiler')() diff --git a/packages/server/lib/plugins/child/index.js b/packages/server/lib/plugins/child/index.js index 6de9649b0b4d..34b755b7e6f1 100644 --- a/packages/server/lib/plugins/child/index.js +++ b/packages/server/lib/plugins/child/index.js @@ -1,8 +1,3 @@ -// if we are running in electron -// we must hack around busted timers -if (process.versions.electron) { - require('../../timers/parent').fix() -} require('graceful-fs').gracefulify(require('fs')) require('@packages/coffee/register') require && require.extensions && delete require.extensions['.litcoffee'] diff --git a/packages/server/test/unit/timers_spec.coffee b/packages/server/test/unit/timers_spec.coffee deleted file mode 100644 index a3a93bf88db2..000000000000 --- a/packages/server/test/unit/timers_spec.coffee +++ /dev/null @@ -1,112 +0,0 @@ -require("../spec_helper") - -_ = require("lodash") - -parent = require("#{root}timers/parent") - -describe "timers/parent", -> - context ".fix", -> - beforeEach -> - parent.restore() - @timer = parent.fix() - - describe "setTimeout", -> - it "returns timer object", (done) -> - obj = setTimeout(done, 10) - - expect(obj.id).to.eq(1) - expect(obj.ref).to.be.a("function") - expect(obj.unref).to.be.a("function") - - it "increments timer id", (done) -> - fn = _.after(2, done) - - obj1 = setTimeout(fn, 10) - obj2 = setTimeout(fn, 10) - - expect(obj2.id).to.eq(2) - - it "slices out of queue once cb is invoked", (done) -> - fn = => - expect(@timer.queue).to.deep.eq({}) - done() - - setTimeout(fn, 10) - - expect(@timer.queue[1].cb).to.eq(fn) - - describe "clearTimeout", -> - it "does not explode when passing null", -> - clearTimeout(null) - - it "can clear the timeout and prevent the cb from being invoked", (done) -> - fn = => - done(new Error("should not have been invoked")) - - timer = setTimeout(fn, 10) - - expect(@timer.queue[1].cb).to.eq(fn) - - clearTimeout(timer) - - expect(@timer.queue).to.deep.eq({}) - - setTimeout -> - done() - , 20 - - describe "setInterval", -> - it "returns timer object", (done) -> - obj = setInterval -> - clearInterval(obj) - - done() - , 10 - - expect(obj.id).to.eq(1) - expect(obj.ref).to.be.a("function") - expect(obj.unref).to.be.a("function") - - it "increments timer id", (done) -> - fn = _.after 2, -> - clearInterval(obj1) - clearInterval(obj2) - done() - - obj1 = setInterval(fn, 10) - obj2 = setInterval(fn, 10000) - - expect(obj2.id).to.eq(2) - - it "continuously polls until cleared", (done) -> - poller = _.after 3, => - clearInterval(t) - - setTimeout -> - expect(fn).to.be.calledThrice - done() - , 100 - - fn = sinon.spy(poller) - - t = setInterval(fn, 10) - - describe "clearInterval", -> - it "does not explode when passing null", -> - clearInterval(null) - - it "can clear the interval and prevent the cb from being invoked", (done) -> - fn = => - done(new Error("should not have been invoked")) - - timer = setInterval(fn, 10) - - expect(@timer.queue[1].cb).to.exist - - clearInterval(timer) - - expect(@timer.queue).to.deep.eq({}) - - setTimeout -> - done() - , 20 diff --git a/packages/server/timers/child.js b/packages/server/timers/child.js deleted file mode 100644 index f57b0d5a64d5..000000000000 --- a/packages/server/timers/child.js +++ /dev/null @@ -1,22 +0,0 @@ -const log = require('debug')('cypress:server:timers') - -process.on('message', (obj = {}) => { - const { id, ms } = obj - - log('child received timer id %d', id) - - setTimeout(() => { - try { - log('child sending timer id %d', id) - - // process.send could throw if - // parent process has already exited - process.send({ - id, - ms, - }) - } catch (err) { - // eslint-disable no-empty - } - }, ms) -}) diff --git a/packages/server/timers/parent.js b/packages/server/timers/parent.js deleted file mode 100644 index bd44be74672e..000000000000 --- a/packages/server/timers/parent.js +++ /dev/null @@ -1,166 +0,0 @@ -// electron has completely busted timers resulting in -// all kinds of bizarre timeouts and unresponsive UI -// https://github.com/electron/electron/issues/7079 -// -// this fixes this problem by replacing all the global -// timers and implementing a lightweight queuing mechanism -// involving a forked process - -const cp = require('child_process') -const path = require('path') -const log = require('debug')('cypress:server:timers') - -const st = global.setTimeout -const si = global.setInterval -const ct = global.clearTimeout -const ci = global.clearInterval - -let child = null - -function noop () {} - -function restore () { - // restore - global.setTimeout = st - global.setInterval = si - global.clearTimeout = ct - global.clearInterval = ci - - if (child) { - child.kill() - } - - child = null -} - -function fix () { - const queue = {} - let idCounter = 0 - - function sendAndQueue (id, cb, ms, args) { - // const started = Date.now() - log('queuing timer id %d after %d ms', id, ms) - - queue[id] = { - // started, - args, - ms, - cb, - } - - child.send({ - id, - ms, - }) - - // return the timer object - return { - id, - ref: noop, - unref: noop, - } - } - - function clear (id) { - log('clearing timer id %d from queue %o', id, queue) - - delete queue[id] - } - - // fork the child process - let child = cp.fork(path.join(__dirname, 'child.js'), [], { - stdio: 'inherit', - }) - .on('message', (obj = {}) => { - const { id } = obj - - const msg = queue[id] - - // if we didn't get a msg - // that means we must have - // cleared the timeout already - if (!msg) { - return - } - - const { cb, args } = msg - - clear(id) - - cb(...args) - }) - - // In linux apparently the child process is never - // exiting which causes cypress to hang indefinitely. - // It would **SEEM** as if we... - // 1. dont need to manually kill our child process - // because it should naturally exit. - // (but of course it doesn't in linux) - // 2. use our restore function already defined above. - // however when using the restore function above - // the 'child' reference is null. how is it null? - // it makes no sense. there must be a rip in the - // space time continuum, obviously. that or the - // child reference as the rest of the matter of - // the universe has succumbed to entropy. - process.on('exit', () => { - child && child.kill() - - restore() - }) - - global.setTimeout = function (cb, ms, ...args) { - idCounter += 1 - - return sendAndQueue(idCounter, cb, ms, args) - } - - global.clearTimeout = function (timer) { - if (!timer) { - return - } - - // return undefined per the spec - clear(timer.id) - } - - global.clearInterval = function (timer) { - if (!timer) { - return - } - - // return undefined per the spec - clear(timer.id) - } - - global.setInterval = function (fn, ms, ...args) { - const permId = idCounter += 1 - - function cb () { - // we want to immediately poll again - // because our permId was just cleared - // from the queue stack - poll() - - fn() - } - - function poll () { - return sendAndQueue(permId, cb, ms, args) - } - - return poll() - } - - return { - child, - - queue, - } -} - -module.exports = { - restore, - - fix, -} From 2858a5bb0227b4161075faaa3f745aaa6cc10744 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Tue, 11 Jun 2019 13:18:08 -0400 Subject: [PATCH 25/27] update snapshot --- packages/server/__snapshots__/6_visit_spec.coffee.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/server/__snapshots__/6_visit_spec.coffee.js b/packages/server/__snapshots__/6_visit_spec.coffee.js index 2931715f822b..c43ba6b5a611 100644 --- a/packages/server/__snapshots__/6_visit_spec.coffee.js +++ b/packages/server/__snapshots__/6_visit_spec.coffee.js @@ -845,8 +845,8 @@ You have set the browser to: 'chrome' A video will not be recorded when using this browser. - ✓ normally finishes in less than XX:XX on localhost with connection: keep-alive ✓ normally finishes in less than XX:XX on localhost with connection: close + ✓ normally finishes in less than XX:XX on localhost with connection: keep-alive 2 passing @@ -899,8 +899,8 @@ exports['e2e visit resolves visits quickly in electron (headless) 1'] = ` Running: fast_visit_spec.coffee... (1 of 1) - ✓ normally finishes in less than XX:XX on localhost with connection: keep-alive ✓ normally finishes in less than XX:XX on localhost with connection: close + ✓ normally finishes in less than XX:XX on localhost with connection: keep-alive 2 passing From 47860ca7454721114fc4468b14332b4721f59010 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Wed, 12 Jun 2019 12:04:05 -0400 Subject: [PATCH 26/27] Revert "try making console writes async" This reverts commit 9c8337e4339ee863b0a19c2e267d1e5a0ca34f6d. --- packages/server/index.js | 2 -- packages/server/lib/util/stdio.js | 41 ------------------------------- 2 files changed, 43 deletions(-) delete mode 100644 packages/server/lib/util/stdio.js diff --git a/packages/server/index.js b/packages/server/index.js index f0939077dc10..5eb0509688fd 100644 --- a/packages/server/index.js +++ b/packages/server/index.js @@ -1,5 +1,3 @@ -require('./lib/util/stdio').makeAsync() - // override tty if we're being forced to require('./lib/util/tty').override() diff --git a/packages/server/lib/util/stdio.js b/packages/server/lib/util/stdio.js deleted file mode 100644 index a90cd74804d3..000000000000 --- a/packages/server/lib/util/stdio.js +++ /dev/null @@ -1,41 +0,0 @@ -const _ = require('lodash') -const fs = require('fs') -const tty = require('tty') - -function writeThruAsync (fd) { - return function write (chunk, enc, cb) { - fs.write(fd, chunk, null, enc, cb || _.noop) - } -} - -/** - * Make stdout and stderr consistently act as asynchronous writes, not synchronous. - * Synchronous writes can block the execution of things we actually care about. - * - * https://github.com/cypress-io/cypress/pull/4385#issuecomment-500543325 - * https://nodejs.org/api/process.html#process_a_note_on_process_i_o - */ -function makeAsync () { - if (process.env.DISABLE_ASYNC_STDIO) { - return - } - - if (process.platform === 'win32') { - // TTYs are asynchronous on Windows - return - } - - [ - [1, process.stdout], - [2, process.stderr], - ].map(([fd, str]) => { - if (tty.isatty(fd)) { - // TTYs are synchronous on POSIX, make it async - str.write = writeThruAsync(fd) - } - }) -} - -module.exports = { - makeAsync, -} From bbff24dc6799a2e9464eebff8e1f9ad468fa5635 Mon Sep 17 00:00:00 2001 From: Zach Bloomquist Date: Mon, 17 Jun 2019 11:15:07 -0400 Subject: [PATCH 27/27] complete in 150ms, not 1000ms --- packages/server/__snapshots__/6_visit_spec.coffee.js | 8 ++++---- .../e2e/cypress/integration/fast_visit_spec.coffee | 12 ++++++++---- 2 files changed, 12 insertions(+), 8 deletions(-) diff --git a/packages/server/__snapshots__/6_visit_spec.coffee.js b/packages/server/__snapshots__/6_visit_spec.coffee.js index c43ba6b5a611..df8c81e561e3 100644 --- a/packages/server/__snapshots__/6_visit_spec.coffee.js +++ b/packages/server/__snapshots__/6_visit_spec.coffee.js @@ -845,8 +845,8 @@ You have set the browser to: 'chrome' A video will not be recorded when using this browser. - ✓ normally finishes in less than XX:XX on localhost with connection: close - ✓ normally finishes in less than XX:XX on localhost with connection: keep-alive + ✓ always finishes in less than XX:XX on localhost with connection: close + ✓ always finishes in less than XX:XX on localhost with connection: keep-alive 2 passing @@ -899,8 +899,8 @@ exports['e2e visit resolves visits quickly in electron (headless) 1'] = ` Running: fast_visit_spec.coffee... (1 of 1) - ✓ normally finishes in less than XX:XX on localhost with connection: close - ✓ normally finishes in less than XX:XX on localhost with connection: keep-alive + ✓ always finishes in less than XX:XX on localhost with connection: close + ✓ always finishes in less than XX:XX on localhost with connection: keep-alive 2 passing diff --git a/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee b/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee index 8cd449f4b267..30c739eda404 100644 --- a/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee +++ b/packages/server/test/support/fixtures/projects/e2e/cypress/integration/fast_visit_spec.coffee @@ -5,18 +5,22 @@ beforeEach -> return null -it "normally finishes in less than 1000ms on localhost with connection: close", -> +it "always finishes in less than 150ms on localhost with connection: close", -> + cy.visit('/close') + Cypress._.times 100, -> cy.visit('/close') .then -> - expect(@lastLog.get("totalTime")).to.be.lte(1000) + expect(@lastLog.get("totalTime")).to.be.lte(150) return undefined -it "normally finishes in less than 1000ms on localhost with connection: keep-alive", -> +it "always finishes in less than 150ms on localhost with connection: keep-alive", -> + cy.visit('/close') + Cypress._.times 100, -> cy.visit('/keepalive') .then -> - expect(@lastLog.get("totalTime")).to.be.lte(1000) + expect(@lastLog.get("totalTime")).to.be.lte(150) return undefined