트랜잭션 통계

Cloud Spanner는 트랜잭션에 대한 통계를 저장하는 기본 제공 테이블이 있습니다. SQL 문을 사용하여 이러한 SPANNER_SYS.TXN_STATS* 테이블에서 통계를 검색할 수 있습니다.

트랜잭션 통계를 사용해야 하는 경우

트랜잭션 통계는 성능 문제를 조사할 때 유용합니다. 예를 들어 데이터베이스에 성능 또는 초당 쿼리 수(QPS)에 영향을 줄 수 있는 실행이 느린 트랜잭션이 있는지 확인할 수 있습니다. 또 다른 시나리오로는 클라이언트 애플리케이션의 트랜잭션 실행 지연 시간이 긴 경우입니다. 트랜잭션 통계를 분석하면 특정 열의 대량 업데이트와 같이 지연 시간에 영향을 줄 수 잠재적 병목 현상을 발견하는데 도움이 됩니다.

가용성

SPANNER_SYS 데이터는 SQL 인터페이스를 통해서만 사용할 수 있습니다(예: executeQuerygcloud spanner databases execute-sql). Cloud Spanner의 다른 단일 읽기 메서드는 SPANNER_SYS를 지원하지 않습니다.

트랜잭션별로 그룹화된 지연 시간 통계

다음 테이블은 특정 기간 동안 TOP 리소스를 소비하는 트랜잭션의 통계를 추적합니다.

  • SPANNER_SYS.TXN_STATS_TOP_MINUTE: 1분 간격으로 집계된 트랜잭션 통계입니다.

  • SPANNER_SYS.TXN_STATS_TOP_10MINUTE: 10분 간격으로 집계된 트랜잭션 통계입니다.

  • SPANNER_SYS.TXN_STATS_TOP_HOUR: 1시간 간격으로 집계된 트랜잭션 통계입니다.

이러한 테이블에는 다음과 같은 속성이 있습니다.

  • 각 테이블에는 테이블 이름에 지정된 길이의 겹치지 않는 시간 간격에 대한 데이터가 포함되어 있습니다.

  • 간격은 시계 시간을 기준으로 합니다. 1분 간격은 매분 정각에 끝나고, 10분 간격은 매시 정각에 시작해서 10분 단위로 끝나며, 1시간 간격은 매시 정각에 끝납니다.

    예를 들어 오전 11:59:30에 SQL 쿼리에 사용할 수 있는 가장 최근 간격은 다음과 같습니다.

    • 1분: 오전 11:58:01~11:59:00
    • 10분: 오전 11:40:01~11:50:00
    • 1시간: 오전 10:00:01~11:00:00
  • Cloud Spanner는 트랜잭션의 FPRINT(디지털 지문)별로 통계를 그룹화합니다. FPRINT는 트랜잭션과 관련된 작업을 기준으로 계산된 해시입니다.

  • 통계는 FPRINT를 기준으로 그룹화되므로 동일한 트랜잭션이 특정 시간 간격 내에 여러 번 실행되는 경우 이 테이블에 해당 트랜잭션에 대한 항목이 하나만 표시됩니다.

  • 각 행에는 Cloud Spanner가 지정 간격 동안 통계를 캡처하는 특정 트랜잭션의 모든 실행에 대한 통계가 포함됩니다.

Cloud Spanner가 이러한 테이블에 간격 동안 실행된 모든 트랜잭션에 대한 통계를 저장할 수 없는 경우, 시스템은 지정된 간격 동안 가장 높은 지연 시간, 커밋 시도, 작성한 바이트로 트랜잭션의 우선 순위를 지정합니다.

테이블 스키마

열 이름 유형 설명
INTERVAL_END TIMESTAMP 포함된 트랜잭션 실행이 발생한 시간 간격의 종료 시간입니다.
FPRINT INT64 디지털 지문은 트랜잭션과 관련된 작업을 기준으로 계산된 해시입니다. INTERVAL_ENDFPRINT가 같이 이러한 테이블의 고유 키 역할을 합니다.
READ_COLUMNS ARRAY<STRING> 트랜잭션을 통해 읽은 열 집합입니다.
WRITE_CONSTRUCTIVE_COLUMNS ARRAY<STRING> 트랜잭션에 의해 새로 작성된(새 값에 할당된) 열 집합입니다.
WRITE_DELETE_TABLES ARRAY<STRING> 삭제되었거나 트랜잭션으로 대체된 행이 있는 테이블 집합입니다.
COMMIT_ATTEMPT_COUNT INT64 트랜잭션의 총 커밋 시도 수입니다.
COMMIT_FAILED_PRECONDITION_COUNT INT64 트랜잭션의 전제조건 실패(FAILED_PRECONDITION) 수입니다.
COMMIT_ABORT_COUNT INT64 트랜잭션의 커밋이 중단된 횟수입니다.
AVG_PARTICIPANTS FLOAT64 각 커밋 시도의 평균 참여자 수입니다. 참여자에 대한 자세한 내용은 Cloud Spanner 읽기 및 쓰기 수명을 참조하세요.
AVG_TOTAL_LATENCY_SECONDS FLOAT64 트랜잭션의 첫 번째 작업에서 커밋/취소하는 데 걸린 평균 시간(초)입니다.
AVG_COMMIT_LATENCY_SECONDS FLOAT64 커밋 작업을 수행하는 데 걸린 평균 시간(초)입니다.
AVG_BYTES FLOAT64 트랜잭션을 통해 작성된 평균 바이트 수입니다.

쿼리 예

이 섹션에는 트랜잭션 통계를 검색하는 SQL 문의 몇 가지 예시가 포함되어 있습니다. 이러한 SQL 문은 클라이언트 라이브러리, gcloud 명령줄 도구 또는 Cloud Console을 사용하여 실행할 수 있습니다.

특정 기간의 각 트랜잭션에 대한 기본 통계 나열

다음 쿼리는 이전 1분 동안의 상위 트랜잭션에 대한 원시 데이터를 반환합니다.

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_total_latency_seconds,
       avg_commit_latency_seconds,
       avg_bytes
FROM spanner_sys.txn_stats_top_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_top_minute);
쿼리 출력
fprint read_columns write_constructive_columns write_delete_tables avg_total_latency_seconds avg_commit_latency_seconds avg_bytes
40015598317 [] ["Routes"] ["Users"] 0.006578737 0.006547737 25286
20524969030 ["id", "no"] [] [] 0.001732442 0.000247442 0
77848338483 [] [] ["Cars", "Routes"] 0.033467418 0.000251418 0

평균 커밋 지연 시간이 가장 긴 트랜잭션 나열

다음 쿼리는 이전 1시간 동안 평균 커밋 지연 시간이 긴 트랜잭션을 가장 긴 시간에서 가장 낮은 시간 순서로 반환합니다.

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_total_latency_seconds,
       avg_commit_latency_seconds,
       avg_bytes
FROM spanner_sys.txn_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_top_hour)
ORDER BY avg_commit_latency_seconds DESC;
쿼리 출력
fprint read_columns write_constructive_columns write_delete_tables avg_total_latency_seconds avg_commit_latency_seconds avg_bytes
40015598317 [] ["Routes"] ["Users"] 0.006578737 0.006547737 25286
77848338483 [] [] ["Cars", "Routes"] 0.033467418 0.000251418 0
20524969030 ["id", "no"] [] [] 0.001732442 0.000247442 0

특정 열을 읽는 트랜잭션의 평균 지연 시간 확인

다음 쿼리는 1시간 통계에서 ADDRESS 열을 읽는 트랜잭션의 평균 지연 시간 정보를 반환합니다.

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_total_latency_seconds
FROM spanner_sys.txn_stats_top_hour
WHERE 'ADDRESS' IN UNNEST(read_columns)
ORDER BY avg_total_latency_seconds DESC;
쿼리 출력
fprint read_columns write_constructive_columns write_delete_tables avg_total_latency_seconds
77848338483 ["ID", "ADDRESS"] [] ["Cars", "Routes"] 0.033467418
40015598317 ["ID", "NAME", "ADDRESS"] [] ["Users"] 0.006578737

수정된 평균 바이트 수를 기준으로 트랜잭션 나열

다음 쿼리는 지난 1시간 동안 샘플링된 트랜잭션을 트랜잭션에 의해 수정된 평균 바이트 수 순서대로 정렬합니다.

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_bytes
FROM spanner_sys.txn_stats_top_hour
ORDER BY avg_bytes DESC;
쿼리 출력
fprint read_columns write_constructive_columns write_delete_tables avg_bytes
40015598317 [] [] ["Users"] 25286
77848338483 [] [] ["Cars", "Routes"] 12005
20524969030 ["ID", "ADDRESS"] [] ["Users"] 10923

집계 통계

