Important Announcement

This forum will be discontinued.

The creation of new topics is disabled.

Please open GitHub issues for the corresponding topics/products in the following Trivadis repositories:

A lot of users have already a GitHub account and the management of the issues is better than in this forum. For example, closing a forum topic is never related to a product change. Closing a GitHub issue for an accepted bug means that the bug is fixed. This should simplify the work for all involved parties.

See this blog post for more information.

Thank you for your understanding.

Notifications
Clear all

[Solved] TVDCC extremely slow

 
PL/SQL Cop
Last Post by filou97 5 years ago
6 Posts
2 Users
1 Reactions
2,097 Views
RSS
0
09/12/2019 10:50 am
Topic starter
filou97 
(@filou97)
Active Member
19 Posts
7 13 3

Hello,

Is there a limitation in the trial/preview version of TVDCC that could explain its extreme slowness?

It takes up to 20 minutes between each processed file (depending on the number of issues found) to write the "tvdcc-result.xml" (result file passed back to SonarQube).

Here is the output of my last tentative (1:43 for 10 scanned files + failed on a timeout error) :

H:\Projects\dbcc-internal-dev\qc_utility>sonar-scanner.bat -D"sonar.projectKey=qc_utility" -D"sonar.sources=." -D"sonar.host.url=htt
p://localhost:9000" -D"sonar.login=66e14a62c006defcb94e8f7c78e3c21190d12cca"
INFO: Scanner configuration file: C:\PGM\sonar-scanner-4.2.0.1873-windows\bin\..\conf\sonar-scanner.properties
INFO: Project root configuration file: H:\Projects\dbcc-internal-dev\qc_utility\sonar-project.properties
INFO: SonarQube Scanner 4.2.0.1873
INFO: Java 11.0.3 AdoptOpenJDK (64-bit)
INFO: Windows 7 6.1 amd64
INFO: User cache: C:\Users\deboiph\.sonar\cache
INFO: SonarQube server 8.0.0
INFO: Default locale: "en_US", source code encoding: "windows-1252" (analysis is platform dependent)
INFO: Load global settings
INFO: Load global settings (done) | time=62ms
INFO: Server id: BF41A1F2-AW7pjfLIpqK443FqIDcS
INFO: User cache: C:\Users\deboiph\.sonar\cache
INFO: Load/download plugins
INFO: Load plugins index
INFO: Load plugins index (done) | time=47ms
INFO: Load/download plugins (done) | time=140ms
INFO: Define PlSql Cop PlugIn - Trivadis PL/SQL Cop
INFO: Process project properties
INFO: Process project properties (done) | time=16ms
INFO: Execute project builders
INFO: Execute project builders (done) | time=0ms
INFO: Project key: qc_utility
INFO: Base dir: H:\Projects\dbcc-internal-dev\qc_utility
INFO: Working dir: H:\Projects\dbcc-internal-dev\qc_utility\.scannerwork
INFO: Load project settings for component key: 'qc_utility'
INFO: Load project settings for component key: 'qc_utility' (done) | time=31ms
INFO: Load quality profiles
INFO: Load quality profiles (done) | time=47ms
INFO: Load active rules
INFO: Load active rules (done) | time=1154ms
INFO: Indexing files...
INFO: Project configuration:
INFO: 69 files indexed
INFO: 0 files ignored because of scm ignore settings
INFO: Quality profile for plsqlcop: Trivadis PL/SQL Cop
INFO: Quality profile for xml: Sonar way
INFO: ------------- Run sensors on module qc_utility
INFO: Define PlSql Cop PlugIn - Trivadis PL/SQL Cop
INFO: Load metrics repository
INFO: Load metrics repository (done) | time=16ms
INFO: PlSQL COP Sensor initializing
INFO: Sensor JaCoCo XML Report Importer [jacoco]
INFO: Sensor JaCoCo XML Report Importer [jacoco] (done) | time=16ms
INFO: Sensor JavaXmlSensor [java]
INFO: 1 source files to be analyzed
INFO: Load project repositories
INFO: Load project repositories (done) | time=15ms
INFO: Sensor JavaXmlSensor [java] (done) | time=234ms
INFO: Sensor HTML [web]
INFO: 1/1 source files have been analyzed
INFO: Sensor HTML [web] (done) | time=0ms
INFO: Sensor XML Sensor [xml]
INFO: 1 source files to be analyzed
INFO: Sensor XML Sensor [xml] (done) | time=327ms
INFO: Sensor Process PlSQLCop Report - Mesure and Issues [plsqlcop]
INFO: PlSQL COP Sensor analyzing
INFO: 1/1 source files have been analyzed
INFO: Executing command: C:/pgm/dev/tvdcc/tvdcc-phd2.cmd path=H:\Projects\dbcc-internal-dev\qc_utility output=H:\Projects\dbcc-inter
nal-dev\qc_utility\.scannerwork\tvdcc-result.xml filter="(pkb|pks)$" timeout=10 excel=false html=false genmodel=false complexity=0 c
leanup=false check= skip= license= validator=com.trivadis.tvdcc.validators.DBCCGuidelines
INFO: CLASSPATH=c:\pgm\dev\tvdcc;c:\pgm\dev\tvdcc\plugin
INFO: JAVA_HOME=C:\PGM\jdk1.8.0_231
INFO:
INFO: Trivadis PL/SQL Cop Version 2.3.0 (2019-09-28 21:09:46 +0200)
INFO: for Trivadis PL/SQL & SQL Coding Guidelines Version 3.3
INFO: Copyright 2010-2019 by Philipp Salvisberg (philipp.salvisberg@trivadis.com)
INFO: Trivadis AG (www.trivadis.com)
INFO:
INFO: Trial/Preview version
INFO: - valid thru: 2020-03-31
INFO: - valid for versions less than: 3
INFO: - max. files: unlimited
INFO: - max. lines: 5000
INFO: - max. commands: 200
INFO: - max. bytes: 400000
INFO:
INFO: Parameters:
INFO: - path: H:\Projects\dbcc-internal-dev\qc_utility
INFO: - filter: (pkb|pks)$
INFO: - timeout: 10
INFO: - complexity: 0
INFO: - output: H:\Projects\dbcc-internal-dev\qc_utility\.scannerwork\tvdcc-result.html
INFO: - template: html.xsl
INFO: - excel: false
INFO: - html: false
INFO: - transonly: false
INFO: - cleanup: false
INFO: - check:
INFO: - skip:
INFO: - nosonar: true
INFO: - license:
INFO: - validator: com.trivadis.tvdcc.validators.TrivadisGuidelines3
INFO: - genmodel: false
INFO:
INFO: processing file 'qc_opsys_demand_cfg.pks'... 1 issue found.
INFO: processing file 'QC_TPL_DEFINES.pks'... 1 issue found.
INFO: processing file 'QC_UTILITY_KRN.pks'... 29 issues found.
INFO: processing file 'QC_UTILITY_MSG.pkb'... 452 issues found.
INFO: processing file 'QC_UTILITY_MSG.pks'... 22 issues found.
INFO: processing file 'QC_UTILITY_ORA_04068.pkb'... 270 issues found.
INFO: processing file 'QC_UTILITY_ORA_04068.pks'... 2 issues found.
INFO: processing file 'QC_UTILITY_STAT.pkb'... 430 issues found.
INFO: processing file 'QC_UTILITY_STAT.pks'... 22 issues found.
INFO: processing file 'QC_UTILITY_VAR.pks'... 56 issues found.
INFO: 56 issues found.
INFO: 2    ERROR CodeChecker        - java.lang.NullPointerException
INFO: java.lang.RuntimeException: java.lang.NullPointerException
INFO:   at com.trivadis.tvdcc.printer.XMLIssuePrinterStrategy.endResource(XMLIssuePrinterStrategy.java:468)
INFO:   at com.trivadis.tvdcc.printer.CompositePrinterStrategy.endResource(CompositePrinterStrategy.java:46)
INFO:   at com.trivadis.tvdcc.process.ProcessResourceTask.stopGracefully(ProcessResourceTask.java:86)
INFO:   at com.trivadis.tvdcc.process.SQLPLUSReader.processSerialResource(SQLPLUSReader.java:283)
INFO:   at com.trivadis.tvdcc.CodeChecker.doCodeCheck(CodeChecker.java:574)
INFO:   at com.trivadis.tvdcc.CodeChecker.mainFunction(CodeChecker.java:605)
INFO:   at com.trivadis.tvdcc.CodeChecker.main(CodeChecker.java:625)
INFO: Caused by: java.lang.NullPointerException
INFO:   at com.trivadis.tvdcc.printer.XMLIssuePrinterStrategy.endResource(XMLIssuePrinterStrategy.java:275)
INFO:   ... 6 more
INFO: ------------------------------------------------------------------------
INFO: EXECUTION FAILURE
INFO: ------------------------------------------------------------------------
INFO: Total time: 1:43:11.847s
INFO: Final Memory: 12M/48M
INFO: ------------------------------------------------------------------------
ERROR: Error during SonarQube Scanner execution
org.sonar.api.utils.command.TimeoutException: Timeout exceeded: 600000 ms [command: C:/pgm/dev/tvdcc/tvdcc-phd2.cmd path=H:\Projects
\dbcc-internal-dev\qc_utility output=H:\Projects\dbcc-internal-dev\qc_utility\.scannerwork\tvdcc-result.xml filter="(pkb|pks)$" time
out=10 excel=false html=false genmodel=false complexity=0 cleanup=false check= skip= license= validator=com.trivadis.tvdcc.validator
s.DBCCGuidelines]
        at org.sonar.api.utils.command.CommandExecutor.execute(CommandExecutor.java:96)
        at org.sonar.api.utils.command.CommandExecutor.execute(CommandExecutor.java:134)
        at com.trivadis.sonar7.plugins.plsqlcop.PlSqlCopExecutor.execute(PlSqlCopExecutor.java:69)
        at com.trivadis.sonar7.plugins.plsqlcop.PlSqlCopSensor.analyze(PlSqlCopSensor.java:43)
        at com.trivadis.sonar7.plugins.plsqlcop.PlSqlCopSensor.execute(PlSqlCopSensor.java:190)
        at org.sonar.scanner.sensor.AbstractSensorWrapper.analyse(AbstractSensorWrapper.java:48)
        at org.sonar.scanner.sensor.ModuleSensorsExecutor.execute(ModuleSensorsExecutor.java:85)
        at org.sonar.scanner.sensor.ModuleSensorsExecutor.lambda$execute$1(ModuleSensorsExecutor.java:59)
        at org.sonar.scanner.sensor.ModuleSensorsExecutor.withModuleStrategy(ModuleSensorsExecutor.java:77)
        at org.sonar.scanner.sensor.ModuleSensorsExecutor.execute(ModuleSensorsExecutor.java:59)
        at org.sonar.scanner.scan.ModuleScanContainer.doAfterStart(ModuleScanContainer.java:82)
        at org.sonar.core.platform.ComponentContainer.startComponents(ComponentContainer.java:136)
        at org.sonar.core.platform.ComponentContainer.execute(ComponentContainer.java:122)
        at org.sonar.scanner.scan.ProjectScanContainer.scan(ProjectScanContainer.java:387)
        at org.sonar.scanner.scan.ProjectScanContainer.scanRecursively(ProjectScanContainer.java:383)
        at org.sonar.scanner.scan.ProjectScanContainer.doAfterStart(ProjectScanContainer.java:346)
        at org.sonar.core.platform.ComponentContainer.startComponents(ComponentContainer.java:136)
        at org.sonar.core.platform.ComponentContainer.execute(ComponentContainer.java:122)
        at org.sonar.scanner.bootstrap.GlobalContainer.doAfterStart(GlobalContainer.java:141)
        at org.sonar.core.platform.ComponentContainer.startComponents(ComponentContainer.java:136)
        at org.sonar.core.platform.ComponentContainer.execute(ComponentContainer.java:122)
        at org.sonar.batch.bootstrapper.Batch.doExecute(Batch.java:72)
        at org.sonar.batch.bootstrapper.Batch.execute(Batch.java:66)
        at org.sonarsource.scanner.api.internal.batch.BatchIsolatedLauncher.execute(BatchIsolatedLauncher.java:46)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.base/java.lang.reflect.Method.invoke(Unknown Source)
        at org.sonarsource.scanner.api.internal.IsolatedLauncherProxy.invoke(IsolatedLauncherProxy.java:60)
        at com.sun.proxy.$Proxy0.execute(Unknown Source)
        at org.sonarsource.scanner.api.EmbeddedScanner.doExecute(EmbeddedScanner.java:189)
        at org.sonarsource.scanner.api.EmbeddedScanner.execute(EmbeddedScanner.java:138)
        at org.sonarsource.scanner.cli.Main.execute(Main.java:112)
        at org.sonarsource.scanner.cli.Main.execute(Main.java:75)
        at org.sonarsource.scanner.cli.Main.main(Main.java:61)
