Vscode: Stabilize Smoke Test

Created on 12 Sep 2017  路  58Comments  路  Source: microsoft/vscode

The smoke test underwent massive invasive surgery. We've accomplished to

  • [x] Reduce randomness in the results
  • [x] Reduce total run duration to under 2 minutes

We still need to

engineering plan-item
Source
picture joaomoreno
👍4

Most helpful comment

Fixed the editor issue by inputting text into it via:

  1. Replacing the textarea contents with the previous text and the new text inserted at the cursor position
  2. Update the cursor position
  3. Fire an input event

Finally closing this since we merged the branch: https://github.com/Microsoft/vscode/commit/db578b9d3ac9510a5675152b999863360fa0bd71

Thanks for the efforts @michelkaporin @sandy081 @isidorn! 馃嵒

picture joaomoreno on 19 Oct 2017
🎉3

All 58 comments

@isidorn I've noticed the smoke test getting the contents of app.js instead of launch.json at this point. That seems to be one of the causes, although I'm sure it's not the only problem since I've seen the test pass that point yet fail later on.

joaomoreno picture joaomoreno on 12 Sep 2017

@joaomoreno great analysis. I have looked into debug failures and the last 2 are the same and as you already noticed they come from the fact that I am getting the contents of app.jsinstead of the launch.json. However I am doing exactly the same wait everybody is doing when waiting for the editor to get focus here
I am not sure is it possible that the editor "launch.json" gets focus but somehow I still get stale text with getEditorVisibleText

As for the first two failures screenshots would be great help, I noticed we have a screenshot step in builds but I am not sure how to access them.

Also when running the smoketest locally with latest I constantly get the following failures
screen shot 2017-09-13 at 12 35 47

isidorn picture isidorn on 13 Sep 2017

@isidorn To prevent getting text from previously opened editors, we have this wait for editor to get focus. Let's see what is that condition is missing in waiting for that editor to focus. I would probably take a screenshot immediately after waiting for launch.json editor is focus.

About those above tests which are failing, I had never seen them. Are you consistently reproducing them?

sandy081 picture sandy081 on 13 Sep 2017

@sandy081 yes those tests are constantly failing for me locally (I just pulled to get latest)

I added more screenshots to check what is the problem.

I have also increased the ping timeout from 400 to 600 ms which should prevent second failure. However the first failure comes from the node debug adapter that step in sometimes continues and this happens rarely. Maybe @weinand can comment more as I remember there was an issue about step actually doing a continue.
As for the last two failures we will know more once the builds are done with the new screenshots. I have queued 3 consectuive linux builds, hope that is fine

isidorn picture isidorn on 13 Sep 2017

However I am doing exactly the same wait everybody is doing when waiting for the editor to get focus here

Maybe there's another monaco-editor hidden somewhere.

I have also increased the ping timeout from 400 to 600 ms which should prevent second failure.

Can we somehow get rid of the timeout altogether and just fire the ping once the debugger is ready for it?

joaomoreno picture joaomoreno on 13 Sep 2017

No, there is no monaco-editor hidden, the screenshot shows it nicely. Somehow it happens that the editor title is launch.json even though the content is from app.js
I am trying to get rid of the timeout...

13-launch json file

isidorn picture isidorn on 13 Sep 2017
👍1

Ok I have

  • removed one timeout all together
  • am now waiting for debugger to say "attached" before pinging, however it is still too early so I had to leave another timout (had no other choice since that attached signal in the console is all I have got)
  • am now parsing JSON multiple times until I get a proper result

Now I triggered 3 linux build they should pass, but we shall see soon

isidorn picture isidorn on 13 Sep 2017
👍1

am now parsing JSON multiple times until I get a proper result

I thought about that too... but it means that others might still hit the bug... can't we nail down the wait criteria for the editor?

joaomoreno picture joaomoreno on 13 Sep 2017

The problem with the search criteria is that the name of the file is nowhere in the content of the editor. So we can not check the content with anything else.
To nail this down further it would be cool if we had a html snapshot functionality. So in that moment we could print out the editor HTML and see if there is something unique to check for once the editor has stale content.

I believe nobody else is hitting this issue yet is due to the fact that most files are being open via quick open and this is one of the rare ones that we use some other action to open a file - debug configure.

isidorn picture isidorn on 13 Sep 2017

Ok for some reason the smoke test is still failing. Continuing investigation tomorrow morning

isidorn picture isidorn on 13 Sep 2017

To nail this down further it would be cool if we had a html snapshot functionality. So in that moment we could print out the editor HTML and see if there is something unique to check for once the editor has stale content.

I believe you can get this from the base API.

I believe nobody else is hitting this issue yet is due to the fact that most files are being open via quick open and this is one of the rare ones that we use some other action to open a file - debug configure.

Interesting. The answer might be here.

At the same time, this doesn't sound like a good criteria. @bpasero might be setting that aria-label as well as calling focus before the file is even read from disk. We need a different assertion there to make sure the editor has loaded the text.

Finally, it seems that you might just want to assert that launch.json was created with the right contents, right? What would happen if the launch.json contents would take more lines than the ones that would fit on a single editor page? You wouldn't be able to get its whole contents by querying for view-lines... So why don't you just read the file straight from disk? Once you run the configure command, assert launch.json is indeed opened as a text editor, but to get to its contents, just use fs.

joaomoreno picture joaomoreno on 13 Sep 2017

At the same time, this doesn't sound like a good criteria. @bpasero might be setting that aria-label as well as calling focus before the file is even read from disk. We need a different assertion there to make sure the editor has loaded the text.

Yup, check this out. I've hit a breakpoint when .focus() is called on the editor, when clicking the gear button in Debug. Right after that happens, the aria-label is there, the text area has focus, yet view-lines has nothing:

image

If there is nothing that would tell us the editor is there and ready, I suggest we introduce that something. A signal, which should be smoketest specific, like data-smoketest-state=idle (with possible loading and idle states) and data-smoketest-file=FILENAME attributes on the editor part or similar.

joaomoreno picture joaomoreno on 13 Sep 2017

Introducing such a smoke test specific attribute makes sense to me. I browsed a bit through the code and this looks like the place once the editor has resolved its input. And the way that would float up to the container would be the same as the AriaLabel all the way up to the editor configuration here.

Another way is instead of introducing a new label we could modify the aria label based on the fact if the editor is completely loaded or not.

fyi @bpasero

@joaomoreno yes I could use fs to get the content of the launch.json. Let me try that

isidorn picture isidorn on 14 Sep 2017
👍1

It seems like the failures yesterday were connected to something failing before debug.
2 smoke tests from today on linux passed. Now I triggered 2 more to verify

isidorn picture isidorn on 14 Sep 2017

Ok, now I am reading the launch.json via fs.
Debug now seems to always pass on linux.
I triggered 4 more linux builds to verify, 2 win, 2 mac. If they all pass then I will victouriously check the box in the top comment for investigate debug.

@sandy081 From time to time I still get data loss failures, example https://monacotools.visualstudio.com/Monaco/_build/explorer?_a=summary&buildId=32387

isidorn picture isidorn on 14 Sep 2017
🎉1

From running the 8 test suits, now I see the following patterns

@sandy081 @joaomoreno any idea what is going on with all the non debug failures

isidorn picture isidorn on 14 Sep 2017

Ok I have updated debug to not have any timeouts at all. I also updated the smoke test such that it prints out the port when it is ready to be pinged, this way there is no randomness on the debug smoke test side.
Triggered 3 more linux builds to verify debug is good.

isidorn picture isidorn on 14 Sep 2017

Editor focus thingy is very subtle. I share the same observation as @joaomoreno that we are hitting the point when

  • Tab of launch.json is active
  • Editor container is having the aria-label of launch.json
  • Text area is focussed
  • But editor still showing the content of old file

I am not sure there is something which we can depend on for the editor is ready. It looks like Arial label containing file name is set on monaco editor only when the accessibility is on. Will check with @alexandrudima and see if he can shed some light here.