또한 SPANNER_SYS에는 Cloud Spanner가 특정 기간 동안 통계를 캡처한 모든 트랜잭션의 집계 데이터를 저장하는 테이블도 포함됩니다.

  • SPANNER_SYS.TXN_STATS_TOTAL_MINUTE: 1분 간격 동안의 모든 트랜잭션에 대한 통계 집계입니다.
  • SPANNER_SYS.TXN_STATS_TOTAL_10MINUTE: 10분 간격 동안의 모든 트랜잭션에 대한 통계 집계입니다.
  • SPANNER_SYS.TXN_STATS_TOTAL_HOUR: 1시간 간격 동안의 모든 트랜잭션에 대한 통계 집계입니다.

집계 통계 테이블에는 다음과 같은 속성이 있습니다.

  • 각 테이블에는 테이블 이름에 지정된 길이의 겹치지 않는 시간 간격에 대한 데이터가 포함되어 있습니다.

  • 간격은 시계 시간을 기준으로 합니다. 1분 간격은 매분 정각에 끝나고, 10분 간격은 매시 정각에 시작해서 10분 단위로 끝나며, 1시간 간격은 매시 정각에 끝납니다.

    예를 들어 오전 11:59:30에 집계 트랜잭션 통계에서 SQL 쿼리에 사용할 수 있는 가장 최근 간격은 다음과 같습니다.

    • 1분: 오전 11:58:01~11:59:00
    • 10분: 오전 11:40:01~11:50:00
    • 1시간: 오전 10:00:01~11:00:00
  • 각 행에는 지정된 간격 동안 데이터베이스에 대해 실행된 모든 트랜잭션에 대한 통계가 함께 집계됩니다. 따라서 시간 간격당 하나의 행만 있습니다.

  • SPANNER_SYS.TXN_STATS_TOTAL_* 테이블에 캡처되는 통계에는 Cloud Spanner가 SPANNER_SYS.TXN_STATS_TOP_* 테이블에 캡처하지 않은 트랜잭션도 포함될 수 있습니다.

테이블 스키마

열 이름 유형 설명
INTERVAL_END TIMESTAMP 이 통계가 캡처된 시간 간격의 종료 시간입니다.
COMMIT_ATTEMPT_COUNT INT64 트랜잭션의 총 커밋 시도 수입니다.
COMMIT_FAILED_PRECONDITION_COUNT INT64 트랜잭션의 전제조건 실패(FAILED_PRECONDITION) 수입니다.
COMMIT_ABORT_COUNT INT64 트랜잭션의 커밋이 중단된 횟수입니다.
AVG_PARTICIPANTS FLOAT64 각 커밋 시도의 평균 참여자 수입니다. 참여자에 대한 자세한 내용은 Cloud Spanner 읽기 및 쓰기 수명을 참조하세요.
AVG_TOTAL_LATENCY_SECONDS FLOAT64 트랜잭션의 첫 번째 작업에서 커밋/취소하는 데 걸린 평균 시간(초)입니다.
AVG_COMMIT_LATENCY_SECONDS FLOAT64 커밋 작업을 수행하는 데 걸린 평균 시간(초)입니다.
AVG_BYTES FLOAT64 트랜잭션을 통해 작성된 평균 바이트 수입니다.

쿼리 예

이 섹션에는 트랜잭션 통계를 검색하는 SQL 문의 몇 가지 예시가 포함되어 있습니다. 이러한 SQL 문은 클라이언트 라이브러리, gcloud 명령줄 도구 또는 Cloud Console을 사용하여 실행할 수 있습니다.

특정 기간의 트랜잭션에 대한 총 커밋 시도 수 찾기

다음 쿼리는 가장 최근의 1분 간격 동안의 모든 트랜잭션에 대한 총 커밋 시도 수를 반환합니다.

SELECT interval_end,
       commit_attempt_count
FROM spanner_sys.txn_stats_total_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_total_minute)
ORDER BY interval_end;
쿼리 출력
interval_end commit_attempt_count
2020-01-17 11:46:00-08:00 21

집계된 통계에는 특정 기간 동안 interval_end당 하나의 항목만 있으므로 결과에 행이 하나만 있습니다.

모든 트랜잭션에서 총 커밋 지연 시간 찾기

다음 쿼리는 이전 10분 동안의 모든 트랜잭션에서 총 커밋 지연 시간을 반환합니다.

SELECT (avg_commit_latency_seconds * commit_attempt_count / 60 / 60)
  AS total_commit_latency_hours
