Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Running in tests mobile chrome emulator kills networking and system - need help with debugging #2864

Closed
andrzej-woof opened this issue Sep 14, 2018 · 9 comments
Assignees
Labels
STATE: Auto-locked An issue has been automatically locked by the Lock bot. TYPE: bug The described behavior is considered as wrong (bug).
Milestone

Comments

@andrzej-woof
Copy link

Are you requesting a feature or reporting a bug?

Bug

What is the current behavior?

I'm running tests in chrome:emulation:device=iphone 6. After few tests first my networking dies

64 bytes from 216.58.210.142: icmp_seq=40 ttl=53 time=83.636 ms
64 bytes from 216.58.210.142: icmp_seq=41 ttl=53 time=81.538 ms
64 bytes from 216.58.210.142: icmp_seq=42 ttl=53 time=92.103 ms
64 bytes from 216.58.210.142: icmp_seq=43 ttl=53 time=93.028 ms
64 bytes from 216.58.210.142: icmp_seq=44 ttl=53 time=80.456 ms
64 bytes from 216.58.210.142: icmp_seq=45 ttl=53 time=80.031 ms
64 bytes from 216.58.210.142: icmp_seq=46 ttl=53 time=80.224 ms
64 bytes from 216.58.210.142: icmp_seq=47 ttl=53 time=79.459 ms
64 bytes from 216.58.210.142: icmp_seq=48 ttl=53 time=79.350 ms
64 bytes from 216.58.210.142: icmp_seq=49 ttl=53 time=79.028 ms
64 bytes from 216.58.210.142: icmp_seq=50 ttl=53 time=80.970 ms
64 bytes from 216.58.210.142: icmp_seq=51 ttl=53 time=79.573 ms
64 bytes from 216.58.210.142: icmp_seq=52 ttl=53 time=86.672 ms
64 bytes from 216.58.210.142: icmp_seq=53 ttl=53 time=107.991 ms
# here it dies, testcafe hangs trying to load page
Request timeout for icmp_seq 54
Request timeout for icmp_seq 55
Request timeout for icmp_seq 56
Request timeout for icmp_seq 57
Request timeout for icmp_seq 58
Request timeout for icmp_seq 59
# Ctrl+C on testcafe and it's automatically alive again
64 bytes from 216.58.210.142: icmp_seq=54 ttl=53 time=6655.958 ms
64 bytes from 216.58.210.142: icmp_seq=61 ttl=53 time=79.661 ms
64 bytes from 216.58.210.142: icmp_seq=62 ttl=53 time=79.978 ms
64 bytes from 216.58.210.142: icmp_seq=63 ttl=53 time=80.583 ms

When that happens (and I can reproduce it on every run) dns resolve stops working, basically no network activity works.

If I don't kill testcafe immediately after few seconds everything on my Mac starts to crash, system is not responsive and I have to hard reboot to make it work again.

If I comment out first few tests it hangs as well so it's not a particular test case that causes fail).

I've also noticed that as the tests go it takes longer and longer for the browser to get responses for HTTP requests (until finally it can't get them anymore) - same thing happens on our Jenkins server.

What is the expected behavior?

Obviously continuing tests without issues. I'd appreciate hints about debugging this, I'd be glad to provide as much info as I can.
My suspect would be either testcafe proxy or a bug in Chrome itself.

How would you reproduce the current behavior (if this is a bug)?

It happens only on my internal site that I'm testing (with lot's of images and video playing in background). Unfortunately I cannot share it since it's intranet. I wasn't able to isolate what exactly causes this.

Specify your

  • operating system: macOS 10.13.6 (17G65)
  • testcafe version: tried with 0.21, 0.22, 0.22-alpha1
  • node.js version: 8.11.4
@AndreyBelym AndreyBelym added the STATE: Need clarification An issue lacks information for further research. label Sep 14, 2018
@AndreyBelym
Copy link
Contributor

Hi @andrzej-kodify, have you tried to open your site in the browser directly (without TestCafe), enable device emulation in mode in DevTools and perform test actions manually?

@andrzej-woof
Copy link
Author