Not sure what is causing this time out in dataloss test. From screenshots I see that test ran successfully. Also I suspect some editor focus issues. I will inspect on non-debug related issues.

Thanks @isidorn

sandy081 picture sandy081 on 14 Sep 2017
👍1

All 3 linux builds passed -> checking off debug in first post, seems to be good now.

isidorn picture isidorn on 14 Sep 2017

Talked to @bpasero and @alexandrudima on the editor focus issue. Looks like active tab showing old content is a real issue. But for the smoke tests, we would need much more reliable way to find if the editor is ready or not. For this @alexandrudima suggested to add an attribute data-uri on editor domNode. Will add it and update the smoke test code.

I will trigger more builds to see if everything is good.

sandy081 picture sandy081 on 14 Sep 2017
👍3

Okay.. Here is some good news... We have green smoke builds. The last 20+ builds are green except one (failing due to slow market place queries) which is OK.

I think we can make them part of our main builds.

Good job guys @joaomoreno @isidorn 馃憤

sandy081 picture sandy081 on 15 Sep 2017
🎉3

@isidorn One of the last Linux builds still failed in Debug: https://monacotools.visualstudio.com/Monaco/_build/index?buildId=32459&_a=summary

Together with @sandy081, we've gone over the debug test suite and added a bit more screenshots so we get an idea of what is happening there. We've also changed a few of the assertions done in the suite. And we've also fixed an issue with the screenshots overall which caused screenshots to be placed in the wrong folder name. Here's our changes: https://github.com/Microsoft/vscode/commit/4c26c77894e60d1db0f70852a5b74b2e4662c186

We triggered many new builds, so let's wait for them to come back.

joaomoreno picture joaomoreno on 15 Sep 2017

@joaomoreno your changes look great to me, thanks

isidorn picture isidorn on 15 Sep 2017

@isidorn We also wrapped those http calls in order to catch errors coming from them.

joaomoreno picture joaomoreno on 15 Sep 2017

@joaomoreno yeah I noticed, good work

isidorn picture isidorn on 15 Sep 2017

Massive issues uncovered today:

  • Parallel runs were reusing the same chrome driver. So when the first one finished, it would kill the driver and ruin the experience for all the others. This is a spectron bug which we should file.
  • The smoketest express app always starts on port 3000, which makes concurrent debug suite test runs impossible. We fixed it by setting the PORT env variable, which the app listens to on startup, to a randomly assigned port number
  • The quick open widget disappears from the DOM when blurred. This especially can happen when tests run in parallel since windows take focus away. We added a --sticky-quickopen cli option to make quick open sticky.
  • We found double nestings of the waitFor util which caused for delays longer than 5 seconds.

Holy cow I think we are close. There just ran all in parallel:

image

joaomoreno picture joaomoreno on 15 Sep 2017

Just fixed an issue in the Debug test suite wrt the quick open input box taking focus away from the quick open tree, only to have the ListService being 50ms late to setting the listFocus context key to false: https://github.com/Microsoft/vscode/commit/ddda90314e75806295720d9e6fd15fe90c095764. This would cause Space to be dispatched as a keybinding to the keybinding service, which triggers the list.toggleExpand command, instead of inserting literal spaces into the quick open input, which is the desired behaviour. @bpasero We should get rid of those 50ms.

These two tests are now sometimes failing, looking into them:

image

joaomoreno picture joaomoreno on 22 Sep 2017
👍2

Debug test suite fails sometimes due to quick open:

2017-10-02T13:43:51.2975220Z   1) Debug configure launch json:
2017-10-02T13:43:51.2993920Z      TypeError: names.some is not a function
2017-10-02T13:43:51.3013680Z       at waitForQuickOpenElements.names (out/areas/quickopen/quickopen.js:46:64)
2017-10-02T13:43:51.3049590Z       at SpectronClient.<anonymous> (out/spectron/client.js:198:25)
2017-10-02T13:43:51.3068890Z       at Generator.next (<anonymous>)
2017-10-02T13:43:51.3088280Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-02T13:43:51.3107420Z       at process._tickDomainCallback (internal/process/next_tick.js:135:7)
2017-10-02T13:43:51.3118030Z 
2017-10-02T13:43:51.3136640Z   2) Debug breakpoints:
2017-10-02T13:43:51.3159910Z      Error: wait for active element: div.quick-open-widget[aria-hidden="false"] .quick-open-input input: Timed out after 20 seconds.
2017-10-02T13:43:51.3186650Z       at SpectronClient.<anonymous> (out/spectron/client.js:189:31)
2017-10-02T13:43:51.3205250Z       at Generator.next (<anonymous>)
2017-10-02T13:43:51.3224040Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-02T13:43:51.3233510Z 
2017-10-02T13:43:51.3251580Z   3) Debug start debugging:
2017-10-02T13:43:51.3274220Z      Error: element with selector .debug-actions-widget .debug-action.pause: Timed out after 20 seconds.
2017-10-02T13:43:51.3298090Z       at SpectronClient.<anonymous> (out/spectron/client.js:189:31)
2017-10-02T13:43:51.3317000Z       at Generator.next (<anonymous>)
2017-10-02T13:43:51.3341790Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-02T13:43:51.3351580Z 
2017-10-02T13:43:51.3371790Z   4) Debug focus stack frames and variables:
2017-10-02T13:43:51.3401710Z      Error: there should be 4 local variables: Timed out after 20 seconds.
2017-10-02T13:43:51.3421220Z       at SpectronClient.<anonymous> (out/spectron/client.js:189:31)
2017-10-02T13:43:51.3440010Z       at Generator.next (<anonymous>)
2017-10-02T13:43:51.3458820Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-02T13:43:51.3468560Z 
2017-10-02T13:43:51.3493710Z   5) Debug stepOver, stepIn, stepOut:
2017-10-02T13:43:51.3517000Z      Error: click with selector .debug-actions-widget .debug-action.step-into: Timed out after 20 seconds.
2017-10-02T13:43:51.3556320Z       at SpectronClient.<anonymous> (out/spectron/client.js:189:31)
2017-10-02T13:43:51.3577720Z       at Generator.next (<anonymous>)
2017-10-02T13:43:51.3597000Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-02T13:43:51.3609530Z 
2017-10-02T13:43:51.3627670Z   6) Debug continue:
2017-10-02T13:43:51.3653370Z      Error: click with selector .debug-actions-widget .debug-action.continue: Timed out after 20 seconds.
2017-10-02T13:43:51.3678440Z       at SpectronClient.<anonymous> (out/spectron/client.js:189:31)
2017-10-02T13:43:51.3698770Z       at Generator.next (<anonymous>)
2017-10-02T13:43:51.3718020Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-02T13:43:51.3728520Z 
2017-10-02T13:43:51.3746700Z   7) Debug debug console:
2017-10-02T13:43:51.3765060Z      Error: undefined: Timed out after 20 seconds.
2017-10-02T13:43:51.3783950Z       at SpectronClient.<anonymous> (out/spectron/client.js:189:31)
2017-10-02T13:43:51.3807660Z       at Generator.next (<anonymous>)
2017-10-02T13:43:51.3826340Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-02T13:43:51.3835850Z 
2017-10-02T13:43:51.3853750Z   8) Debug stop debugging:
2017-10-02T13:43:51.3876380Z      Error: click with selector .debug-actions-widget .debug-action.stop: Timed out after 20 seconds.
2017-10-02T13:43:51.3899460Z       at SpectronClient.<anonymous> (out/spectron/client.js:189:31)
2017-10-02T13:43:51.3918810Z       at Generator.next (<anonymous>)
2017-10-02T13:43:51.3937310Z       at fulfilled (out/spectron/client.js:8:58)
joaomoreno picture joaomoreno on 2 Oct 2017

@joaomoreno the only time that test depends on quick open is here https://github.com/Microsoft/vscode/blob/master/test/smoke/src/areas/debug/debug.test.ts#L49
And we use that open file api in all other tests

isidorn picture isidorn on 2 Oct 2017

