트랜잭션 통계

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

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

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

사용 가능 여부

SPANNER_SYS 데이터는 SQL 인터페이스를 통해서만 사용할 수 있습니다. 예를 들면 다음과 같습니다.

  • Google Cloud 콘솔에 있는 데이터베이스의 Spanner 스튜디오 페이지

  • gcloud spanner databases execute-sql 명령어

  • 트랜잭션 통계 대시보드

  • executeQuery API

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:00–11:58:59
    • 10분: 오전 11:40:00–11:49:59
    • 1시간: 오전 10:00:00~10:59:59

  • Spanner는 트랜잭션의 FPRINT(디지털 지문)별로 통계를 그룹화합니다. 트랜잭션 태그가 있으면 FPRINT는 태그의 해시입니다. 그렇지 않으면 트랜잭션과 관련된 작업을 기준으로 계산된 해시입니다.

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

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

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

테이블 스키마

열 이름 유형 설명
INTERVAL_END TIMESTAMP 포함된 트랜잭션이 실행된 시간 간격의 종료 시간입니다.
TRANSACTION_TAG STRING 이 트랜잭션 작업의 선택적 트랜잭션 태그입니다. 태그 사용에 대한 자세한 내용은 트랜잭션 태그 문제 해결을 참조하세요. 태그 문자열이 동일한 여러 트랜잭션의 통계는 해당 태그 문자열과 일치하는 `TRANSACTION_TAG`와 함께 단일 행으로 그룹화됩니다.
FPRINT INT64 TRANSACTION_TAG의 해시입니다(있는 경우). 그렇지 않으면 해시는 트랜잭션과 관련된 작업을 기준으로 계산됩니다. INTERVAL_END 및 FPRINT가 함께 이러한 테이블의 고유 키 역할을 합니다.
READ_COLUMNS ARRAY<STRING> 트랜잭션을 통해 읽은 열 집합입니다.
WRITE_CONSTRUCTIVE_COLUMNS ARRAY<STRING> 트랜잭션에 의해 새로 작성된(즉, 새 값에 할당된) 열 집합입니다.

변경 내역의 경우 트랜잭션이 변경 내역에서 감시하는 열 및 테이블에 쓰기를 수행하면 WRITE_CONSTRUCTIVE_COLUMNS에 두 개의 열, .data 및 ._exists1가 포함되며 변경 내역 이름이 프리픽스로 사용됩니다.
WRITE_DELETE_TABLES ARRAY<STRING> 삭제되었거나 트랜잭션으로 대체된 행이 있는 테이블 집합입니다.
ATTEMPT_COUNT INT64 '커밋'을 호출하기 전에 취소된 시도를 포함하여 트랜잭션이 시도된 총 횟수입니다.
COMMIT_ATTEMPT_COUNT INT64 총 트랜잭션 커밋 시도 횟수입니다. 트랜잭션의 commit 메서드 호출 수와 일치해야 합니다.
COMMIT_ABORT_COUNT INT64 트랜잭션의 commit 메서드를 호출하기 전에 취소된 시도를 포함하여 취소된 총 트랜잭션 시도 횟수입니다.
COMMIT_RETRY_COUNT INT64 이전에 취소된 시도에서 재시도된 총 시도 횟수입니다. 잠금 경합 또는 일시적인 이벤트로 인해 커밋되기 전에 Spanner 트랜잭션이 여러 번 시도될 수 있습니다. 커밋 시도와 관련된 재시도 횟수가 많으면 조사할 만한 문제가 있을 수 있습니다. 자세한 내용은 이 페이지의 트랜잭션 및 커밋 수 이해를 참조하세요.
COMMIT_FAILED_PRECONDITION_COUNT INT64 실패한 사전 조건 오류(예: UNIQUE 색인 위반, 이미 존재하는 행, 찾을 수 없는 행 등)를 반환한 총 트랜잭션 커밋 시도 횟수입니다.
AVG_PARTICIPANTS FLOAT64 각 커밋 시도의 평균 참여자 수입니다. 참여자에 대한 자세한 내용은 Spanner 읽기 및 쓰기 수명을 참조하세요.
AVG_TOTAL_LATENCY_SECONDS FLOAT64 트랜잭션의 첫 작업에서 커밋/취소하는 데 걸린 평균 시간(초)입니다.
AVG_COMMIT_LATENCY_SECONDS FLOAT64 커밋 작업을 수행하는 데 걸린 평균 시간(초)입니다.
AVG_BYTES FLOAT64 트랜잭션을 통해 작성된 평균 바이트 수입니다.
TOTAL_LATENCY_DISTRIBUTION ARRAY<STRUCT>