Hi @AndreyBelym
I did tried lot's of things trying to figure out what's wrong.

  1. Yes, my site does work if I just use it without testcafe or at least couldn't manually reproduce that failure (and I have 100% success rate in reproducing it after running aprox 8 tests cases in single fixture).
  2. I did try to remove any logic on my side that could've caused that (like request logger). Basically I've made new project and reproduced that failure with only this code
fixture('Test');

for(let i = 0; i<100; i++) {
    test(`Test ${i}`, async (browser) => {
        await browser
            .navigateTo("http://localhost:49998/")
            .wait(10000);
    });
}

It seems to cause hangs when test i=5 is completed and test i=6 starts.

  1. I did try to run chrome with lots of different command line switches with no difference.

  2. I've tried to grab some chrome stats (probably not useful but maybe you'll notice something obvious I've missed)

 Running tests in:
 - Chrome 69.0.3497 / Mac OS X 10.13.6

 Test
{ metrics:
   [ { name: 'Timestamp', value: 58168.125724 },
     { name: 'AudioHandlers', value: 0 },
     { name: 'Documents', value: 2 },
     { name: 'Frames', value: 2 },
     { name: 'JSEventListeners', value: 16 },
     { name: 'LayoutObjects', value: 27 },
     { name: 'MediaKeySessions', value: 0 },
     { name: 'MediaKeys', value: 0 },
     { name: 'Nodes', value: 73 },
     { name: 'Resources', value: 15 },
     { name: 'ScriptPromises', value: 0 },
     { name: 'PausableObjects', value: 40 },
     { name: 'V8PerContextDatas', value: 1 },
     { name: 'WorkerGlobalScopes', value: 0 },
     { name: 'UACSSResources', value: 0 },
     { name: 'RTCPeerConnections', value: 0 },
     { name: 'ResourceFetchers', value: 3 },
     { name: 'AdSubframes', value: 0 },
     { name: 'DetachedScriptStates', value: 0 },
     { name: 'LayoutCount', value: 0 },
     { name: 'RecalcStyleCount', value: 0 },
     { name: 'LayoutDuration', value: 0 },
     { name: 'RecalcStyleDuration', value: 0 },
     { name: 'ScriptDuration', value: 0.000295 },
     { name: 'TaskDuration', value: 0.001749 },
     { name: 'JSHeapUsedSize', value: 2596408 },
     { name: 'JSHeapTotalSize', value: 5509120 },
     { name: 'FirstMeaningfulPaint', value: 58164.12921 },
     { name: 'DomContentLoaded', value: 58164.028974 },
     { name: 'NavigationStart', value: 58163.008568 } ] }
{ usedSize: 3112560, totalSize: 5509120 }
 ✓ Test 0
{ metrics:
   [ { name: 'Timestamp', value: 58178.927836 },
     { name: 'AudioHandlers', value: 0 },
     { name: 'Documents', value: 8 },
     { name: 'Frames', value: 2 },
     { name: 'JSEventListeners', value: 1299 },
     { name: 'LayoutObjects', value: 1092 },
     { name: 'MediaKeySessions', value: 0 },
     { name: 'MediaKeys', value: 0 },
     { name: 'Nodes', value: 3725 },
     { name: 'Resources', value: 119 },
     { name: 'ScriptPromises', value: 0 },
     { name: 'PausableObjects', value: 103 },
     { name: 'V8PerContextDatas', value: 2 },
     { name: 'WorkerGlobalScopes', value: 0 },
     { name: 'UACSSResources', value: 2 },
     { name: 'RTCPeerConnections', value: 0 },
     { name: 'ResourceFetchers', value: 8 },
     { name: 'AdSubframes', value: 0 },
     { name: 'DetachedScriptStates', value: 1 },
     { name: 'LayoutCount', value: 72 },
     { name: 'RecalcStyleCount', value: 152 },
     { name: 'LayoutDuration', value: 0.070869 },
     { name: 'RecalcStyleDuration', value: 0.118868 },
     { name: 'ScriptDuration', value: 1.7419 },
     { name: 'TaskDuration', value: 3.015951 },
     { name: 'JSHeapUsedSize', value: 31772920 },
     { name: 'JSHeapTotalSize', value: 63180800 },
     { name: 'FirstMeaningfulPaint', value: 0 },
     { name: 'DomContentLoaded', value: 58169.516077 },
     { name: 'NavigationStart', value: 58168.411816 } ] }
{ usedSize: 31838552, totalSize: 63180800 }
 ✓ Test 1
{ metrics:
   [ { name: 'Timestamp', value: 58189.500335 },
     { name: 'AudioHandlers', value: 0 },
     { name: 'Documents', value: 8 },
     { name: 'Frames', value: 2 },
     { name: 'JSEventListeners', value: 1300 },
     { name: 'LayoutObjects', value: 1092 },
     { name: 'MediaKeySessions', value: 0 },
     { name: 'MediaKeys', value: 0 },
     { name: 'Nodes', value: 3725 },
     { name: 'Resources', value: 120 },
     { name: 'ScriptPromises', value: 0 },
     { name: 'PausableObjects', value: 120 },
     { name: 'V8PerContextDatas', value: 2 },
     { name: 'WorkerGlobalScopes', value: 0 },
     { name: 'UACSSResources', value: 2 },
     { name: 'RTCPeerConnections', value: 0 },
     { name: 'ResourceFetchers', value: 8 },
     { name: 'AdSubframes', value: 0 },
     { name: 'DetachedScriptStates', value: 1 },
     { name: 'LayoutCount', value: 143 },
     { name: 'RecalcStyleCount', value: 297 },
     { name: 'LayoutDuration', value: 0.106 },
     { name: 'RecalcStyleDuration', value: 0.193498 },
     { name: 'ScriptDuration', value: 3.36599 },
     { name: 'TaskDuration', value: 5.848493 },
     { name: 'JSHeapUsedSize', value: 32128336 },
     { name: 'JSHeapTotalSize', value: 61083648 },
     { name: 'FirstMeaningfulPaint', value: 0 },
     { name: 'DomContentLoaded', value: 58179.580168 },
     { name: 'NavigationStart', value: 58179.113907 } ] }
{ usedSize: 32199824, totalSize: 61083648 }
 ✓ Test 2
{ metrics:
   [ { name: 'Timestamp', value: 58200.070733 },
     { name: 'AudioHandlers', value: 0 },
     { name: 'Documents', value: 8 },
     { name: 'Frames', value: 2 },
     { name: 'JSEventListeners', value: 1300 },
     { name: 'LayoutObjects', value: 1092 },
     { name: 'MediaKeySessions', value: 0 },
     { name: 'MediaKeys', value: 0 },
     { name: 'Nodes', value: 3726 },
     { name: 'Resources', value: 126 },
     { name: 'ScriptPromises', value: 0 },
     { name: 'PausableObjects', value: 89 },
     { name: 'V8PerContextDatas', value: 2 },
     { name: 'WorkerGlobalScopes', value: 0 },
     { name: 'UACSSResources', value: 2 },
     { name: 'RTCPeerConnections', value: 0 },
     { name: 'ResourceFetchers', value: 8 },
     { name: 'AdSubframes', value: 0 },
     { name: 'DetachedScriptStates', value: 1 },
     { name: 'LayoutCount', value: 215 },
     { name: 'RecalcStyleCount', value: 454 },
     { name: 'LayoutDuration', value: 0.144796 },
     { name: 'RecalcStyleDuration', value: 0.295298 },
     { name: 'ScriptDuration', value: 4.852062 },
     { name: 'TaskDuration', value: 8.43378 },
     { name: 'JSHeapUsedSize', value: 22920448 },
     { name: 'JSHeapTotalSize', value: 64753664 },
     { name: 'FirstMeaningfulPaint', value: 58190.222325 },
     { name: 'DomContentLoaded', value: 58190.139034 },
     { name: 'NavigationStart', value: 58189.655912 } ] }
{ usedSize: 22982200, totalSize: 64753664 }
 ✓ Test 3
{ metrics:
   [ { name: 'Timestamp', value: 58210.619 },
     { name: 'AudioHandlers', value: 0 },
     { name: 'Documents', value: 8 },
     { name: 'Frames', value: 2 },
     { name: 'JSEventListeners', value: 1300 },
     { name: 'LayoutObjects', value: 1092 },
     { name: 'MediaKeySessions', value: 0 },
     { name: 'MediaKeys', value: 0 },
     { name: 'Nodes', value: 3725 },
     { name: 'Resources', value: 120 },
     { name: 'ScriptPromises', value: 0 },
     { name: 'PausableObjects', value: 134 },
     { name: 'V8PerContextDatas', value: 2 },
     { name: 'WorkerGlobalScopes', value: 0 },
     { name: 'UACSSResources', value: 2 },
     { name: 'RTCPeerConnections', value: 0 },
     { name: 'ResourceFetchers', value: 8 },
     { name: 'AdSubframes', value: 0 },
     { name: 'DetachedScriptStates', value: 1 },
     { name: 'LayoutCount', value: 287 },
     { name: 'RecalcStyleCount', value: 612 },
     { name: 'LayoutDuration', value: 0.178259 },
     { name: 'RecalcStyleDuration', value: 0.366097 },
     { name: 'ScriptDuration', value: 6.456673 },
     { name: 'TaskDuration', value: 11.074539 },
     { name: 'JSHeapUsedSize', value: 25371464 },
     { name: 'JSHeapTotalSize', value: 70520832 },
     { name: 'FirstMeaningfulPaint', value: 58200.759039 },
     { name: 'DomContentLoaded', value: 58200.692239 },
     { name: 'NavigationStart', value: 58200.232293 } ] }
{ usedSize: 25429152, totalSize: 70520832 }
 ✓ Test 4
{ metrics:
   [ { name: 'Timestamp', value: 58221.08782 },
     { name: 'AudioHandlers', value: 0 },
     { name: 'Documents', value: 8 },
     { name: 'Frames', value: 2 },
     { name: 'JSEventListeners', value: 1300 },
     { name: 'LayoutObjects', value: 1092 },
     { name: 'MediaKeySessions', value: 0 },
     { name: 'MediaKeys', value: 0 },
     { name: 'Nodes', value: 3725 },
     { name: 'Resources', value: 120 },
     { name: 'ScriptPromises', value: 0 },
     { name: 'PausableObjects', value: 103 },
     { name: 'V8PerContextDatas', value: 2 },
     { name: 'WorkerGlobalScopes', value: 0 },
     { name: 'UACSSResources', value: 2 },
     { name: 'RTCPeerConnections', value: 0 },
     { name: 'ResourceFetchers', value: 8 },
     { name: 'AdSubframes', value: 0 },
     { name: 'DetachedScriptStates', value: 1 },
     { name: 'LayoutCount', value: 368 },
     { name: 'RecalcStyleCount', value: 750 },
     { name: 'LayoutDuration', value: 0.217508 },
     { name: 'RecalcStyleDuration', value: 0.442327 },
     { name: 'ScriptDuration', value: 7.839051 },
     { name: 'TaskDuration', value: 13.528696 },
     { name: 'JSHeapUsedSize', value: 32505624 },
     { name: 'JSHeapTotalSize', value: 66850816 },
     { name: 'FirstMeaningfulPaint', value: 0 },
     { name: 'DomContentLoaded', value: 58211.19053 },
     { name: 'NavigationStart', value: 58210.767804 } ] }
{ usedSize: 32557112, totalSize: 66850816 }
 ✓ Test 5
{ metrics:
   [ { name: 'Timestamp', value: 58231.709996 },
     { name: 'AudioHandlers', value: 0 },
     { name: 'Documents', value: 8 },
     { name: 'Frames', value: 2 },
     { name: 'JSEventListeners', value: 1300 },
     { name: 'LayoutObjects', value: 1092 },
     { name: 'MediaKeySessions', value: 0 },
     { name: 'MediaKeys', value: 0 },
     { name: 'Nodes', value: 3725 },
     { name: 'Resources', value: 119 },
     { name: 'ScriptPromises', value: 0 },
     { name: 'PausableObjects', value: 112 },
     { name: 'V8PerContextDatas', value: 2 },
     { name: 'WorkerGlobalScopes', value: 0 },
     { name: 'UACSSResources', value: 2 },
     { name: 'RTCPeerConnections', value: 0 },
     { name: 'ResourceFetchers', value: 8 },
     { name: 'AdSubframes', value: 0 },
     { name: 'DetachedScriptStates', value: 1 },
     { name: 'LayoutCount', value: 447 },
     { name: 'RecalcStyleCount', value: 914 },
     { name: 'LayoutDuration', value: 0.253343 },
     { name: 'RecalcStyleDuration', value: 0.512693 },
     { name: 'ScriptDuration', value: 9.288904 },
     { name: 'TaskDuration', value: 16.030423 },
     { name: 'JSHeapUsedSize', value: 31144896 },
     { name: 'JSHeapTotalSize', value: 62656512 },
     { name: 'FirstMeaningfulPaint', value: 0 },
     { name: 'DomContentLoaded', value: 58221.777586 },
     { name: 'NavigationStart', value: 58221.241587 } ] }
{ usedSize: 31197768, totalSize: 62656512 }
^CStopping TestCafe...

