TiDB Lightningログ メッセージの説明

このドキュメントでは、成功したテスト データのインポートに基づいて、ローカル バックエンド モードのTiDB Lightning v5.4のログ メッセージについて説明します。各ログ メッセージの起源と意味を深く掘り下げます。 TiDB Lightningログをより深く理解するには、このドキュメントを参照してください。

このドキュメントを完全に理解するには、 TiDB Lightningに精通しており、 TiDB Lightningの概要で説明されているその高レベルのワークフローについての事前知識がある必要があります。馴染みのない用語が出てきた場合は、 用語集を参照してください。

このドキュメントを使用すると、 TiDB Lightningソース コードをすばやくナビゲートし、その内部動作を洞察し、各ログ メッセージの背後にある重要性を理解することができます。

このドキュメントには重要なログのみが含まれていることに注意してください。重要性の低いログは省略されています。

ログメッセージの説明

[INFO] [info.go:49] ["Welcome to TiDB-Lightning"] [release-version=v5.4.0] [git-hash=55f3b24c1c9f506bd652ef1d162283541e428872] [git-branch=HEAD] [go-version=go1.16.6] [utc-build-time="2022-04-21 02:07:55"] [race-enabled=false]

info.go:49 : TiDB Lightning のバージョン情報を出力します。

[INFO] [lightning.go:233] [cfg] [cfg="{\"id\":1650510440481957437,\"lightning\":{\"table-concurrency\":6,\"index-concurrency\":2,\"region-concurrency\":8,\"io-concurrency\":5,\"check-requirements\":true,\"meta-schema-name\":\"lightning_metadata\", ...

ライトニングゴー:233 : TiDB Lightning構成情報を出力します。

[INFO] [lightning.go:312] ["load data source start"]

ライトニングゴー:312 : TiDB Lightning mydumper data-source-dir設定フィールドで定義されているデータソースディレクトリまたは外部storageをスキャンしますから開始し、将来の使用に備えてすべてのデータ ソース ファイルのメタ情報を内部データ構造にロードします。

[INFO] [loader.go:289] ["[loader] file is filtered by file router"] [path=metadata]

ローダー.go:289 : TiDB Lightning mydumper ファイルの設定フィールドで定義されたファイルルーターのルール 、またはファイルルールが定義されていませんの場合は内部デフォルトのファイルルータールールに基づいてスキップされた印刷データ ソース ファイル。

[INFO] [lightning.go:315] ["load data source completed"] [takeTime=273.964µs] []

ライトニングゴー:315 : 後でインポートするために、データ ソース ファイル情報のMydumper ファイルローダーへのロードが完了しました。

[INFO] [checkpoints.go:977] ["open checkpoint file failed, going to create a new one"] [path=/tmp/tidb_lightning_checkpoint.pb] [error="open /tmp/tidb_lightning_checkpoint.pb: no such file or directory"]

チェックポイント.go:977 : TiDB Lightning がファイルを使用してチェックポイントを保存し、ローカル チェックポイント ファイルが見つからない場合、 TiDB Lightning は新しいチェックポイントを作成します。

[INFO] [restore.go:444] ["the whole procedure start"]

復元.go:444 : インポート手順を開始します。

[INFO] [restore.go:748] ["restore all schema start"]

復元.go:748 : データ ソース スキーマ情報に基づいて、データベースとテーブルの作成を開始します。

[INFO] [restore.go:767] ["restore all schema completed"] [takeTime=189.766729ms]

復元.go:767 : データベースとテーブルの作成が完了しました。

[INFO] [check_info.go:680] ["datafile to check"] [db=sysbench] [table=sbtest1] [path=sysbench.sbtest1.000000000.sql]

check_info.go:680 : 事前チェックの一環として、 TiDB Lightning は各テーブルの最初のデータ ファイルを使用して、ソース データ ファイルとターゲット クラスタ テーブルのスキーマが一致するかどうかをチェックします。

[INFO] [version.go:360] ["detect server version"] [type=TiDB] [version=5.4.0]

バージョン.go:360 : 現在の TiDBサーバーのバージョンを検出して出力します。ローカル バックエンド モードでデータをインポートするには、TiDB v4.0 以降が必要です。同じバージョンチェックがデータ競合の検出にも実装されています。

[INFO] [check_info.go:995] ["sample file start"] [table=sbtest1]

check_info.go:995 : 事前チェックの一環として、 TiDB Lightning はソース データ サイズを推定して、以下を決定します。

• TiDB Lightning がローカル バックエンド モードの場合、ローカル ディスクに十分なスペースがあるかどうか 。
• ターゲット クラスターに、変換された KV ペアを保存するのに十分なスペースがあるかどうか 。

TiDB Lightning は、各テーブルの最初のソース データ ファイルをサンプリングし、そのサイズと KV ペアのサイズの比率を計算することにより、変換された KV ペアのサイズを推定します。次に、その比率にソース データ ファイルのサイズを乗算して、変換された KV ペアのサイズを推定します。

[INFO] [check_info.go:1080] ["Sample source data"] [table=sbtest1] [IndexRatio=1.3037832180660969] [IsSourceOrder=true]

check_info.go:1080 : テーブルソースファイルのサイズと KV ペアのサイズの比率が計算されています。

[INFO] [pd.go:415] ["pause scheduler successful at beginning"] [name="[balance-region-scheduler,balance-leader-scheduler,balance-hot-region-scheduler]"]
[INFO] [pd.go:423] ["pause configs successful at beginning"] [cfg="{\"enable-location-replacement\":\"false\",\"leader-schedule-limit\":4,\"max-merge-region-keys\":0,\"max-merge-region-size\":0,\"max-pending-peer-count\":2147483647,\"max-snapshot-count\":40,\"region-schedule-limit\":40}"]

PD.GO:415 、 PD.GO:423 : ローカル バックエンド モードでは、TiKV リージョンを分割および分散し、SST を取り込むために、一部のPDスケジューラが無効になり、一部の設定項目が変更される無効になります。

[INFO] [restore.go:1683] ["switch to import mode"]

復元.go:1683 : ローカル バックエンド モードでは、 TiDB Lightning は各 TiKV ノードをインポート モードに切り替えてインポート プロセスを高速化しますが、そのstorageスペースが犠牲になります。 tidb バックエンド モードを使用する場合、 TiKV をインポートモードに切り替える必要はありません。

[INFO] [restore.go:1462] ["restore table start"] [table=`sysbench`.`sbtest1`]

復元.go:1462 : テーブルsysbenchの復元を開始します。 sbtest1 ． TiDB Lightning は、 index-concurrency構成に基づいて複数のテーブルを同時に復元します。テーブルごとに、 region-concurrency構成に基づいてテーブル内のデータ ファイルを同時に復元します。

[INFO] [table_restore.go:91] ["load engines and files start"] [table=`sysbench`.`sbtest1`]

table_restore.go:91 : 論理的に各テーブルのソース データ ファイルを分割する倍数チャンク/テーブル領域に変換し始めます。各テーブルのソース データ ファイルはエンジンに割り当てられるになるため、ソース データ ファイルは異なるエンジン間で並行して処理できます。

[INFO] [region.go:241] [makeTableRegions] [filesCount=8] [MaxRegionSize=268435456] [RegionsCount=8] [BatchSize=107374182400] [cost=53.207µs]

地域.go:241 : 処理されたテーブル データ ファイルの量 ( filesCount )、CSV ファイルの最大チャンク サイズ ( MaxRegionSize )、生成されたテーブル領域/チャンクの数 ( RegionsCount )、および割り当てに使用されるbatchSizeを出力します。データファイルを処理するためのさまざまなエンジン。

[INFO] [table_restore.go:129] ["load engines and files completed"] [table=`sysbench`.`sbtest1`] [enginesCnt=2] [ime=75.563µs] []

table_restore.go:129 : テーブルデータファイルの論理分割が完了しました。

[INFO] [backend.go:346] ["open engine"] [engineTag=`sysbench`.`sbtest1`:-1] [engineUUID=3942bab1-bd60-52e2-bf53-e17aebf962c6]

バックエンド.go:346 : ID -1のエンジンはインデックス エンジンです。変換されたインデックス KV ペアを保存するために、 エンジンのプロセスを復元するのインデックス エンジンが最初に開きます。

[INFO] [table_restore.go:270] ["import whole table start"] [table=`sysbench`.`sbtest1`]

table_restore.go:270 : 特定のテーブルのさまざまなデータ エンジンを復元するを同時に開始します。

[INFO] [table_restore.go:317] ["restore engine start"] [table=`sysbench`.`sbtest1`] [engineNumber=0]

table_restore.go:317 : エンジン0の復元を開始します。 -1以外のエンジン ID はデータ エンジンを示します。 「復元エンジン」と「インポート エンジン」（ログの後半に表示されます）は異なるプロセスを指すことに注意してください。 「復元エンジン」は、割り当てられたエンジンに KV ペアを送信して並べ替えるプロセスを示し、「インポート エンジン」は、エンジン ファイル内の並べ替えられた KV ペアを TiKV ノードに取り込むプロセスを示します。

[INFO] [table_restore.go:422] ["encode kv data and write start"] [table=`sysbench`.`sbtest1`] [engineNumber=0]

table_restore.go:422 : テーブルデータをチャンク単位で復元するまで開始します。

[INFO] [backend.go:346] ["open engine"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7]

バックエンド.go:346 : 変換されたデータ KV ペアを保存するために、ID = 0 でデータ エンジンを開きます。

[INFO] [restore.go:2482] ["restore file start"] [table=`sysbench`.`sbtest1`] [engineNumber=0] [fileIndex=0] [path=sysbench.sbtest1.000000000.sql:0]

復元.go:2482 : このログは、インポートされたテーブルのデータ サイズに基づいて複数回表示される場合があります。この形式の各ログは、チャンク/テーブル領域の復元の開始を示します。同時にチャンクを復元します リージョン同時実行によって定義された内部地域労働者に基づいています。各チャンクの復元プロセスは次のとおりです。

1. SQLをKVペアにエンコードします 。
2. KV ペアをデータ エンジンとインデックス エンジンに書き込みます 。

[INFO] [engine.go:777] ["write data to local DB"] [size=134256327] [kvs=621576] [files=1] [sstFileSize=108984502] [file=/home/centos/tidb-lightning-temp-data/sorted-kv-dir/d173bb2e-b753-5da9-b72e-13a49a46f5d7.sst/11e65bc1-04d0-4a39-9666-cae49cd013a9.sst] [firstKey=74800000000000003F5F728000000000144577] [lastKey=74800000000000003F5F7280000000001DC17E]

エンジン.go:777 : 生成された SST ファイルの組み込みエンジンへの取り込みを開始します。それSST ファイルを同時に取り込む ．

[INFO] [restore.go:2492] ["restore file completed"] [table=`sysbench`.`sbtest1`] [engineNumber=0] [fileIndex=1] [path=sysbench.sbtest1.000000001.sql:0] [readDur=3.123667511s] [encodeDur=5.627497136s] [deliverDur=6.653498837s] [checksum="{cksum=6610977918434119862,size=336040251,kvs=2646056}"] [takeTime=15.474211783s] []

復元.go:2492 : 指定されたテーブルのチャンク ( fileIndex=1で定義されたデータ ソース ファイル) がエンコードされ、エンジンに格納されています。

[INFO] [table_restore.go:584] ["encode kv data and write completed"] [table=`sysbench`.`sbtest1`] [engineNumber=0] [read=16] [written=2539933993] [takeTime=23.598662501s] []
[source code]

table_restore.go:584 : エンジンengineNumber=0に属するすべてのチャンク/テーブル領域がエンコードされ、エンジンengineNumber=0に保存されています。

[INFO] [backend.go:438] ["engine close start"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7]
[INFO] [backend.go:440] ["engine close completed"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7] [takeTime=2.879906ms] []

バックエンド.go:438 : エンジンレストアの最終段階と同様に、データ エンジンが閉じられ、TiKV ノードへのインポートの準備が整います。

[INFO] [table_restore.go:319] ["restore engine completed"] [table=`sysbench`.`sbtest1`] [engineNumber=0] [takeTime=27.031916498s] []

table_restore.go:319 : KV ペアのエンコードとデータ エンジン 0 への書き込みが完了しました。

[INFO] [table_restore.go:927] ["import and cleanup engine start"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7]
[INFO] [backend.go:452] ["import start"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7] [retryCnt=0]

table_restore.go:927 、 バックエンド.go:452 : エンジンに保存されている輸入 KV ペアをターゲット TiKV ノードに開始します。

[INFO] [local.go:1023] ["split engine key ranges"] [engine=d173bb2e-b753-5da9-b72e-13a49a46f5d7] [totalSize=2159933993] [totalCount=10000000] [firstKey=74800000000000003F5F728000000000000001] [lastKey=74800000000000003F5F728000000000989680] [ranges=22]

ローカル.ゴー:1023 : インポートエンジン手順の前に、 TiDB Lightning はRegionSplitSize構成に基づいてエンジン データをより小さい範囲に論理的に分割します。

[INFO] [local.go:1336] ["start import engine"] [uuid=d173bb2e-b753-5da9-b72e-13a49a46f5d7] [ranges=22] [count=10000000] [size=2159933993]

local.go:1336 : 範囲を分割して KV ペアのエンジンへのインポートを開始します。

[INFO] [localhelper.go:89] ["split and scatter region"] [minKey=7480000000000000FF3F5F728000000000FF0000010000000000FA] [maxKey=7480000000000000FF3F5F728000000000FF9896810000000000FA] [retry=0]

ローカルヘルパー.go:89 : エンジン範囲minKeyおよびmaxKeyに基づいて分裂して飛び散る TiKV 領域に開始します。

[INFO] [localhelper.go:108] ["paginate scan regions"] [count=1] [start=7480000000000000FF3F5F728000000000FF0000010000000000FA] [end=7480000000000000FF3F5F728000000000FF9896810000000000FA]
[INFO] [localhelper.go:116] ["paginate scan region finished"] [minKey=7480000000000000FF3F5F728000000000FF0000010000000000FA] [maxKey=7480000000000000FF3F5F728000000000FF9896810000000000FA] [regions=1]

ローカルヘルパー.go:108 、 ローカルヘルパー.go:116 : PD の地域情報のバッチのスキャンをページネーションします。

[INFO] [split_client.go:460] ["checking whether need to scatter"] [store=1] [max-replica=3]
[INFO] [split_client.go:113] ["skipping scatter because the replica number isn't less than store count."]

分割クライアント.go:460 、 分割クライアント.go:113 : max-replica >= TiKV ストアの数であるため、散乱領域フェーズをスキップします。Scatteringリージョンは、PD スケジューラがリージョンとそのレプリカを異なる TiKV ストアに分散するプロセスです。

[INFO] [localhelper.go:240] ["batch split region"] [region_id=2] [keys=23] [firstKey="dIAAAAAAAAA/X3KAAAAAAAAAAQ=="] [end="dIAAAAAAAAA/X3KAAAAAAJiWgQ=="]

ローカルヘルパー.go:240 : TiKV リージョンのバッチ分割が完了しました。

[INFO] [localhelper.go:319] ["waiting for scattering regions done"] [skipped_keys=0] [regions=23] [take=6.505195ms]

ローカルヘルパー.go:319 : TiKV 領域の分散が完了しました。

[INFO] [local.go:1371] ["import engine success"] [uuid=d173bb2e-b753-5da9-b72e-13a49a46f5d7] [size=2159933993] [kvs=10000000] [importedSize=2159933993] [importedCount=10000000]
[INFO] [backend.go:455] ["import completed"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7] [retryCnt=0] [takeTime=20.179184481s] []

local.go:1371 、 バックエンド.go:455 : 特定のエンジンの KV ペアを TiKV ストアにインポートする作業が完了しました。

[INFO] [backend.go:467] ["cleanup start"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7]
[INFO] [backend.go:469] ["cleanup completed"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7] [takeTime=209.800004ms] []

バックエンド.go:467 、 バックエンド.go:469 : インポート段階で中間データをクリーンアップします。 TiDB Lightning は、エンジン関連のメタ情報と DB ファイルを掃除します。

[INFO] [table_restore.go:946] ["import and cleanup engine completed"] [engineTag=`sysbench`.`sbtest1`:0] [engineUUID=d173bb2e-b753-5da9-b72e-13a49a46f5d7] [takeTime=20.389269402s] []

table_restore.go:946 : インポートとクリーンアップが完了しました。

[INFO] [table_restore.go:345] ["import whole table completed"] [table=`sysbench`.`sbtest1`] [takeTime=47.421324969s] []

table_restore.go:345 : テーブルデータのインポートが完了しました。 TiDB Lightning は、すべてのテーブル データを KV ペアに変換し、TiKV クラスターに取り込みました。

[INFO] [tidb.go:401] ["alter table auto_increment start"] [table=`sysbench`.`sbtest1`] [auto_increment=10000002]
[INFO] [tidb.go:403] ["alter table auto_increment completed"] [table=`sysbench`.`sbtest1`] [auto_increment=10000002] [takeTime=82.225557ms] []

tidb.go:401 、 tidb.go:403 : 後処理フェーズでは、新しく追加されたデータによる競合を避けるためにテーブルの自動インクリメントIDを調整するになります。

[INFO] [restore.go:1466] ["restore table completed"] [table=`sysbench`.`sbtest1`] [takeTime=53.280464651s] []

復元.go:1466 : テーブルの復元が完了しました。

[INFO] [restore.go:1396] ["add back PD leader&region schedulers"]
[INFO] [pd.go:462] ["resume scheduler"] [schedulers="[balance-region-scheduler,balance-leader-scheduler,balance-hot-region-scheduler]"]
[INFO] [pd.go:448] ["exit pause scheduler and configs successful"]
[INFO] [pd.go:482] ["resume scheduler successful"] [scheduler=balance-region-scheduler]
[INFO] [pd.go:573] ["restoring config"] [config="{\"enable-location-replacement\":\"true\",\"leader-schedule-limit\":4,\"max-merge-region-keys\":200000,\"max-merge-region-size\":20,\"max-pending-peer-count\":64,\"max-snapshot-count\":64,\"region-schedule-limit\":2048}"]

復元.go:1396 、 PD.GO:462 、 PD.GO:448 、 PD.GO:482 、 PD.GO:573 : インポート前に一時停止した PD スケジューラを再開し、PD 構成をリセットします。

[INFO] [restore.go:1244] ["cancel periodic actions"] [do=true]

復元.go:1244 : インポートの進行状況を定期的に出力定期的なアクションキャンセルを開始し、TiKV がまだインポート モードであるかどうかを確認します。

[INFO] [restore.go:1688] ["switch to normal mode"]

復元.go:1688 : TiKV をインポート モードから通常モードに切り替えます。

[INFO] [table_restore.go:736] ["local checksum"] [table=`sysbench`.`sbtest1`] [checksum="{cksum=9970490404295648092,size=2539933993,kvs=20000000}"]
[INFO] [checksum.go:172] ["remote checksum start"] [table=sbtest1]
[INFO] [checksum.go:175] ["remote checksum completed"] [table=sbtest1] [takeTime=2.817086758s] []
[INFO] [table_restore.go:971] ["checksum pass"] [table=`sysbench`.`sbtest1`] [local="{cksum=9970490404295648092,size=2539933993,kvs=20000000}"]

table_restore.go:736 、 チェックサム.go:172 、 チェックサム.go:175 、 table_restore.go:971 : ローカルとリモートのチェックサムを比較するは、インポートされたデータを検証します。

[INFO] [table_restore.go:976] ["analyze start"] [table=`sysbench`.`sbtest1`]
[INFO] [table_restore.go:978] ["analyze completed"] [table=`sysbench`.`sbtest1`] [takeTime=26.410378251s] []

table_restore.go:976 、 table_restore.go:978 : TiDB はテーブルを分析して、TiDB がテーブルとインデックスに基づいて構築する統計を更新します。大規模なバッチ更新またはレコードのインポートを実行した後、またはクエリ実行プランが最適ではないことに気づいた場合は、 ANALYZE実行することをお勧めします。

[INFO] [restore.go:1440] ["cleanup task metas"]

復元.go:1440 : 必要に応じて、インポート タスク メタ、テーブル メタ、およびスキーマ データベースをクリーンアップします。

[INFO] [restore.go:1842] ["clean checkpoints start"] [keepAfterSuccess=remove] [taskID=1650516927467320997]
[INFO] [restore.go:1850] ["clean checkpoints completed"] [keepAfterSuccess=remove] [taskID=1650516927467320997] [takeTime=18.543µs] []

復元.go:1842 、 復元.go:1850 : チェックポイントをクリーンアップします。

[INFO] [restore.go:473] ["the whole procedure completed"] [takeTime=1m22.804337152s] []

復元.go:473 : インポート手順がすべて完了しました。

[INFO] [restore.go:1143] ["everything imported, stopping periodic actions"]

復元.go:1143 : インポート完了後、 定期的なアクションをすべて停止します。