SonarQube Scanner - Long pause between plugin downloads

scanner

(Brad) #1

Hey Gurus, working on rolling out SonarQube to some of our teams.

One of the teams that was using CE in our pilot started experiencing issues while bringing new repositories onboard with our new enterprise deployment. They build in our travis CI enterprise deployment which is geographically separated from our SonarQube server.

Travis is configured to fail and stop builds after 10 minutes without any output to the command line.

It was failing about here
17:20:48.487 INFO: Load plugins index
17:20:48.719 INFO: Load plugins index (done) | time=231ms
Which seemed strange, since it used to work.

With some debugging enabled we saw what was the problem.

17:20:48.486 INFO: Load/download plugins
17:20:48.487 INFO: Load plugins index
17:20:48.684 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/installed | time=197ms
17:20:48.719 INFO: Load plugins index (done) | time=231ms

17:20:48.722 DEBUG: Download plugin 'cksslacknotifier' to '/home/travis/.sonar/_tmp/fileCache9006929556279479354.tmp'
17:20:48.916 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=cksslacknotifier&acceptCompressions=pack200 | time=193ms

17:21:00.672 DEBUG: Download plugin 'scmgit' to '/home/travis/.sonar/_tmp/fileCache2596820092661418651.tmp'
17:21:00.864 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=scmgit&acceptCompressions=pack200 | time=190ms

17:21:44.613 DEBUG: Download plugin 'issueresolver' to '/home/travis/.sonar/_tmp/fileCache7671627749776003534.tmp'
17:21:44.806 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=issueresolver&acceptCompressions=pack200 | time=192ms

17:23:28.837 DEBUG: Download plugin 'ldap' to '/home/travis/.sonar/_tmp/fileCache1930437100740836350.tmp'
17:23:29.029 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=ldap&acceptCompressions=pack200 | time=192ms

17:23:32.941 DEBUG: Download plugin 'license' to '/home/travis/.sonar/_tmp/fileCache4215381398285870863.tmp'
17:23:33.133 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=license&acceptCompressions=pack200 | time=190ms

17:23:33.320 DEBUG: Download plugin 'softvis3d' to '/home/travis/.sonar/_tmp/fileCache4083277362464229624.tmp'
17:23:33.512 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=softvis3d&acceptCompressions=pack200 | time=190ms

17:23:53.319 DEBUG: Download plugin 'abap' to '/home/travis/.sonar/_tmp/fileCache9207295696351296066.tmp'
17:23:53.509 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=abap&acceptCompressions=pack200 | time=190ms

17:24:14.215 DEBUG: Download plugin 'csharp' to '/home/travis/.sonar/_tmp/fileCache3614045872248234162.tmp'
17:24:14.406 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=csharp&acceptCompressions=pack200 | time=191ms

17:24:37.541 DEBUG: Download plugin 'cpp' to '/home/travis/.sonar/_tmp/fileCache1183432374129872787.tmp'
17:24:37.743 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=cpp&acceptCompressions=pack200 | time=201ms

17:26:12.823 DEBUG: Download plugin 'cobol' to '/home/travis/.sonar/_tmp/fileCache6470717478509517697.tmp'
17:26:13.035 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=cobol&acceptCompressions=pack200 | time=211ms

17:27:05.859 DEBUG: Download plugin 'cssfamily' to '/home/travis/.sonar/_tmp/fileCache3442823742983415113.tmp'
17:27:06.050 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=cssfamily&acceptCompressions=pack200 | time=191ms

17:28:38.397 DEBUG: Download plugin 'flex' to '/home/travis/.sonar/_tmp/fileCache5890277166001067818.tmp'
17:28:38.588 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=flex&acceptCompressions=pack200 | time=191ms

17:29:00.313 DEBUG: Download plugin 'go' to '/home/travis/.sonar/_tmp/fileCache1592327155933812291.tmp'
17:29:00.505 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=go&acceptCompressions=pack200 | time=192ms

17:29:45.217 DEBUG: Download plugin 'web' to '/home/travis/.sonar/_tmp/fileCache9020834144395845608.tmp'
17:29:45.419 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=web&acceptCompressions=pack200 | time=202ms

17:30:03.780 DEBUG: Download plugin 'javascript' to '/home/travis/.sonar/_tmp/fileCache5133843894256050121.tmp'
17:30:03.971 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=javascript&acceptCompressions=pack200 | time=190ms

