debug(spring): spring init

framework/src/main/java/org/tron/common/application/BeanLifecycleTimingProcessor.java

@@ -0,0 +1,140 @@
+package org.tron.common.application;
+
+import java.util.LinkedHashMap;
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.ConcurrentMap;
+import lombok.extern.slf4j.Slf4j;
+import org.springframework.beans.BeansException;
+import org.springframework.beans.factory.config.BeanPostProcessor;
+import org.springframework.beans.factory.config.InstantiationAwareBeanPostProcessor;
+import org.springframework.beans.factory.support.MergedBeanDefinitionPostProcessor;
+import org.springframework.beans.factory.support.RootBeanDefinition;
+import org.springframework.context.ApplicationListener;
+import org.springframework.context.event.ContextRefreshedEvent;
+import org.springframework.stereotype.Component;
+
+@Component
+@Slf4j(topic = "app")
+public class BeanLifecycleTimingProcessor implements
+    BeanPostProcessor, InstantiationAwareBeanPostProcessor,
+    MergedBeanDefinitionPostProcessor, ApplicationListener<ContextRefreshedEvent> {
+
+  private final ConcurrentMap<String, BeanTimingInfo> beanTimings = new ConcurrentHashMap<>();
+
+  static class BeanTimingInfo {
+    long instantiationStartTime;
+    long postProcessBeforeInstantiationTime;
+    long instantiationEndTime;
+    long postProcessAfterInstantiationTime;
+    long populatePropertiesStartTime;
+    long populatePropertiesEndTime;
+    long postProcessBeforeInitTime;
+    long initMethodStartTime;
+    long initMethodEndTime;
+    long postProcessAfterInitTime;
+    long totalTime;
+
+    Map<String, Long> getDurations() {
+      Map<String, Long> durations = new LinkedHashMap<>();
+      durations.put("Instantiation", instantiationEndTime - instantiationStartTime);
+      if (populatePropertiesEndTime > 0) {
+        durations.put("Properties", populatePropertiesEndTime - populatePropertiesStartTime);
+      }
+      if (initMethodEndTime > 0) {
+        durations.put("Initialization", initMethodEndTime - initMethodStartTime);
+      }
+      if (postProcessAfterInitTime > 0) {
+        durations.put("PostProcessing", postProcessAfterInitTime - postProcessBeforeInitTime);
+      }
+      durations.put("Total", totalTime);
+      return durations;
+    }
+  }
+
+  @Override
+  public void postProcessMergedBeanDefinition(RootBeanDefinition beanDefinition,
+                                            Class<?> beanType, String beanName) {
+    BeanTimingInfo timing = new BeanTimingInfo();
+    timing.instantiationStartTime = System.nanoTime();
+    beanTimings.put(beanName, timing);
+  }
+
+  @Override
+  public Object postProcessBeforeInstantiation(Class<?> beanClass, String beanName)
+      throws BeansException {
+    BeanTimingInfo timing = beanTimings.get(beanName);
+    if (timing != null) {
+      timing.postProcessBeforeInstantiationTime = System.nanoTime();
+    }
+    return null;
+  }
+
+  @Override
+  public boolean postProcessAfterInstantiation(Object bean, String beanName)
+      throws BeansException {
+    BeanTimingInfo timing = beanTimings.get(beanName);
+    if (timing != null) {
+      timing.instantiationEndTime = System.nanoTime();
+      timing.postProcessAfterInstantiationTime = System.nanoTime();
+      timing.populatePropertiesStartTime = System.nanoTime();
+    }
+    return true;
+  }
+
+  @Override
+  public Object postProcessBeforeInitialization(Object bean, String beanName)
+      throws BeansException {
+    BeanTimingInfo timing = beanTimings.get(beanName);
+    if (timing != null) {
+      timing.populatePropertiesEndTime = System.nanoTime();
+      timing.postProcessBeforeInitTime = System.nanoTime();
+      timing.initMethodStartTime = System.nanoTime();
+    }
+    return bean;
+  }
+
+  @Override
+  public Object postProcessAfterInitialization(Object bean, String beanName)
+      throws BeansException {
+    BeanTimingInfo timing = beanTimings.get(beanName);
+    if (timing != null) {
+      timing.initMethodEndTime = System.nanoTime();
+      timing.postProcessAfterInitTime = System.nanoTime();
+      timing.totalTime = timing.postProcessAfterInitTime - timing.instantiationStartTime;
+    }
+    return bean;
+  }
+
+  @Override
+  public void onApplicationEvent(ContextRefreshedEvent event) {
+    if (event.getApplicationContext().getParent() == null) {
+      printTimingStatistics();
+    }
+  }
+
+  public void printTimingStatistics() {
+    logger.debug("=== Bean Lifecycle Timing Statistics ===");
+    beanTimings.entrySet().stream()
+        .sorted((e1, e2) -> Long.compare(e2.getValue().totalTime, e1.getValue().totalTime))
+        .forEach(e -> {
+          String beanName = e.getKey();
+          BeanTimingInfo timing = e.getValue();
+          logger.debug("Bean: {}", beanName);
+          Map<String, Long> durations = timing.getDurations();
+          durations.forEach((phase, duration) -> {
+            double durationMs = duration / 1_000_000.0;
+            logger.debug("  {}: {} ms", phase, durationMs);
+          });
+          System.out.println();
+        });
+    long totalTime = beanTimings.values().stream()
+        .mapToLong(timing -> timing.totalTime)
+        .sum();
+    double avgTime = totalTime / (double) beanTimings.size();
+    logger.debug("Summary:");
+    logger.debug("Total beans processed: {}", beanTimings.size());
+    logger.debug("Total time: {} ms", totalTime / 1_000_000.0);
+    logger.debug("Average time per bean: {} ms", avgTime / 1_000_000.0);
+  }
+}

framework/src/main/java/org/tron/core/config/DefaultConfig.java

@@ -9,6 +9,7 @@
 import org.springframework.context.annotation.Conditional;
 import org.springframework.context.annotation.Configuration;
 import org.springframework.context.annotation.Import;
+import org.tron.common.application.BeanLifecycleTimingProcessor;
 import org.tron.common.utils.StorageUtils;
 import org.tron.core.config.args.Args;
 import org.tron.core.db.RevokingDatabase;
@@ -96,4 +97,9 @@ public HttpApiOnPBFTService getHttpApiOnPBFTService() {
   public BackupRocksDBAspect backupRocksDBAspect() {
     return new BackupRocksDBAspect();
   }
+
+  @Bean
+  public BeanLifecycleTimingProcessor beanTimingProcessor() {
+    return new BeanLifecycleTimingProcessor();
+  }
 }