모든 트랜잭션 시도의 첫 번째 트랜잭션 작업 시작 시간부터 커밋 또는 취소 시간까지의 총 커밋 지연 시간 히스토그램입니다.

트랜잭션이 여러 번 취소된 후 성공적으로 커밋되면 최종 성공 커밋까지 각 시도에 대한 지연 시간이 측정됩니다. 값은 초 단위로 측정됩니다.

배열에는 단일 요소가 포함되며 배열 유형은 다음과 같습니다.
ARRAY<STRUCT<
  COUNT INT64,
  MEAN FLOAT64,
  SUM_OF_SQUARED_DEVIATION FLOAT64,
  NUM_FINITE_BUCKETS INT64,
  GROWTH_FACTOR FLOAT64,
  SCALE FLOAT64,
  BUCKET_COUNTS ARRAY<INT64>>>
값에 대한 자세한 내용은 분포를 참조하세요.

분포에서 원하는 백분위수 지연 시간을 계산하려면 예상 n번째 백분위수를 반환하는 SPANNER_SYS.DISTRIBUTION_PERCENTILE(distribution, n FLOAT64) 함수를 사용합니다. 관련 예시는 트랜잭션의 99번째 백분위수 지연 시간 확인을 참조하세요.

자세한 내용은 백분위수 및 분포 값 측정항목을 참조하세요.

OPERATIONS_BY_TABLE ARRAY<STRUCT>

테이블별 트랜잭션에 의해 INSERT 또는 UPDATE 작업이 미치는 영향. 이는 행의 영향을 받는 횟수 및 작성한 바이트 수로 표시됩니다.

이 열은 테이블의 부하를 시각화하는 데 도움이 되며 트랜잭션이 테이블에 쓰는 속도에 대한 통계를 제공합니다.

배열을 다음과 같이 지정합니다.
ARRAY<STRUCT<
  TABLE STRING(MAX),
  INSERT_OR_UPDATE_COUNT INT64,
  INSERT_OR_UPDATE_BYTES INT64>>

1 _exists는 특정 행이 있는지 여부를 확인하는 데 사용되는 내부 필드입니다.

쿼리 예

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

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

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

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_total_latency_seconds,
       avg_commit_latency_seconds,
       operations_by_table,
       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 operations_by_table avg_bytes
40015598317 [] ["Routes.name", "Cars.model"] ["Users"] 0.006578737 0.006547737 [["Cars",1107,30996],["Routes",560,26880]] 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.name", "Cars.model"] ["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에는 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:00–11:58:59
    • 10분: 오전 11:40:00–11:49:59
    • 1시간: 오전 10:00:00~10:59:59

  • 각 행에는 지정된 간격 동안 데이터베이스에 대해 실행된 모든 트랜잭션에 대한 통계가 함께 집계됩니다. 따라서 시간 간격당 하나의 행만 있습니다.

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

  • 이러한 테이블의 일부 열은 Cloud Monitoring에서 측정항목으로 노출됩니다. 노출된 측정항목은 다음과 같습니다.

    • 커밋 시도 수
    • 커밋 재시도 수
    • 트랜잭션 참여자
    • 트랜잭션 지연 시간
    • 작성한 바이트

    자세한 내용은 Spanner 측정항목을 참조하세요.

테이블 스키마

열 이름 유형 설명
INTERVAL_END TIMESTAMP 이 통계가 캡처된 시간 간격의 종료 시간입니다.
ATTEMPT_COUNT INT64 '커밋'을 호출하기 전에 취소된 시도를 포함하여 트랜잭션이 시도된 총 횟수입니다.
COMMIT_ATTEMPT_COUNT INT64 총 트랜잭션 커밋 시도 횟수입니다. 트랜잭션의 commit 메서드 호출 수와 일치해야 합니다.
COMMIT_ABORT_COUNT INT64 트랜잭션의 commit 메서드를 호출하기 전에 취소된 시도를 포함하여 취소된 총 트랜잭션 시도 횟수입니다.
COMMIT_RETRY_COUNT INT64 이전에 중단된 시도에서 재시도된 커밋 시도 횟수입니다. Spanner 트랜잭션은 잠금 경합 또는 일시적인 이벤트로 인해 커밋되기 전에 여러 번 시도될 수 있습니다. 커밋 시도와 관련된 재시도 횟수가 많으면 조사할 만한 문제가 있을 수 있습니다. 자세한 내용은 이 페이지의 트랜잭션 및 커밋 수 이해를 참조하세요.
COMMIT_FAILED_PRECONDITION_COUNT INT64 실패한 사전 조건 오류(예: UNIQUE 색인 위반, 이미 존재하는 행, 찾을 수 없는 행 등)를 반환한 총 트랜잭션 커밋 시도 횟수입니다.
AVG_PARTICIPANTS FLOAT64 각 커밋 시도의 평균 참여자 수입니다. 참여자에 대한 자세한 내용은 Spanner 읽기 및 쓰기 수명을 참조하세요.
AVG_TOTAL_LATENCY_SECONDS FLOAT64 트랜잭션의 첫 작업에서 커밋/취소하는 데 걸린 평균 시간(초)입니다.
AVG_COMMIT_LATENCY_SECONDS FLOAT64 커밋 작업을 수행하는 데 걸린 평균 시간(초)입니다.
AVG_BYTES FLOAT64 트랜잭션을 통해 작성된 평균 바이트 수입니다.
TOTAL_LATENCY_DISTRIBUTION ARRAY<STRUCT>

첫 번째 트랜잭션 작업 시작 시간부터 모든 트랜잭션 시도에 대한 커밋 또는 취소 시간까지의 총 커밋 지연 시간에 대한 히스토그램입니다.

트랜잭션이 여러 번 취소된 후 성공적으로 커밋되면 최종 성공 커밋까지 각 시도에 대한 지연 시간이 측정됩니다. 값은 초 단위로 측정됩니다.

배열에는 단일 요소가 포함되며 배열 유형은 다음과 같습니다.
ARRAY<STRUCT<
  COUNT INT64,
  MEAN FLOAT64,
  SUM_OF_SQUARED_DEVIATION FLOAT64,
  NUM_FINITE_BUCKETS INT64,
  GROWTH_FACTOR FLOAT64,
  SCALE FLOAT64,
  BUCKET_COUNTS ARRAY<INT64>>>
값에 대한 자세한 내용은 분포를 참조하세요.

분포에서 원하는 백분위수 지연 시간을 계산하려면 예상 n번째 백분위수를 반환하는 SPANNER_SYS.DISTRIBUTION_PERCENTILE(distribution, n FLOAT64) 함수를 사용합니다. 예시는 트랜잭션의 99번째 백분위수 지연 시간 확인을 참조하세요.

자세한 내용은 백분위수 및 분포 값 측정항목을 참조하세요.

OPERATIONS_BY_TABLE ARRAY<STRUCT>

테이블별 모든 트랜잭션에 의해 INSERT 또는 UPDATE 작업이 미치는 영향. 이는 행의 영향을 받는 횟수 및 작성한 바이트 수로 표시됩니다.

이 열은 테이블의 부하를 시각화하는 데 도움이 되며 트랜잭션이 테이블에 쓰는 속도에 대한 통계를 제공합니다.

배열을 다음과 같이 지정합니다.
ARRAY<STRUCT<
  TABLE STRING(MAX),
  INSERT_OR_UPDATE_COUNT INT64,
  INSERT_OR_UPDATE_BYTES INT64>>

쿼리 예

이 섹션에는 트랜잭션 통계를 검색하는 SQL 문의 몇 가지 예시가 포함되어 있습니다. 이러한 SQL 문은 클라이언트 라이브러리, gcloud spanner 또는 Google 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당 하나의 항목만 있으므로 결과에 행이 하나만 있습니다.

트랜잭션의 99번째 백분위수 지연 시간 확인

다음 쿼리는 이전 10분 동안 실행된 트랜잭션의 99번째 백분위수 지연 시간을 반환합니다.

SELECT interval_end, avg_total_latency_seconds,
       SPANNER_SYS.DISTRIBUTION_PERCENTILE(total_latency_distribution[OFFSET(0)], 99.0)
  AS percentile_latency
FROM spanner_sys.txn_stats_total_10minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_total_10minute)
ORDER BY interval_end;
쿼리 출력
interval_end avg_total_latency_seconds percentile_latency
2022-08-17 11:46:00-08:00 0.34576998305986395 9.00296190476190476

평균과 99번째 백분위수 지연 시간 간의 큰 차이를 확인합니다. 99번째 백분위수 지연 시간은 높은 지연 시간으로 가능한 이상점 트랜잭션을 식별하는 데 도움이 됩니다.

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

데이터 보관

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

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

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

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

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

트랜잭션 및 커밋 수 이해

Spanner 트랜잭션을 커밋하기 전에 여러 번 시도해야 할 수 있습니다. 이 문제는 주로 두 트랜잭션이 동시에 같은 데이터에서 작업을 시도하고 트랜잭션의 격리 속성을 유지하기 위해 트랜잭션 중 하나를 중단해야 할 때 발생합니다. 트랜잭션이 취소될 수 있는 기타 일시적 이벤트는 다음과 같습니다.

  • 일시적인 네트워크 문제

  • 트랜잭션이 커밋되는 동안 데이터베이스 스키마 변경사항이 적용됩니다.

  • Spanner 인스턴스에 수신되는 모든 요청을 처리할 수 있는 용량이 없습니다.

이러한 시나리오에서 클라이언트는 성공적으로 커밋되거나 제한 시간이 될 때까지 취소된 트랜잭션을 다시 시도해야 합니다. 공식 Spanner 클라이언트 라이브러리 사용자를 위해 라이브러리마다 자동 재시도 메커니즘을 구현했습니다. 클라이언트 코드의 커스텀 버전을 사용하는 경우 트랜잭션 커밋을 재시도 루프로 래핑합니다.

트랜잭션 제한 시간, 권한 문제 또는 잘못된 테이블/열 이름과 같은 재시도 불가능한 오류로 인해 Spanner 트랜잭션이 취소될 수도 있습니다. 이러한 트랜잭션을 재시도할 필요는 없으며 Spanner 클라이언트 라이브러리가 즉시 오류를 반환합니다.

다음 표에서는 COMMIT_ATTEMPT_COUNT, COMMIT_ABORT_COUNT, COMMIT_RETRY_COUNT가 서로 다른 시나리오에서 로깅되는 방법의 몇 가지 예시를 설명합니다.

시나리오 COMMIT_ATTEMPT_COUNT COMMIT_ABORT_COUNT COMMIT_RETRY_COUNT
첫 번째 시도에서 트랜잭션이 성공적으로 커밋되었습니다. 1 0 0
제한 시간 오류로 인해 트랜잭션이 취소되었습니다. 1 1 0
일시적인 네트워크 문제로 인해 트랜잭션이 중단되었고 재시도 1회 후 성공적으로 커밋되었습니다. 2 1 1
동일한 FPRINT가 포함된 트랜잭션 5개가 10분 간격으로 실행됩니다. 트랜잭션 3개가 첫 시도에서 성공적으로 커밋되었지만 트랜잭션 2개는 중단된 후 첫 재시도에서 성공적으로 커밋되었습니다. 7 2 2

