Cypress: Cypress hangs on empty tests files

[paulfalgout]

Current behavior:

In v3 we have a few test files that don't yet contain tests. In v2 it wasn't a problem, and most of the time it's fine in v3. But occasionally Cypress will hang on these files. I've only seen this in CI so far.

In the dashboard these runs still say "running" with an increasing duration, even though they're not.

Further these panels aren't super useful as due to our folder structure every panel is labeled "assets/tests/integrati..." I can resize my screen to see a little more, but never the file name.

Otherwise really loving the v3 direction!

Desired behavior:

Shouldn't hang and should produce better errors if they do.

Steps to reproduce:

Unsure other than empty test files and multiple runs

Versions

Cypress 3.0.1

[paulfalgout]

Related to the "running" status part of this: https://github.com/cypress-io/cypress/issues/1891 Looks like that may be fixed

[jennifer-shehane]

We're updating this entire view in the Dashboard pretty soon. We've been using it and also have not been satisfied with various things like the spec name being cut off!

I created a repo with an empty test file and am unable to recreate an 'error' state. The tests show up as status 'No Tests':

• Do you have any code within the file?
• Do you have any before, after hooks, or code in your support files?
• Do you have any add-on code set up in your plugins file?
• What CI are you running from? When clicking on "See CI logs", what are those logs?

[paulfalgout]

We didn't have any code in the file.. however now i'm seeing it on files with code as well.
There are no hooks in our support files, but we have many Cypress.Commands.adds
We're using @cypress/webpack-preprocessor in plugins but that's it.
We're running travis

  Running: clinicians/clinician-profile.js...                                             (2 of 43) 
No output has been received in the last 10m0s, this potentially indicates a stalled build or something wrong with the build itself.
Check the details on how to adjust your build configuration on: https://docs.travis-ci.com/user/common-build-problems/#Build-times-out-because-no-output-was-received
The build has been terminated

The problem is inconsistent, but when it does fail it seems to be in the same spots. It always seem to fail prior to any tests starting in a new file.
I can't seem to get it to happen locally. Seems like this might be a duplicate of https://github.com/cypress-io/cypress/issues/1912 and https://github.com/cypress-io/cypress/issues/1890 We weren't experiencing this in v2.

There's nothing else really in the log currently. Anyway to force more output for travis?

[paulfalgout]

Definitely this one: https://github.com/cypress-io/cypress/issues/1934

[jennifer-shehane]

The only logging information can be printed by setting DEBUG=cypress:* env var in cypress run

[paulfalgout]

welp if I turn on debug in travis I get The log length has exceeded the limit of 4 MB (this usually means that the test suite is raising the same exception over and over). But I don't think it reaches any error.. just a log of log dump

[paulfalgout]

  (Uploading Results)

  cypress:server:timers queuing timer id 5189 after 30000 ms +77ms
  cypress:server:timers child received timer id 5189 +77ms
  cypress:server:timers queuing timer id 5190 after 10000 ms +4ms
  cypress:server:timers child received timer id 5190 +4ms
  cypress:server:timers clearing timer id 5189 from queue { '5188': { args: [], ms: 85000, cb: [Function] }, '5189': { args: [], ms: 30000, cb: [Function: bound cleanupWebsocketResources] }, '5190': { args: [], ms: 10000, cb: [Function] } } +1ms
  cypress:server:timers clearing timer id 5188 from queue { '5188': { args: [], ms: 85000, cb: [Function] }, '5190': { args: [], ms: 10000, cb: [Function] } } +1ms
  cypress:server:timers clearing timer id 5188 from queue { '5190': { args: [], ms: 10000, cb: [Function] } } +0ms
  cypress:server:timers clearing timer id 5190 from queue { '5190': { args: [], ms: 10000, cb: [Function] } } +12ms
  - Nothing to Upload
  cypress:server:timers queuing timer id 5191 after 10000 ms +268ms
  cypress:server:timers child received timer id 5191 +282ms
  cypress:server:timers child sending timer id 4891 +23ms
  cypress:server:timers clearing timer id 5191 from queue { '5191': { args: [], ms: 10000, cb: [Function] } } +23ms
  cypress:server:timers child sending timer id 4893 +6ms
  cypress:server:timers child sending timer id 4898 +112ms
  cypress:server:timers queuing timer id 5192 after 10000 ms +148ms
  cypress:server:timers child received timer id 5192 +30ms
  cypress:server:timers clearing timer id 5192 from queue { '5192': { args: [], ms: 10000, cb: [Function] } } +14ms
  cypress:server:timers child sending timer id 4899 +38ms
  cypress:server:timers child sending timer id 4900 +2ms
  cypress:server:timers child sending timer id 4901 +45ms
  cypress:server:timers child sending timer id 4902 +32ms
  cypress:server:timers child sending timer id 4903 +1ms
  cypress:server:timers child sending timer id 4904 +1ms
  cypress:server:timers child sending timer id 4905 +2ms
  cypress:server:timers child sending timer id 4906 +56ms

  cypress:server:timers child sending timer id 4907 +1ms