@isidorn Hopefully fixed in https://github.com/Microsoft/vscode/commit/d28ace31aa147596e35adf101a27768a048c79ec

joaomoreno picture joaomoreno on 3 Oct 2017

@joaomoreno lovely jovely

isidorn picture isidorn on 3 Oct 2017

@sandy081 Check those two builds:

https://monacotools.visualstudio.com/Monaco/Monaco%20Team/_build/index?buildId=33064&_a=summary
https://monacotools.visualstudio.com/Monaco/Monaco%20Team/_build/index?buildId=33062&_a=summary

Both had this problem:

2017-10-03T14:18:43.1153920Z   1) Preferences turns off editor line numbers and verifies the live change:
2017-10-03T14:18:43.1182370Z      Error: elements with selector .line-numbers: Timed out after 20 seconds.
2017-10-03T14:18:43.1199670Z       at SpectronClient.<anonymous> (out/spectron/client.js:189:31)
2017-10-03T14:18:43.1211660Z       at Generator.next (<anonymous>)
2017-10-03T14:18:43.1227440Z       at fulfilled (out/spectron/client.js:8:58)

Here's what I can see locally:

screenshot_20171003_165503

joaomoreno picture joaomoreno on 3 Oct 2017

@joaomoreno Above screenshot is not from the failing test in the build. Failing test in the build is

'turns off editor line numbers and verifies the live change'

and the above screen shot is from the test