트랜잭션 통계 테이블의 데이터는 시간 간격 동안 집계된 데이터입니다. 특정 간격의 경우 트랜잭션 취소 및 재시도가 경계 근처에서 발생하고 서로 다른 버킷으로 분류될 수 있습니다. 따라서 특정 시간 간격의 중단과 재시도가 동일하지 않을 수 있습니다.

이러한 통계는 문제 해결 및 점검을 위해 설계됐으며 100% 정확성을 보장하지는 않습니다. 통계는 Spanner 테이블에 저장되기 전에 메모리에 집계됩니다. 업그레이드나 기타 유지보수 작업 중에 Spanner 서버가 다시 시작되면 숫자 정확성이 영향을 받을 수 있습니다.

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

SQL 코드 또는 트랜잭션 통계 대시보드를 사용하여 잠금 경합으로 인해 높은 지연 시간을 일으킬 수 있는 데이터베이스의 트랜잭션을 볼 수 있습니다.

다음 주제에서는 SQL 코드를 사용하여 이러한 트랜잭션을 조사하는 방법을 보여줍니다.

조사 기간 선택

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,
  commit_retry_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 commit_retry_count
2020-05-17 18:40:00-07:00 15185072816865185658 0.3508 0.0139 278802 142205 129884
2020-05-17 18:40:00-07:00 15435530087434255496 0.1633 0.0142 129012 27177 24559
2020-05-17 18:40:00-07:00 14175643543447671202 0.1423 0.0133 5357 636 433
2020-05-17 18:40:00-07:00 898069986622520747 0.0198 0.0158 6 0 0
2020-05-17 18:40:00-07:00 10510121182038036893 0.0168 0.0125 7 0 0
2020-05-17 18:40:00-07:00 9287748709638024175 0.0159 0.0118 4269 1 0
2020-05-17 18:40:00-07:00 7129109266372596045 0.0142 0.0102 182227 0 0
2020-05-17 18:40:00-07:00 15630228555662391800 0.0120 0.0107 58 0 0
2020-05-17 18:40:00-07:00 7907238229716746451 0.0108 0.0097 65 0 0
2020-05-17 18:40:00-07:00 10158167220149989178 0.0095 0.0047 3454 0 0
2020-05-17 18:40:00-07:00 9353100217060788102 0.0093 0.0045 725 0 0
2020-05-17 18:40:00-07:00 9521689070912159706 0.0093 0.0045 164 0 0
2020-05-17 18:40:00-07:00 11079878968512225881 0.0064 0.0019 65 0 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_tables
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_retry_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_retry_count commit_failed_precondition_count avg_bytes
2020-05-17 16:40:00-07:00 0.095 0.010 53230 4752 4330 0 91
2020-05-17 16:50:00-07:00 0.069 0.009 61264 3589 3364 0 91
2020-05-17 17:00:00-07:00 0.150 0.010 75868 10557 9322 0 91
2020-05-17 17:10:00-07:00 0.248 0.013 103151 30220 28483 0 91
2020-05-17 17:20:00-07:00 0.310 0.012 130078 45655 41966 0 91
2020-05-17 17:30:00-07:00 0.294 0.012 160064 64930 59933 0 91
2020-05-17 17:40:00-07:00 0.315 0.013 209614 104949 96770 0 91
2020-05-17 17:50:00-07:00 0.322 0.012 215682 100408 95867 0 90
2020-05-17 18:00:00-07:00 0.310 0.012 230932 106728 99462 0 91
2020-05-17 18:10:00-07:00 0.309 0.012 259645 131049 125889 0 91
2020-05-17 18:20:00-07:00 0.315 0.013 272171 137910 129411 0 90
2020-05-17 18:30:00-07:00 0.292 0.013 258944 121475 115844 0 91
2020-05-17 18:40:00-07:00 0.350 0.013 278802 142205 134229 0 91
2020-05-17 18:50:00-07:00 0.302 0.013 256259 115626 109756 0 91
2020-05-17 19:00:00-07:00 0.315 0.014 250560 110662 100322 0 91
2020-05-17 19:10:00-07:00 0.271 0.014 238384 99025 90187 0 91
2020-05-17 19:20:00-07:00 0.273 0.014 219687 84019 79874 0 91
2020-05-17 19:30:00-07:00 0.198 0.013 195357 59370 55909 0 91
2020-05-17 19:40:00-07:00 0.181 0.013 167514 35705 32885 0 91

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