────────────────────────────────────────────────────────────────────────────────────────────────────

  Running: unit.js...                                                                    (43 of 43) 
  cypress:server:timers child sending timer id 4908 +1ms
  cypress:server:timers queuing timer id 5193 after 30000 ms +166ms
  cypress:server:timers child received timer id 5193 +1ms
  cypress:server:timers child sending timer id 4909 +3ms
  cypress:server:timers child sending timer id 4913 +509ms
  cypress:server:timers child sending timer id 4914 +4ms
  cypress:server:timers child sending timer id 4918 +122ms
  cypress:server:timers child sending timer id 4919 +72ms
  cypress:server:timers child sending timer id 4920 +1ms
  cypress:server:timers child sending timer id 4921 +23ms
  cypress:server:timers child sending timer id 4922 +53ms
  cypress:server:timers child sending timer id 4923 +2ms
  cypress:server:timers child sending timer id 4924 +1ms
  cypress:server:timers child sending timer id 4925 +0ms
  cypress:server:timers child sending timer id 4926 +85ms
  cypress:server:timers child sending timer id 4927 +2ms
  cypress:server:timers child sending timer id 4928 +4ms
  cypress:server:timers child sending timer id 4929 +6ms
  cypress:server:timers child sending timer id 4933 +505ms
  cypress:server:timers child sending timer id 4935 +5ms
  cypress:server:timers child sending timer id 4938 +132ms
  cypress:server:timers child sending timer id 4939 +74ms
  cypress:server:timers child sending timer id 4940 +2ms
  cypress:server:timers child sending timer id 4941 +23ms
  cypress:server:timers child sending timer id 4942 +32ms
  cypress:server:timers child sending timer id 4943 +4ms
  cypress:server:timers child sending timer id 4944 +2ms
  cypress:server:timers child sending timer id 4945 +3ms
  cypress:server:timers child sending timer id 4946 +52ms
  cypress:server:timers child sending timer id 4947 +2ms
  cypress:server:timers child sending timer id 4948 +2ms
  cypress:server:timers child sending timer id 4949 +2ms
  cypress:server:timers child sending timer id 4954 +542ms
  cypress:server:timers child sending timer id 4956 +6ms
  cypress:server:timers child sending timer id 4958 +100ms
  cypress:server:timers child sending timer id 4959 +46ms
  cypress:server:timers child sending timer id 4960 +2ms
  cypress:server:timers child sending timer id 4961 +30ms
  cypress:server:timers child sending timer id 4962 +31ms
  cypress:server:timers child sending timer id 4963 +1ms
  cypress:server:timers child sending timer id 4964 +2ms
  cypress:server:timers child sending timer id 4965 +3ms
  cypress:server:timers child sending timer id 4966 +81ms
  cypress:server:timers child sending timer id 4967 +8ms
  cypress:server:timers child sending timer id 4968 +2ms
  cypress:server:timers child sending timer id 4969 +3ms
  cypress:server:timers child sending timer id 4977 +625ms
  cypress:server:timers child sending timer id 5135 +262ms
  cypress:server:timers child sending timer id 5136 +299ms
  cypress:server:timers child sending timer id 5137 +228ms
  cypress:server:timers child sending timer id 4981 +673ms
  cypress:server:timers child sending timer id 4492 +2s
  cypress:server:timers child sending timer id 4493 +52ms
  cypress:server:timers child sending timer id 5010 +60ms
  cypress:server:timers child sending timer id 4494 +4ms
  cypress:server:timers child sending timer id 4495 +1ms
  cypress:server:timers child sending timer id 4496 +1ms
  cypress:server:timers child sending timer id 5011 +43ms
  cypress:server:timers child sending timer id 5012 +8ms
  cypress:server:timers child sending timer id 4497 +37ms
  cypress:server:timers child sending timer id 5013 +77ms
  cypress:server:timers child sending timer id 5014 +75ms
  cypress:server:timers child sending timer id 5015 +1ms
  cypress:server:timers child sending timer id 5016 +2ms
  cypress:server:timers child sending timer id 5017 +2ms
  cypress:server:timers child sending timer id 5018 +192ms
  cypress:server:timers child sending timer id 5019 +2ms
  cypress:server:timers child sending timer id 5020 +3ms
  cypress:server:timers child sending timer id 5021 +3ms
  cypress:server:timers child sending timer id 5028 +1s
  cypress:server:timers child sending timer id 5032 +691ms
  cypress:server:timers child sending timer id 5190 +342ms
  cypress:server:timers child sending timer id 5191 +282ms
  cypress:server:timers child sending timer id 5192 +171ms
  cypress:server:timers child sending timer id 4510 +723ms
  cypress:server:timers child sending timer id 4511 +38ms
  cypress:server:timers child sending timer id 4512 +17ms
  cypress:server:timers child sending timer id 4513 +4ms
  cypress:server:timers child sending timer id 4514 +3ms
  cypress:server:timers child sending timer id 4515 +122ms
  cypress:server:timers child sending timer id 5062 +954ms
  cypress:server:timers child sending timer id 5063 +63ms
  cypress:server:timers child sending timer id 5064 +5ms
  cypress:server:timers child sending timer id 5065 +107ms
  cypress:server:timers child sending timer id 5066 +36ms
  cypress:server:timers child sending timer id 5067 +3ms
  cypress:server:timers child sending timer id 5068 +9ms
  cypress:server:timers child sending timer id 5069 +3ms
  cypress:server:timers child sending timer id 5070 +169ms
  cypress:server:timers child sending timer id 5071 +12ms
  cypress:server:timers child sending timer id 5072 +3ms
  cypress:server:timers child sending timer id 5073 +49ms
  cypress:server:timers child sending timer id 4528 +2s
  cypress:server:timers child sending timer id 4529 +35ms
  cypress:server:timers child sending timer id 4530 +22ms
  cypress:server:timers child sending timer id 4531 +6ms
  cypress:server:timers child sending timer id 4532 +15ms
  cypress:server:timers child sending timer id 4533 +143ms
  cypress:server:timers child sending timer id 5074 +3s
  cypress:server:timers child sending timer id 5075 +16ms
  cypress:server:timers child sending timer id 5083 +635ms
  cypress:server:timers child sending timer id 5086 +1s
  cypress:server:timers child sending timer id 4546 +20ms
  cypress:server:timers child sending timer id 4547 +847ms
  cypress:server:timers child sending timer id 4548 +33ms
  cypress:server:timers child sending timer id 4549 +91ms
  cypress:server:timers child sending timer id 4550 +1ms
  cypress:server:timers child sending timer id 4551 +2ms
  cypress:server:timers child sending timer id 4552 +118ms
  cypress:server:timers child sending timer id 5116 +1s
  cypress:server:timers child sending timer id 5117 +64ms
  cypress:server:timers child sending timer id 5118 +3ms
  cypress:server:timers child sending timer id 5119 +95ms
  cypress:server:timers child sending timer id 5120 +43ms
  cypress:server:timers child sending timer id 5121 +3ms
  cypress:server:timers child sending timer id 5122 +3ms
  cypress:server:timers child sending timer id 5123 +2ms
  cypress:server:timers child sending timer id 5124 +247ms
  cypress:server:timers child sending timer id 5125 +2ms
  cypress:server:timers child sending timer id 5126 +2ms
  cypress:server:timers child sending timer id 5127 +3ms
  cypress:server:timers child sending timer id 5134 +2s
  cypress:server:timers child sending timer id 5138 +728ms
  cypress:server:timers child sending timer id 5171 +3s
  cypress:server:timers child sending timer id 5172 +55ms
  cypress:server:timers child sending timer id 5173 +3ms
  cypress:server:timers child sending timer id 5174 +84ms
  cypress:server:timers child sending timer id 5175 +68ms
  cypress:server:timers child sending timer id 5176 +2ms
  cypress:server:timers child sending timer id 5177 +3ms
  cypress:server:timers child sending timer id 5178 +2ms
  cypress:server:timers child sending timer id 5179 +173ms
  cypress:server:timers child sending timer id 5180 +2ms
  cypress:server:timers child sending timer id 5181 +2ms
  cypress:server:timers child sending timer id 5182 +36ms
  cypress:server:timers child sending timer id 4565 +1s
  cypress:server:timers child sending timer id 4566 +45ms
  cypress:server:timers child sending timer id 4567 +90ms
  cypress:server:timers child sending timer id 4568 +7ms
  cypress:server:timers child sending timer id 4569 +7ms
  cypress:server:timers child sending timer id 4570 +5ms
  cypress:server:timers child sending timer id 4571 +3ms
  cypress:server:timers child sending timer id 5189 +695ms
  cypress:server:timers child sending timer id 5193 +636ms
  cypress:server:timers child sending timer id 4578 +450ms
  cypress:server:timers child sending timer id 4579 +69ms
  cypress:server:timers child sending timer id 4580 +36ms
  cypress:server:timers child sending timer id 4582 +73ms
  cypress:server:timers child sending timer id 4583 +70ms
  cypress:server:timers child sending timer id 4584 +1ms
  cypress:server:timers child sending timer id 4585 +534ms
  cypress:server:timers child sending timer id 4586 +13ms
  cypress:server:timers child sending timer id 4587 +22ms
  cypress:server:timers child sending timer id 4588 +1ms
  cypress:server:timers child sending timer id 4589 +44ms
  cypress:server:timers child sending timer id 4590 +2ms
  cypress:server:timers child sending timer id 4591 +1ms
  cypress:server:timers child sending timer id 4592 +1ms
  cypress:server:timers child sending timer id 4593 +17ms
  cypress:server:timers child sending timer id 4594 +85ms
  cypress:server:timers child sending timer id 4595 +59ms
  cypress:server:timers child sending timer id 4596 +31ms
  cypress:server:timers child sending timer id 4597 +116ms
  cypress:server:timers child sending timer id 4598 +6ms
  cypress:server:timers child sending timer id 4599 +28ms
  cypress:server:timers child sending timer id 4600 +104ms
  cypress:server:timers child sending timer id 4601 +166ms
  cypress:server:timers child sending timer id 4602 +17ms
  cypress:server:timers child sending timer id 4603 +5ms
  cypress:server:timers child sending timer id 4604 +8ms
  cypress:server:timers child sending timer id 4605 +17ms
  cypress:server:timers child sending timer id 4606 +15ms
  cypress:server:timers child sending timer id 4607 +121ms
  cypress:server:timers child sending timer id 4608 +16ms
  cypress:server:timers child sending timer id 4609 +40ms
  cypress:server:timers child sending timer id 4610 +4ms
  cypress:server:timers child sending timer id 4611 +26ms
  cypress:server:timers child sending timer id 4612 +56ms
  cypress:server:timers child sending timer id 4625 +1s
  cypress:server:timers child sending timer id 4626 +1s
  cypress:server:timers child sending timer id 4627 +2ms
  cypress:server:timers child sending timer id 4628 +0ms
  cypress:server:timers child sending timer id 4629 +1ms
  cypress:server:timers child sending timer id 4630 +30ms
  cypress:server:timers child sending timer id 4631 +11ms
  cypress:server:timers child sending timer id 4632 +8ms
  cypress:server:timers child sending timer id 4633 +5ms
  cypress:server:timers child sending timer id 4634 +106ms
  cypress:server:timers child sending timer id 4647 +977ms
  cypress:server:timers child sending timer id 4648 +1s
  cypress:server:timers child sending timer id 4649 +11ms
  cypress:server:timers child sending timer id 4650 +6ms
  cypress:server:timers child sending timer id 4651 +6ms
  cypress:server:timers child sending timer id 4652 +40ms
  cypress:server:timers child sending timer id 4653 +5ms
  cypress:server:timers child sending timer id 4654 +5ms
  cypress:server:timers child sending timer id 4655 +5ms
  cypress:server:timers child sending timer id 4656 +127ms
  cypress:server:timers child sending timer id 4669 +980ms
  cypress:server:timers child sending timer id 4671 +1s
  cypress:server:timers child sending timer id 4672 +20ms
  cypress:server:timers child sending timer id 4673 +10ms
  cypress:server:timers child sending timer id 4674 +6ms
  cypress:server:timers child sending timer id 4675 +59ms
  cypress:server:timers child sending timer id 4676 +4ms
  cypress:server:timers child sending timer id 4677 +3ms
  cypress:server:timers child sending timer id 4678 +6ms
  cypress:server:timers child sending timer id 4679 +106ms
  cypress:server:timers child sending timer id 4692 +852ms
  cypress:server:timers child sending timer id 4694 +2s
  cypress:server:timers child sending timer id 4695 +9ms
  cypress:server:timers child sending timer id 4696 +7ms
  cypress:server:timers child sending timer id 4697 +13ms
  cypress:server:timers child sending timer id 4698 +9ms
  cypress:server:timers child sending timer id 4699 +3ms
  cypress:server:timers child sending timer id 4700 +4ms
  cypress:server:timers child sending timer id 4701 +7ms
  cypress:server:timers child sending timer id 4708 +2s
  cypress:server:timers child sending timer id 4709 +92ms
  cypress:server:timers child sending timer id 4710 +35ms
  cypress:server:timers child sending timer id 4712 +98ms
  cypress:server:timers child sending timer id 4713 +77ms
  cypress:server:timers child sending timer id 4714 +4ms
  cypress:server:timers child sending timer id 4715 +416ms
  cypress:server:timers child sending timer id 4716 +25ms
  cypress:server:timers child sending timer id 4717 +41ms
  cypress:server:timers child sending timer id 4718 +4ms
  cypress:server:timers child sending timer id 4719 +65ms
  cypress:server:timers child sending timer id 4720 +37ms
  cypress:server:timers child sending timer id 4721 +6ms
  cypress:server:timers child sending timer id 4722 +22ms
  cypress:server:timers child sending timer id 4723 +98ms
  cypress:server:timers child sending timer id 4724 +67ms
  cypress:server:timers child sending timer id 4725 +63ms
  cypress:server:timers child sending timer id 4726 +119ms
  cypress:server:timers child sending timer id 4727 +86ms
  cypress:server:timers child sending timer id 4728 +14ms
  cypress:server:timers child sending timer id 4729 +14ms
  cypress:server:timers child sending timer id 4730 +20ms
  cypress:server:timers child sending timer id 4731 +15ms
  cypress:server:timers child sending timer id 4732 +17ms
  cypress:server:timers child sending timer id 4733 +141ms
  cypress:server:timers child sending timer id 4734 +4ms
  cypress:server:timers child sending timer id 4735 +15ms
  cypress:server:timers child sending timer id 4736 +5ms
  cypress:server:timers child sending timer id 4737 +23ms
  cypress:server:timers child sending timer id 4738 +46ms
  cypress:server:timers child sending timer id 4751 +1s
  cypress:server:timers child sending timer id 4752 +233ms
  cypress:server:timers child sending timer id 4753 +70ms
  cypress:server:timers child sending timer id 4754 +13ms
  cypress:server:timers child sending timer id 4755 +12ms
  cypress:server:timers child sending timer id 4758 +147ms
  cypress:server:timers child sending timer id 4771 +2s
  cypress:server:timers child sending timer id 4772 +39ms
  cypress:server:timers child sending timer id 4773 +5ms
  cypress:server:timers child sending timer id 4774 +5ms
  cypress:server:timers child sending timer id 4775 +4ms
  cypress:server:timers child sending timer id 4776 +120ms
  cypress:server:timers child sending timer id 4789 +678ms
  cypress:server:timers child sending timer id 4790 +37ms
  cypress:server:timers child sending timer id 4791 +36ms
  cypress:server:timers child sending timer id 4794 +17ms
  cypress:server:timers child sending timer id 4795 +8ms
  cypress:server:timers child sending timer id 4796 +135ms
  cypress:server:timers child sending timer id 4809 +635ms
  cypress:server:timers child sending timer id 4810 +39ms
  cypress:server:timers child sending timer id 4811 +1ms
  cypress:server:timers child sending timer id 4812 +1ms
  cypress:server:timers child sending timer id 4813 +11ms
  cypress:server:timers child sending timer id 4816 +121ms
  cypress:server:timers child sending timer id 4829 +843ms
  cypress:server:timers child sending timer id 4830 +11ms
  cypress:server:timers child sending timer id 4831 +50ms
  cypress:server:timers child sending timer id 4834 +19ms
  cypress:server:timers child sending timer id 4835 +10ms
  cypress:server:timers child sending timer id 4836 +131ms
  cypress:server:timers child sending timer id 4849 +592ms
  cypress:server:timers child sending timer id 4850 +39ms
  cypress:server:timers child sending timer id 4853 +20ms
  cypress:server:timers child sending timer id 4854 +11ms
  cypress:server:timers child sending timer id 4855 +10ms
  cypress:server:timers child sending timer id 4856 +93ms
  cypress:server:timers child sending timer id 4869 +684ms
  cypress:server:timers child sending timer id 4870 +36ms
  cypress:server:timers child sending timer id 4871 +21ms
  cypress:server:timers child sending timer id 4872 +6ms
  cypress:server:timers child sending timer id 4875 +22ms
  cypress:server:timers child sending timer id 4876 +100ms
  cypress:server:timers child sending timer id 4889 +727ms
  cypress:server:timers child sending timer id 4890 +35ms
  cypress:server:timers child sending timer id 4892 +45ms
  cypress:server:timers child sending timer id 4894 +12ms
  cypress:server:timers child sending timer id 4895 +11ms
  cypress:server:timers child sending timer id 4896 +6ms
  cypress:server:timers child sending timer id 4897 +78ms
  cypress:server:timers child sending timer id 4910 +672ms
  cypress:server:timers child sending timer id 4911 +39ms
  cypress:server:timers child sending timer id 4912 +11ms
  cypress:server:timers child sending timer id 4915 +20ms
  cypress:server:timers child sending timer id 4916 +10ms
  cypress:server:timers child sending timer id 4917 +96ms
  cypress:server:timers child sending timer id 4930 +701ms
  cypress:server:timers child sending timer id 4931 +35ms
  cypress:server:timers child sending timer id 4932 +17ms
  cypress:server:timers child sending timer id 4934 +10ms
  cypress:server:timers child sending timer id 4936 +23ms
  cypress:server:timers child sending timer id 4937 +104ms
  cypress:server:timers child sending timer id 4950 +691ms
  cypress:server:timers child sending timer id 4951 +37ms
  cypress:server:timers child sending timer id 4952 +9ms
  cypress:server:timers child sending timer id 4953 +1ms
  cypress:server:timers child sending timer id 4955 +14ms
  cypress:server:timers child sending timer id 4957 +94ms
  cypress:server:timers child sending timer id 4970 +716ms
  cypress:server:timers child sending timer id 4971 +61ms
  cypress:server:timers child sending timer id 4972 +1ms
  cypress:server:timers child sending timer id 4973 +1ms
  cypress:server:timers child sending timer id 4974 +3ms
  cypress:server:timers child sending timer id 4975 +6ms
  cypress:server:timers child sending timer id 4976 +1ms
  cypress:server:timers child sending timer id 4983 +3s
  cypress:server:timers child sending timer id 4984 +82ms
  cypress:server:timers child sending timer id 4985 +34ms
  cypress:server:timers child sending timer id 4987 +101ms
  cypress:server:timers child sending timer id 4988 +66ms
  cypress:server:timers child sending timer id 4989 +0ms
  cypress:server:timers child sending timer id 4990 +333ms
  cypress:server:timers child sending timer id 4991 +12ms
  cypress:server:timers child sending timer id 4992 +19ms
  cypress:server:timers child sending timer id 4993 +2ms
  cypress:server:timers child sending timer id 4994 +50ms
  cypress:server:timers child sending timer id 4995 +3ms
  cypress:server:timers child sending timer id 4996 +3ms
  cypress:server:timers child sending timer id 4997 +46ms
  cypress:server:timers child sending timer id 4998 +103ms
  cypress:server:timers child sending timer id 4999 +31ms
  cypress:server:timers child sending timer id 5000 +21ms
  cypress:server:timers child sending timer id 5001 +32ms
  cypress:server:timers child sending timer id 5002 +42ms
  cypress:server:timers child sending timer id 5003 +14ms
  cypress:server:timers child sending timer id 5004 +65ms
  cypress:server:timers child sending timer id 5005 +7ms
  cypress:server:timers child sending timer id 5006 +10ms
  cypress:server:timers child sending timer id 5007 +4ms
  cypress:server:timers child sending timer id 5008 +29ms
  cypress:server:timers child sending timer id 5009 +86ms
  cypress:server:timers child sending timer id 5022 +1s
  cypress:server:timers child sending timer id 5023 +28ms
  cypress:server:timers child sending timer id 5024 +6ms
  cypress:server:timers child sending timer id 5025 +8ms
  cypress:server:timers child sending timer id 5026 +4ms
  cypress:server:timers child sending timer id 5027 +4ms
  cypress:server:timers child sending timer id 5034 +2s
  cypress:server:timers child sending timer id 5035 +93ms
  cypress:server:timers child sending timer id 5036 +39ms
  cypress:server:timers child sending timer id 5038 +107ms
  cypress:server:timers child sending timer id 5039 +69ms
  cypress:server:timers child sending timer id 5040 +5ms
  cypress:server:timers child sending timer id 5041 +564ms
  cypress:server:timers child sending timer id 5042 +16ms
  cypress:server:timers child sending timer id 5043 +19ms
  cypress:server:timers child sending timer id 5044 +3ms
  cypress:server:timers child sending timer id 5045 +50ms
  cypress:server:timers child sending timer id 5046 +13ms
  cypress:server:timers child sending timer id 5047 +4ms
  cypress:server:timers child sending timer id 5048 +18ms
  cypress:server:timers child sending timer id 5049 +231ms
  cypress:server:timers child sending timer id 5050 +32ms
  cypress:server:timers child sending timer id 5051 +8ms
  cypress:server:timers child sending timer id 5052 +13ms
  cypress:server:timers child sending timer id 5053 +21ms
  cypress:server:timers child sending timer id 5054 +17ms
  cypress:server:timers child sending timer id 5055 +16ms
  cypress:server:timers child sending timer id 5056 +146ms
  cypress:server:timers child sending timer id 5057 +8ms
  cypress:server:timers child sending timer id 5058 +22ms
  cypress:server:timers child sending timer id 5059 +17ms
  cypress:server:timers child sending timer id 5060 +39ms
  cypress:server:timers child sending timer id 5061 +95ms
  cypress:server:timers child sending timer id 5076 +6s
  cypress:server:timers child sending timer id 5077 +162ms
  cypress:server:timers child sending timer id 5078 +45ms
  cypress:server:timers child sending timer id 5079 +6ms
  cypress:server:timers child sending timer id 5080 +5ms
  cypress:server:timers child sending timer id 5081 +1ms
  cypress:server:timers child sending timer id 5088 +2s
  cypress:server:timers child sending timer id 5089 +67ms
  cypress:server:timers child sending timer id 5090 +36ms
  cypress:server:timers child sending timer id 5092 +71ms
  cypress:server:timers child sending timer id 5093 +67ms
  cypress:server:timers child sending timer id 5094 +7ms
  cypress:server:timers child sending timer id 5095 +300ms
  cypress:server:timers child sending timer id 5096 +11ms
  cypress:server:timers child sending timer id 5097 +19ms
  cypress:server:timers child sending timer id 5098 +2ms
  cypress:server:timers child sending timer id 5099 +52ms
  cypress:server:timers child sending timer id 5100 +3ms
  cypress:server:timers child sending timer id 5101 +0ms
  cypress:server:timers child sending timer id 5102 +33ms
  cypress:server:timers child sending timer id 5103 +221ms
  cypress:server:timers child sending timer id 5104 +43ms
  cypress:server:timers child sending timer id 5105 +11ms
  cypress:server:timers child sending timer id 5106 +9ms
  cypress:server:timers child sending timer id 5107 +11ms
  cypress:server:timers child sending timer id 5108 +11ms
  cypress:server:timers child sending timer id 5109 +10ms
  cypress:server:timers child sending timer id 5110 +67ms
  cypress:server:timers child sending timer id 5111 +4ms
  cypress:server:timers child sending timer id 5112 +19ms
  cypress:server:timers child sending timer id 5113 +15ms
  cypress:server:timers child sending timer id 5114 +38ms
  cypress:server:timers child sending timer id 5115 +88ms
  cypress:server:timers child sending timer id 5128 +2s
  cypress:server:timers child sending timer id 5129 +73ms
  cypress:server:timers child sending timer id 5130 +17ms
  cypress:server:timers child sending timer id 5131 +6ms
  cypress:server:timers child sending timer id 5132 +6ms
  cypress:server:timers child sending timer id 5133 +7ms
  cypress:server:timers child sending timer id 5140 +2s
  cypress:server:timers child sending timer id 5141 +89ms
  cypress:server:timers child sending timer id 5142 +37ms
  cypress:server:timers child sending timer id 5144 +101ms
  cypress:server:timers child sending timer id 5145 +67ms
  cypress:server:timers child sending timer id 5146 +3ms
  cypress:server:timers child sending timer id 5147 +371ms
  cypress:server:timers child sending timer id 5148 +14ms
  cypress:server:timers child sending timer id 5149 +19ms
  cypress:server:timers child sending timer id 5150 +2ms
  cypress:server:timers child sending timer id 5151 +51ms
  cypress:server:timers child sending timer id 5152 +1ms
  cypress:server:timers child sending timer id 5153 +1ms
  cypress:server:timers child sending timer id 5154 +24ms
  cypress:server:timers child sending timer id 5155 +35ms
  cypress:server:timers child sending timer id 5156 +67ms
  cypress:server:timers child sending timer id 5157 +62ms
  cypress:server:timers child sending timer id 5158 +39ms
  cypress:server:timers child sending timer id 5159 +136ms
  cypress:server:timers child sending timer id 5160 +35ms
  cypress:server:timers child sending timer id 5161 +16ms
  cypress:server:timers child sending timer id 5162 +20ms
  cypress:server:timers child sending timer id 5163 +16ms
  cypress:server:timers child sending timer id 5164 +14ms
  cypress:server:timers child sending timer id 5165 +124ms
  cypress:server:timers child sending timer id 5166 +6ms
  cypress:server:timers child sending timer id 5167 +19ms
  cypress:server:timers child sending timer id 5168 +15ms
  cypress:server:timers child sending timer id 5169 +39ms
  cypress:server:timers child sending timer id 5170 +86ms
  cypress:server:timers child sending timer id 5183 +3s
  cypress:server:timers child sending timer id 5184 +30ms
  cypress:server:timers child sending timer id 5185 +39ms
  cypress:server:timers child sending timer id 5186 +4ms
  cypress:server:timers child sending timer id 5187 +4ms
  cypress:server:timers child sending timer id 5188 +3ms


No output has been received in the last 10m0s, this potentially indicates a stalled build or something wrong with the build itself.
Check the details on how to adjust your build configuration on: https://docs.travis-ci.com/user/common-build-problems/#Build-times-out-because-no-output-was-received

The build has been terminated

tried just logging cypress:server:timers

[paulfalgout]

not sure what to log.. can't log everything as travis can't handle it.. without logging nothing is displayed and no tests start for the file it crashes on.. doesn't happen on any particular file consistently. Always after Running: some-file.js and never before any test runs

[brian-mann]

@paulfalgout I don't think you need to do anything. We've collected data from about 4 other situations that are experiencing the same bug.

We're working on it now. We believe it has to do with a file lock never releasing, which causes a Promise to hang that never resolves.

Can you try to run your tests in Chrome? We believe this problem only has to do with Electron, but don't quote me on that just yet.

[brian-mann]

Most definitely the same issue as this: https://github.com/cypress-io/cypress/issues/1912 and https://github.com/withspectrum/spectrum/pull/3334#issuecomment-397671374 which failed in Circle job: https://circleci.com/gh/withspectrum/spectrum/8642

We also have reports from two other organizations with the same problem.

[paulfalgout]

👍 ok trying chrome

[paulfalgout]

@brian-mann yep so this time a couple of times it said Timed out waiting for the browser to connect. Retrying... but it finished 🎉 It also seems to be faster. I think at least for me for now, this is resolved.

