

# Aurora PostgreSQL Limitless Database의 PostgreSQL 로그에서 분산 쿼리 추적
<a name="limitless-query.tracing"></a>

분산 쿼리 추적은 Aurora PostgreSQL Limitless Database에서 PostgreSQL 로그의 쿼리를 추적하고 상호 연관시키는 도구입니다. Aurora PostgreSQL에서는 트랜잭션 ID를 사용하여 트랜잭션을 식별합니다. 그러나 Aurora PostgreSQL Limitless Database에서는 트랜잭션 ID가 다양한 라우터에서 반복될 수 있습니다. 따라서 Limitless Database에서는 대신 추적 ID를 사용하는 것이 좋습니다.

주요 사용 사례는 다음과 같습니다.
+ `rds_aurora.limitless_get_last_trace_id()` 함수를 사용하여 현재 세션에서 마지막으로 실행된 쿼리의 고유한 추적 ID를 찾습니다. 그런 다음 해당 추적 ID를 사용하여 Amazon CloudWatch Logs에서 DB 클러스터 로그 그룹을 검색하여 모든 관련 로그를 찾습니다.

  `log_min_messages` 및 `log_min_error_statement` 파라미터를 함께 사용하여 인쇄된 로그 볼륨을 제어하고 추적 ID가 포함된 문을 인쇄할 수 있습니다.
+ `log_min_duration_statement` 파라미터를 사용하여 모든 쿼리가 실행 기간 및 추적 ID를 인쇄하는 기준이 되는 실행 시간을 결정합니다. 그런 다음 CloudWatch Logs의 DB 클러스터 로그 그룹에서 이 실행 시간을 검색하여 병목 노드와 플래너 최적화 노력을 확인할 수 있습니다.

  `log_min_duration_statement` 파라미터는 `log_min_messages` 및 `log_min_error_statement` 파라미터의 값에 관계없이 모든 노드에 대해 추적 ID를 활성화합니다.

