tag:help.appveyor.com,2012-11-13:/discussions/problems/6898-buildtest-timeoutsAppVeyor: Discussion 2018-10-19T08:18:23Ztag:help.appveyor.com,2012-11-13:Comment/427936412017-06-18T11:55:30Z2017-06-18T11:55:31ZBuild/test timeouts<div><p>Ooops,</p>
<p>Of course, I meant the update on Jul 12th.<br>
<a href="https://www.appveyor.com/updates/">https://www.appveyor.com/updates/</a></p>
<p>K.</p></div>Krzysztof Czurylotag:help.appveyor.com,2012-11-13:Comment/427936412017-06-18T18:19:14Z2017-06-18T18:19:14ZBuild/test timeouts<div><p>Hi Krzysztof,</p>
<p>Indeed, I've tested the last commit on both "previous" and current images and noticed the regression: <a href="https://ci.appveyor.com/project/FeodorFitsner/nvml/history">https://ci.appveyor.com/project/FeodorFitsner/nvml/history</a></p>
<p>Among other things installed on June 12th update were latest Windows updates and most probably something could be related to that. Will be taking a look.</p>
<p>Can you give me some hint what part of the test could become slow - is it something IO related or perhaps some chore PS task before/after test, etc.?</p></div>Feodor Fitsnertag:help.appveyor.com,2012-11-13:Comment/427936412017-06-19T02:56:57Z2017-06-19T02:56:57ZBuild/test timeouts<div><p>Oh, forgot to mention - to unblock the builds please run on <code>image: Previous Visual Studio 2015</code> for now.</p></div>Feodor Fitsnertag:help.appveyor.com,2012-11-13:Comment/427936412017-06-19T07:32:08Z2017-06-19T07:32:10ZBuild/test timeouts<div><p>Hi Feodor,</p>
<p>Thanks for quick response.<br>
I analyzed the logs and it looks like the problem is not in the tests, but in the PowerShell scripts that are used to execute them. Each test program/script is run in a subprocess / PS job. The execution time of each job is printed in the log and in most cases it's below 1s. But when you compare it with the timestamp of the log line, it appears that spawning this subprocess/job may take a couple of seconds. It used to be ~3s (average), now it is 9s avg. (not less than 4 sec.!!!).<br>
I have no idea whether this change it is related to the PowerShell itself or some other Windows updates.</p></div>Krzysztof Czurylotag:help.appveyor.com,2012-11-13:Comment/427936412017-06-19T13:51:46Z2017-06-19T13:51:46ZBuild/test timeouts<div><p>How do you invoke PS scripts with tests? I'd like to to a reproduce to use in regression testing.</p></div>Feodor Fitsnertag:help.appveyor.com,2012-11-13:Comment/427936412017-06-20T15:32:29Z2017-06-20T15:32:30ZBuild/test timeouts<div><p>It's something like this:</p>
<p>$sb = { cd $args[0] Invoke-Expression $args[1] } $j1 = Start-Job -Name $name -ScriptBlock $sb -ArgumentList (pwd).Path, ".\$runscript" ... Receive-Job -Job $j1</p>
<p>If needed, I can write a simple script that would illustrate that.</p>
<p>K.</p></div>Krzysztof Czurylotag:help.appveyor.com,2012-11-13:Comment/427936412017-06-20T16:05:41Z2017-06-20T16:05:41ZBuild/test timeouts<div><p>Yes, please, an example appveyor build in public repository would be great help. Maybe with a loop to see real delay. Thank you!</p></div>Feodor Fitsnertag:help.appveyor.com,2012-11-13:Comment/427936412017-06-27T09:48:53Z2017-06-27T09:48:54ZBuild/test timeouts<div><p>Hi Feodor,</p>
<p>Sorry for late response.<br>
Eventually I found some time to write a simple script that reproduces the issue. It's a simplified version of the actual script we use - stripped out from everything that is not relevant.</p>
<p>See: src/test/RUNTESTS.ps1 + src/test/TEST.ps1<br>
The comments in these files should explain how it works.</p>
<p><a href="https://github.com/krzycz/nvml/commits/av-test_job_time1">https://github.com/krzycz/nvml/commits/av-test_job_time1</a><br>
<a href="https://github.com/krzycz/nvml/commits/av-test_job_time2">https://github.com/krzycz/nvml/commits/av-test_job_time2</a></p>
<p>I have run it on the old and new OS image and here are the results:<br>
<a href="https://ci.appveyor.com/project/krzycz/nvml/build/1.0.1607">https://ci.appveyor.com/project/krzycz/nvml/build/1.0.1607</a><br>
<a href="https://ci.appveyor.com/project/krzycz/nvml/build/1.0.1608">https://ci.appveyor.com/project/krzycz/nvml/build/1.0.1608</a></p></div>Krzysztof Czurylotag:help.appveyor.com,2012-11-13:Comment/427936412017-06-28T16:33:37Z2017-06-28T16:33:37ZBuild/test timeouts<div><p>Even when using <code>image: Previous Visual Studio 2015</code>, we still observe sporadic time outs. I.e. one job completes in 30 min.s, while the second one timeouts.</p></div>Krzysztof Czurylotag:help.appveyor.com,2012-11-13:Comment/427936412017-06-28T16:42:15Z2017-06-28T16:42:28ZBuild/test timeouts<div><p>Hi Krzysztof,</p>
<p>Thanks for the provided repro. We are currently looking into this issue.</p></div>Feodor Fitsnertag:help.appveyor.com,2012-11-13:Comment/427936412017-06-29T03:56:22Z2017-06-29T03:56:22ZBuild/test timeouts<div><p>Hi Krzysztof,</p>
<p>Sorry with some delay and not providing too much results. Here is what I did:</p>
<ul>
<li>Forked your repository</li>
<li>Reset to your <a href="https://github.com/IlyaFinkelshteyn/nvml/commit/ec2f4e09fe70817c37edb1c98b1a3f0403663b62">test commit</a></li>
<li>Added <a href="https://github.com/IlyaFinkelshteyn/nvml/commit/1dd29e6f9e76841fa4543ae2817582c3c5c4eb34">build matrix to test both images simultaneously</a>. Build results was <a href="https://ci.appveyor.com/project/IlyaFinkelshteyn/nvml/build/1.0.2">even faster on new image</a></li>
<li>Added <a href="https://github.com/IlyaFinkelshteyn/nvml/commit/b7fd73021e43bb3caee97d9613ad319e6d6a8360">loop to have more representative results</a>. Build results are <a href="https://ci.appveyor.com/project/IlyaFinkelshteyn/nvml/build/1.0.3">still similar</a></li>
</ul>
<p>I can miss something with this repro, can you please advise?</p>
<p>Ilya.</p></div>Ilya Finkelshteyntag:help.appveyor.com,2012-11-13:Comment/427936412017-06-29T09:29:32Z2017-06-29T09:29:33ZBuild/test timeouts<div><p>Hi,</p>
<p>In all your tests, "RUNTESTS TOTAL" is between 48-54 sec., which means you hit the regression is all the cases. The 2-5sec. difference doesn't matter, because the actual problem is that the total time used to be ~20 sec.<br>
See: <a href="https://ci.appveyor.com/project/krzycz/nvml/build/1.0.1607">https://ci.appveyor.com/project/krzycz/nvml/build/1.0.1607</a></p>
<p>Note that the actual test time is about 10s (10 iterations x 1s), but since the overhead of spawning new job is about 1s (that's very long, but still acceptable), then with additional 10s and it gives us 20s in total. (that's how it used to be)<br>
Now the total time is ~50s, so the overhead is 40s (4s per job), which is veeeery bad.</p>
<p>Based on your results and on the fact we still observe sporadic timeouts when using old image, I suspect the problem may be related not to the image update, but rather some other factor - server machines, build cloud, etc...</p>
<p>K.</p></div>Krzysztof Czurylotag:help.appveyor.com,2012-11-13:Comment/427936412017-06-29T13:44:22Z2017-06-29T13:44:23ZBuild/test timeouts<div><p>Hi Ilya,</p>
<p>I took yours commit and started a new build and here you have a results:<br>
<a href="https://ci.appveyor.com/project/lplewa/nvml/build/1.0.599">https://ci.appveyor.com/project/lplewa/nvml/build/1.0.599</a></p>
<p>it is 9:30min to 3:30 min on old image</p>
<p>It's look like that tests on new image is always slow, on old images sometimes is fast sometimes it is slow.</p></div>Ćukasz Plewatag:help.appveyor.com,2012-11-13:Comment/427936412017-06-30T16:40:36Z2017-06-30T16:40:36ZBuild/test timeouts<div><p>Hi Łukasz and Krzysztof,</p>
<p>Apparently <a href="https://support.microsoft.com/en-ie/help/4014507">update 4014507</a> causes this. We hope that installing latest updates on top of it could fix that, but they did not. We are not sure if it is safe to uninstall it globally from image. For now workaround is to uninstall it at <code>init</code> stage as I did <a href="https://github.com/IlyaFinkelshteyn/nvml/blob/master/appveyor.yml#L6">here</a>. It takes about 40 seconds (including reboot), which maybe tolerable for you, in comparison to performance degrade you observe.</p>
<p>We will look what else we can do, but for now this is workaround we propose.</p>
<p>Also sorry for confusion with <code>Previous Visual Studio 2015</code> image -- it worked the same as new one sometimes because it was actually new one. We are in process of adding more Hyper-V hosts to our datacenter and during this process there are short periods when older images still not deployed to new host.</p>
<p>Ilya.</p></div>Ilya Finkelshteyntag:help.appveyor.com,2012-11-13:Comment/427936412017-07-22T04:41:40Z2017-07-22T04:41:40ZBuild/test timeouts<div><p>Hi guys,</p>
<p>We've just deployed an updated "Visual Studio 2015" image with PS performance issue fixed! No workarounds needed anymore.</p></div>Feodor Fitsnertag:help.appveyor.com,2012-11-13:Comment/427936412017-07-22T08:30:06Z2017-07-22T08:30:08ZBuild/test timeouts<div><p>Hi Feodor,</p>
<p>Thanks a lot for your support.</p></div>Krzysztof Czurylo