[jira] (MNG-4639) Be able to profile a maven build

["Alexander Klimetschek (JIRA)" <ji...@codehaus.org>]

     [ https://jira.codehaus.org/browse/MNG-4639?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Alexander Klimetschek updated MNG-4639:
---------------------------------------

    Attachment: 0001-MNG-4639-Be-able-to-profile-a-maven-build.patch

I implemented this - see [attached patch|^0001-MNG-4639-Be-able-to-profile-a-maven-build.patch] or the [diff in my github maven fork|https://github.com/alexkli/maven/commit/efb72827d2df44abf1114bcc7aeff3efeca2cd55].

Output looks like this at the end of the build (running "mvn -a install" for maven itself):
{noformat}
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 1:55.148s
[INFO] Finished at: Tue Mar 19 15:50:33 CET 2013
[INFO] Final Memory: 29M/102M
[INFO] ------------------------------------------------------------------------
[INFO] MOJO EXECUTION TIMES
[INFO] ------------------------------------------------------------------------
[INFO]  35% maven-surefire-plugin [40.74s]
[INFO]      * test
[INFO]  23% animal-sniffer-maven-plugin [27.65s]
[INFO]      * check
[INFO]  13% project setup [15.85s]
[INFO]   7% maven-assembly-plugin [8.83s]
[INFO]      * single
[INFO]   4% maven-jar-plugin [4.86s]
[INFO]      * jar
[INFO]   3% maven-compiler-plugin [4.21s]
[INFO]      * compile 3% [4.10s]
[INFO]      * testCompile 0% [0.11s]
[INFO]   3% maven-remote-resources-plugin [4.12s]
[INFO]      * process
[INFO]   3% plexus-component-metadata [3.49s]
[INFO]      * generate-metadata 2% [2.65s]
[INFO]      * generate-test-metadata 0% [0.85s]
[INFO]   1% modello-maven-plugin [1.56s]
[INFO]      * java 0% [1.13s]
[INFO]      * xpp3-reader 0% [0.20s]
[INFO]      * xpp3-writer 0% [0.15s]
[INFO]      * xpp3-extended-reader 0% [0.08s]
[INFO]   0% maven-site-plugin [1.10s]
[INFO]      * attach-descriptor
[INFO]   0% other [0.78s]
[INFO]   0% maven-resources-plugin [0.71s]
[INFO]      * resources 0% [0.45s]
[INFO]      * testResources 0% [0.25s]
[INFO]   0% scanning for projects [0.71s]
[INFO]   0% buildnumber-maven-plugin [0.61s]
[INFO]      * create-timestamp 0% [0.39s]
[INFO]      * create 0% [0.22s]
[INFO]   0% maven-install-plugin [0.35s]
[INFO]      * install
[INFO] ------------------------------------------------------------------------
{noformat}

Details from the commit message:
* adds new option "-a / --analyze" to the maven cli
* which will profile mojo executions and output their time and percentage of total time sorted at the end of the build
* groups by maven plugin and shows measurements split up by plugin goals
* also measures project discovery ("scanning"), project setup time before first mojo ("project setup") and anything else ("other")
* implemented in a special ExecutionListener called ProfilingExecutionListener
* which is chained with the normal ExecutionEventLogger by a new ExecutionListenerChain helper that forwards the events to multiple listeners

WDYT?
                
> Be able to profile a maven build
> --------------------------------
>
>                 Key: MNG-4639
>                 URL: https://jira.codehaus.org/browse/MNG-4639
>             Project: Maven 2 & 3
>          Issue Type: New Feature
>            Reporter: Baptiste MATHUS
>             Fix For: Issues to be reviewed for 3.x
>
>         Attachments: 0001-MNG-4639-Be-able-to-profile-a-maven-build.patch
>
>
> A common problem with builds is that they can become quite long to run. As it is a know anti-pattern for CI for example, one has the need to try and optimize their builds.
> The thing is: the current granularity isn't sufficiently precise. In fact, you only only the time spent to build each module. This is a good start, though.
> Maven currently displays something like the following (let's speak only about maven 3):
> {quote}
> [INFO] Reactor Summary:
> [INFO] ------------------------------------------------------------------------
> [INFO] p1 ........................ SUCCESS [1:12.938s]
> [INFO] p2 ........................ SUCCESS [5.750s]
> [INFO] p3 ........................ SUCCESS [3:58.488s]
> [INFO] p4 ........................ SUCCESS [24.437s]
> [INFO] p5 ........................ SUCCESS [1.563s]
> [INFO] ------------------------------------------------------------------------
> [INFO] ------------------------------------------------------------------------
> [INFO] BUILD SUCCESSFUL
> [INFO] ------------------------------------------------------------------------
> [INFO] Total time: 5 minutes 46 seconds
> {quote}
> What would be great would be adding an option that would higher the details. Something like -A/--analyze (--profile would be too close to -P/profile option) would add detailed analysis, would print something like. 
> {quote}
> [INFO] Reactor Summary:
> [INFO] ------------------------------------------------------------------------
> [INFO] p1 ........................ SUCCESS [1:12.938s]
>         clean:clean (somepkg.CleanMojo) : 10.3s
>         compiler:compile (...) : 50s
>         ...
>         and so on
> {quote}
> I'm not very well aware the level of details maven 3 API could provide. So the printing above could become irrelevant. In this case, printing a dedicated html or so report might be a better choice.
> Cheers
> PS : Though I'm really not introduced into maven code, if you think it's not too complicated, I could try and contribute on this field if I'm given some hints or good starting points. 

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira