Add and enable build profiling extensions #1498

woj-tek · 2023-03-21T13:54:35Z

Adds and enables maven build profiling extensions as per discussion in https://www.mail-archive.com/server-dev@james.apache.org/msg72994.html

I enabled storing profiling artifacts in build - I hope it's ok (IMHO it's better than spamming stdout). csv (from maven-buildtime-extension) is about ~0,5M and html (from maven-profiler) is ~1,7M.

EDIT: https://issues.apache.org/jira/browse/JAMES-3879

chibenwa

Looks nice to me.

Can you share screenshot of these reports?

jeantil · 2023-03-22T15:44:12Z

well the build step is completed on the latest build of the MR : https://ci-builds.apache.org/job/james/job/ApacheJames/job/PR-1498/4/artifact/.profiler/profiler-report-2023-03-22-13-55-28.html
and the winner is ....

<h2>Apache James :: Server :: JMAP RFC 8621 (242.8 s)</h2>
            

Plugin execution | Duration
-- | --
net.alchim31.maven:scala-maven-plugin:4.6.1:compile {execution: scala-compile-first} | 131.8 s
net.alchim31.maven:scala-maven-plugin:4.6.1:testCompile {execution: scala-test-compile} | 96.03 s
io.github.evis:scalafix-maven-plugin_2.13:0.1.6_0.9.34:scalafix {execution: scala-check-style} | 7.203 s

woj-tek · 2023-03-22T18:49:57Z

Can you share screenshot of these reports?

@jeantil already provided the link.

There should also be a CSV but I'm not sure why there is no target in root directory (thus no buildstats*.csv files)

woj-tek · 2023-03-23T02:25:18Z

I had some fun with jq to get some summary - total time (in minutes) and number of executions of particular mojos, with:

[.projects[].mojos[]] |
group_by(.mojo) |
map({
    mojo: first.mojo,
    count: [.[].time] | length,
    totals: [.[].time | sub(" ms"; "") | tonumber/1000/60] | add
    }
) | 
sort_by(.totals) | reverse

the result for profiler-report-2023-03-22-19-11-22.json is following:

$ jq '[.projects[].mojos[]] | group_by(.mojo) | map({ mojo: first.mojo,count: [.[].time] | length, totals: [.[].time | sub(" ms"; "") | tonumber/1000/60] | add } )  | sort_by(.totals) | reverse' /Users/wojtek/dev/tmps/profiler-report-2023-03-22-19-11-22.json
[
  {
    "mojo": "pl.project13.maven:git-commit-id-plugin:4.9.10:revision {execution: get-the-git-infos}",
    "count": 779,
    "totals": 9.122933333333318
  },
  {
    "mojo": "net.alchim31.maven:scala-maven-plugin:4.6.1:compile {execution: scala-compile-first}",
    "count": 21,
    "totals": 9.057266666666667
  },
  {
    "mojo": "org.apache.maven.plugins:maven-remote-resources-plugin:1.6.0:process {execution: process-resource-bundles}",
    "count": 259,
    "totals": 6.400850000000002
  },
  {
    "mojo": "net.alchim31.maven:scala-maven-plugin:4.6.1:testCompile {execution: scala-test-compile}",
    "count": 21,
    "totals": 5.044933333333333
  },
  {
    "mojo": "org.apache.maven.plugins:maven-compiler-plugin:3.8.1:testCompile {execution: default-testCompile}",
    "count": 246,
    "totals": 4.712283333333328
  },
  {
    "mojo": "org.apache.maven.plugins:maven-checkstyle-plugin:3.1.2:check {execution: check-style}",
    "count": 259,
    "totals": 4.661833333333332
  },
  {
    "mojo": "org.apache.maven.plugins:maven-assembly-plugin:3.1.1:single {execution: make-assembly}",
    "count": 11,
    "totals": 3.6231166666666663
  },
  {
    "mojo": "org.apache.maven.plugins:maven-compiler-plugin:3.8.1:compile {execution: default-compile}",
    "count": 246,
    "totals": 2.4721500000000027
  },
  {
    "mojo": "com.google.cloud.tools:jib-maven-plugin:3.2.1:buildTar {execution: default}",
    "count": 6,
    "totals": 2.392116666666667
  },
  {
    "mojo": "org.apache.maven.plugins:maven-assembly-plugin:3.1.1:single {execution: default}",
    "count": 6,
    "totals": 1.5907999999999998
  },
  {
    "mojo": "org.apache.maven.plugins:maven-jar-plugin:3.2.2:test-jar {execution: build-test-jars}",
    "count": 259,
    "totals": 1.2979333333333347
  },
  {
    "mojo": "org.apache.maven.plugins:maven-javadoc-plugin:3.1.1:jar {execution: create-javadocs}",
    "count": 2,
    "totals": 1.29455
  },
  {
    "mojo": "org.apache.maven.plugins:maven-source-plugin:3.1.0:test-jar {execution: attach-sources}",
    "count": 259,
    "totals": 1.2465166666666672
  },
  {
    "mojo": "org.apache.maven.plugins:maven-clean-plugin:3.1.0:clean {execution: default-clean}",
    "count": 269,
    "totals": 1.219366666666675
  },
  {
    "mojo": "org.apache.maven.plugins:maven-jar-plugin:3.2.2:jar {execution: default-jar}",
    "count": 237,
    "totals": 1.1574999999999998
  },
  {
    "mojo": "org.apache.maven.plugins:maven-source-plugin:3.1.0:jar {execution: attach-sources}",
    "count": 259,
    "totals": 1.1063666666666685
  },
  {
    "mojo": "org.apache.maven.plugins:maven-assembly-plugin:3.2.0:single {execution: make-assembly}",
    "count": 2,
    "totals": 0.85205
  },
  {
    "mojo": "org.apache.maven.plugins:maven-javadoc-plugin:3.1.1:javadoc {execution: create-javadocs}",
    "count": 2,
    "totals": 0.8237333333333334
  },
  {
    "mojo": "org.apache.maven.plugins:maven-resources-plugin:3.2.0:resources {execution: default-resources}",
    "count": 237,
    "totals": 0.8219999999999985
  },
  {
    "mojo": "org.apache.maven.plugins:maven-enforcer-plugin:1.4.1:enforce {execution: enforce-maven-version}",
    "count": 789,
    "totals": 0.667283333333332
  },
  {
    "mojo": "org.apache.maven.plugins:maven-resources-plugin:3.2.0:testResources {execution: default-testResources}",
    "count": 237,
    "totals": 0.6591833333333316
  },
  {
    "mojo": "com.google.cloud.tools:jib-maven-plugin:2.7.1:buildTar {execution: default}",
    "count": 1,
    "totals": 0.5494666666666668
  },
  {
    "mojo": "org.apache.maven.plugins:maven-surefire-plugin:2.22.2:test {execution: default-test}",
    "count": 237,
    "totals": 0.5447833333333318
  },
  {
    "mojo": "io.github.evis:scalafix-maven-plugin_2.13:0.1.6_0.9.34:scalafix {execution: scala-check-style}",
    "count": 6,
    "totals": 0.48495000000000005
  },
  {
    "mojo": "org.apache.maven.plugins:maven-site-plugin:3.7.1:attach-descriptor {execution: attach-descriptor}",
    "count": 10,
    "totals": 0.46373333333333333
  },
  {
    "mojo": "org.apache.maven.plugins:maven-site-plugin:3.8.2:attach-descriptor {execution: attach-descriptor}",
    "count": 259,
    "totals": 0.4478166666666661
  },
  {
    "mojo": "org.apache.maven.plugins:maven-install-plugin:2.5.2:install {execution: default-install}",
    "count": 269,
    "totals": 0.4441666666666647
  },
  {
    "mojo": "com.googlecode.maven-download-plugin:download-maven-plugin:1.6.8:wget {execution: install-glowroot}",
    "count": 6,
    "totals": 0.42071666666666674
  },
  {
    "mojo": "org.apache.maven.plugins:maven-plugin-plugin:3.6.4:helpmojo {execution: generated-helpmojo}",
    "count": 3,
    "totals": 0.3625333333333333
  },
  {
    "mojo": "com.github.ekryd.sortpom:sortpom-maven-plugin:3.1.2:verify {execution: strict-pom-ordering}",
    "count": 779,
    "totals": 0.3358833333333306
  },
  {
    "mojo": "org.apache.maven.plugins:maven-remote-resources-plugin:1.7.0:process {execution: process-resource-bundles}",
    "count": 10,
    "totals": 0.31811666666666666
  },
  {
    "mojo": "org.apache.maven.plugins:maven-enforcer-plugin:1.4.1:enforce {execution: enforce-maven}",
    "count": 779,
    "totals": 0.22956666666666664
  },
  {
    "mojo": "net.alchim31.maven:scala-maven-plugin:4.6.1:add-source {execution: scala-compile-first}",
    "count": 21,
    "totals": 0.2054833333333333
  },
  {
    "mojo": "com.github.ekryd.sortpom:sortpom-maven-plugin:3.1.2:sort {execution: sort-reduced-pom}",
    "count": 1,
    "totals": 0.19024999999999997
  },
  {
    "mojo": "org.apache.maven.plugins:maven-resources-plugin:3.2.0:copy-resources {execution: copy-glowroot-resources}",
    "count": 6,
    "totals": 0.1664333333333333
  },
  {
    "mojo": "org.apache.openjpa:openjpa-maven-plugin:3.2.0:enhance {execution: enhancer}",
    "count": 2,
    "totals": 0.15291666666666667
  },
  {
    "mojo": "org.apache.james:mailetdocs-maven-plugin:3.8.0-SNAPSHOT:mailetdocs {execution: default}",
    "count": 8,
    "totals": 0.14173333333333332
  },
  {
    "mojo": "org.apache.maven.plugins:maven-dependency-plugin:3.3.0:copy-dependencies {execution: copy-dependencies}",
    "count": 7,
    "totals": 0.09411666666666667
  },
  {
    "mojo": "org.apache.rat:apache-rat-plugin:0.13:check {execution: default}",
    "count": 10,
    "totals": 0.0856
  },
  {
    "mojo": "org.apache.maven.plugins:maven-plugin-plugin:3.6.4:descriptor {execution: default-descriptor}",
    "count": 2,
    "totals": 0.0806
  },
  {
    "mojo": "org.apache.maven.plugins:maven-jar-plugin:3.2.0:jar {execution: default-jar}",
    "count": 9,
    "totals": 0.0644
  },
  {
    "mojo": "org.apache.maven.plugins:maven-remote-resources-plugin:1.6.0:process {execution: default}",
    "count": 10,
    "totals": 0.06273333333333334
  },
  {
    "mojo": "org.apache.maven.plugins:maven-shade-plugin:3.2.1:shade {execution: default}",
    "count": 1,
    "totals": 0.05811666666666667
  },
  {
    "mojo": "org.codehaus.mojo:appassembler-maven-plugin:2.1.0:assemble {execution: make-appassemble}",
    "count": 1,
    "totals": 0.0528
  },
  {
    "mojo": "org.apache.maven.plugins:maven-surefire-plugin:2.22.0:test {execution: default-test}",
    "count": 9,
    "totals": 0.037200000000000004
  },
  {
    "mojo": "org.apache.felix:maven-bundle-plugin:3.3.0:manifest {execution: bundle-manifest}",
    "count": 1,
    "totals": 0.025183333333333332
  },
  {
    "mojo": "org.apache.maven.plugins:maven-antrun-plugin:1.8:run {execution: default}",
    "count": 1,
    "totals": 0.023799999999999998
  },
  {
    "mojo": "org.apache.maven.plugins:maven-resources-plugin:3.1.0:resources {execution: default-resources}",
    "count": 9,
    "totals": 0.011349999999999999
  },
  {
    "mojo": "org.codehaus.mojo:appassembler-maven-plugin:2.1.0:generate-daemons {execution: make-appassemble}",
    "count": 1,
    "totals": 0.007
  },
  {
    "mojo": "org.apache.maven.plugins:maven-resources-plugin:3.1.0:testResources {execution: default-testResources}",
    "count": 9,
    "totals": 0.00115
  },
  {
    "mojo": "org.scalatest:scalatest-maven-plugin:2.0.2:test {execution: test}",
    "count": 1,
    "totals": 0.00095
  },
  {
    "mojo": "org.apache.maven.plugins:maven-jar-plugin:3.2.2:test-jar {execution: test-jar}",
    "count": 6,
    "totals": 0.0007666666666666666
  },
  {
    "mojo": "org.apache.maven.plugins:maven-jar-plugin:3.2.2:test-jar {execution: default}",
    "count": 5,
    "totals": 0.0006333333333333334
  },
  {
    "mojo": "org.apache.maven.plugins:maven-dependency-plugin:3.3.0:copy-dependencies {execution: default}",
    "count": 1,
    "totals": 0.00015
  },
  {
    "mojo": "org.apache.maven.plugins:maven-plugin-plugin:3.6.4:addPluginArtifactMetadata {execution: default-addPluginArtifactMetadata}",
    "count": 2,
    "totals": 6.666666666666667e-05
  }
]

