전체 쿼리 로깅

전체 쿼리 로깅 (Full Query Logging)

Apache Cassandra 4.0은 라이브 쿼리 로깅을 지원하는 새로운 고성능 기능을 추가했어요(CASSANDRA-13983). FQL은 힙 메모리와 디스크 공간에 구성 가능한 한도를 두고 out-of-memory 오류를 방지하므로 프로덕션에서 안전하게 사용할 수 있습니다. 이 기능은 라이브 트래픽 캡처뿐만 아니라 트래픽 재생(traffic replay)에도 유용해요. 제공되는 도구는 쿼리 트래픽 디버깅과 마이그레이션 모두에 사용할 수 있어요. FQL을 활성화·비활성화·리셋하기 위한 새 nodetool 옵션도 추가되었고, 바이너리 로그를 읽고 재생하는 새 도구도 함께 추가되었습니다. 전체 쿼리 로깅(FQL) 기능은 Chronicle-Queue를 사용해 쿼리 로그를 롤링합니다. 이 페이지의 나머지 부분에서는 전체 쿼리 로그를 로그라고 부를게요.

FQL의 기능 중 일부는 다음과 같아요:

• 비동기 단일 스레드 로그 항목 쓰기가 디스크로 이루어져 쿼리 지연 시간에 미치는 영향이 줄어듭니다.
• 힙 메모리 사용은 가중 큐(weighted queue)로 제한되며, 로깅 스레드 앞에 구성 가능한 최대 가중치가 있습니다.
• 가중 큐가 가득 차면 프로듀서가 차단되거나 샘플이 버려질 수 있어요.
• 디스크 활용은 구성 가능한 크기로 제한되며, 한도에 도달하면 오래된 로그 세그먼트를 삭제합니다.
• 유연한 스키마 바이너리 형식인 Chronicle-Wire를 온디스크 직렬화에 사용해, 인식하지 못하는 필드를 건너뛰거나 새 필드를 추가하거나 옛 필드를 생략할 수 있어요.
• JMX 도구인 nodetool을 사용해 활성화·비활성화·리셋(온디스크 데이터 삭제)할 수 있습니다.
• cassandra.yaml 파일 또는 nodetool로 설정을 구성할 수 있어요.
• 새 fqltool을 도입했으며, 현재 바이너리 로그를 읽을 수 있는 형식으로 덤프할 수 있습니다. 다른 옵션은 Replay와 Compare예요.

FQL은 데이터를 수정하는 이벤트와 조회하는 이벤트를 모두 포함한 모든 성공적인 Cassandra Query Language(CQL) 요청을 기록해요. 오디트 로그도 CQL 요청을 포함하지만, FQL은 CQL 요청만 기록합니다. 이 차이는 FQL이 로그를 재생하거나 비교하는 데 사용될 수 있지만 오디트 로깅은 그럴 수 없다는 것을 의미해요. FQL은 CQL 쿼리를 디버깅, 성능 벤치마킹, 테스트, 감사하는 데 유용하고, 오디트 로그는 규정 준수(compliance)에 유용합니다.

성능 테스트에서 FQL은 WRITE 전용 워크로드에서 오버헤드가 거의 또는 전혀 없고, MIXED 워크로드에서는 약간의 오버헤드가 있는 것으로 보입니다.

출처: 문서

본문

기록되는 쿼리 정보

쿼리 로그에는 다음이 포함됩니다:

• 호출된 모든 쿼리
• 호출된 대략적인 시간
• 와일드카드 값을 바인딩하는 데 필요한 모든 파라미터
• 모든 쿼리 옵션

로거는 단일 또는 배치 CQL 쿼리가 끝난 뒤 기록하므로, 성공적으로 완료된 쿼리만 기록됩니다. 실패하거나 타임아웃된 쿼리는 기록되지 않아요. 쿼리 유형에 따라 기록되는 데이터가 다릅니다.

단일 CQL 쿼리 로그 항목에는 다음이 포함됩니다:

• query - CQL 쿼리 텍스트
• queryOptions - 쿼리 호출과 연관된 옵션
• queryState - 쿼리 호출과 연관된 타임스탬프 상태
• queryTimeMillis - 쿼리가 호출된 이후 에포크로부터의 대략적인 밀리초 시간

배치 CQL 쿼리 로그 항목에는 다음이 포함됩니다:

• queries - 쿼리의 CQL 텍스트
• queryOptions - 쿼리 호출과 연관된 옵션
• queryState - 쿼리 호출과 연관된 타임스탬프 상태
• batchTimeMillis - 배치가 호출된 이후 에포크로부터의 대략적인 밀리초 시간
• type - 배치의 유형
• values - 쿼리의 파라미터로 바인딩할 값

FQL은 Binlog로 지원되므로 성능과 공간(footprint)이 예측 가능하고, 로그 레코드 프로듀서에 미치는 영향이 최소화됩니다. 성능 안전은 로깅이 뒤처지면 가중 큐를 사용해 레코드를 버림으로써 프로듀서가 로그에 과부하를 주지 않도록 합니다. 단일 스레드 비동기 기록이 로그를 생성하고, Chronicle-Queue는 로그 롤링을 위한 쉬운 방법을 제공해요.

기록되는 로깅 정보

FQL은 저장된 로그 파일에 대한 정보도 추적합니다:

• 추가되는 저장 로그 파일과 그 저장 공간 영향. 저장 한도를 초과하면 삭제합니다.
• 이미 롤된 Chronicle-Queue의 로그 파일
• 이미 롤된 로그 파일의 바이트 수

로깅 시퀀스

로거는 명확히 정의된 일련의 이벤트를 따릅니다:

• 로그 레코드를 쓰는 컨슈머 스레드가 시작됩니다. 이 동작은 한 번만 발생할 수 있어요.
• 컨슈머 스레드가 레코드를 로그에 제공합니다. 인메모리 큐가 가득 차면 레코드는 버려지고 offer는 false를 반환해요.
• 받아들여지면 레코드는 로그에 들어갑니다. 인메모리 큐가 가득 차면 공간이 생기거나 중단될 때까지 넣는 스레드가 차단됩니다.
• 버퍼는 스레드 종료 시 정리됩니다. 파이널라이제이션은 큐에 남은 것이 없는지 다시 확인합니다.
• 컨슈머 스레드가 중지됩니다. 여러 번 호출될 수 있어요.

FQL 사용

FQL을 사용하려면 두 가지 작업을 완료해야 해요. FQL을 cassandra.yaml 파일 또는 nodetool로 구성해야 하고, nodetool enablefullquerylog로 로깅을 활성화해야 합니다. 어느 방법이든 최소한 로그 디렉터리 경로를 지정해야 해요. 두 작업 모두 노드별로 완료됩니다. 전체 쿼리 로그는 활성화된 각 노드에서 생성되므로 각 노드의 로그에는 그 노드의 쿼리가 들어 있습니다.

cassandra.yaml에서 FQL 구성

cassandra.yaml 파일을 사용해 nodetool로 기능을 활성화하기 전에 FQL을 구성할 수 있어요.

파일에는 사용을 위해 주석을 해제할 수 있는 다음 옵션이 포함됩니다:

# default options for full query logging - these can be overridden from command line
# when executing nodetool enablefullquerylog
#full_query_logging_options:
   # log_dir:
   # roll_cycle: HOURLY
   # block: true
   # max_queue_weight: 268435456 # 256 MiB
   # max_log_size: 17179869184 # 16 GiB
   # archive command is "/path/to/script.sh %path" where %path is replaced with the file being rolled:
   # archive_command:
   # max_archive_retries: 10

log_dir

로그를 쓰려면 log_dir에 존재하는 디렉터리를 설정해야 해요.

디렉터리는 읽기, 쓰기, 실행을 허용하도록 적절한 권한이 설정되어 있어야 합니다. 로깅은 필요에 따라 디렉터리 내용을 재귀적으로 삭제할 거예요. 파일시스템의 다른 부분으로의 링크를 이 디렉터리에 두지 마세요. 예: log_dir: /tmp/cassandrafullquerylog.

roll_cycle

roll_cycle은 로그 세그먼트가 롤되는 빈도를 정의합니다. 지원되는 값은 HOURLY(기본값), MINUTELY, DAILY예요. 예: roll_cycle: DAILY.

block

block 옵션은 FQL이 뒤처질 때 쓰기를 차단할지 로그 레코드를 버릴지 지정합니다. 지원되는 불리언 값은 true(기본값) 또는 false예요. 예: block: false로 레코드 버리기.

max_queue_weight

max_queue_weight 옵션은 파일에 쓰기 전에 차단하거나 버리기 전까지, 파일에 기록되기를 기다리는 레코드의 인메모리 큐 최대 가중치를 설정합니다. 옵션은 양수 값으로 설정해야 해요. 기본값은 268435456, 즉 256 MiB입니다. 예를 들어 기본값을 바꾸려면: max_queue_weight: 134217728 # 128 MiB.

max_log_size

max_log_size 옵션은 가장 오래된 파일을 삭제하기 전에 디스크에 보관할 롤된 파일의 최대 크기를 설정합니다. 양수 값으로 설정해야 해요. 기본값은 17179869184, 즉 16 GiB입니다. 예를 들어 기본값을 바꾸려면: max_log_size: 34359738368 # 32 GiB.

archive_command

archive_command 옵션은 롤된 로그 파일에 대해 실행할 사용자 정의 아카이브 스크립트를 설정합니다. 정의되지 않으면 파일이 삭제되며, 기본 ""는 org.apache.cassandra.utils.binlog.DeletingArchiver에 매핑됩니다. 예: archive_command: /usr/local/bin/archiveit.sh %path # %path는 롤되는 파일.

max_archive_retries

max_archive_retries 옵션은 실패한 아카이브 명령의 최대 재시도 횟수를 설정합니다. 기본값은 10이에요. 예: max_archive_retries: 10.

FQL은 기능을 활성화할 때 nodetool로도 구성할 수 있으며, 다음 섹션에서 논의하듯 cassandra.yaml 파일에 설정된 값을 덮어씁니다.

FQL 활성화

FQL은 nodetool enablefullquerylog 명령으로 노드별로 활성화됩니다. log_dir이 cassandra.yaml 파일에 설정되어 있지 않다면 최소한 로깅 디렉터리 경로를 정의해야 해요.

nodetool enablefullquerylog 명령의 문법에는 cassandra.yaml 파일에 설정할 수 있는 것과 동일한 모든 옵션이 있습니다. 또한 nodetool에는 명령을 실행할 호스트와 포트, 명령에 인증이 필요할 경우 사용자 이름과 비밀번호를 설정하는 옵션이 있어요.

  nodetool [(-h <host> | --host <host>)] [(-p <port> | --port <port>)]
 [(-pp | --print-port)] [(-pw <password> | --password <password>)]
 [(-pwf <passwordFilePath> | --password-file <passwordFilePath>)]
 [(-u <username> | --username <username>)] enablefullquerylog
 [--archive-command <archive_command>] [--blocking]
 [--max-archive-retries <archive_retries>]
 [--max-log-size <max_log_size>] [--max-queue-weight <max_queue_weight>]
 [--path <path>] [--roll-cycle <roll_cycle>]

 OPTIONS
   --archive-command <archive_command>
  Command that will handle archiving rolled full query log files.
  Format is "/path/to/script.sh %path" where %path will be replaced
  with the file to archive

   --blocking
  If the queue is full whether to block producers or drop samples.

   -h <host>, --host <host>
  Node hostname or ip address

   --max-archive-retries <archive_retries>
  Max number of archive retries.

   --max-log-size <max_log_size>
  How many bytes of log data to store before dropping segments. Might
  not be respected if a log file hasn't rolled so it can be deleted.

   --max-queue-weight <max_queue_weight>
  Maximum number of bytes of query data to queue to disk before
  blocking or dropping samples.

   -p <port>, --port <port>
  Remote jmx agent port number

   --path <path>
  Path to store the full query log at. Will have it's contents
  recursively deleted.

   -pp, --print-port
  Operate in 4.0 mode with hosts disambiguated by port number

   -pw <password>, --password <password>
  Remote jmx agent password

   -pwf <passwordFilePath>, --password-file <passwordFilePath>
  Path to the JMX password file

   --roll-cycle <roll_cycle>
  How often to roll the log file (MINUTELY, HOURLY, DAILY).

   -u <username>, --username <username>
  Remote jmx agent username

FQL을 활성화하려면 로깅을 활성화하려는 클러스터의 각 노드에서 다음 명령을 실행하세요:

$ nodetool enablefullquerylog --path /tmp/cassandrafullquerylog

FQL 비활성화 또는 리셋

nodetool disablefullquerylog를 사용해 로깅을 비활성화하세요. nodetool resetfullquerylog를 사용해 FQL을 중지하고 구성된 디렉터리의 로그 파일을 지웁니다. 중요: nodetool resetfullquerylog는 로그 파일을 삭제합니다! 모든 로그 파일을 삭제해야 하는 경우가 아니라면 이 명령을 사용하지 마세요.

fqltool

fqltool 명령은 로그를 보고(dump), 재생(replay), 비교(compare)하는 데 사용됩니다. fqltool dump는 바이너리 로그 파일을 사람이 읽을 수 있는 형식으로 변환합니다. 명령줄 옵션으로 로그 디렉터리만 제공하면 돼요.

fqltool replay(CASSANDRA-14618)는 로그 재생을 가능하게 합니다. 이 명령은 테스트, 디버깅, 성능 벤치마킹을 위해 다른 머신이나 클러스터에서 실행할 수 있어요. 이 명령은 삭제된 데이터베이스 객체를 재생성하는 데도 사용할 수 있습니다. fqltool replay를 사용해 프로덕션 트래픽의 다양한 실행을 Cassandra의 다른 버전/구성이나 다른 클러스터에 대해 기록하고 비교할 수 있어요. 또 다른 용도는 여러 머신에서 로그를 모아 기록된 타임스탬프 기준 "순서대로" 재생하는 것입니다.

fqltool replay의 문법은 다음과 같아요:

  fqltool replay [--keyspace <keyspace>] [--results <results>]
 [--store-queries <store_queries>] --target <target>... [--] <path1>
 [<path2>...<pathN>]

 OPTIONS
   --keyspace <keyspace>
  Only replay queries against this keyspace and queries without
  keyspace set.

   --results <results>
  Where to store the results of the queries, this should be a
  directory. Leave this option out to avoid storing results.

   --store-queries <store_queries>
  Path to store the queries executed. Stores queries in the same order
  as the result sets are in the result files. Requires --results

   --target <target>
  Hosts to replay the logs to, can be repeated to replay to more
  hosts.

   --
  This option can be used to separate command-line options from the
  list of argument, (useful when arguments might be mistaken for
  command-line options

   <path1> [<path2>...<pathN>]
  Paths containing the FQ logs to replay.

fqltool compare(CASSANDRA-14619)는 fqltool replay로 생성된 결과 파일을 비교합니다. 이 명령은 fqltool replay의 기록된 실행을 사용해 로그를 비교하고, 차이점(잠재적으로 모든 쿼리)을 출력합니다. 또한 비교할 때 전체 결과를 인메모리로 읽지 않도록 각 행을 별도의 chronicle 문서로 저장합니다.

fqltool compare의 문법은 다음과 같아요:

   fqltool compare --queries <queries> [--] <path1> [<path2>...<pathN>]

 OPTIONS
   --queries <queries>
  Directory to read the queries from. It is produced by the fqltool
  replay --store-queries option.

   --
  This option can be used to separate command-line options from the
  list of argument, (useful when arguments might be mistaken for
  command-line options

   <path1> [<path2>...<pathN>]
  Directories containing result files to compare.

비교는 다음 표시를 설정합니다:

• 쿼리 집합의 시작 표시:

  version: int16
  type: column_definitions
  column_count: int32;
  column_definition: text, text
  column_definition: text, text
  ....

• 실패한 쿼리 집합 표시:

  version: int16
  type: query_failed
  message: text

• 행 집합 표시:

  version: int16
  type: row
  row_column_count: int32
  column: bytes

• 결과 집합의 끝 표시:

  version: int16
  type: end_resultset

예제

• FQL을 시연하려면 먼저 클러스터의 노드에서 FQL을 구성하고 활성화하세요:

$ nodetool enablefullquerylog --path /tmp/cassandrafullquerylog

• 이제 cqlsh로 데모 키스페이스와 테이블을 만들고 데이터를 삽입하세요:

 cqlsh> CREATE KEYSPACE querylogkeyspace
   ... WITH replication = {'class': 'SimpleStrategy', 'replication_factor' : 1};
 cqlsh> USE querylogkeyspace;
 cqlsh:querylogkeyspace> CREATE TABLE t (
 ...id int,
 ...k int,
 ...v text,
 ...PRIMARY KEY (id)
 ... );
 cqlsh:querylogkeyspace> INSERT INTO t (id, k, v) VALUES (0, 0, 'val0');
 cqlsh:querylogkeyspace> INSERT INTO t (id, k, v) VALUES (0, 1, 'val1');

• 그런 다음 데이터가 삽입되었는지 확인하세요:

 cqlsh:querylogkeyspace> SELECT * FROM t;

 id | k | v
 ----+---+------
  0 | 1 | val1

 (1 rows)

• fqltool dump 명령으로 로그를 보세요.

$ fqltool dump /tmp/cassandrafullquerylog

이 명령은 로그의 읽을 수 있는 버전을 반환합니다. 이 데모의 명령에 대한 로그의 부분 샘플은 다음과 같아요:

WARN  [main] 2019-08-02 03:07:53,635 Slf4jExceptionHandler.java:42 - Using Pauser.sleepy() as not enough processors, have 2, needs 8+
      Type: single-query
      Query start time: 1564708322030
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system.peers
      Values:

      Type: single-query
      Query start time: 1564708322054
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system.local WHERE key='local'
      Values:

      Type: single-query
      Query start time: 1564708322109
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system_schema.keyspaces
      Values:

      Type: single-query
      Query start time: 1564708322116
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system_schema.tables
      Values:

      Type: single-query
      Query start time: 1564708322139
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system_schema.columns
      Values:

      Type: single-query
      Query start time: 1564708322142
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system_schema.functions
      Values:

      Type: single-query
      Query start time: 1564708322141
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system_schema.aggregates
      Values:

      Type: single-query
      Query start time: 1564708322143
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system_schema.types
      Values:

      Type: single-query
      Query start time: 1564708322144
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system_schema.indexes
      Values:

      Type: single-query
      Query start time: 1564708322145
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708322
      Query: SELECT * FROM system_schema.views
      Values:

      Type: single-query
      Query start time: 1564708345408
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:-2147483648
      Query: CREATE KEYSPACE querylogkeyspace
      WITH replication = {'class': 'SimpleStrategy', 'replication_factor' : 1};
      Values:

      Type: single-query
      Query start time: 1564708360873
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:-2147483648
      Query: USE querylogkeyspace;
      Values:

      Type: single-query
      Query start time: 1564708360874
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:-2147483648
      Query: USE "querylogkeyspace"
      Values:

      Type: single-query
      Query start time: 1564708378837
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:-2147483648
      Query: CREATE TABLE t (
          id int,
          k int,
          v text,
          PRIMARY KEY (id)
      );
      Values:

      Type: single-query
      Query start time: 1564708379247
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708379
      Query: SELECT * FROM system_schema.tables WHERE keyspace_name = 'querylogkeyspace' AND table_name = 't'
      Values:

      Type: single-query
      Query start time: 1564708397144
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708397
      Query: INSERT INTO t (id, k, v) VALUES (0, 0, 'val0');
      Values:

      Type: single-query
      Query start time: 1564708434782
      Protocol version: 4
      Generated timestamp:-9223372036854775808
      Generated nowInSeconds:1564708434
      Query: SELECT * FROM t;
      Values:

• fqltool replay를 시연하려면 먼저 키스페이스를 삭제하세요.

cqlsh:querylogkeyspace> DROP KEYSPACE querylogkeyspace;

• 이제 --results와 --store-queries에 각각 쿼리 결과와 실행된 쿼리 목록을 저장할 디렉터리를 지정해 fqltool replay를 실행하세요:

$ fqltool replay \
--keyspace querylogkeyspace --results /cassandra/fql/logs/results/replay \
--store-queries /cassandra/fql/logs/queries/replay \
-- target 3.91.56.164 \
/tmp/cassandrafullquerylog

--results와 --store-queries 디렉터리는 선택사항이지만, --store-queries를 설정하면 --results도 반드시 설정해야 해요. --target은 로그를 재생할 노드를 지정합니다.

• DESCRIBE KEYSPACES 명령으로 키스페이스가 재생되어 다시 존재하는지 확인하세요:

 cqlsh:querylogkeyspace> DESC KEYSPACES;

 system_schema  system  system_distributed  system_virtual_schema
 system_auth    querylogkeyspace  system_traces  system_views

더 알아보기 (Learn more)

• 오디트 로깅 — 규정 준수용 오디트 로그와의 차이
• cassandra.yaml 설정 — FQL 설정 옵션