バネデータjpaとhibernateのパフォーマンスの差 - jHipster

Question

データベースを照会するときにjHipsterアプリの速度が遅い理由を調べようとしています。

これは、各メソッドのパフォーマンスを記録するために、スプリング・データのPagingAndSortingRepository

@Transactional(readOnly = true) 
public Page<Center> findAll(Pageable pageable) { 
    log.debug("Request to get all Centers"); 

    return centerRepository.findAll(pageable);   
} 

私が使用したJHipsters' LoggingAspectて、コメントを追加し、タイマーを使用して、私のサービスの1つです。

@Around("loggingPointcut()") 
public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable { 
    Stopwatch stopwatch = null; 
    if (log.isDebugEnabled()) { 
     log.debug("Enter: {}.{}() with argument[s] = {}", joinPoint.getSignature().getDeclaringTypeName(), 
      joinPoint.getSignature().getName(), Arrays.toString(joinPoint.getArgs())); 
     stopwatch = Stopwatch.createStarted(); 
    } 
    try { 
     Object result = joinPoint.proceed(); 
     if (log.isDebugEnabled()) { 
      log.debug("Exit: {}.{}() [took {} ms] with result = {}", joinPoint.getSignature().getDeclaringTypeName(), 
       joinPoint.getSignature().getName(), stopwatch.elapsed(MILLISECONDS), result); 
     } 
     return result; 
    } catch (IllegalArgumentException e) { 
     log.error("Illegal argument: {} in {}.{}()", Arrays.toString(joinPoint.getArgs()), 
       joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName()); 

     throw e; 
    } 
} 

私はstaticticsを生成するために休止状態に構成：

spring.jpa.properties.hibernate.generate_statistics=true 

私はorg.hibernate.stat.internal.ConcurrentStatisticsImplとorg.hibernate.engine.internal.StatisticalLoggingSessionEventListenerのログレベルを変更した場合、私は次のログを参照してください。あなたが取る場合

2016-10-13 11:00:00,640 DEBUG [http-nio-8080-exec-8] LoggingAspect: Enter: com.fluidda.broncholab.service.CenterService.findAll() with argument[s] = [Page request [number: 0, size 20, sort: id: ASC]] 
2016-10-13 11:00:00,643 DEBUG [http-nio-8080-exec-8] CenterService: Request to get all Centers 
2016-10-13 11:00:02,238 DEBUG [http-nio-8080-exec-8] ConcurrentStatisticsImpl: HHH000117: HQL: select count(generatedAlias0) from Center as generatedAlias0, time: 1ms, rows: 1 
2016-10-13 11:00:02,241 DEBUG [http-nio-8080-exec-8] ConcurrentStatisticsImpl: HHH000117: HQL: select generatedAlias0 from Center as generatedAlias0 order by generatedAlias0.id asc, time: 2ms, rows: 3 
2016-10-13 11:00:02,242 DEBUG [http-nio-8080-exec-8] LoggingAspect: Exit: com.fluidda.broncholab.service.CenterService.findAll() [took 1601 ms] with result = Page 1 of 1 containing com.fluidda.broncholab.domain.Center instances 
2016-10-13 11:00:02,243 INFO [http-nio-8080-exec-8] StatisticalLoggingSessionEventListener: Session Metrics { 
    568512 nanoseconds spent acquiring 1 JDBC connections; 
    0 nanoseconds spent releasing 0 JDBC connections; 
    92324 nanoseconds spent preparing 2 JDBC statements; 
    992105 nanoseconds spent executing 2 JDBC statements; 
    0 nanoseconds spent executing 0 JDBC batches; 
    34717 nanoseconds spent performing 3 L2C puts; 
    0 nanoseconds spent performing 0 L2C hits; 
    0 nanoseconds spent performing 0 L2C misses; 
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections); 
    2943 nanoseconds spent executing 2 partial-flushes (flushing a total of 0 entities and 0 collections) 

を（アイテムが記録されたタイムスタンプではなく）タイミングを見ると、次のような大きな違いが見られます。

• ConcurrentStatisticsImpl：時間：2msの、行：3
• LoggingAspectは：
• StatisticalLoggingSessionEventListener [1601ミリ秒た]： 2つのJDBC文の実行に費やさ992105ナノ秒。

これらの性能の問題は、ではなく、が常に発生することです。これはドロップウォーカーの統計です：

Service name        Count Mean Min p50 p75 p95 p99 Max 
....web.rest.CenterResource.getAllCenters 5  13  10 16 16 16 16 1,612 

これらのパフォーマンス低下の原因は何ですか？

今後どのように調査することができますか？

Answer 1

ASYNCロガーを使用せずに余分なロギングを追加した後、サーバーがHQLを解析する時間を失っていたことがわかりました。

私はこれについて別の質問を作成しました：あなたは1秒のギャップを持っている場合はHibernate QueryTranslatorImpl HQL AST parsing performance