ODPは、パフォーマンスボトルネックを特定するために豊富な内部テーブルとシステムログを提供しており、主に監査ログ、スロークエリログ、統計ログを用いてODPの動作を分析します。
ODP側でよくある問題は、主に以下のカテゴリに分類されます:

その中で:
接続失敗
アプリケーションシステムがOBServerに接続できなかったことを示します。バックエンドのデータベースシステムがリクエストでパンクし接続に失敗した場合や、アプリケーションシステム自体の問題(例:fullgcが発生した場合、アプリケーションサーバーのNIC異常、アプリケーション層のデータベース設定ミスなど)、またはアプリケーションサーバーとOBServer間のネットワーク異常などが原因である可能性があります。この種のエラーメッセージは、アプリケーション側、ODP側、OBServer側すべてで発生する可能性があります。
SQL実行問題
エラー返却:バックエンドデータベースシステムが明確なエラーコードを返したことを示します。OBServer側で調査することができます。
実行遅延:まず、時間消費がどのコンポーネントで発生しているかを特定し、詳細に調査する必要があります。
接続切断:まず、どのコンポーネントが積極的に接続を切断したかを特定し、詳細に調査する必要があります。
ODPは問題の調査に利用できる豊富なログを提供しています。
エラーログ
ファイル名は
obproxy_error.logです。エラーログは、ODP固有のエラーやOBServerから返されたエラーを含む、実行エラーが発生したリクエストを記録します。監査ログ
ファイル名は
obproxy_digest.logです。監査ログは、実行時間がパラメータquery_digest_time_thresholdのしきい値(デフォルトは100ms)を超えるリクエストと、エラーレスポンスリクエストを記録します。説明
query_digest_time_thresholdはリクエスト実行時間のしきい値を設定します。しきい値を超えると、obproxy_digest.logファイルにログが出力されます。値の範囲は [0s, 30d] です。スロークエリログ
ファイル名は
obproxy_slow.logです。スロークエリログは、実行時間がslow_query_time_thresholdのしきい値(デフォルトは500ms)を超えるリクエストを記録します。説明
slow_query_time_thresholdはスロークエリの実行時間しきい値です。しきい値を超えると、obproxy_slow.logファイルにログが出力されます。値の範囲は [0s, 30d] です。統計ログ
ファイル名は
obproxy_stat.logです。統計ログは、デフォルトで1分ごと(monitor_stat_dump_intervalパラメータで制御)に出力されます。このログから、ODPの1分間のSQL実行状況を確認できます。メインログ
ファイル名は
obproxy.logです。DEBUG、TRACE、INFO、ERRORの4つのレベルがあり、syslog_levelパラメータで制御されます。問題の原因をさらに調査する必要がある場合、trace_idフィールドを使用して、あるセッション上のすべてのログをフィルタリングできます。
メインログに記録される情報は非常に詳細です。スローSQLについては、キーワードはSlow Queryで、メインログには各サブステップの所要時間が記録されています。例:
[2022-07-11 14:32:51.758195] WARN [PROXY.SM] update_cmd_stats (ob_mysql_sm.cpp:8425) [74744][Y0-7F4B1CEA13A0] [lt=7] [dc=0] Slow Query: ((
client_ip={127.0.0.1:50422}, // SQLを送信したクライアントのアドレス
server_ip={xx.xx.xx.xx:33041}, // SQLがルーティングされたターゲットOBServer
obproxy_client_port={xx.xx.xx.xx:52052}, // OBServerと接続するローカルアドレス
server_trace_id=Y81100B7C0535-0005E3460FBBE3CD-0-0, // ターゲットOBServer内での実行プロセス中のtrace id
route_type=ROUTE_TYPE_NONPARTITION_UNMERGE_LOCAL, // SQLで使用されるルーティングポリシー
user_name=root, // ユーザー名
tenant_name=sys, // テナント名
cluster_name=ob9988.zhixin.lm.100.xx.xx.xx, // クラスタ名
logic_database_name=, // 論理データベース名
logic_tenant_name=, // 論理テナント名
ob_proxy_protocol=0, // プロトコルタイプ
cs_id=14, // client login時に表示されるconnection id、proxyが割り当てる
proxy_sessid=7230691598940700681, // clientがOBServerにアクセスする際に内部で記録されるconnection id
ss_id=21,
server_sessid=3221588238, // SQLがターゲットOBServer内でのconnection id、OBServerが割り当てる
sm_id=14,
cmd_size_stats={
client_request_bytes:20, // clientがproxyに送信するリクエストパケットのサイズ
server_request_bytes:38, // ODPがターゲットOBServerに送信するリクエストパケットのサイズ
server_response_bytes:0, // ターゲットOBServerがproxyに送信する応答パケットのサイズ
client_response_bytes:71}, // ODPがclientに送信する応答パケットのサイズ
cmd_time_stats={
client_transaction_idle_time_us=0, // トランザクション内でこのSQLと前のSQLの実行終了間の時間間隔、すなわちclientトランザクション間時間
client_request_read_time_us=97, // ODPがclientソケットからリクエストパケットを読み取る時間
client_request_analyze_time_us=95, // ODPがclientのSQLを分析する時間
cluster_resource_create_time_us=0, // ODPがクラスタリソースを作成する時間(クラスタへの初回アクセス時のみ必要)
pl_lookup_time_us=0, // SQLに基づいて関連するルーティングテーブルを取得する時間
pl_process_time_us=0, // 関連するルーティングテーブルのフィルタリングとソートの時間
congestion_control_time_us=21, // SQLに基づいてブラックリスト情報を取得する時間
congestion_process_time_us=3, // ブラックリストに関連するチェックとフィルタリングの時間
do_observer_open_time_us=55, // ターゲットOBServerから利用可能な接続を取得する時間、connect_timeを含む
server_connect_time_us=0, // ターゲットOBServerで接続を作成する時間
server_sync_session_variable_time_us=0, // 選択されたターゲット接続の初期化にかかる時間、saved_login、db同期、システム変数同期、last_insert_id同期、start_trans同期を含む
server_send_saved_login_time_us=0, // 選択されたターゲット接続でsaved loginにかかる時間
server_send_use_database_time_us=0, // 選択されたターゲット接続でdb同期にかかる時間
server_send_session_variable_time_us=0, // 選択されたターゲット接続で変更されたシステム変数を同期する時間
server_send_all_session_variable_time_us=0, // 選択されたターゲット接続ですべてのシステムを同期する時間
server_send_last_insert_id_time_us=0, // 選択されたターゲット接続でlast_insert_idを同期する時間
server_send_start_trans_time_us=0, // 選択されたターゲット接続でstart_trans/beginを同期する時間
build_server_request_time_us=23, // ターゲットserverへのリクエストパケットを構築する時間
plugin_compress_request_time_us=0, // リクエストパケットを圧縮する時間
prepare_send_request_to_server_time_us=409, // ODPがクライアントリクエストを受信してからOBServerに転送して実行するまでの合計時間、通常は前述のすべての時間の合計であるべきです
server_request_write_time_us=32, // ODPがターゲットserverソケットにリクエストパケットを送信する時間
server_process_request_time_us=3039883, // ターゲットserverがこのSQLを実行する時間
server_response_read_time_us=67, // ODPがターゲットserverソケットから応答パケットを読み取る時間
plugin_decompress_response_time_us=59, // 応答パケットを解凍する時間
server_response_analyze_time_us=70, // 応答パケットを分析する時間
ok_packet_trim_time_us=0, // 応答パケットから最後のokパケットをトリムする時間
client_response_write_time_us=185, // ODPがclientソケットに応答パケットを送信する時間
request_total_time_us=3041116}, // ODPがこのリクエストを処理する総時間、前述のすべての時間の合計に等しい
sql=select sleep(3) //clientのリクエストSQL
)
ここで request_total_time_us はODPがこのリクエストを処理する総時間を記録し、server_process_request_time_us はODPがOBServerに送信するリクエストの時間を記録します。これにはネットワーク時間とOBServerの処理時間が含まれます。このログにより、スローSQLの各ステップの時間を特定し、スローSQL問題をより容易に特定できます。