**Topics**
+ [추적 ID](#limitless-query.tracing.ID)
+ [쿼리 추적 사용](#limitless-query.tracing.using)
+ [로그 예제](#limitless-query.tracing.examples)

## 추적 ID
<a name="limitless-query.tracing.ID"></a>

이 기능의 핵심은 *추적 ID*라고 하는 고유 식별자입니다. 추적 ID는 PostgreSQL 로그의 STATEMENT 로그 줄에 추가된 31자리 문자열로, 특정 쿼리 실행과 관련된 로그를 상호 연관시키기 위한 정확한 식별자 역할을 합니다. 대표적인 예는 `1126253375719408504000000000011` 및 `1126253375719408495000000000090`입니다.

추적 ID는 다음으로 구성됩니다.
+ 트랜잭션 식별자 - 트랜잭션을 고유하게 식별하는 처음 20자리입니다.
+ 명령 식별자 - 트랜잭션 내의 개별 쿼리를 나타내는 처음 30자리입니다.

  명시적 트랜잭션 블록 내에서 4,294,967,294개 이상의 쿼리가 실행되는 경우 명령 식별자는 `1`로 래핑됩니다. 이 경우 PostgreSQL 로그에 다음 `LOG` 메시지가 표시됩니다.

  ```
  wrapping around the tracing ID back to 1 after running 4294967294 (4.2 billion or 2^32-2) queries inside of an explicit transaction block
  ```
+ 노드 유형 식별자 - 노드가 코디네이터 라우터(`1`) 또는 참가자 노드(`0`) 중 무엇으로 작동하는지 나타내는 마지막 숫자입니다.

다음 예시에서는 추적 ID의 구성 요소를 보여줍니다.
+ `1126253375719408504000000000011`:
  + 트랜잭션 식별자 - `1126253375719408504`
  + 명령 식별자 - `112625337571940850400000000001`은 트랜잭션 블록의 첫 번째 명령을 나타냅니다.
  + 노드 유형 식별자 - `1`은 코디네이터 라우터를 나타냅니다.
+ `1126253375719408495000000000090`:
  + 트랜잭션 식별자 - `1126253375719408495`
  + 명령 식별자 - `112625337571940849500000000009`는 트랜잭션 블록의 9번째 명령을 나타냅니다.
  + 노드 유형 식별자 - `0`은 참가자 노드를 나타냅니다.

## 쿼리 추적 사용
<a name="limitless-query.tracing.using"></a>

쿼리 추적을 사용하려면 다음 작업을 수행합니다.

1. 추적이 활성화되어 있는지 확인합니다.

   다음 명령을 사용하여 확인할 수 있습니다.

   ```
   SHOW rds_aurora.limitless_log_distributed_trace_id;
   ```

   기본적으로 활성화(`on`)되어 있습니다. 활성화되지 않은 경우 다음 명령을 사용하여 설정합니다.

   ```
   SET rds_aurora.limitless_log_distributed_trace_id = on;
   ```

1. 로그 심각도 수준을 구성하여 인쇄된 로그 볼륨을 제어합니다.

   로그 볼륨은 `log_min_messages` 파라미터로 제어됩니다. `log_min_error_statement` 파라미터는 추적 ID가 있는 `STATEMENT` 줄을 인쇄하는 데 사용됩니다. 둘 다 기본적으로 `ERROR`로 설정됩니다. 다음 명령을 사용하여 확인할 수 있습니다.

   ```
   SHOW log_min_messages;
   SHOW log_min_error_statement;
   ```

   심각도 수준을 업데이트하고 현재 세션의 `STATEMENT` 줄을 인쇄하려면 다음 심각도 수준 중 하나와 함께 다음 명령을 사용합니다.

   ```
   SET log_min_messages = '{{DEBUG5}} | {{DEBUG4}} | {{DEBUG3}} | {{DEBUG2}} | {{DEBUG1}} | {{INFO}} | {{NOTICE}} | {{WARNING}} | {{ERROR}} | {{LOG}} | {{FATAL}} | {{PANIC}}';
   SET log_min_error_statement = '{{DEBUG5}} | {{DEBUG4}} | {{DEBUG3}} | {{DEBUG2}} | {{DEBUG1}} | {{INFO}} | {{NOTICE}} | {{WARNING}} | {{ERROR}} | {{LOG}} | {{FATAL}} | {{PANIC}}';
   ```

   예시:

   ```
   SET log_min_messages = 'WARNING';
   SET log_min_error_statement = 'WARNING';
   ```

1. 특정 실행 시간을 초과하는 로그에서 추적 ID 인쇄를 활성화합니다.

   `log_min_duration_statement` 파라미터를 최소 쿼리 실행 시간으로 변경할 수 있습니다. 이 시간을 초과하면 쿼리가 DB 클러스터 전반의 추적 ID와 함께 실행 기간이 포함된 로그 줄을 인쇄합니다. 이 파라미터는 기본적으로 `-1`로 설정되어 있으며 비활성화되어 있다는 뜻입니다. 다음 명령을 사용하여 확인할 수 있습니다.

   ```
   SHOW log_min_duration_statement;
   ```

   `0`으로 변경하면 DB 클러스터 전체의 모든 쿼리에 대한 로그에 기간 및 추적 ID를 인쇄합니다. 다음 명령을 사용하여 현재 세션에 대해 `0`으로 설정할 수 있습니다.

   ```
   SET log_min_duration_statement = 0;
   ```

1. 추적 ID를 가져옵니다.

   쿼리를 실행한 후(명시적 트랜잭션 블록 내에서도) `rds_aurora.limitless_get_last_trace_id` 함수를 직접 호출하여 마지막 쿼리 실행의 추적 ID를 가져옵니다.

   ```
   SELECT * FROM rds_aurora.limitless_get_last_trace_id();
   ```

   이 함수는 트랜잭션 식별자와 명령 식별자를 반환합니다. 노드 유형 식별자는 반환되지 않습니다.

   ```
   => SELECT * FROM customers;
    customer_id | fname | lname 
   -------------+-------+-------
   (0 rows)
   
   => SELECT * FROM rds_aurora.limitless_get_last_trace_id();
    transaction_identifier |       command_identifier       
   ------------------------+--------------------------------
    10104661421959001813   | 101046614219590018130000000001
   (1 row)
   ```

   추적 ID가 없으므로 함수는 분산되지 않은 쿼리에 대해 빈 줄을 반환합니다.

   ```
   => SET search_path = public;
   SET
   
   => SELECT * FROM rds_aurora.limitless_get_last_trace_id();
    transaction_identifier | command_identifier 
   ------------------------+--------------------
                           | 
   (1 row)
   ```
**참고**  
VACUUM 및 ANALYZE 쿼리의 경우 기간 문은 추적 ID와 함께 로깅되지 않습니다. 따라서 `limitless_get_last_trace_id()`는 추적 ID를 반환하지 않습니다. VACUUM 또는 ANALYZE가 장기 실행 작업인 경우 다음 쿼리를 사용하여 해당 작업에 대한 추적 ID를 가져올 수 있습니다.  

   ```
   SELECT * FROM rds_aurora.limitless_stat_activity 
   WHERE distributed_tracing_id IS NOT NULL;
   ```
마지막 추적 ID를 찾기 전에 서버가 중지되면 PostgreSQL 로그를 수동으로 검색하여 실패 직전의 로그에서 추적 ID를 찾아야 합니다.

1. CloudWatch를 사용하여 DB 클러스터 로그에서 추적 ID를 검색합니다.

   다음 예시와 같이 [CloudWatch Insights](https://docs.aws.amazon.com/AmazonCloudWatch/latest/logs/AnalyzingLogData.html)를 사용하여 DB 클러스터의 로그 그룹을 쿼리합니다.
   + 특정 트랜잭션 식별자 및 그 안에서 실행되는 모든 명령에 대한 쿼리:

     ```
     fields @timestamp, @message
     | filter @message like /10104661421959001813/
     | sort @timestamp desc
     ```
   + 특정 명령 식별자에 대한 쿼리:

     ```
     fields @timestamp, @message
     | filter @message like /101046614219590018130000000001/
     | sort @timestamp desc
     ```

1. 분산 쿼리에서 생성된 DB 클러스터의 모든 로그를 검사합니다.

## 로그 예제
<a name="limitless-query.tracing.examples"></a>

다음 예시는 쿼리 추적 사용을 보여줍니다.

### 오류가 발생하기 쉬운 쿼리에 대한 로그 상호 연관
<a name="limitless-query.tracing.example1"></a>

이 예시에서 `TRUNCATE` 명령은 해당 테이블이 없으면 `customers` 테이블에서 실행됩니다.

**쿼리 추적 없음**  
코디네이터 라우터의 PostgreSQL 로그 파일:  

```
2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[27503]:ERROR: failed to execute remote query
2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[27503]:DETAIL: relation "public.customers" does not exist
2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[27503]:CONTEXT: remote SQL command: truncate public.customers;
2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[27503]:STATEMENT: truncate customers;
```
참가자 샤드의 PostgreSQL 로그 파일:  

```
2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[ 27503]:ERROR: failed to execute remote query
2023-09-26 04:03:19 UTC:[local]: postgres@postgres_limitless:[ 27503]:STATEMENT: truncate customers;
```
이러한 로그는 일반적인 로그입니다. DB 클러스터 전체에서 쿼리를 쉽게 상호 연관시키는 데 필요한 정확한 식별자가 부족합니다.

**쿼리 추적 있음**  
코디네이터 라우터의 PostgreSQL 로그 파일:  

```
2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:ERROR: failed to execute remote query
2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:DETAIL: relation "public.customers" does not exist
2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:CONTEXT: remote SQL command: truncate public.customers;
2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:STATEMENT: /* tid = 1126253375719408502700000000011 */ truncate customers;
```
참가자 샤드의 PostgreSQL 로그 파일:  

```
2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:ERROR:  failed to execute remote query
2023-09-26 04:03:19 UTC:[local]:postgres@postgres_limitless:[27503]:STATEMENT:  /* tid = 1126253375719408502700000000010 */ truncate customers;
```
쿼리 추적이 있는 경우 각 로그 라인에 31자리 고유 식별자가 추가됩니다. 여기서 `1126253375719408502700000000011` 및 `1126253375719408502700000000010`은 각각 코디네이터 및 참가자 노드의 추적 ID를 나타냅니다.  
+ 트랜잭션 식별자 - `11262533757194085027`
+ 명령 식별자 –`112625337571940850270000000001`
+ 노드 유형 식별자 - 마지막 자리인 `1` 또는 `0`은 각각 코디네이터 라우터와 참가자 노드를 나타냅니다.

### 로그를 상호 연관시켜 다양한 노드에서 쿼리 실행 시간 찾기
<a name="limitless-query.tracing.example2"></a>

이 예시에서 `log_min_duration_statement` 파라미터는 모든 쿼리의 기간을 인쇄하기 위해 `0`으로 업데이트되었습니다.

**쿼리 추적 없음**  

```
2024-01-15 07:28:46 UTC:[local]:postgres@postgres_limitless:[178322]:LOG: duration: 12.779 ms statement: select * from customers;
```

**쿼리 추적 있음**  
코디네이터 라우터의 PostgreSQL 로그 파일:  

```
2024-01-15 07:32:08 UTC:[local]:postgres@postgres_limitless:[183877]:LOG: duration: 12.618 ms statement: /* tid = 0457669566240497088400000000011 */ select * from customers;
```
참가자 샤드의 PostgreSQL 로그 파일:  

```
2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.279 ms statement: /* tid = 0457669566240497088400000000010 */ START TRANSACTION ISOLATION LEVEL READ COMMITTED
2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.249 ms parse <unnamed>: SELECT customer_id, fname, lname FROM public.customers
2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.398 ms bind <unnamed>/c1: SELECT customer_id, fname, lname FROM public.customers
2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.019 ms execute <unnamed>/c1: SELECT customer_id, fname, lname FROM public.customers
2024-01-15 07:32:08 UTC:localhost(46358):postgres@postgres_limitless:[183944]:LOG: duration: 0.073 ms statement: /* tid = 0457669566240497088400000000010 */ COMMIT TRANSACTION
```