결론

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

올바르게 재시도되지 않은 트랜잭션 식별

다음 쿼리는 지난 10분 동안 샘플링되고 커밋 취소 수가 많지만 재시도가 없는 트랜잭션을 반환합니다.

SELECT
  *
FROM (
  SELECT
    fprint,
    SUM(commit_attempt_count) AS total_commit_attempt_count,
    SUM(commit_abort_count) AS total_commit_abort_count,
    SUM(commit_retry_count) AS total_commit_retry_count
  FROM
    SPANNER_SYS.TXN_STATS_TOP_10MINUTE
  GROUP BY
    fprint )
WHERE
  total_commit_retry_count = 0
  AND total_commit_abort_count > 0
ORDER BY
  total_commit_abort_count DESC;
fprint total_commit_attempt_count total_commit_abort_count total_commit_retry_count
1557557373282541312 3367894 44232 0
5776062322886969344 13566 14 0

fprint 1557557373282541312가 있는 트랜잭션은 44232회 취소되었지만 재시도되지 않았습니다. 취소 횟수가 많지만 재시도 불가능한 오류로 인해 모든 중단이 발생했을 가능성은 낮으므로 의심스러운 트랜잭션으로 보입니다. 반면 fprint 5776062322886969344가 포함된 트랜잭션의 경우 총 중단 횟수가 많지 않으므로 덜 의심스럽습니다.

다음 쿼리는 read_columns,write_constructive_columns, write_delete_tables가 포함된 fprint 1557557373282541312가 있는 트랜잭션에 대한 자세한 내용을 반환합니다. 이 정보는 이 시나리오의 재시도 논리를 검토할 수 있는 클라이언트 코드에서 트랜잭션을 식별하는 데 도움이 됩니다.

SELECT
  interval_end,
  fprint,
  read_columns,
  write_constructive_columns,
  write_delete_tables,
  commit_attempt_count,
  commit_abort_count,
  commit_retry_count
FROM
  SPANNER_SYS.TXN_STATS_TOP_10MINUTE
WHERE
  fprint = 1557557373282541312
ORDER BY
  interval_end DESC;
interval_end fprint read_columns write_constructive_columns write_delete_tables commit_attempt_count commit_abort_count commit_retry_count
2021-01-27T18:30:00Z 1557557373282541312 ['Singers._exists'] ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] [] 805228 1839 0
2021-01-27T18:20:00Z 1557557373282541312 ['Singers._exists'] ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] [] 1034429 38779 0
2021-01-27T18:10:00Z 1557557373282541312 ['Singers._exists'] ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] [] 833677 2266 0
2021-01-27T18:00:00Z 1557557373282541312 ['Singers._exists'] ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] [] 694560 1348 0

이 트랜잭션에는 행의 존재 여부를 확인하기 위해 Singers._exists 숨겨진 열 읽기가 포함되어 있습니다. 트랜잭션은 Singers.FirstName 및 Singer.LastName 열에도 기록합니다. 이 정보는 커스텀 클라이언트 라이브러리에 구현된 트랜잭션 재시도 메커니즘이 예상대로 작동하는지 여부를 확인하는 데 도움이 될 수 있습니다.

다음 단계