[paulfalgout]

v3 never fails with the browser set to chrome, but runs are averaging between 15-18 mins. In v2 we were getting between 5-7 mins. For the moment we're reverting.

[brian-mann]

We have noticed that Chrome does indeed run faster. The v3 performance problems are a separate issue altogether that we are looking at. We believe we have the fixes for the spec file just hanging as per this PR: https://github.com/cypress-io/cypress/pull/2020

[paulfalgout]

Good deal thanks. I'll follow that PR and re-upgrade when it's released

[brian-mann]

Released in 3.0.2.

[kamituel]

I'm sorry to be the bearer of bad news, but I think this remains an issue on 3.0.2 (I didn't take part in this discussion, but we've been experiencing it since at least 3.0.1 - not sure about 3.0.0).

Our build hang 4 times out of 10 runs today.

Here are some clues I've noticed (or might be useful):

1. When running with DEBUG=cypress:*, test runs hang less frequently.

2. From all the times I've managed to capture logs of it hanging, the last meaningful log message always is (this is a log from 3.0.1, I didn't yet manage to capture it on 3.0.2, so an extra logging added in #2013 isn't here):

cypress:server:file reading JSON file /root/.config/Cypress/cy/production/projects/project-name-71948c40449279172805d15f83be086b/state.json

All the subsequent log statements are like this:

cypress:server:timers child sending timer id 903
cypress:server:timers child sending timer id 920
cypress:server:timers child sending timer id 921
cypress:server:timers child sending timer id 922
cypress:server:timers child sending timer id 924

1. This led me to open() in server/lib/browsers/electron.coffee. There's a promise there that either resolves immediately with a concrete value of the options map, or invokes the before:browser:launch and returns a promise. We've not been using this hook, so I added a dummy one. This seems to decrease the likelihood of test run hanging, but doesn't fix it completely (got 1 hang out of 10 test runs today, compared to 4 hangs without this plugin - but the sample size is small, so it might've been a chance).

2. Our Cypress tests are a bit unorthodox in that some spec files are empty (have no describe()'s). That's a long story, and I don't have any reason to believe that's the source of the issue - mentioning this just in case it's relevant.

We're using Bamboo, with Cypress running within a Docker container (custom image, not based on images provided by Cypress).

We can't upgrade to Cypress 3.0.x because of that :/ so I'll be grateful for any tips. I'll be also happy to help debug this, if needed.

[kamituel]

Oh, I actually managed to capture logs on 3.0.2 just now.

Here's the log for the suite that hanged:

  Running: <obscured>.js...                                                      (17 of 18)
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:run about to run spec { spec: { name: '<obscured>.js', relative: 'cypress/integration/<obscured>.js', absolute: '/<obscured>/cypress/integration/<obscured>.js' }, isHeadless: true, browserName: 'electron' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture started { command: 'ffmpeg -n 20 /root/.cache/Cypress/3.0.2/Cypress/resources/app/packages/server/node_modules/@ffmpeg-installer/linux-x64/ffmpeg -f image2pipe -use_wallclock_as_timestamps 1 -i pipe:0 -y -vcodec libx264 -preset ultrafast /results/videos/<obscured>js.mp4' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:openproject resetting project state, preparing to launch browser
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:project resetting project instance <obscured>
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:server Setting remoteAuth undefined
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:server Setting remoteOrigin http://localhost:44476
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:server Setting remoteStrategy file
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:server Setting remoteHostAndPort null
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:server Setting remoteDocDomain localhost
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:server Setting remoteFileServer http://localhost:48398
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:server Getting remote state: { auth: undefined, props: null, origin: 'http://localhost:44476', strategy: 'file', visiting: false, domainName: 'localhost', fileServer: 'http://localhost:48398' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:timers queuing timer id 273 after 30000 ms
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:openproject launching browser: electron, spec: cypress/integration/<obscured>.js
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:timers child received timer id 273
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:browsers opening browser electron
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:saved_state noop saved state
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: 'ffmpeg version N-45896-g19c3df0cd-static https://johnvansickle.com/ffmpeg/  Copyright (c) 2000-2018 the FFmpeg developers' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  built with gcc 6.3.0 (Debian 6.3.0-18+deb9u1) 20170516' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  configuration: --enable-gpl --enable-version3 --enable-static --disable-debug --disable-ffplay --disable-indev=sndio --disable-outdev=sndio --cc=gcc-6 --enable-fontconfig --enable-frei0r --enable-gnutls --enable-gray --enable-libaom --enable-libfribidi --enable-libass --enable-libvmaf --enable-libfreetype --enable-libmp3lame --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-librubberband --enable-libsoxr --enable-libspeex --enable-libvorbis --enable-libopus --enable-libtheora --enable-libvidstab --enable-libvo-amrwbenc --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzimg' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  libavutil      56. 17.100 / 56. 17.100' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  libavcodec     58. 19.100 / 58. 19.100' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  libavformat    58. 13.100 / 58. 13.100' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  libavdevice    58.  4.100 / 58.  4.100' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  libavfilter     7. 20.100 /  7. 20.100' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  libswscale      5.  2.100 /  5.  2.100' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  libswresample   3.  2.100 /  3.  2.100' }
Mon, 02 Jul 2018 12:54:23 GMT cypress:server:video capture stderr log { message: '  libpostproc    55.  2.100 / 55.  2.100' }
Mon, 02 Jul 2018 12:54:24 GMT cypress:server:timers child sending timer id 166
Mon, 02 Jul 2018 12:54:26 GMT cypress:server:timers child sending timer id 179
Mon, 02 Jul 2018 12:54:27 GMT cypress:server:timers child sending timer id 180
Mon, 02 Jul 2018 12:54:30 GMT cypress:server:timers child sending timer id 193
Mon, 02 Jul 2018 12:54:31 GMT cypress:server:timers child sending timer id 194
Mon, 02 Jul 2018 12:54:33 GMT cypress:server:timers child sending timer id 207
Mon, 02 Jul 2018 12:54:34 GMT cypress:server:timers child sending timer id 208
Mon, 02 Jul 2018 12:54:36 GMT cypress:server:timers child sending timer id 221
Mon, 02 Jul 2018 12:54:37 GMT cypress:server:timers child sending timer id 222
Mon, 02 Jul 2018 12:54:40 GMT cypress:server:timers child sending timer id 240
Mon, 02 Jul 2018 12:54:40 GMT cypress:server:timers child sending timer id 241
Mon, 02 Jul 2018 12:54:40 GMT cypress:server:timers child sending timer id 242
... (many more logs from cypress:sever:timers) ...

[kamituel]

@brian-mann @jennifer-shehane I see this issue has been removed from 3.0.2 milestone and closed again. What does it mean? Last time I heard, there were plans to add more verbose logging and let us run this to reproduce. Is it still the case? Is it going to happen on 3.0.2?

[jennifer-shehane]

@kamituel The fix did not make it into 3.0.2 and is instead included in version 3.0.3 - which is pending release. We close issues that have a closed PR associated with it, so be on the lookout for 3.0.3 official release here soon.

[paulfalgout]

So I've tried upgrading to 3.0.3. I'm running --browser chrome and I'm running video: false.

So far I haven't seen any outright failures, but I'm still getting quite a bit of:

Timed out waiting for the browser to connect. Retrying...
Timed out waiting for the browser to connect. Retrying again...

And when these happen the tests are way slower than they were in 2.x. It's usually over double the run time, but I'm not sure why.

Any ideas?

Insights says 45 spec files ran for 04:26 but duration was 17:38
Pervious run in 2.1.0 said all specs ran in 04:48 but the duration was 05:24

Also as far as I can tell the time outs are unrelated to what's in the spec file. Some had 1 test some had many. Multiple runs has timeouts on different spec files. I get timeouts basically every time, but it's not consistently reproducible.

[paulfalgout]

Found one thing. If chrome stable isn't explicitly set on travis it uses chromium 62 which seems to perform _much_ worse than chrome 68. https://docs.travis-ci.com/user/chrome#selecting-a-chrome-version

It seems to be doing a little bit better.. though I'm not through the first run yet and it's still quite a bit slower.

[paulfalgout]

I think part of the reason it's slow is because it re-runs webpack every time. We are using quite a few plugins and so our webpack isn't exactly quick. Wasn't a problem in v2 I think because it packed at the beginning, but it's a lot of overhead to rerun it each time.

[paulfalgout]

No optimization I tried with the webpack preprocessor made any difference. It also ran quite a bit slower on CI than locally.

I'm sure this defeats the purpose of the split in v3, and it certainly makes the dashboard less pretty but.. if I serialize all of the tests in one file like:

describe('Integration Tests', function() {
    const req = require.context('./', true, /^(.*\.(js$))[^.]*$/i);
    req.keys().forEach(function(key) {
        req(key);
    });
});

... the tests run at the same rate, maybe faster, but the overall cypress time goes from 18 mins down to under 8 which is faster than it was with 2.1.0. We're shooting for < 10min so I can move forward with this, but realistically it'd be ideal to get all of the tests preprocessed/built in one go and then split for the runner somehow..

[kamituel]

@brian-mann @jennifer-shehane I can confirm 3.1.0 indeed fixes that issue! While previously out of 10 CI runs, we've seen Cypress hang 4 times, yesterday it worked flawlessly every single time.

Kudos for fixing that! We can finally upgrade from 2.x.x :)