FROM spanner_sys.txn_stats_total_10minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_total_10minute);
쿼리 출력
total_commit_latency_hours
0.8967

집계된 통계에는 특정 기간 동안 interval_end당 하나의 항목만 있으므로 결과에 행이 하나만 있습니다.

데이터 보관

Cloud Spanner는 각 테이블의 데이터를 최소한 다음 기간 동안 보관합니다.

  • SPANNER_SYS.TXN_STATS_TOP_MINUTESPANNER_SYS.TXN_STATS_TOTAL_MINUTE: 이전 6시간을 포함하는 간격

  • SPANNER_SYS.TXN_STATS_TOP_10MINUTESPANNER_SYS.TXN_STATS_TOTAL_10MINUTE: 이전 4일을 포함하는 간격

  • SPANNER_SYS.TXN_STATS_TOP_HOURSPANNER_SYS.TXN_STATS_TOTAL_HOUR: 이전 30일을 포함하는 간격

Cloud Spanner의 트랜잭션 통계는 애플리케이션이 데이터베이스를 사용하는 방법에 대한 정보를 제공하며 성능 문제를 조사할 때 유용합니다. 예를 들어 경합을 유발하는 느린 실행 트랜잭션이 있는지 확인하거나 특정 열에 대한 대량 업데이트와 같이 부하가 높은 잠재적 소스를 식별할 수 있습니다. 다음 단계에 따라 트랜잭션 통계를 사용하여 데이터베이스의 경합을 조사하는 방법을 확인할 수 있습니다.

트랜잭션 통계를 사용하여 데이터베이스 경합 문제해결

조사할 기간 선택

Cloud Spanner를 사용하는 애플리케이션에서 찾을 수 있습니다.

이 연습에서는 2020년 5월 17일 오후 5시 20분 경에 문제가 발생했다고 가정해 보겠습니다.

선택한 기간의 트랜잭션 통계 수집

조사를 시작하기 위해 문제 시작 부분에서 TXN_STATS_TOTAL_10MINUTE 테이블을 쿼리합니다. 이 쿼리의 결과에는 해당 기간 동안 지연 시간 및 기타 트랜잭션 통계가 어떻게 변경되었는지 표시됩니다.

예를 들어 다음 쿼리는 4:30 pm에서 7:40 pm(포함)의 집계된 트랜잭션 통계를 반환합니다.

SELECT
  interval_end,
  ROUND(avg_total_latency_seconds,4) as avg_total_latency_seconds,
  commit_attempt_count,
  commit_abort_count
FROM SPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
WHERE
  interval_end >= "2020-05-17T16:40:00"
  AND interval_end <= "2020-05-17T19:40:00"
ORDER BY interval_end;

다음 표에는 쿼리에서 반환된 데이터의 예시가 나와 있습니다.

interval_end avg_total_latency_seconds commit_attempt_count commit_abort_count
2020-05-17 16:40:00-07:00 0.0284 315691 5170
2020-05-17 16:50:00-07:00 0.0250 302124 3828
2020-05-17 17:00:00-07:00 0.0460 346087 11382
2020-05-17 17:10:00-07:00 0.0864 379964 33826
2020-05-17 17:20:00-07:00 0.1291 390343 52549
2020-05-17 17:30:00-07:00 0.1314 456455 76392
2020-05-17 17:40:00-07:00 0.1598 507774 121458
2020-05-17 17:50:00-07:00 0.1641 516587 115875
2020-05-17 18:00:00-07:00 0.1578 552711 122626
2020-05-17 18:10:00-07:00 0.1750 569460 154205
2020-05-17 18:20:00-07:00 0.1727 613571 160772
2020-05-17 18:30:00-07:00 0.1588 601994 143044
2020-05-17 18:40:00-07:00 0.2025 604211 170019
2020-05-17 18:50:00-07:00 0.1615 601622 135601
2020-05-17 19:00:00-07:00 0.1653 596804 129511
2020-05-17 19:10:00-07:00 0.1414 560023 112247
2020-05-17 19:20:00-07:00 0.1367 570864 100596
2020-05-17 19:30:00-07:00 0.0894 539729 65316
2020-05-17 19:40:00-07:00 0.0820 479151 40398

여기에서 강조표시된 기간 동안 집계된 지연 시간과 취소 수가 더 높은 것을 확인할 수 있습니다. 집계된 지연 시간 또는 취소 수가 높은 10분 간격을 선택할 수 있습니다. 2020-05-17T18:40:00으로 끝나는 간격을 선택하고 다음 단계에서 이를 사용하여 지연 시간과 취소 횟수를 늘리는 트랜잭션을 식별해 보겠습니다.

