khmarbaise · clayreimann · May 19, 2022
diff --git a/.drone.yml b/.drone.yml
@@ -30,7 +30,7 @@ steps:
       mount:
         - .repo
 
-  - name: mavenjdk8
+  - name: mavenjdk11
     pull: always
     image: docker.io/maven:3.8.4-openjdk-11-slim
     volumes:

diff --git a/src/main/java/com/soebes/maven/extensions/BuildTimeProfiler.java b/src/main/java/com/soebes/maven/extensions/BuildTimeProfiler.java
@@ -24,6 +24,8 @@
 import java.util.List;
 import java.util.Map;
 import java.util.Map.Entry;
+import java.util.function.BiConsumer;
+import java.util.stream.Collectors;
 
 import javax.inject.Named;
 import javax.inject.Singleton;
@@ -47,6 +49,8 @@
 import com.soebes.maven.extensions.metadata.MetadataDownloadTimer;
 import com.soebes.maven.extensions.metadata.MetadataInstallTimer;
 
+import static com.soebes.maven.extensions.ProjectKey.fromMavenProject;
+
 /**
  * @author Karl Heinz Marbaise <a href="mailto:[email protected]">[email protected]</a>
  */
@@ -57,6 +61,8 @@ public class BuildTimeProfiler
 {
     private static final Logger LOGGER = LoggerFactory.getLogger(BuildTimeProfiler.class);
 
+    private static final String DIVIDER = "------------------------------------------------------------------------";
+
     final List<String> lifeCyclePhases;
 
     private final DiscoveryTimer discoveryTimer;
@@ -397,67 +403,29 @@ private void executionResultEventHandler( MavenExecutionResult event )
         LOGGER.debug( "MBTP: executionResultEventHandler: {}", event.getProject() );
 
         LOGGER.info( "--             Maven Build Time Profiler Summary                      --" );
-        LOGGER.info( "------------------------------------------------------------------------" );
+        LOGGER.info(DIVIDER);
 
         discoveryTimer.report();
 
         if ( mojoTimer.hasEvents() )
         {
-            LOGGER.info( "Project Build Time (reactor order):" );
-            LOGGER.info( "" );
-            for ( MavenProject mavenProject : event.getTopologicallySortedProjects() )
-            {
-                LOGGER.info( "{}:", mavenProject.getName() );
-
-                for ( String phase : lifeCyclePhases )
-                {
-                    ProjectKey projectKey = mavenProjectToProjectKey( mavenProject );
-
-                    if ( !mojoTimer.hasTimeForProjectAndPhase( projectKey, phase ) )
-                    {
-                        continue;
-                    }
+            logProjects(event);
+            LOGGER.info(DIVIDER);
 
-                    long timeForPhaseAndProjectInMillis =
-                        mojoTimer.getTimeForProjectAndPhaseInMillis( projectKey, phase );
-                    LOGGER.info( "    {} ms : {}", String.format( "%8d", timeForPhaseAndProjectInMillis ), phase );
-
-                }
-
-            }
-            LOGGER.info( "------------------------------------------------------------------------" );
-            LOGGER.info( "Lifecycle Phase summary:" );
-            LOGGER.info( "" );
-            for ( String phase : lifeCyclePhases )
-            {
-                long timeForPhaseInMillis = mojoTimer.getTimeForPhaseInMillis( phase );
-                LOGGER.info( "{} ms : {}", String.format( "%8d", timeForPhaseInMillis ), phase );
-            }
+            logPhaseSummary();
+            LOGGER.info(DIVIDER);
 
             // List all plugins per phase
-            LOGGER.info( "------------------------------------------------------------------------" );
-            LOGGER.info( "Plugins in lifecycle Phases:" );
-            LOGGER.info( "" );
-            for ( String phase : lifeCyclePhases )
-            {
-                LOGGER.info( "{}:", phase );
-                Map<ProjectMojo, SystemTime> plugisInPhase = mojoTimer.getPluginsInPhase( phase );
-                for ( Entry<ProjectMojo, SystemTime> pluginInPhase : plugisInPhase.entrySet() )
-                {
-                    LOGGER.info( "{} ms: {}", String.format( "%8d", pluginInPhase.getValue().getElapsedTime() ),
-                                 pluginInPhase.getKey().getMojo().getFullId() );
-                }
-
-            }
-            LOGGER.info( "------------------------------------------------------------------------" );
+            logDetailedPhaseExecutions();
+            LOGGER.info(DIVIDER);
         }
 
         if ( goalTimer.hasEvents() )
         {
             LOGGER.info( "Plugins directly called via goals:" );
             LOGGER.info( "" );
             goalTimer.report();
-            LOGGER.info( "------------------------------------------------------------------------" );
+            LOGGER.info(DIVIDER);
         }
 
         installTimer.report();
@@ -471,9 +439,59 @@ private void executionResultEventHandler( MavenExecutionResult event )
         forkProject.report();
     }
 