@andrzej-woof
Copy link
Author

andrzej-woof commented Sep 17, 2018

Hi @AndreyBelym,

I think I've got some luck in reproducing the issue on public URL.

node_modules/.bin/testcafe "chrome:emulation:device=iPhone 6" tests

fixture('Test')

for(let i = 0; i<100; i++) {
    test(`Test ${i}`, async (browser) => {
        await browser
            .navigateTo("https://codepen.io/anon/pen/RYePPg")
            .wait(10000);
    });
}

It seems related to video playing in chrome but possibly also somehow to testcafe triggering this problem (I wasn't able to reproduce it manually browsing).
Also the issue happens more often with mobile emulator but it's not limited (we've managed to reproduce it after more tries with desktop mode as well).

Hope this helps.

@miherlosev
Copy link
Collaborator

Unfortunately, I cannot reproduce the problem with [email protected]. We need another example in which we can reproduce the problem.

image

@andrzej-woof
Copy link
Author

@miherlosev
Could it be OSX related? I see you've run the script on windows.

@miherlosev
Copy link
Collaborator

miherlosev commented Oct 4, 2018

I don't know. I will check with macOS.

@AlexSkorkin AlexSkorkin added STATE: Need clarification An issue lacks information for further research. and removed STATE: Need clarification An issue lacks information for further research. labels Oct 22, 2018
@Farfurix
Copy link
Contributor

Farfurix commented Nov 1, 2018

I've reproduced the problem on macOS (Node 10.11.0, TestCafe 0.23.0).

@Farfurix Farfurix added TYPE: bug The described behavior is considered as wrong (bug). and removed STATE: Need clarification An issue lacks information for further research. labels Nov 1, 2018
@AndreyBelym AndreyBelym added this to the Sprint #23 milestone Nov 28, 2018
@AndreyBelym AndreyBelym modified the milestones: Sprint #23, Planned Dec 12, 2018
@AndreyBelym AndreyBelym modified the milestones: Planned, Sprint #31 Apr 2, 2019
@miherlosev miherlosev self-assigned this Apr 12, 2019
@miherlosev
Copy link
Collaborator

I ran the provided test example on Window and MacOS systems. All works fine on Windows, but Google Chrome begins to hang after 15th test loop on MacOS. 
I've discovered large memory utilization during the test execution.
We use the same Google Chrome API for running the browser on Window and MacOS systems.
I.e.. we have the same browser, the same test, and the same API to run the browser on both operating systems.
So, it doesn't look like a TestCafe problem. 
Probably, it's a problem with the emulation mode or video playing in the Google Chrome browser.
Now, we cannot fix this on our side.
However, it will be possible to run your test after the enhancement from #1815 is implemented. Track this issue to be informed about our progress.

@lock
Copy link

lock bot commented Apr 26, 2019

This thread has been automatically locked since it is closed and there has not been any recent activity. Please open a new issue for related bugs or feature requests. We recommend you ask TestCafe API, usage and configuration inquiries on StackOverflow.

@lock lock bot added the STATE: Auto-locked An issue has been automatically locked by the Lock bot. label Apr 26, 2019
@lock lock bot locked as resolved and limited conversation to collaborators Apr 26, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
STATE: Auto-locked An issue has been automatically locked by the Lock bot. TYPE: bug The described behavior is considered as wrong (bug).
Projects
None yet
Development

No branches or pull requests

5 participants