OceanBaseデータベースは、特定のSQLリクエストに関連するログの検索をサポートしています。ただし、現在のシステムログレベルや具体的なSQL異常のシナリオによっては、必ずしもログファイルで対応するSQLリクエストのログが見つかるとは限りませんが、試してみる価値は常にあります。
特定のSQLリクエストのログを検索することは、観測可能性の分野において非常に有用な技術です。基本的な技術ポイントは、ノードIPアドレスとTRACE_IDを用いてログファイルからログを検索し、手がかりを捉え、それに沿って全リンクをたどり、最初の事件現場を突き止めることです。その特長は、「事後」と「全リンク」という2つの属性を備えている点にあり、監視指標の有力な補完となります。監視指標は異常の検出に長けており、システムログは詳細の検出と全リンク追跡に長けています。
手順
OceanBaseクラスタにログインし、以下のSQLを実行します。このSQLはエラーが発生します。
obclient> select timestamp'0001-01-33'; ERROR 1525 (HY000): Incorrect DATETIME value: '0001-01-33'注意
ここで実行するSQLは説明のためのものです。実際の業務では、SQLは通常アプリケーションシステムによって実行されます。エラーコードの返却や実行時間の長さなど、異常が発生した場合、アプリケーション担当者は運用保守担当者に連絡し、問題の特定を依頼します。
システムテナントにログインし、
GV$OB_SQL_AUDITビューを使用して、このSQLの実行情報を照会します。注意
GV$OB_SQL_AUDITで結果が取得できない場合は、audit機能が無効になっていないか確認してください。enable_sql_audit構成パラメータがFalseに設定されていないか確認してください。enable_sql_audit構成パラメータの詳細については、enable_sql_auditを参照してください。obclient> select * from gv$ob_sql_audit where query_sql like '%select timestamp%' limit 1\G *************************** 1. row *************************** SVR_IP: xx.xx.xx.158 SVR_PORT: 2882 REQUEST_ID: 374223576 SQL_EXEC_ID: 389174628 TRACE_ID: YB4206019C9E-0005F55950FFAF04-0-0 SID: 3222268068 CLIENT_IP: xx.xx.xx.88 CLIENT_PORT: 54896 TENANT_ID: 1 TENANT_NAME: sys EFFECTIVE_TENANT_ID: 1 USER_ID: 200001 USER_NAME: dba_read USER_GROUP: 0 USER_CLIENT_IP: xx.xx.xx.113 DB_ID: 201001 DB_NAME: oceanbase SQL_ID: 86CC23B2B299FFAB9C50809C7238E891 QUERY_SQL: select timestamp'0001-01-33' PLAN_ID: 0 AFFECTED_ROWS: 0 RETURN_ROWS: 0 PARTITION_CNT: 0 RET_CODE: -5241 QC_ID: 0 DFO_ID: 0 SQC_ID: 0 WORKER_ID: 0 EVENT: P1TEXT: P1: 0 P2TEXT: P2: 0 P3TEXT: P3: 0 LEVEL: 0 WAIT_CLASS_ID: 100 WAIT_CLASS#: 0 WAIT_CLASS: OTHER STATE: MAX_WAIT TIME ZERO WAIT_TIME_MICRO: 0 TOTAL_WAIT_TIME_MICRO: 0 TOTAL_WAITS: 0 RPC_COUNT: 0 PLAN_TYPE: 0 IS_INNER_SQL: 0 IS_EXECUTOR_RPC: 0 IS_HIT_PLAN: 0 REQUEST_TIME: 1678603660669976 ELAPSED_TIME: 254 NET_TIME: 0 NET_WAIT_TIME: 2 QUEUE_TIME: 53 DECODE_TIME: 0 GET_PLAN_TIME: 158 EXECUTE_TIME: 4 APPLICATION_WAIT_TIME: 0 CONCURRENCY_WAIT_TIME: 0 USER_IO_WAIT_TIME: 0 SCHEDULE_TIME: 0 ROW_CACHE_HIT: 0 BLOOM_FILTER_CACHE_HIT: 0 BLOCK_CACHE_HIT: 0 DISK_READS: 0 RETRY_CNT: 0 TABLE_SCAN: 0 CONSISTENCY_LEVEL: -1 MEMSTORE_READ_ROW_COUNT: 0 SSSTORE_READ_ROW_COUNT: 0 DATA_BLOCK_READ_CNT: 0 DATA_BLOCK_CACHE_HIT: 0 INDEX_BLOCK_READ_CNT: 0 INDEX_BLOCK_CACHE_HIT: 0 BLOCKSCAN_BLOCK_CNT: 0 BLOCKSCAN_ROW_CNT: 0 PUSHDOWN_STORAGE_FILTER_ROW_CNT: 0 REQUEST_MEMORY_USED: 65536 EXPECTED_WORKER_COUNT: 0 USED_WORKER_COUNT: 0 SCHED_INFO: NULL FUSE_ROW_CACHE_HIT: 0 PS_CLIENT_STMT_ID: -1 PS_INNER_STMT_ID: -1 TX_ID: 0 SNAPSHOT_VERSION: 0 REQUEST_TYPE: 2 IS_BATCHED_MULTI_STMT: 0 OB_TRACE_INFO: NULL PLAN_HASH: 0 LOCK_FOR_READ_TIME: 0 PARAMS_VALUE: 1 row in set (1.08 sec)上記のクエリ結果から、このSQLリクエストが実行されたターゲットノードと
TRACE_IDを取得できます。SVR_IP: xx.xx.xx.158 TRACE_ID: YB4206019C9E-0005F55950FFAF04-0-0注意
この例では、
GV$OB_SQL_AUDITビューを使用してノードIPとTRACE_IDを取得していますが、OceanBaseデータベースは他にも多くの取得方法を提供しています。例えば、ODPのログや、イベント待機関連のビューを通じて取得する方法などです。ターゲットノードにログインし、
TRACE_IDを使用してログファイルを検索します。[hellodba@xx.xx.xx.158 /home/admin/oceanbase/log] $ grep 'YB4206019C9E-0005F55950FFAF04-0-0' observer.log [2023-03-12 14:47:40.670100] WARN resolve_const (ob_resolver_utils.cpp:2420) [116987][T1_TNT_L0_G0][T1][YB4206019C9E-0005F55950FFAF04-0-0] [lt=21] Incorrect DATETIME value: '0001-01-33' [2023-03-12 14:47:40.670205] WARN resolve_const (ob_resolver_utils.cpp:2420) [116987][T1_TNT_L0_G0][T1][YB4206019C9E-0005F55950FFAF04-0-0] [lt=37] Incorrect DATETIME value: '0001-01-33'注意
observer.logで関連するログがgrepできない場合は、observer.logがファイルを切り替えた可能性があります。grep YB4206019C9E-0005F55950FFAF04-0-0 observer.log.*を試すことができます。TRACE_IDに関連するログを検索することは最初のステップに過ぎません。真の目的は、綿密な分析にあります：- ログのコンテキスト、OSメトリクス、OSイベントなど、多角的な指標を組み合わせて、当該ノードを分析します。
TRACE_IDに対応するRPC呼び出しを通じて、他のOceanBaseノード、ODPノード、アプリケーションノードをつなぎ、エンドツーエンドで分析します。