`changes 'workbench.action.toggleSidebarPosition' command key binding and verifies it

But both of them are same suite. Does both tests are failing for you?

I cannot reproduce locally now because, I am getting different error in Preferences due to the message box

image

Due to the message box, smoke test is not able to find the dirty file to save.

sandy081 picture sandy081 on 4 Oct 2017

Sorry, I have to update my npm packages. This could be due to that.

sandy081 picture sandy081 on 4 Oct 2017

It failed only once on my machine (where the screenshot came from).

joaomoreno picture joaomoreno on 4 Oct 2017

This could happen when the following happens

  • There is a setting already in the settings file
  • Preferences first test adds a setting to the file without comma. This will create errors in the file
  • Preferences second test triggers VS Code to add another setting and you see this error

Not sure how you landed into that situation. But added a fix in Preferences to always add a trailing comma to prevent this.

Otherwise, preferences tests are good locally

sandy081 picture sandy081 on 4 Oct 2017

Latest round of tests:

https://monacotools.visualstudio.com/Monaco/_build/index?buildId=33116&_a=summary

Windows fails in dataloss, debug and git:

2017-10-04T13:20:22.1701767Z   1) Dataloss verifies that 'hot exit' works for dirty files:
2017-10-04T13:20:22.1701767Z      Error: click with selector .tabs-container div.tab[aria-label="Untitled-1, tab"]: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   2) Preferences turns off editor line numbers and verifies the live change:
2017-10-04T13:20:22.1701767Z      Error: click with selector .tabs-container div.tab[aria-label="app.js, tab"]: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   3) Debug configure launch json:
2017-10-04T13:20:22.1701767Z      Error: click with selector div[id="workbench.parts.sidebar"] .actions-container .configure: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   4) Debug start debugging:
2017-10-04T13:20:22.1701767Z      Error: element with selector .debug-actions-widget .debug-action.pause: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   5) Debug focus stack frames and variables:
2017-10-04T13:20:22.1701767Z      Error: there should be 4 local variables: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   6) Debug stepOver, stepIn, stepOut:
2017-10-04T13:20:22.1701767Z      Error: click with selector .debug-actions-widget .debug-action.step-into: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   7) Debug continue:
2017-10-04T13:20:22.1701767Z      Error: click with selector .debug-actions-widget .debug-action.continue: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   8) Debug debug console:
2017-10-04T13:20:22.1701767Z      Error: undefined: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   9) Debug stop debugging:
2017-10-04T13:20:22.1701767Z      Error: click with selector .debug-actions-widget .debug-action.stop: Timed out after 20 seconds.
2017-10-04T13:20:22.1701767Z       at SpectronClient.<anonymous> (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:20:22.1701767Z       at Generator.next (<anonymous>)
2017-10-04T13:20:22.1701767Z       at fulfilled (D:\work\agent2\5\s\test\smoke\out\spectron\client.js:8:58)
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   10) Git reflects working tree changes:
2017-10-04T13:20:22.1701767Z      unknown error: Element <a class="action-label icon contrib-cmd-icon-2" role="button" title="Refresh" tabindex="0"></a> is not clickable at point (194, 17). Other element would receive the click: <div class="message-left-side message-overflow-ellipsis">...</div>
2017-10-04T13:20:22.1701767Z   Error
2017-10-04T13:20:22.1701767Z 
2017-10-04T13:20:22.1701767Z   11) Git stages, commits changes and verifies outgoing change:
2017-10-04T13:20:22.1701767Z      unknown error: Element <a class="action-label icon contrib-cmd-icon-11" role="button" title="Commit" tabindex="0"></a> is not clickable at point (162, 17). Other element would receive the click: <span class="message-left-side severity app-info" title="Code - Insiders for 64-bit Windows is now available!" style="background-color: rgb(0, 122, 204); color: rgb(238, 238, 238);">...</span>
2017-10-04T13:20:22.1701767Z   Error

Mac fails in dataloss:

https://monacotools.visualstudio.com/Monaco/_build/index?buildId=33115&_a=summary

2017-10-04T13:17:05.7949513Z   1) Dataloss verifies that 'hot exit' works for dirty files:
2017-10-04T13:17:05.7949513Z      Error: getTextContent with selector .monaco-editor[data-uri$="Untitled-1"] .view-lines: Timed out after 20 seconds.
2017-10-04T13:17:05.7949513Z       at SpectronClient.<anonymous> (D:\work\agent1\6\s\test\smoke\out\spectron\client.js:189:31)
2017-10-04T13:17:05.7949513Z       at Generator.next (<anonymous>)
2017-10-04T13:17:05.7949513Z       at fulfilled (D:\work\agent1\6\s\test\smoke\out\spectron\client.js:8:58)

And both Linux runs are failing with a very strange error:

https://monacotools.visualstudio.com/Monaco/_build/index?buildId=33118&_a=summary
https://monacotools.visualstudio.com/Monaco/_build/index?buildId=33117&_a=summary

2017-10-04T13:06:27.5081100Z   1) Search "before all" hook:
2017-10-04T13:06:27.5108930Z      Error: Timeout of 60000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves.
2017-10-04T13:06:27.5128040Z
joaomoreno picture joaomoreno on 4 Oct 2017

Debug failed because the smoke test could not find the configure button since it is covered by the message box. All debug errors are failing due to this.

screen shot 2017-10-04 at 15 36 36

isidorn picture isidorn on 4 Oct 2017
👍1

Windows:

  • because of the message box hiding the UI elements like Tabs.

Mac:

  • Not sure why the content is not written correctly into the editor. Instead of Hello, Untitled Code it is Hello, Untitled Coed.

image

Linux:

  • It seems Status bar tests are not even started after Git tests. This making me to suspect if the following call in the set up is taking for ever

cp.execSync('git checkout .', { cwd: WORKSPACE_PATH });

sandy081 picture sandy081 on 4 Oct 2017

Issue 1: Why are we seeing that message box - We should assume that there should be any messages by default.

Issue 2: Waiting for text content to write is not still reliable?

Issue 3: Git check out might be taking time in the set up?

sandy081 picture sandy081 on 4 Oct 2017

Very interesting. That bar shouldn't be there but also just thought about how dangerous it is to tell Spectron to click a specific element: another might be on top.

I'll make sure that update popup doesn't come up.

Not sure about issue 2. Something must be up.

I'll also investigate issue 3.

joaomoreno picture joaomoreno on 4 Oct 2017

https://github.com/Microsoft/vscode/commit/08e6c5d09efb2c294dca2adc40e880cdc2d8ca74 should disable updates during the smoketest.

Looking into issue 3.

joaomoreno picture joaomoreno on 4 Oct 2017

Issue 3 possibly related to https://github.com/electron/spectron/issues/219

joaomoreno picture joaomoreno on 4 Oct 2017

Related to issue 3: https://github.com/Microsoft/vscode/commit/d78d5da119e8aacf5ef252c2314d34502d800257 should kill all leftover running instances of Code before starting the smoketest.

joaomoreno picture joaomoreno on 5 Oct 2017

Getting very close.

@sandy081 Macos just failed with

2017-10-05T08:26:02.5172290Z   1) Preferences turns off editor line numbers and verifies the live change:
2017-10-05T08:26:02.5189500Z      Error: elements with selector .line-numbers: Timed out after 20 seconds.
2017-10-05T08:26:02.5208590Z       at SpectronClient.<anonymous> (out/spectron/client.js:188:31)
2017-10-05T08:26:02.5219830Z       at Generator.next (<anonymous>)
2017-10-05T08:26:02.5232900Z       at fulfilled (out/spectron/client.js:8:58)

Here's the screenshot:

11-timeout

joaomoreno picture joaomoreno on 5 Oct 2017

This last failure happens due to some letters are switched/missing when typing in the editor. It is the same underlying issue behind the Dataloss occasional failures.

we're starting to see something very strange in macos smoketest:
only in the editor (so far), it appears that sometimes we send a sequence of keys to type in something
eg: lineNumbers
and sometimes it comes up as ilneNumbers
or Hello, Untitled Code becomes Hello, Unitled Coed (notice here a t is missing and the last two letters are swapped)
do you think there might be something in our input detection/textarea polling code which could cause this?

I also just saw this happening on Linux too!

Investigating...

cc @alexandrudima

joaomoreno picture joaomoreno on 5 Oct 2017

About

2017-10-04T13:06:27.5108930Z      Error: Timeout of 60000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves.

I found out that the application stays stuck here:

gotcha

Now... why?

joaomoreno picture joaomoreno on 5 Oct 2017

Here's what we're hitting: https://bugs.chromium.org/p/chromium/issues/detail?id=522853

After some effort I was able to get our very own application logs (which I will soon make a part of the artifacts to create during a smoketest build). Right in the beginning there appeared this message:

[51990:1005/140613.896448:WARNING:discardable_shared_memory_manager.cc(193)] Less than 64 MB of free space in temporary directory for shared memory files: 8

I checked what this meant and the shared memory in Linux is represented by the /dev/shm device, which in our Docker containers is only 64MB. Now, if Electron complains when this free memory is low... could it be that everything just crumbles down when that limit is hit? That would explain everything we've seen so far:

  • It only happens sometimes (only when that memory limit is hit)
  • When it happens, the processes crash but stay running and don't free any of that shared memory, making successful runs even more prone to fail, since less memory is available

I've tried saturating that memory manually and, lo and behold, YES, THAT'S IT.

The fix is to increase that shared memory level to something more than 64MB. Working on that.

joaomoreno picture joaomoreno on 5 Oct 2017
🎉3

@isidorn @mjbvz Another message going over the debug toolbar... 馃

Both Debug and Git are suffering from this. The amount of work to get this ** working is surreal.

37-timeout

2017-10-05T16:20:21.0231720Z   6) Debug stepOver, stepIn, stepOut:
2017-10-05T16:20:21.0260920Z      Error: click with selector .debug-actions-widget .debug-action.step-into: Timed out after 20 seconds.
2017-10-05T16:20:21.0294780Z       at SpectronClient.<anonymous> (out/spectron/client.js:188:31)
2017-10-05T16:20:21.0340020Z       at Generator.next (<anonymous>)
2017-10-05T16:20:21.0359470Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-05T16:20:21.0369090Z 
2017-10-05T16:20:21.0387380Z   7) Debug continue:
2017-10-05T16:20:21.0416720Z      Error: click with selector .debug-actions-widget .debug-action.continue: Timed out after 20 seconds.
2017-10-05T16:20:21.0450630Z       at SpectronClient.<anonymous> (out/spectron/client.js:188:31)
2017-10-05T16:20:21.0469700Z       at Generator.next (<anonymous>)
2017-10-05T16:20:21.0488840Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-05T16:20:21.0498470Z 
2017-10-05T16:20:21.0517000Z   8) Debug stop debugging:
2017-10-05T16:20:21.0546280Z      Error: click with selector .debug-actions-widget .debug-action.stop: Timed out after 20 seconds.
2017-10-05T16:20:21.0576450Z       at SpectronClient.<anonymous> (out/spectron/client.js:188:31)
2017-10-05T16:20:21.0600460Z       at Generator.next (<anonymous>)
2017-10-05T16:20:21.0619480Z       at fulfilled (out/spectron/client.js:8:58)
2017-10-05T16:20:21.0629500Z 
2017-10-05T16:20:21.0648160Z   9) Git stages, commits changes and verifies outgoing change:
2017-10-05T16:20:21.0691860Z      unknown error: Element <a class="action-label icon contrib-cmd-icon-11" role="button" title="Commit" tabindex="0"></a> is not clickable at point (166, 17). Other element would receive the click: <span class="message-left-side severity app-warning" title="[TypeScript support for VSCode] Could not install typings files for JavaScript language features. Please ensure that NPM is installed or configure 'typescript.npm' in your user settings" style="background-color: rgb(184, 149, 0); color: rgb(238, 238, 238);">...</span>
2017-10-05T16:20:21.0742610Z   Error
joaomoreno picture joaomoreno on 5 Oct 2017

@mjbvz Can we get an easy way out of this, not through the settings?

joaomoreno picture joaomoreno on 5 Oct 2017

It seems it was a one time thing... no idea what happened there... maybe no Internet?

joaomoreno picture joaomoreno on 6 Oct 2017

/dev/shm fix didn't quite fix it...

But https://github.com/Microsoft/vscode/issues/32908 is interesting...

joaomoreno picture joaomoreno on 6 Oct 2017

Nope...

I was able to get dbus working inside the container, those Failed to connect to the bus error messages went away and the app still crashes every now and then.

I start to think the problem is really behind using Ubuntu 14.04 for the base container image:

joaomoreno picture joaomoreno on 6 Oct 2017

@joaomoreno Are you still running into the npm issue? If the issue is just that npm is not being picked up properly, try setting an explicit path with "typescript.npm" You can also disable automatic type by setting: "typescript.disableAutomaticTypeAcquisition": true.

mjbvz picture mjbvz on 8 Oct 2017

No, it seemed to have only happened once.

joaomoreno picture joaomoreno on 9 Oct 2017

The crash problem was related to both /dev/shm and enabling dbus. It seems to be much more stable now.

I'll investigate the editor problem.

joaomoreno picture joaomoreno on 10 Oct 2017
🎉1

OK there are only two problems left as far as I know:

The editor input issue, in which some characters appear _delayed_ in the buffer. We might want to have programmatic access to the editor @alexandrudima as a workaround. This happens in Windows, Linux and macOS.

8-timeout

1-timeout

37-timeout

And the preferences conflict save, which could be related to the previous one as it occurs also when the previous one does @sandy081.

9-timeout

joaomoreno picture joaomoreno on 10 Oct 2017

Fixed the editor issue by inputting text into it via:

  1. Replacing the textarea contents with the previous text and the new text inserted at the cursor position
  2. Update the cursor position
  3. Fire an input event

Finally closing this since we merged the branch: https://github.com/Microsoft/vscode/commit/db578b9d3ac9510a5675152b999863360fa0bd71

Thanks for the efforts @michelkaporin @sandy081 @isidorn! 馃嵒

joaomoreno picture joaomoreno on 19 Oct 2017
🎉3
Was this page helpful?
0 / 5 - 0 ratings

Related issues

lukehoban picture lukehoban  路  3Comments
shanalikhan picture shanalikhan  路  3Comments
DovydasNavickas picture DovydasNavickas  路  3Comments
villiv picture villiv  路  3Comments
omidgolparvar picture omidgolparvar  路  3Comments