지연 시간이 긴 트랜잭션 식별

이제 TXN_STATS_TOP_10MINUTE 테이블에서 이전 단계에서 선택한 간격을 쿼리해 보겠습니다. 이 데이터를 사용하면 지연 시간이 길어지거나 취소 횟수가 많은 트랜잭션을 파악할 수 있습니다.

다음 쿼리를 실행하여 2020-05-17T18:40:00에서 끝나는 예시 간격의 총 지연 시간을 내림차순으로 하여 성능에 가장 영향을 미치는 트랜잭션을 가져옵니다.

SELECT
  interval_end,
  fprint,
  ROUND(avg_total_latency_seconds,4) as avg_total_latency_seconds,
  ROUND(avg_commit_latency_seconds,4) as avg_commit_latency_seconds,
  commit_attempt_count,
  commit_abort_count
FROM SPANNER_SYS.TXN_STATS_TOP_10MINUTE
WHERE
  interval_end = "2020-05-17T18:40:00"
ORDER BY avg_total_latency_seconds DESC;
interval_end fprint avg_total_latency_seconds avg_commit_latency_seconds commit_attempt_count commit_abort_count
2020-05-17 18:40:00-07:00 15185072816865185658 0.3508 0.0139 278802 142205
2020-05-17 18:40:00-07:00 15435530087434255496 0.1633 0.0142 129012 27177
2020-05-17 18:40:00-07:00 14175643543447671202 0.1423 0.0133 5357 636
2020-05-17 18:40:00-07:00 898069986622520747 0.0198 0.0158 6 0
2020-05-17 18:40:00-07:00 10510121182038036893 0.0168 0.0125 7 0
2020-05-17 18:40:00-07:00 9287748709638024175 0.0159 0.0118 4269 1
2020-05-17 18:40:00-07:00 7129109266372596045 0.0142 0.0102 182227 0
2020-05-17 18:40:00-07:00 15630228555662391800 0.0120 0.0107 58 0
2020-05-17 18:40:00-07:00 7907238229716746451 0.0108 0.0097 65 0
2020-05-17 18:40:00-07:00 10158167220149989178 0.0095 0.0047 3454 0
2020-05-17 18:40:00-07:00 9353100217060788102 0.0093 0.0045 725 0
2020-05-17 18:40:00-07:00 9521689070912159706 0.0093 0.0045 164 0
2020-05-17 18:40:00-07:00 11079878968512225881 0.0064 0.0019 65 0

이전 테이블의 첫 번째 행(강조 표시됨)에 높은 커밋 중단 수로 인해 지연 시간이 높은 트랜잭션이 표시되는 것을 확실하게 볼 수 있습니다. 다음 단계에서는 이 문제의 원인을 더 자세히 조사합니다.

지연 시간이 긴 트랜잭션과 관련된 열 찾기

이 단계에서는 중단 횟수가 높은 트랜잭션에 대해 read_columns, write_constructive_columns, write_delete_tables 데이터를 인출하여 동일한 열 집합에서 높은 지연 시간 트랜잭션이 작동하는지 확인합니다. FPRINT 값은 다음 단계에서도 유용합니다.

SELECT
  fprint,
  read_columns,
  write_constructive_columns,
  write_delete_tables
FROM SPANNER_SYS.TXN_STATS_TOP_10MINUTE
WHERE
  interval_end = "2020-05-17T18:40:00"
ORDER BY avg_total_latency_seconds DESC LIMIT 3;
fprint read_columns write_constructive_columns write_delete
15185072816865185658 [TestHigherLatency._exists,TestHigherLatency.lang_status,TestHigherLatency.score,globalTagAffinity.shares] [TestHigherLatency._exists,TestHigherLatency.shares,TestHigherLatency_lang_status_score_index.shares] []
15435530087434255496 [TestHigherLatency._exists,TestHigherLatency.lang_status,TestHigherLatency.likes,globalTagAffinity.score] [TestHigherLatency._exists,TestHigherLatency.likes,TestHigherLatency_lang_status_score_index.likes] []
14175643543447671202 [TestHigherLatency._exists,TestHigherLatency.lang_status,TestHigherLatency.score,globalTagAffinity.ugcCount] [TestHigherLatency._exists,TestHigherLatency.ugcCount,TestHigherLatency_lang_status_score_index.ugcCount] []

