chrony ver.3.5のログ出力結果を見ると、意味がよく分からない項目が多かったため、公式リファレンスおよび一部内部処理を調べてまとめてみました。
主なログファイル
- refclocks.log
- measurements.log
- statistics.log
- tracking.log
ntpdとchronyのログの対応関係は概ね下記の通り。
基本的にntpdで収集していたデータはchronyでも収集している。
ただ一部のパラメータの定義や取得するタイミングが異なるため、比較して分析する際は注意が必要。
例えば、ntpdではJitterなどの「安定性を示すパラメータ」はRMS（二乗平均平方根）を使って示されるが、chronyでは偏差値や分散で示される。
| ntpd | chrony | ログ出力箇所 |
|---|---|---|
| clockstats | refclocks.log | refclock.c log_sample関数 |
| rawstats | measurements.log | ntp_core.c receive_packet関数 |
| peerstats | statistics.log | sourcestats.c SST_DoNewRegression関数 |
| loopstats | tracking.log | reference.c write_log関数 |
なお、ntpdはntp_util.cにてログ出力を行っている。
NTPの用語
ログの説明に利用されるNTP用語の内、よく使われるものや意味が曖昧なものを説明する。
| 用語 | 意味 |
|---|---|
| オフセット | 時刻の補正値。NTPサーバの時刻が10 sec進んでいたら、オフセットは「+10 sec」となる |
| システムクロック | OSが示す時刻 |
| ハードウェアクロック | マザーボード上に実装された時刻。RTC（Real Time Clock）とも呼ばれる。 |
NTPログの共通事項
基本的に、単位がPPMまたはsec/secとなっているパラメータ（Diff freqなど）は「時刻を刻むタイミングを合わせる」ために利用され、単位がsecとなっているパラメータ（Offsetなど）は「NTPサーバとNTPクライアントがある瞬間に同一の時刻を刻んでいる」ために利用される。
また各パラメータの分散・標準偏差（Disp.やOffset sd、Est skewなど）は「そのパラメータがどれだけ安定しているか」を示す。したがって、値が大きい程、その値を持つNTPサーバが不安定であることを示す。
ログの詳細
refclocks.log
参照クロックの測定値に関するログ。GPSや原子時計などを利用したStratum1のNTPサーバを立てた場合、このログが出力される。
refclock.cのlog_sample関数で出力される。
===============================================================================
Date (UTC) Time Refid DP L P Raw offset Cooked offset Disp.
===============================================================================
2019-11-08 23:05:09.101766 GPS 8 N 0 -1.050650e-01 -1.017668e-01 2.600e-07
2019-11-08 23:05:10.106299 GPS 9 N 0 -1.095483e-01 -1.062998e-01 2.600e-07
2019-11-08 23:05:11.101969 GPS 10 N 0 -1.051689e-01 -1.019696e-01 2.600e-07
| パラメータ | 内容 | 単位 |
|---|---|---|
| Date (UTC) Time | ログ出力時のUTC時刻 | |
| Refid | 同期先のIPアドレスまたはID（GPSなど）。 | |
| DP | raw sampleのポーリング間隔内で、時刻ドライバのポーリングにおけるシーケンス番号 | |
| L | うるう秒の処理状態。N：通常、+：1 sec挿入、-：1 sec削除、?：非同期状態 | |
| P | 1PPSのパルス信号が使用されているかを示すフラグ。1なら使用, 0なら未使用、- なら不明（filtered sample） | |
| Raw offset | 参照する時刻ドライバ（GPSなど）で測定されたシステムクロックのオフセット。 | sec |
| Cooked offset | Raw offsetを補正した値。正の値のとき、システムクロックは遅れていることを示す | sec |
| Disp. | 推定される測定値（sample）の分散 |
DPについて調査した。以前Stratum1のNTPサーバを立てた際の設定を見直すと（ここを参照）、GPSモジュールがGPSからデータを取得する間隔は1 回/sec、chronyがGPSモジュールからデータを取得するポーリング間隔は16 sec、ログを見るとDPが0～15を遷移していた。これらの情報から、DPには、chronydがGPSモジュールに時刻同期の問い合わせに行く間、GPSモジュールがGPSと通信したシーケンス番号が記載されていると考えられる。
Cooked Offsetについて調査した。chronyのrefclock.c内にあるRCL_AddSample関数で計算されている。Cooked Offsetは、sys_netbsd.cのget_offset_correction関数で生成されたCorrectionという値とOffsetを利用して算出される。
get_offset_correction関数内部でadjtimeが呼び出されており、correctionはadjtimeの第二引数の値（olddelta）を格納する。adjtimeの解説サイトより、
olddelta が NULL でない場合、 olddelta が指すバッファーに、過去の調整要求でまだ完了せず残っている時間量が格納して返される。
とあることから、Cooked Offsetは、過去の時刻修正要求を踏まえた修正が行われたオフセットといえる。
measurements.log
そのままの（NTPのアルゴリズムによって修正が加えられていない）NTP測定値と関連情報のログ。
NTPサーバとNTPクライアント間でNTP通信を一回行うごとに、このログへ時刻情報などが蓄積される。
Stratum2以降のNTPサーバはこのログが出力される。
ntp_core.cのreceive_packet関数にてログが出力される。
========================================================================================================================================
Date (UTC) Time IP Address L St 123 567 ABCD LP RP Score Offset Peer del. Peer disp. Root del. Root disp. Refid MTxRx
========================================================================================================================================
2019-11-09 04:15:24 192.168.1.23 N 1 111 111 1111 6 6 0.00 9.328e-03 7.326e-03 6.641e-07 1.526e-05 1.027e-02 47505300 4B D K
2019-11-09 04:16:29 192.168.1.23 N 1 111 111 1111 6 6 0.00 1.427e-02 5.473e-03 6.149e-07 1.526e-05 1.134e-02 47505300 4B D K
2019-11-09 04:17:33 192.168.1.23 N 1 111 111 1111 6 6 0.00 1.965e-02 9.492e-03 6.861e-07 1.526e-05 6.775e-03 47505300 4B D K
| パラメータ | 内容 | 単位 |
|---|---|---|
| Date (UTC) Time | ログ出力時のUTC時刻 | |
| IP Address | 同期先のIPアドレス。GPSなどの時刻源は名前で表記 | |
| L | うるう秒の処理状態。N：通常、+：1 sec挿入、-：1 sec削除、?：非同期状態 | |
| St | 同期先のStratum | |
| 123 | RFC5905のPacket Error Checks（1,2,3） | |
| 567 | RFC5905のPacket Error Checks（5,6,7） | |
| ABCD | 最大遅延、最大遅延比、最大遅延の偏差値の比、同期ループしていないかの判定（sanity check） | |
| LP | 自身のポーリングレベル | |
| RP | 同期相手のポーリングレベル。おそらくNTP応答パケット内部のPoll値 | |
| Score | 各ポーリングレベルにおいて、ポーリングのレベルを増減するタイミングを決定するために使用される内部スコア。LPが変化する際は必ず変化 | |
| Offset | オフセット。正の値のとき、システムクロックは同期先より遅れている | sec |
| Peer del. | 同期先とのRound Trip Time（またはRound Delay Time）。 | sec |
| Peer disp. | 「同期先とのRTT」の分散 | |
| Root del. | Stratum1サーバとのRound Trip Time（またはRound Delay Time）。 | sec |
| Root disp. | 「Stratum1サーバとのRTT」の分散 | |
| Ref id | 同期先NTPサーバの同期先のID。16進数表記のIPv4アドレスまたはMD5によるIPv6アドレスのハッシュ値が表示 | |
| M | 受信したパケットのNTPサーバ/クライアントのモード。1=active peer, 2=passive peer, 4=server, B=basic, I=interleaved | |
| Tx | NTPパケット送信時の自身のタイムスタンプ配信元。送信するNTPパケットの「Transmit Timestamp」に入る時刻が、NTPデーモンによる送信時刻なら「D」が入る。（D=daemon, K=kernel, H=hardware） | |
| Rx | NTPパケット受信時の自身のタイムスタンプ配信元。送信するNTPパケットの「Receive Timestamp」に入る時刻が、NTPデーモンによる受信時刻なら「D」が入る。（D=daemon, K=kernel, H=hardware） |
上記のTest 1～3、5～7、ABCDはchronyのgithubに詳細な内容が記載されている。
以下抜粋。
Test A requires that the minimum estimate of the peer delay is not
larger than the configured maximum, in both client modes that the
server processing time is sane, and in interleaved symmetric mode that
the measured delay and intervals between remote timestamps don't
indicate a missed response
Test B requires in client mode that the ratio of the round trip delay
to the minimum one currently in the stats data register is less than
an administrator-defined value
Test C requires that the ratio of the increase in delay from the minimum
one in the stats data register to the standard deviation of the offsets
in the register is less than an administrator-defined value or the
difference between measured offset and predicted offset is larger than
the increase in delay
Test D requires that the source is not synchronised to us and is not us
to prevent a synchronisation loop
（2024/03/09追記）
ログ内の「123」と「567」はRFC5905のPacket Error Checksに対応する。
各番号に対応するパケットのチェック内容は下記の通り。
| テスト番号 | パケットタイプ | 説明 |
|---|---|---|
| 1 | duplicate packet | パケットの重複。第三者によるリプレイ攻撃、ポーリング間隔が不均一な場合に対称モードで発生する可能性があります |
| 2 | bogus packet | 偽のパケットかどうか。クライアントが送信した最新のNTPリクエストパケットに応答しているか |
| 3 | invalid | 一つ以上のタイムスタンプのフィールドに無効な値が入っている |
| 4 | access denied | ブラックリストで弾かれた時刻源による情報。measurements.logに載る際はテスト4はすでに合格しているためログに本項目は記載なし |
| 5 | authentication failure | 認証の失敗。認証設定を行っている場合はチェックが入る |
| 6 | unsynchronized | サーバと同期できているか確認。無効なStrarum値のチェックもここで実施 |
| 7 | bad header data | RFCではNTPヘッダのフィールドに無効な値が入っているか確認とあるが、chronyではRoot Distanceを事前に設定した閾値を超えていないか確認 |
statistics.log
回帰分析に関するログ。
このログには、同期候補先となる各NTPサーバにおける統計値（オフセット、分散など）の代表値を記録している。
NTPクライアント（chronyd）はNTPパケット一つに記載された時刻情報をそのまま時刻同期に利用しない。複数取得した時刻情報を統計的に処理し、一つの「NTPサーバが示す代表的な時刻情報」に集約する。その集約された値（代表値）を使って、時刻同期先を決定する。NTPサーバや、そのサーバ間の通信経路に問題があると、大体このログの値が異常を示す。
sourcestats.cのSST_DoNewRegression関数にてこのログが出力される。
====================================================================================================================
Date (UTC) Time IP Address Std dev'n Est offset Offset sd Diff freq Est skew Stress Ns Bs Nr Asym
====================================================================================================================
2019-11-09 02:57:41 GPS 2.851e-03 3.678e-03 1.638e-03 -1.360e-04 4.042e-04 2.1e-01 7 1 3 0.00
2019-11-09 02:57:58 GPS 2.415e-03 -5.837e-04 1.289e-03 -1.272e-04 2.123e-04 2.2e-02 7 0 5 0.00
2019-11-09 02:58:13 GPS 2.331e-03 4.025e-04 1.230e-03 -1.057e-04 1.585e-04 1.0e-01 8 0 5 0.00
| パラメータ | 内容 | 単位 |
|---|---|---|
| Date (UTC) Time | ログ出力時のUTC時刻 | |
| IP Address | 同期先のIPアドレス。GPSなどの時刻源は名前で表記 | |
| Std dev'n | 時刻源から得た測定値（measurements）の標準偏差 | sec |
| Est offset | オフセット。正の値はシステムクロックが同期先より早いことを示す | sec |
| Offset sd | オフセットの標準偏差。sdはstandard deviationの略 | sec |
| Diff freq | 1秒当たりにシステムクロックが進退した時間。以降rateと示す。正の値は時間が進んでいることを示す | sec/sec |
| Est skew | Diff freqの推定誤差の範囲 | sec/sec |
| Stress | ストレス値。この値が大きい程、あまりよい統計モデリングを得られていない。数式はこの後示す。 | |
| Ns | 現在回帰分析に利用されている測定結果の数。「Number of sample」の略 | |
| Bs | 新しい開始インデックス（最も古いサンプル（測定値）のインデックスは0で表記。測定値が線形モデルに適合していないように見える場合に、古いサンプルを削除するために使用される）。0の場合は、これまでのサンプルを利用することを示す。「Best start」の略 | |
| Nr | 最新の回帰を追跡している同一符号を持つ剰余の実行数。この数字がサンプル数に対して少なくなりすぎる場合は、線形モデルがデータに適合しなくなったことを意味する。実行数が少なすぎる場合、chronyd は古いサンプルを破棄し、実行数が受け入れ可能なものになるまで回帰を再実行。基本的にサンプル数の約半分の値（4以上だと思われる）が示される。 「Number of runs」の略 | |
| Asym | オフセットの修正に利用された時刻源への経路上のjitter（ゆらぎ、分散）の非対称性。-0.5～0.5の値をとる。 |
ストレス値の数式は下記の通り。
\frac{|(現在のrate)-(直前のrate)|}{(現在のEst skew)}
ntpdでは「Clock Filter Algorithm」を利用して、回帰分析を実施、ピアにおける統計値を算出している。chronyでも同様に回帰分析を実施しているが、ntpdとchronyでは回帰分析に利用するサンプル数やそれに対する処理が異なる。例えばntpdでは最新8回分のサンプルを対象に統計値を算出するが、chronyでは線形モデルから大きく逸脱していない最新の7～10個のサンプルをもとに算出する。また、サンプルの値に対し、ntpdでは取得したタイミングが新しい程重みを置くが、chronyではRoot Distanceに基づき重みを置く。
オフセットについて、ntpdでは「最小の遅延」となるサンプルのオフセットをピアとしてのオフセットとして選出する。chronyは前述の重みを利用した加重平均で算出したオフセットを設定する。
このようにchrony内部での処理はRFC5905から大きく逸脱しているため、ntpdとchronyのログを単純比較できないことに注意する必要がある。
tracking.log
システムクロックが進むまたは遅れる割合の予測に対する変更などを出力したログ。
chronyを動かしているNTPサーバ・クライアントのOS内部時刻を修正するために利用される値は、このログに出力される。
現在のNTPサーバの同期状態を把握する場合はこのログを参照にするとよい。
reference.cのwrite_log関数でログが出力される。
===================================================================================================================================
Date (UTC) Time IP Address St Freq ppm Skew ppm Offset L Co Offset sd Rem. corr. Root delay Root disp. Max. error
===================================================================================================================================
2019-11-09 08:53:58 GPS 1 -25.388 83.246 2.618e-03 N 1 3.764e-03 -9.425e-04 1.000e-09 6.998e-03 1.319e-02
2019-11-09 08:54:14 GPS 1 -25.388 83.246 1.221e-02 N 1 3.888e-03 -1.317e-03 1.000e-09 7.416e-03 1.196e-02
2019-11-09 08:54:30 GPS 1 -25.388 83.246 1.091e-03 N 1 2.426e-03 5.341e-07 1.000e-09 6.203e-03 2.421e-02
| パラメータ | 内容 | 単位 |
|---|---|---|
| Date (UTC) Time | ログ出力時のUTC時刻 | |
| IP Address | 同期先のIPアドレス。GPSなどの時刻源は名前で表記 | |
| St | 自身のStratum | |
| Freq ppm | システムクロックの動作周波数。正の値のとき、システムクロックがUTCの時刻より早く進んでいる | ppm |
| Skew ppm | Freq ppmの誤差範囲 | ppm |
| Offset | epoch（1900 1/1 0:00 UTC）における推定されたオフセット。正の値のとき、システムクロックがUTCの時刻より早く進んでいる | |
| L | うるう秒の処理状態。N：通常、+：1 sec挿入、-：1 sec削除、?：非同期状態 | |
| Co | Combined Algorithmに選択された同期先の数 | |
| Offset sd | Combinedされたオフセットの標準偏差 | |
| Rem. corr. | 前回の更新からの残りのオフセット補正 | |
| Root delay | Stratum1サーバとのRound Trip Time（またはRound Delay Time）。 | sec |
| Root disp. | 「Stratum1サーバとのRTT」の分散 | |
| Max. error | 前回の更新以降からのシステムクロックの最大推定誤差。 前回のRoot dispersionの更新からのオフセット、残りのオフセット補正、Root delay、およびRoot dispersionが含まれる。 | sec |
主なコマンド
下記のようなコマンドを利用することで、ログファイルを確認せずに様々なパラメータを確認可能。
- chronyc tracking
- chronyc clients
- chronyc sources
- chronyc sourcestats
- chronyc ntpdata
基本的に17.3. CHRONY の使用-- Red Hatを参考にすれば出力結果の解釈に支障はない。
おまけ
ログファイルではないものの、chronyに関係するファイル・データについて補足。
driftfile
chrony.confにドリフトファイルの設定を行うことによって、chrony.driftという、UTCとシステムクロック間における時刻の進み方のずれ（ドリフト）を記述したファイルが生成される。
$ cat /var/lib/chrony/chrony.drift
3.479778 50.005267
二つのパラメータが記述されており、1つ目のパラメータは、システムクロックの時間が増減する割合で、単位はppmで示される。例えば100.0の値のとき、システムクロックが1秒進んだときに、実際には100マイクロ秒増加したことを示す。したがって、実際の時間は999900マイクロ秒だけ進んでいることになる。 2つ目のパラメータは、1つ目のパラメータおける誤差範囲の推定値を示しており、この範囲内に真の補正値（ドリフトを寸分の狂いなく合わせる値）が存在する。
なお、ntpdのdriftfileには、chronyにおける1つ目のパラメータのみ記述されている。
struct SST_Stats_Record
chrony内部で定義されている構造体。ソースからのデータの履歴を保持するために使用される。
下記に構造体メンバの詳細を示す。なお、配列要素であるメンバには下記のパラメータが使用されている。
MAX_SAMPLES：64
REGRESS_RUNS_RATIO：2
| 型 | メンバ名 | 内容 |
|---|---|---|
| uint32_t | refid | 時刻源のID。GPSなど |
| IPAddr | *ip_addr | 時刻源のIPアドレス |
| int | min_samples | ユーザ定義のサンプルの最小数 |
| int | max_samples | ユーザ定義のサンプルの最大数 |
| double | fixed_min_delay | ユーザによって定義された最小遅延 |
| double | fixed_asymmetry | ユーザによって定義されたネットワークジッタの非対称性 |
| int | n_samples | 現在保存されているサンプルの数。サンプルは循環バッファ（FILO、キュー）に保存される。 |
| int | runs_samples | サンプルの配列において、回帰分析の対象となるサンプル群の先頭を指し示すインデックス |
| int | last_sample | 最新のサンプルが格納されているバッファのインデックス |
| int | regression_ok | 最後の回帰が成功したかどうかを示すフラグ |
| int | best_single_sample | 現時点で最小の「Root distance」を保持しているサンプルのインデックス |
| int | min_delay_sample | peer_delaysの遅延が最小のサンプルのインデックス |
| double | estimated_offset | 修正されたオフセット |
| double | estimated_offset_sd | estimated_offsetの標準偏差 |
| struct timespec | offset_time | 最新のサンプルを取得した時刻 |
| int | nruns | 最新の回帰を追跡している同一符号を持つ剰余の実行数 |
| int | asymmetry_run | 同じ符号（+/-）が付いた推定非対称性の連続した数 |
| double | asymmetry | jitterの最新の推定非対称性 |
| double | estimated_frequency | 推定頻度を含む、自身と時刻源との周波数の差。正の値の場合、ローカルクロックは時刻源より進んでいる |
| double | estimated_frequency_sd | estimated_frequencyの標準偏差 |
| double | skew | 想定される最悪の場合における推定周波数の境界。真の周波数は、推定周波数の約半分の+/-以内にあると仮定 |
| double | std_dev | サンプルの推定標準偏差 |
| struct timespec | sample_times[MAX_SAMPLES * REGRESS_RUNS_RATIO] | ローカルクロックに関するサンプルエポックを含む配列 |
| double | offsets[MAX_SAMPLES * REGRESS_RUNS_RATIO] | サンプル時間に対応する秒単位のオフセットの配列。この配列内の値は独自の計算に基づいており、RFCに準拠していない。 |
| double | orig_offsets[MAX_SAMPLES] | 測定時のままのオフセットの配列 |
| double | peer_delays[MAX_SAMPLES * REGRESS_RUNS_RATIO] | ピアへの遅延（RTT）の配列 |
| double | peer_dispersions[MAX_SAMPLES] | ピア分散の配列 |
| double | root_delays[MAX_SAMPLES] | 各サンプルのルート遅延 |
| double | root_dispersions[MAX_SAMPLES] | 測定時の各サンプルのルート分散 |
| int | stratum | 時刻源の階層 |
| NTP_Leap | leap | うるう秒の状態 |
さいごに
chronyでは同期先判定（Clock Select処理）がかなり緩く設定されており、同期相手から取得する値の厳密さを求めるならntpdの方が良いでしょう（ネットワーク環境が不安定なら、公式リファレンスにもあるようにchronyの方が分があります）。