Caused by: java.util.concurrent.TimeoutException
        at java.base/java.util.concurrent.FutureTask.get(Unknown Source)
        at org.sonar.api.utils.command.CommandExecutor.execute(CommandExecutor.java:87)
        ... 34 more
ERROR:
ERROR: Re-run SonarQube Scanner using the -X switch to enable full debug logging.

H:\Projects\dbcc-internal-dev\qc_utility>

Tested versions:
- sonarqube-8.0 + sonar-scanner-4.2.0.1873-windows + sonar-plsql-cop-plugin-7.9.0.1 + jdk-11.0.5
- tvdcc-2.3.0 + validators.jar + jdk1.8.0_231

Thanks,
Philippe

5 Answers
1
11/12/2019 9:49 am
Topic starter
filou97 
(@filou97)
Active Member
19 Posts
7 13 3

I get about the same performance as yours when testing on the "sample" directory (installed on my C drive). This rang a bell to me! Indeed, my packages are located on... a network drive. After moving them to my C: drive, the processing time went down from 3 minutes to 3 seconds. Bingo!

So, problem solved, you can close the topic.

Thanks

0
09/12/2019 11:29 am
Philipp Salvisberg 
(@phs)
Admin
  Trusted Member
50 Posts
0 40 9

You set the timeout to 10 seconds per file. If you process 10 files and every file gets a timeout then the process is terminated after 1:40 minutes without any useful result. This does not explain the 20 minutes per file issue. 