Another curiosity I noticed in https://ci-builds.apache.org/job/james/job/ApacheJames/job/PR-1498/6/artifact/.profiler/profiler-report-2023-03-22-19-11-22.html is the Artifact Downloading of 2413s so 40 minutes is dedicated to just downloading the artifacts (?!). Not sure about maven versions and the downloading itself, but recently maven got paralel downloads of dependencies (https://issues.apache.org/jira/browse/MRESOLVER-7?focusedCommentId=17692969&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-17692969) and it's possible to futher improve resolution and download with additional configuration (https://issues.apache.org/jira/browse/MRESOLVER-324) - possibly worth considering as well (gives a nice speed improvement on my machine)?

chibenwa · 2023-03-23T06:50:21Z

👍 to kill git-commit-id-plugin

possibly worth considering as well (gives a nice speed improvement on my machine)?

👍

chibenwa · 2023-03-23T06:51:38Z

Is it as easy as specifying -Dmaven.artifact.threads=4 ?

…e maven-remote-resources-plugin by default

woj-tek · 2023-03-23T14:51:06Z

to kill git-commit-id-plugin

Removed

Is it as easy as specifying -Dmaven.artifact.threads=4 ?

I didn't know that option. The one mentioned by you is to parallel download the artifacts. One mentioned (and linked) by me is to resolve poms/dependencies in parallel as well. I included both.