-    private ProjectKey mavenProjectToProjectKey( MavenProject project )
+
+    private void logProjects(MavenExecutionResult event)
+    {
+        LOGGER.info( "Project Build Time (reactor order):" );
+        LOGGER.info( "" );
+        for ( MavenProject mavenProject : event.getTopologicallySortedProjects() )
+        {
+            LOGGER.info( "{}:", mavenProject.getName() );
+
+            for ( String phase : lifeCyclePhases )
+            {
+                ProjectKey projectKey = fromMavenProject( mavenProject );
+
+                if ( !mojoTimer.hasTimeForProjectAndPhase( projectKey, phase ) )
+                {
+                    continue;
+                }
+
+                logTime( mojoTimer.getTimeForProjectAndPhaseInMillis( projectKey, phase ), phase );
+            }
+
+        }
+    }
+
+    private void logPhaseSummary()
+    {
+        LOGGER.info( "Lifecycle Phase summary:" );
+        LOGGER.info( "" );
+        for ( String phase : lifeCyclePhases )
+        {
+            logTime( mojoTimer.getTimeForPhaseInMillis( phase ), phase );
+        }
+    }
+
+    private void logDetailedPhaseExecutions()
+    {
+        LOGGER.info( "Plugins in lifecycle Phases:" );
+        LOGGER.info( "" );
+        for ( String phase : lifeCyclePhases )
+        {
+            LOGGER.info( "{}:", phase );
+            Map<ProjectMojo, SystemTime> plugisInPhase = mojoTimer.getPluginsInPhase( phase );
+            for ( Entry<ProjectMojo, SystemTime> pluginInPhase : plugisInPhase.entrySet() )
+            {
+                logTime( pluginInPhase.getValue().getElapsedTime(), pluginInPhase.getKey().getLifecycleId() );
+            }
+
+        }
+    }
+
+    private void logTime(long millis, String label)
     {
-        return new ProjectKey( project.getGroupId(), project.getArtifactId(), project.getVersion() );
+        LOGGER.info( "{} ms : {}", String.format( "%8d", millis ), label );
     }
 
     private void collectAllLifeCylcePhases( String phase )

diff --git a/src/main/java/com/soebes/maven/extensions/GoalTimer.java b/src/main/java/com/soebes/maven/extensions/GoalTimer.java
@@ -6,10 +6,11 @@
 
 import org.apache.maven.execution.ExecutionEvent;
 import org.apache.maven.plugin.MojoExecution;
-import org.apache.maven.project.MavenProject;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
+import static com.soebes.maven.extensions.ProjectKey.fromMavenProject;
+
 /**
  * @author Karl Heinz Marbaise <a href="mailto:[email protected]">[email protected]</a>
  */
@@ -29,11 +30,6 @@ public boolean hasEvents()
         return !timerEvents.isEmpty();
     }
 