The logs are not conclusive. Looks like the are based on several runs since different validators are used. Could you try to use the command line utility (tvdcc.sh / tvdcc.cmd) with default settings (default validator) and post the result here? Thank you

0
10/12/2019 1:50 pm
Topic starter
filou97 
(@filou97)
Active Member
19 Posts
7 13 3

I understand your point on the timeout (and I will fine tune those 2 parameters) but, as you said, it's does not explain the slowness issue.

I ran different tests on a more limited set of files (".pks" only):

  • with your validators.jar and with the one I've created;
  • with the following validators: Guidelines3, Guidelines3Plus and (my) DBCCGuidelines;
  • by launching directly tvdcc or by launching it through sonar-scanner.

My conclusion is that the execution time is proportional to the number of issues found rather than on the number of lines scanned. I explain this by the fact that it's the writing of the XML which takes most of the time, not the scanning of the source code itself. Also, sonar-scanner add very little overhead compared to a direct launch of tvdcc.

Here is the output of a direct invocation of tvdcc with your validators.jar:

H:\Projects\dbcc-internal-dev\qc_utility>C:/pgm/dev/tvdcc/tvdcc.cmd path=H:\Projects\dbcc-internal-dev\qc_utility output=H:\Pro
jects\dbcc-internal-dev\qc_utility\.scannerwork\tvdcc-result.xml filter="(pkb|pks)$" timeout=10 excel=false html=false genmodel=fals
e complexity=0 cleanup=false check= skip= license= validator=com.trivadis.tvdcc.validators.TrivadisGuidelines3Plus