While building locally I also noticed that maven-remote-resources-plugin is executed always. Judging by the configuration the indention was to have it defined but disabled globally and only enabled for mailets - I adjusted the configuration, so it's executed as such (it showed up as top plugin when re-running mvn install thus less re-compillation.

There is also elephant in the room - Scala - for 21 projects it takes ~14 minutes (9 to compile + 5 for tests) while building the rest (~250 modules) takes half that time... @chibenwa - you mentioned that slow Scala build is due to some feature/library/dependency?

chibenwa · 2023-03-23T14:58:02Z

@chibenwa - you mentioned that slow Scala build is due to some feature/library/dependency?

Part of the code is written in scala itself.

CF https://github.com/apache/james-project/blob/master/src/adr/0024-polyglot-strategy.md

CF https://www.mail-archive.com/server-dev@james.apache.org/msg66100.html

woj-tek · 2023-03-23T18:25:52Z

Part of the code is written in scala itself.

I'm aware of that and we already talked about that (in gitter?). You mentioned particular Scala feature or library (can't recall the name) that makes the compilation particularly slow.

(got it: "Actually compiling scala is slow, especially with maven, especially with macros." -- so I guess it's due to the macros? is there a possibility to somehow improve it?)

CF https://www.mail-archive.com/server-dev@james.apache.org/msg66100.html

Interesting read :-)

With the recent changes compilation time went from 14m21s to 9m49s

woj-tek added 4 commits March 21, 2023 10:51

Add and enable build profiling extensions

7fa0ecd

Do away with stage name variable

977edb5

Disable storing tests output with disabled test runs...

f74959d

Don't fail the build if files are not found.

64ddd48

chibenwa approved these changes Mar 22, 2023

View reviewed changes

Archive perormance artifacts even if build is unsuccessful; change paths

2facc2c

Add parallel build configuration; remove git-commit-id-plugin; disabl…

a417e70

…e maven-remote-resources-plugin by default

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add and enable build profiling extensions #1498

Add and enable build profiling extensions #1498

woj-tek commented Mar 21, 2023 •

edited

Loading

chibenwa left a comment

jeantil commented Mar 22, 2023

woj-tek commented Mar 22, 2023

woj-tek commented Mar 23, 2023

chibenwa commented Mar 23, 2023

chibenwa commented Mar 23, 2023

woj-tek commented Mar 23, 2023

chibenwa commented Mar 23, 2023

woj-tek commented Mar 23, 2023

Add and enable build profiling extensions #1498

Are you sure you want to change the base?

Add and enable build profiling extensions #1498

Conversation

woj-tek commented Mar 21, 2023 • edited Loading

chibenwa left a comment

Choose a reason for hiding this comment

jeantil commented Mar 22, 2023

woj-tek commented Mar 22, 2023

woj-tek commented Mar 23, 2023

chibenwa commented Mar 23, 2023

chibenwa commented Mar 23, 2023

woj-tek commented Mar 23, 2023

chibenwa commented Mar 23, 2023

woj-tek commented Mar 23, 2023

woj-tek commented Mar 21, 2023 •

edited

Loading