2016-09-16 2 views
1

JdbcTemplate과 기본 Tomcat 연결 풀에서 Spring Boot를 사용하고 있습니다.스프링 부트 + JdbcTemplate에 설명 할 수없는 쿼리 속도 저하가 있습니까?

내 MVC 응용 프로그램에서 경로를 누르면 JdbcTemplate을 사용하여 쿼리가 실행됩니다. 여기에 로그됩니다. "JDBC 연결 반환"당신이 볼 수 있듯이

Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.441 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL update 
Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.443 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [UPDATE tokens SET last_accessed = NOW() where token = ?] 
Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.444 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.datasource.DataSourceUtils  : Fetching JDBC Connection from DataSource 
Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.451 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate    : SQL update affected 1 rows 
Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.452 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.datasource.DataSourceUtils  : Returning JDBC Connection to DataSource 
Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.457 INFO 24249 --- [io-8080-exec-10] e.u.d.d.w.e.u.d.d.w.c.CensusController : Before census query:Fri Sep 16 16:04:34 PDT 2016 
Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.458 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL query 
Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.459 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [SELECT o.acad_term_code, o.crse_num, o.acad_subject_code, sum(s.current_enrol_cnt) as current_enrol_cnt, sum(o.max_enrol_cnt) as max_enrol_cnt, s.snapshot_code, sum(s.wait_cnt) as wait_cnt FROM course_sect_snapshot s INNER JOIN course_sect_offering o ON s.crn_num = o.crn_num AND s.acad_term_code = o.acad_term_code AND s.vers = o.vers WHERE s.vers = (SELECT max(vers) FROM cdw_vers WHERE import_finished IS NOT NULL) AND o.acad_subject_code = ? AND o.crse_num = ? AND s.snapshot_code IN ('INSTR_BEG', 'CURRENT', 'DAY5', 'DAY10', 'DAY15') GROUP BY o.acad_term_code, o.acad_subject_code, o.crse_num, s.snapshot_code ORDER BY o.acad_term_code, o.crse_num] 
Sep 16 16:04:34 beta.dw java[24249]: 2016-09-16 16:04:34.460 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.datasource.DataSourceUtils  : Fetching JDBC Connection from DataSource 
Sep 16 16:04:42 beta.dw java[24249]: 2016-09-16 16:04:42.243 DEBUG 24249 --- [io-8080-exec-10] o.s.jdbc.datasource.DataSourceUtils  : Returning JDBC Connection to DataSource 
Sep 16 16:04:42 beta.dw java[24249]: 2016-09-16 16:04:42.244 INFO 24249 --- [io-8080-exec-10] e.u.d.d.w.e.u.d.d.w.c.CensusController : After census query:Fri Sep 16 16:04:42 PDT 2016 

, 그것은 "가져 오기 JDBC 연결"사이에 약 8 초 소요

그러나 쿼리에는 8 초가 걸리지 않습니다. 'mysql'명령을 통해 동일한 서버에서 동일한 쿼리를 실행하면 정확한 쿼리 (동일한 매개 변수가 채워짐)가 약 1.8 초 걸린다는 것을 알 수 있습니다.

누락 된 6.2s는 어디에서 왔습니까? 저는 Tomcat 연결 풀을 의심합니다. 예를 들어, Spring Boot를 시작한 후 첫 쿼리를 수행 할 때만 - 시작시에는 아니지만 페이지로드시 - Tomcat 연결 풀이 연결 수집을 방해합니다.

아이디어를 디버깅하는 방법은 무엇입니까?

+0

외관상으로는 연결 누출이있는 것으로 보입니다. 응용 프로그램 코드가 연결을 올바르게 해제하지 못할 수 있습니다. 연결을 얻은 곳의 전체 코드를 보지 않고 문제가 어디에 있는지 말하고 사용하고 해제하는 것은 불가능합니다. 또한 일부 연결 풀 (Tomcat 포함)은 연결을 회수하는 데 열악합니다. HikariCP 또는 BoneCP와 같은 최근 풀을 사용하면 더 나은 결과를 얻을 수 있습니다. – manish

답변

0

이것은 VM에서 실행되는 MySQL과 관련된 성능 문제로 밝혀졌습니다.

관련 문제