위 표에 나와 있는 것처럼 출력에서 평균 총 지연 시간이 가장 긴 트랜잭션이 동일한 열을 읽습니다. 또한 트랜잭션이 동일한 열(즉, TestHigherLatency._exists)에 쓰기 때문에 일부 쓰기 경합을 관찰할 수 있습니다.

시간 경과에 따른 트랜잭션 성능의 변화 파악

이 트랜잭션 형태와 관련된 통계가 일정 기간 동안 어떻게 변화했는지 확인할 수 있습니다. 다음 쿼리를 사용합니다. 여기서 $FPRINT는 이전 단계의 지연 시간이 높은 트랜잭션의 디지털 지문입니다.

SELECT
  interval_end,
  ROUND(avg_total_latency_seconds, 3) AS latency,
  ROUND(avg_commit_latency_seconds, 3) AS commit_latency,
  commit_attempt_count,
  commit_abort_count,
  commit_failed_precondition_count,
  avg_bytes
FROM SPANNER_SYS.TXN_STATS_TOP_10MINUTE
WHERE
  interval_end >= "2020-05-17T16:40:00"
  AND interval_end <= "2020-05-17T19:40:00"
  AND fprint = $FPRINT
ORDER BY interval_end;
interval_end 지연 시간 commit_latency commit_attempt_count commit_abort_count commit_failed_precondition_count avg_bytes
2020-05-17 16:40:00-07:00 0.095 0.010 53230 4752 0 91
2020-05-17 16:50:00-07:00 0.069 0.009 61264 3589 0 91
2020-05-17 17:00:00-07:00 0.150 0.010 75868 10557 0 91
2020-05-17 17:10:00-07:00 0.248 0.013 103151 30220 0 91
2020-05-17 17:20:00-07:00 0.310 0.012 130078 45655 0 91
2020-05-17 17:30:00-07:00 0.294 0.012 160064 64930 0 91
2020-05-17 17:40:00-07:00 0.315 0.013 209614 104949 0 91
2020-05-17 17:50:00-07:00 0.322 0.012 215682 100408 0 90
2020-05-17 18:00:00-07:00 0.310 0.012 230932 106728 0 91
2020-05-17 18:10:00-07:00 0.309 0.012 259645 131049 0 91
2020-05-17 18:20:00-07:00 0.315 0.013 272171 137910 0 90
2020-05-17 18:30:00-07:00 0.292 0.013 258944 121475 0 91
2020-05-17 18:40:00-07:00 0.350 0.013 278802 142205 0 91
2020-05-17 18:50:00-07:00 0.302 0.013 256259 115626 0 91
2020-05-17 19:00:00-07:00 0.315 0.014 250560 110662 0 91
2020-05-17 19:10:00-07:00 0.271 0.014 238384 99025 0 91
2020-05-17 19:20:00-07:00 0.273 0.014 219687 84019 0 91
2020-05-17 19:30:00-07:00 0.198 0.013 195357 59370 0 91
2020-05-17 19:40:00-07:00 0.181 0.013 167514 35705 0 91

위 출력에서는 강조 표시된 기간에 대해 총 지연 시간이 높은 것을 확인할 수 있습니다. 또한 커밋 지연 시간(commit_latency)이 크게 변경되지 않았더라도 총 지연 시간이 높은 곳마다 commit_attempt_countcommit_abort_coun도 높습니다. 트랜잭션 커밋이 더 자주 중단되기 때문에 커밋 재시도로 인해 커밋 시도 수도 높습니다.

결론

이 예시에서는 높은 커밋 취소 횟수가 지연 시간이 높은 원인임을 확인했습니다. 다음 단계는 애플리케이션에서 수신한 커밋 취소 오류 메시지를 확인하여 취소 이유를 확인하는 것입니다. 애플리케이션에서 로그를 검사하여 이 기간 동안 애플리케이션이 실제로 워크로드를 변경했음을 알 수 있습니다.즉, 다른 트랜잭션 형태가 높은 attempts_per_second와 함께 표시되고 야간 정리 작업과 같은 다른 트랜잭션이 추가 잠금 충돌의 원인임을 알 수 있습니다.

다음 단계

  • 다른 점검 도구에 대해 알아보기
  • Cloud Spanner가 각 데이터베이스에 대해 데이터베이스의 정보 스키마 테이블에 저장하는 다른 정보 알아보기
  • Cloud Spanner 관련 SQL 권장사항에 대해 자세히 알아보기