Repository navigation
test: windows ci timeouts related to child_process #1383
Description
With ARM timeouts fixed, this looks to be the last persistent test failure on the CI. If we can solve this, the builds should start to get blue, and all that's left are some intermittent failures on OS X and ARM.
https://jenkins-iojs.nodesource.com/job/iojs+any-pr+multi/473/nodes=iojs-win2012r2/
cc: @rvagg @piscisaureus
=== release test-child-process-double-pipe ===
Path: parallel/test-child-process-double-pipe
grep stdin write 7
grep stdin write 6
grep stdin write 5
grep stdin write 7
echo exit
Command: c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\Release\iojs.exe c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\parallel\test-child-process-double-pipe.js
--- TIMEOUT ---
=== release test-child-process-exit-code ===
Path: parallel/test-child-process-exit-code
Command: c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\Release\iojs.exe c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\parallel\test-child-process-exit-code.js
--- TIMEOUT ---
=== release test-child-process-spawnsync ===
Path: parallel/test-child-process-spawnsync
sleep started
Command: c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\Release\iojs.exe c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\parallel\test-child-process-spawnsync.js
--- TIMEOUT ---
=== release test-child-process-spawnsync-input ===
Path: parallel/test-child-process-spawnsync-input
Command: c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\Release\iojs.exe c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\parallel\test-child-process-spawnsync-input.js
--- TIMEOUT ---
=== release test-http-curl-chunk-problem ===
Path: parallel/test-http-curl-chunk-problem
dd command: "c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\Release\iojs.exe" "c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\fixtures\create-file.js" "c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\tmp.3\big" 10485760
Server running at http://localhost:8080
making curl request
Command: c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\Release\iojs.exe c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\parallel\test-http-curl-chunk-problem.js
--- TIMEOUT ---
=== release test-process-kill-null ===
Path: parallel/test-process-kill-null
Command: c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\Release\iojs.exe c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\parallel\test-process-kill-null.js
--- TIMEOUT ---
=== release test-pipe-head ===
Path: sequential/test-pipe-head
Command: c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\Release\iojs.exe c:\workspace\iojs+any-pr+multi\nodes\iojs-win2012r2\test\sequential\test-pipe-head.js
--- TIMEOUT ---
Activity
Fishrock123 commentedon Apr 9, 2015
And ya beat me to it.
Some analysis on when the errors started on the CI will be coming soon.
Fishrock123 commentedon Apr 9, 2015
Note: this picks out only the builds that were done against
v1.x.The last consistently stable
v1.xbuild was209Since then, there have been 5 stable
v1.xbuilds:363364367368369Here are some builds after
209where errors started cropping up. The errors seem slightly different than the ones currently on v1.x:210212213217 (aborted)218 (rebuild of 217, git failed)219 (rebuild of 217)220 (rebuild of 217)The commits from 209 into 220 are:
2b47fd2eb6] - stream_base:.writev()has limited support (Fedor Indutny) #1008c9151547bc] - Working on v1.4.3 (Rod Vagg)b6b9628df7] - 2015-02-28 io.js v1.4.2 Release (Rod Vagg)1ab7e80838] - tls: proxyhandle.readingback to parent handle (Fedor Indutny) #10047887e119ed] - install: new performance counters provider guid (Russell Dempsey) #1001755461219d] - tls: fix typohandle._reading=>handle.reading(Fedor Indutny) #994675cffb33e] - http: don't confuse automatic headers for others (Christian Tellnes) #82825da0742ee] - build: improve vcbuild.bat (Bert Belder) #998b8310cbd3e] - build: reduce tarball size by 8-10% (Johan Bergström) #961Fishrock123 commentedon Apr 9, 2015
Hmm, of note:
25da0742ee] - build: improve vcbuild.bat (Bert Belder) #998Did not have a CI run against the PR.
silverwind commentedon Apr 9, 2015
Hmm, nothing suspicious in that commit log, except maybe the vcbuild thing. Maybe an CI issue?
Fishrock123 commentedon Apr 9, 2015
CI pre - 25da074 / vcbuild improvements: https://jenkins-iojs.nodesource.com/view/iojs/job/iojs+any-pr+multi/475/
silverwind commentedon Apr 9, 2015
Maybe related to #1005? A lot of the same timeouts there too.
Fishrock123 commentedon Apr 9, 2015
Everything in #1005 should have been fixed... and, iirc, was fixed..
Fishrock123 commentedon Apr 9, 2015
Ok, I think I was wrong.
The current timeouts appear to have been introduced in
370, and first manifested in389373contains @indutny's last fix for #1005, which should have been green.. That "narrows" down the commits to:36f017afaf] - js2c: fix module id generation on windows (Ben Noordhuis) #12812903410aa8] - src: don't lazy-load timer globals (Ben Noordhuis) #12805e609e9324] - _Revert_ "doc: clarify real name requirement" (Jeremiah Senkpiel) #127608acf1352c] - win,node-gyp: make delay-load hook optional (Bert Belder) #1266776b73b243] - timers: cleanup interval handling (Jeremiah Senkpiel) #1272caf0b36de3] - timers: assure setTimeout callback only runs once (Roman Reiss) #12312ccc8f3970] - tls_wrap: fix this incredibly stupid leak (Fedor Indutny) #1244e74b5d278c] - tls_wrap: fix BIO leak on SSL error (Fedor Indutny) #12442db758c562] - iojs: introduce internal modules (Vladimir Kurchatkin) #84845814216ee] - doc: fix format docs discrepancy (Brendan Ashworth) #12558a945814dd] - string_decoder: optimize write() (Brian White) #1209(probably in the commits below, see the below comment)
3d46fefe0c] - win,node-gyp: allow node.exe/iojs.exe to be renamed (Bert Belder) #1251c9207f7fc2] - fs: fix corruption in writeFile and writeFileSync (Olov Lassus) #10634e9bf93e9c] - doc: clarify real name requirement (Roman Reiss) #1250e84dd5f651] - doc: document repl on-demand module loading (Roman Reiss) #12491832743e18] - lib: add missingnewfor errors lib/*.js (Mayhem) #12467dd5e824be] - assert: simplify logic of testing buffer equality (Alex Yursha) #1171269e46be37] - deps: make node-gyp work with io.js (cjihrig) #990b542fb94a4] - deps: upgrade npm to 2.7.3 (Forrest L Norvell) #12192e5b87a147] - src: remove unnecessary environment lookups (Ben Noordhuis) #12387e88a9322c] - src: make accessors immune to context confusion (Ben Noordhuis) #123820c4498e76] - Working on v1.6.3 (Rod Vagg)33c57354aa] - 2015-03-23 io.js v1.6.2 Release (Rod Vagg)849319a260] - util: Check input to util.inherits (Connor Peet) #1240Fishrock123 commentedon Apr 9, 2015
That being said, due to
373I suspect it was caused before:8a945814dd] - string_decoder: optimize write() (Brian White) #1209Fishrock123 commentedon Apr 9, 2015
https://jenkins-iojs.nodesource.com/view/iojs/job/iojs+any-pr+multi/476/
Narrowed it down to
c9207f7fc2] - fs: fix corruption in writeFile and writeFileSync (Olov Lassus) #10634e9bf93e9c] - doc: clarify real name requirement (Roman Reiss) #1250e84dd5f651] - doc: document repl on-demand module loading (Roman Reiss) #12491832743e18] - lib: add missingnewfor errors lib/*.js (Mayhem) #12467dd5e824be] - assert: simplify logic of testing buffer equality (Alex Yursha) #1171269e46be37] - deps: make node-gyp work with io.js (cjihrig) #990b542fb94a4] - deps: upgrade npm to 2.7.3 (Forrest L Norvell) #12192e5b87a147] - src: remove unnecessary environment lookups (Ben Noordhuis) #12387e88a9322c] - src: make accessors immune to context confusion (Ben Noordhuis) #123820c4498e76] - Working on v1.6.3 (Rod Vagg)33c57354aa] - 2015-03-23 io.js v1.6.2 Release (Rod Vagg)849319a260] - util: Check input to util.inherits (Connor Peet) #1240Fishrock123 commentedon Apr 9, 2015
https://jenkins-iojs.nodesource.com/view/iojs/job/iojs+any-pr+multi/477/
1.6.3 fails.
I Suspect the culprit is:
849319a260] - util: Check input to util.inherits (Connor Peet) #1240(No CI was run on that PR either)
silverwind commentedon Apr 9, 2015
All tests seem to timeout on
spawnorspawnSync.silverwind commentedon Apr 9, 2015
Hmm, not sure about that, there are three uses of
inheritsinchild_process.js, which all look valid, but of course the issue can happen elsewhere.5 remaining items
Fishrock123 commentedon Apr 13, 2015
Jenkins
So it looks like win2008r2 has decided to also begin timing out on similar tests.
jbergstroem commentedon Apr 16, 2015
Just wanted to reference #19 here. Seems like we've had similar child process issues prior to the commits triaged above. Since both windows bots has been seeing similar issues lately, we should probably update the issue topic to just "windows" 😢
[-]test: timeouts on win2012 CI[/-][+]test: windows ci timeouts related to child_process[/+]jbergstroem commentedon Apr 17, 2015
So, I just tried running jenkins straight out of powershell instead of wrapping through windows services (that in turn uses nssm.exe). Results here: https://jenkins-iojs.nodesource.com/job/iojs+any-pr+multi/529/nodes=win2008r2/console. No more timeouts. The test that failed is irrelevant to timeouts (we should fix it though :). I'll debug further.
Edit: Here's a run using nssm (and not proxied through windows services): https://jenkins-iojs.nodesource.com/job/iojs+any-pr+multi/nodes=win2008r2/530/console (hint: full pass)
Edit2: If you look at https://jenkins-iojs.nodesource.com/job/iojs+any-pr+multi/531/ windows2012 and 2008 doesn't have any timeouts. I restarted all by avoiding starting/stopping through windows services and only using nssm.
I'm far from a windows expert, but there is something going on with how and what services launches what.
rvagg commentedon Apr 17, 2015
Give it time. We've had passes under the current config before but they end up at failure over time. I.e. don't celebrate yet.
jbergstroem commentedon Apr 17, 2015
Not celebrating at all. It pretty much feels like I have no clue what I'm doing :)
silverwind commentedon May 25, 2015
Seems the recent switch to running through
cmdinstead of a service did fix these at least for the CI. Now we need some testing done if the issues surface on a non-CI box when ran through a service.jbergstroem commentedon May 25, 2015
Lets give it a week so we can confirm that we still don't see them. As mentioned above, I managed to get a pretty stable environment by launching through nssm.
silverwind commentedon Jun 7, 2015
I think this is new on Windows CI:
https://jenkins-iojs.nodesource.com/job/iojs+any-pr+multi/777/nodes=win2008r2/tapTestReport/test.tap-134/
Fishrock123 commentedon Jun 7, 2015
Sounds like a build machine needs to be cleaned. cc @rvagg
jbergstroem commentedon Jun 8, 2015
Currebtly on the run, but last I checked it had lots of disk space. I think it might be related to something else. Will investigate when I'm back tomorrow.
rvagg commentedon Jun 8, 2015
I've had a look, enough space on all of the windows machines but I've done a clean-out and restart on them all anyway, want to try again @silverwind?
jbergstroem commentedon Jun 8, 2015
I recall starting to see this when libuv 1.6.0 landed (when we had all other strange fs-max errors)
silverwind commentedon Aug 22, 2015
Haven't seen this recently.