17:31:01.156 DEBUG: Download plugin 'java' to '/home/travis/.sonar/_tmp/fileCache3069852081462033407.tmp'
17:31:01.346 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=java&acceptCompressions=pack200 | time=189ms

17:33:14.035 DEBUG: Download plugin 'kotlin' to '/home/travis/.sonar/_tmp/fileCache970098732460625394.tmp'
17:33:14.411 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=kotlin&acceptCompressions=pack200 | time=375ms

17:34:35.975 DEBUG: Download plugin 'php' to '/home/travis/.sonar/_tmp/fileCache7664369306006888514.tmp'
17:34:36.168 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=php&acceptCompressions=pack200 | time=193ms

17:35:18.148 DEBUG: Download plugin 'pli' to '/home/travis/.sonar/_tmp/fileCache6623812319988941513.tmp'
17:35:18.340 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=pli&acceptCompressions=pack200 | time=192ms

17:35:45.065 DEBUG: Download plugin 'plsql' to '/home/travis/.sonar/_tmp/fileCache5678320035194999400.tmp'
17:35:45.256 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=plsql&acceptCompressions=pack200 | time=191ms

17:36:15.591 DEBUG: Download plugin 'python' to '/home/travis/.sonar/_tmp/fileCache1748699607127318415.tmp'
17:36:15.782 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=python&acceptCompressions=pack200 | time=190ms

17:36:40.294 DEBUG: Download plugin 'rpg' to '/home/travis/.sonar/_tmp/fileCache7334874488757136921.tmp'
17:36:40.485 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=rpg&acceptCompressions=pack200 | time=191ms

17:37:03.911 DEBUG: Download plugin 'security' to '/home/travis/.sonar/_tmp/fileCache1010981287733196610.tmp'
17:37:04.103 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=security&acceptCompressions=pack200 | time=192ms

17:37:20.952 DEBUG: Download plugin 'swift' to '/home/travis/.sonar/_tmp/fileCache3068664198418458736.tmp'
17:37:21.145 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=swift&acceptCompressions=pack200 | time=193ms

17:37:58.656 DEBUG: Download plugin 'typescript' to '/home/travis/.sonar/_tmp/fileCache5152044360122851319.tmp'
17:37:58.847 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=typescript&acceptCompressions=pack200 | time=191ms

17:38:28.114 DEBUG: Download plugin 'tsql' to '/home/travis/.sonar/_tmp/fileCache239962116675507065.tmp'
17:38:28.303 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=tsql&acceptCompressions=pack200 | time=189ms

17:38:55.537 DEBUG: Download plugin 'vbnet' to '/home/travis/.sonar/_tmp/fileCache8012101540053163031.tmp'
17:38:55.728 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=vbnet&acceptCompressions=pack200 | time=191ms

17:39:13.688 DEBUG: Download plugin 'vb' to '/home/travis/.sonar/_tmp/fileCache3089733126814119994.tmp'
17:39:13.878 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=vb&acceptCompressions=pack200 | time=190ms

17:39:58.408 DEBUG: Download plugin 'xml' to '/home/travis/.sonar/_tmp/fileCache6711645797509320693.tmp'
17:39:58.599 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=xml&acceptCompressions=pack200 | time=191ms

17:40:28.411 DEBUG: Download plugin 'scmsvn' to '/home/travis/.sonar/_tmp/fileCache9059441404638520997.tmp'
17:40:28.603 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=scmsvn&acceptCompressions=pack200 | time=192ms

17:42:11.416 DEBUG: Download plugin 'jdepend' to '/home/travis/.sonar/_tmp/fileCache8772581271132760902.tmp'
17:42:11.603 DEBUG: GET 200 http://10.0.0.0:9000/api/plugins/download?plugin=jdepend&acceptCompressions=pack200 | time=187ms

17:42:11.615 INFO: Load/download plugins (done) | time=1283129ms

It is taking 21 minutes to download the plugins. With debugging on, the scanner is chatty enough to keep Travis alive.

What struck me as odd is that it logs that it is downloading a plugin (Ex, scmsvn), logs the get for the file in a reasonable time of a few hundred ms, then waits minutes before logging about the next plugin! I’m still digging through the source code to try and find the answer, but I’m wondering if anyone has seen this before.

Thanks!