Trivadis PL/SQL Cop Version 2.3.0 (2019-09-28 21:09:46 +0200)
for Trivadis PL/SQL & SQL Coding Guidelines Version 3.3
Copyright 2010-2019 by Philipp Salvisberg (philipp.salvisberg@trivadis.com)
Trivadis AG (www.trivadis.com)

Trial/Preview version
- valid thru: 2020-03-31
- valid for versions less than: 3
- max. files: unlimited
- max. lines: 5000
- max. commands: 200
- max. bytes: 400000

Parameters:
- path: H:\Projects\dbcc-internal-dev\qc_utility
- filter: (pkb|pks)$
- timeout: 10
- complexity: 0
- output: H:\Projects\dbcc-internal-dev\qc_utility\.scannerwork\tvdcc-result.html
- template: html.xsl
- excel: false
- html: false
- transonly: false
- cleanup: false
- check:
- skip:
- nosonar: true
- license:
- validator: com.trivadis.tvdcc.validators.TrivadisGuidelines3Plus
- genmodel: false

processing file 'qc_opsys_demand_cfg.pks'... 1 issue found.
processing file 'QC_TPL_DEFINES.pks'... 1 issue found.
processing file 'QC_UTILITY_KRN.pks'... 112 issues found.
processing file 'QC_UTILITY_MSG.pks'... 51 issues found.
processing file 'QC_UTILITY_ORA_04068.pks'... 4 issues found.
processing file 'QC_UTILITY_STAT.pks'... 47 issues found.
processing file 'QC_UTILITY_VAR.pks'... 41 issues found.

Summary:
- Total files: 7
- Total bytes: 58386
- Total lines: 1824
- Total comment lines: 1387
- Total blank lines: 3
- Total net lines: 434
- Total commands: 7
- Total statements (PL/SQL): 0
- Max. cyclomatic complexity: 0
- Max. Halstead volume: 0.0
- Min. maintainability index (MI): 221.0
- Total issues: 257
- Total warnings: 257
- Total errors: 0
- Total processing time in seconds: 555.874

You can see that it takes almost 10 minutes for only 7 relatively small files.  The number of issues detected for a given file is reported almost instantly (which makes me say that the scanning is quite fast). It's between 2 files (during which the XML seems to be written) that most of the time is spent: for the 3rd file, about 5 minutes for the 112 issues.

Philipp Salvisberg 10/12/2019 4:43 pm

Could you please post the result without using the validator parameter? You are currently using TrivadisGuidelines3Plus validator. I do not see if this is the original or an amended validator. Thanks.

 
0
11/12/2019 7:27 am
Topic starter
filou97 
(@filou97)
Active Member
19 Posts
7 13 3

Here is the requested log:

H:\Projects\dbcc-internal-dev\qc_utility>C:/pgm/dev/tvdcc/tvdcc.cmd path=H:\Projects\dbcc-internal-dev\qc_utility output=H:\Projects\dbcc-internal-dev\qc_utility\.scannerwork\tvdcc-result.xml filter="pks$" timeout=60 excel=false html=false genmodel=false complexity=0 cleanup=false check= skip= license=

Trivadis PL/SQL Cop Version 2.3.0 (2019-09-28 21:09:46 +0200)
for Trivadis PL/SQL & SQL Coding Guidelines Version 3.3
Copyright 2010-2019 by Philipp Salvisberg (philipp.salvisberg@trivadis.com)
Trivadis AG (www.trivadis.com)

Trial/Preview version
- valid thru: 2020-03-31
- valid for versions less than: 3
- max. files: unlimited
- max. lines: 5000
- max. commands: 200
- max. bytes: 400000

Parameters:
- path: H:\Projects\dbcc-internal-dev\qc_utility
- filter: pks$
- timeout: 60
- complexity: 0
- output: H:\Projects\dbcc-internal-dev\qc_utility\.scannerwork\tvdcc-result.html
- template: html.xsl
- excel: false
- html: false
- transonly: false
- cleanup: false
- check:
- skip:
- nosonar: true
- license:
- validator: com.trivadis.tvdcc.validators.TrivadisGuidelines3
- genmodel: false

processing file 'qc_opsys_demand_cfg.pks'... 1 issue found.
processing file 'QC_TPL_DEFINES.pks'... 1 issue found.
processing file 'QC_UTILITY_KRN.pks'... 29 issues found.
processing file 'QC_UTILITY_MSG.pks'... 7 issues found.
processing file 'QC_UTILITY_ORA_04068.pks'... 2 issues found.
processing file 'QC_UTILITY_STAT.pks'... 7 issues found.
processing file 'QC_UTILITY_VAR.pks'... 17 issues found.

Summary:
- Total files: 7
- Total bytes: 58386
- Total lines: 1824
- Total comment lines: 1387
- Total blank lines: 3
- Total net lines: 434
- Total commands: 7
- Total statements (PL/SQL): 0
- Max. cyclomatic complexity: 0
- Max. Halstead volume: 0.0
- Min. maintainability index (MI): 221.0
- Total issues: 64
- Total warnings: 64
- Total errors: 0
- Total processing time in seconds: 169.863

Of course it's quicker (nearly 3 minutes for 7 files) as naming conventions are no more checked and therefore less issues are detected and written in the XML file. But, the average time per issue is 170 / 64 = 2,66 sec, which is still comparable to 556 / 257 = 2,16 sec.

This post was modified 5 years ago by filou97
0
11/12/2019 8:15 am
Philipp Salvisberg 
(@phs)
Admin
  Trusted Member
50 Posts
0 40 9

This is really slow. I've changed to the sample directory of tvdcc and run "tvdcc.sh path=.".

The result was: 

Summary:
- Total files: 93
- Total bytes: 183172
- Total lines: 8015
- Total comment lines: 814
- Total blank lines: 1294
- Total net lines: 5907
- Total commands: 211
- Total statements (PL/SQL): 1426
- Max. cyclomatic complexity: 5
- Max. Halstead volume: 574.8833010612884
- Min. maintainability index (MI): 83.45140948052318
- Total issues: 288
- Total warnings: 288
- Total errors: 0
- Total processing time in seconds: 8.841

The HTML file contains also a section where the elapsed time per file is recorded (see "File Overview" in attached file). The first file typically takes a bit longer. 

However, your run times are way off. I have currently no idea what the reason is. I cannot imagine that your computer or VM is that slow.

Any chance to provide the 7 files?

This post was modified 5 years ago 4 times by Philipp Salvisberg
Forum Jump:
  Previous Topic
Next Topic