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가 이러한 테이블에 간격 동안 실행된 모든 트랜잭션에 대한 통계를 저장할 수 없는 경우, 시스템은 지정된 간격 동안 가장 높은 지연 시간, 커밋 시도, 작성한 바이트로 트랜잭션의 우선 순위를 지정합니다.
테이블의 모든 열은 null을 허용합니다.
테이블 스키마
열 이름 | 유형 | 설명 |
---|---|---|
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 및 ._exists 1가 포함되며 변경 내역 이름이 프리픽스로 사용됩니다.
|
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>
|
모든 트랜잭션 시도의 첫 번째 트랜잭션 작업 시작 시간부터 커밋 또는 취소 시간까지의 총 커밋 지연 시간 히스토그램입니다.
트랜잭션이 여러 번 취소된 후 성공적으로 커밋되면 최종 성공 커밋까지 각 시도에 대한 지연 시간이 측정됩니다. 값은 초 단위로 측정됩니다.
배열에는 단일 요소가 포함되며 배열 유형은 다음과 같습니다. 분포에서 원하는 백분위수 지연 시간을 계산하려면 예상 n번째 백분위수를 반환하는 자세한 내용은 백분위수 및 분포 값 측정항목을 참조하세요. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
테이블별 트랜잭션에 의해
이 열은 테이블의 부하를 시각화하는 데 도움이 되며 트랜잭션이 테이블에 쓰는 속도에 대한 통계를 제공합니다.
배열을 다음과 같이 지정합니다.
|
1 _exists
는 특정 행이 있는지 여부를 확인하는 데 사용되는 내부 필드입니다.
쿼리 예
이 섹션에는 트랜잭션 통계를 검색하는 SQL 문의 몇 가지 예시가 포함되어 있습니다. 클라이언트 라이브러리, gcloud spanner 또는 Google Cloud 콘솔을 사용하여 이러한 SQL 문을 실행할 수 있습니다.
특정 기간의 각 트랜잭션에 대한 기본 통계 나열
다음 쿼리는 이전 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>
|
첫 번째 트랜잭션 작업 시작 시간부터 모든 트랜잭션 시도에 대한 커밋 또는 취소 시간까지의 총 커밋 지연 시간에 대한 히스토그램입니다.
트랜잭션이 여러 번 취소된 후 성공적으로 커밋되면 최종 성공 커밋까지 각 시도에 대한 지연 시간이 측정됩니다. 값은 초 단위로 측정됩니다.
배열에는 단일 요소가 포함되며 배열 유형은 다음과 같습니다. 분포에서 원하는 백분위수 지연 시간을 계산하려면 예상 n번째 백분위수를 반환하는 자세한 내용은 백분위수 및 분포 값 측정항목을 참조하세요. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
테이블별 모든 트랜잭션에 의해
이 열은 테이블의 부하를 시각화하는 데 도움이 되며 트랜잭션이 테이블에 쓰는 속도에 대한 통계를 제공합니다.
배열을 다음과 같이 지정합니다.
|
쿼리 예
이 섹션에는 트랜잭션 통계를 검색하는 SQL 문의 몇 가지 예시가 포함되어 있습니다. 클라이언트 라이브러리, gcloud spanner 또는 Google Cloud 콘솔을 사용하여 이러한 SQL 문을 실행할 수 있습니다.
모든 트랜잭션의 총 커밋 시도 수 확인
다음 쿼리는 가장 최근의 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
열에도 기록합니다. 이 정보는 커스텀 클라이언트 라이브러리에 구현된 트랜잭션 재시도 메커니즘이 예상대로 작동하는지 여부를 확인하는 데 도움이 될 수 있습니다.
다음 단계
- 다른 점검 도구 알아보기
- Spanner가 각 데이터베이스에 대해 데이터베이스의 정보 스키마 테이블에 저장하는 다른 정보 알아보기
- Spanner 관련 SQL 권장사항 자세히 알아보기
- 높은 CPU 사용률 조사 자세히 알아보기