-    private ProjectKey createProjectKey( MavenProject project )
-    {
-        return new ProjectKey( project.getGroupId(), project.getArtifactId(), project.getVersion() );
-    }
-
     private GoalKey createGoalKey( MojoExecution mojo )
     {
         return new GoalKey( mojo.getGroupId(), mojo.getArtifactId(), mojo.getVersion(), mojo.getGoal(),
@@ -43,14 +39,14 @@ private GoalKey createGoalKey( MojoExecution mojo )
     public void mojoStart( ExecutionEvent event )
     {
         ProjectGoal pm =
-            new ProjectGoal( createProjectKey( event.getProject() ), createGoalKey( event.getMojoExecution() ) );
+            new ProjectGoal( fromMavenProject(event.getProject()), createGoalKey(event.getMojoExecution() ) );
         timerEvents.put( pm, new SystemTime().start() );
     }
 
     public void mojoStop( ExecutionEvent event )
     {
         ProjectGoal pm =
-            new ProjectGoal( createProjectKey( event.getProject() ), createGoalKey( event.getMojoExecution() ) );
+            new ProjectGoal( fromMavenProject(event.getProject()), createGoalKey(event.getMojoExecution() ) );
         if ( !timerEvents.containsKey( pm ) )
         {
             throw new IllegalArgumentException( "Unknown mojoId (" + pm.getId() + ")" );

diff --git a/src/main/java/com/soebes/maven/extensions/MojoKey.java b/src/main/java/com/soebes/maven/extensions/MojoKey.java
@@ -19,6 +19,8 @@
  * under the License.
  */
 
+import org.apache.maven.plugin.MojoExecution;
+
 /**
  * @author Karl Heinz Marbaise <a href="mailto:[email protected]">[email protected]</a>
  */
@@ -31,6 +33,11 @@ class MojoKey
 
     private String phase;
 
+    public static MojoKey fromMojo(MojoExecution mojo) {
+        return new MojoKey( mojo.getGroupId(), mojo.getArtifactId(), mojo.getVersion(), mojo.getGoal(),
+                            mojo.getExecutionId(), mojo.getLifecyclePhase() );
+    }
+
     public MojoKey( String groupId, String artifactId, String version, String goal, String executionId,
                     String lifeCyclePhase )
     {
@@ -75,6 +82,11 @@ public String getFullId()
         return super.getId() + ":" + getGoal() + " (" + getExecutionId() + ")";
     }
 
+    public String getFullIdWithPhase()
+    {
+        return super.getId() + ":" + getGoal() + " (" + getExecutionId() + ":" + getPhase() + ")";
+    }
+
     @Override
     public int hashCode()
     {

diff --git a/src/main/java/com/soebes/maven/extensions/MojoTimer.java b/src/main/java/com/soebes/maven/extensions/MojoTimer.java
@@ -30,6 +30,8 @@
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
+import static com.soebes.maven.extensions.MojoKey.fromMojo;
+
 /**
  * @author Karl Heinz Marbaise <a href="mailto:[email protected]">[email protected]</a>
  */
@@ -44,17 +46,6 @@ public MojoTimer()
         this.timerEvents = new ConcurrentHashMap<>();
     }
 
-    private ProjectKey createProjectKey( MavenProject project )
-    {
-        return new ProjectKey( project.getGroupId(), project.getArtifactId(), project.getVersion() );
-    }
-
-    private MojoKey createMojoKey( MojoExecution mojo )
-    {
-        return new MojoKey( mojo.getGroupId(), mojo.getArtifactId(), mojo.getVersion(), mojo.getGoal(),
-                            mojo.getExecutionId(), mojo.getLifecyclePhase() );
-    }
-
     public boolean hasEvents()
     {
         return !this.timerEvents.isEmpty();
@@ -63,15 +54,13 @@ public boolean hasEvents()
     public void mojoStart( ExecutionEvent event )
     {
 
-        ProjectMojo pm =
-            new ProjectMojo( createProjectKey( event.getProject() ), createMojoKey( event.getMojoExecution() ) );
+        ProjectMojo pm = new ProjectMojo( event.getProject(), fromMojo( event.getMojoExecution() ) );
         timerEvents.put( pm, new SystemTime().start() );
     }
 
     public void mojoStop( ExecutionEvent event )
     {
-        ProjectMojo pm =
-            new ProjectMojo( createProjectKey( event.getProject() ), createMojoKey( event.getMojoExecution() ) );
+        ProjectMojo pm = new ProjectMojo( event.getProject(), fromMojo( event.getMojoExecution() ) );
         if ( !timerEvents.containsKey( pm ) )
         {
             throw new IllegalArgumentException( "Unknown mojoId (" + pm + ")" );
@@ -139,7 +128,7 @@ public void report()
     {
         for ( Entry<ProjectMojo, SystemTime> item : this.timerEvents.entrySet() )
         {
-            LOGGER.info( "{} : {}", item.getKey().getId(), item.getValue().getElapsedTime() );
+            LOGGER.info( "{} : {}", item.getKey().getFullId(), item.getValue().getElapsedTime() );
         }
     }
 }
diff --git a/src/main/java/com/soebes/maven/extensions/ProjectKey.java b/src/main/java/com/soebes/maven/extensions/ProjectKey.java
@@ -19,6 +19,8 @@
  * under the License.
  */
 
+import org.apache.maven.project.MavenProject;
+
 /**
  * @author Karl Heinz Marbaise <a href="mailto:[email protected]">[email protected]</a>
  */
@@ -30,6 +32,10 @@ class ProjectKey
 
     private final String version;
 
+    public static ProjectKey fromMavenProject(MavenProject project) {
+        return new ProjectKey(project.getGroupId(), project.getArtifactId(), project.getVersion());
+    }
+
     public ProjectKey( final String groupId, final String artifactId, final String version )
     {
         super();

diff --git a/src/main/java/com/soebes/maven/extensions/ProjectMojo.java b/src/main/java/com/soebes/maven/extensions/ProjectMojo.java
@@ -19,19 +19,26 @@
  * under the License.
  */
 
+import org.apache.maven.project.MavenProject;
+
+import static com.soebes.maven.extensions.ProjectKey.fromMavenProject;
+
 /**
  * @author Karl Heinz Marbaise <a href="mailto:[email protected]">[email protected]</a>
  */
 class ProjectMojo
 {
     private ProjectKey project;
 
+    private String projectName;
+
     private MojoKey mojo;
 
-    public ProjectMojo( ProjectKey project, MojoKey mojo )
+    public ProjectMojo( MavenProject project, MojoKey mojo )
     {
         super();
-        this.project = project;
+        this.project = fromMavenProject( project );
+        this.projectName = project.getName();
         this.mojo = mojo;
     }
 
@@ -65,12 +72,14 @@ public int hashCode()
         return result;
     }
 
-    public String getId()
+    public String getLifecycleId()
+    {
+        return projectName + "@" + mojo.getFullId();
+    }
+
+    public String getFullId()
     {
-        String s1 = getMojo().getGroupId() + ":" + getMojo().getArtifactId() + ":" + getMojo().getVersion() + ":"
-            + getMojo().getGoal() + " (" + getMojo().getExecutionId() + ":" + getMojo().getPhase() + ")";
-        String s2 = getProject().getGroupId() + ":" + getProject().getArtifactId() + ":" + getProject().getVersion();
-        return s1 + " @ " + s2;
+        return mojo.getFullIdWithPhase() + " @ " + project.getId();
     }
 
     @Override