Yocto Pokyを使用して完全に自己交差コンパイルされた組み込みLinuxインストールがあります。
多くのシステムサービスに加えて、ヘッドレスデーモンとして実行される完全にカスタマイズされたアプリケーションがあります。
重要な場合、アプリケーションは完全にC ++で書かれています。
何が起こっているのかについての情報を提供するために、アプリケーションは通常syslog()適切なパラメータを使用して呼び出します。
これ〜らしいうまくいきますが、/var/log/messagesをよく調べてみると、ログブロックが完全に間違った順序で到着し、数分で「戻る」ことがわかります。
具体的には、100msごとにシーケンス番号（厳密に増加するカウンタ、非常に愚かなコード）を記録する作業があります。
タイムスタンプとシーケンス番号は同期されているように見えます（たとえば、連続したシーケンス番号はほぼ正確に100ms離れており、ドリフトはマルチスレッド遅延と完全に互換性があります）、ブロックは「スクランブル」されて表示されます。これは、いくつかの大きな（数分）約1,000個のメッセージ）ブロックが、いわゆる「前」ブロックと呼ばれる他のブロック「後ろ」に現れることがあります。
この説明が問題を理解するのに「十分でない」場合は、教えてください。
以下は小さな（編集された）抜粋です：
-----------------------------------------------------------------------------------------------------------
Jan 18 20:38:23 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:38:23.501] [D] [1794] pushBleMessage():Save a STATUS message [63308] to cache
Jan 18 20:38:23 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:38:23.601] [D] [1794] pushBleMessage():Save a STATUS message [63309] to cache
Jan 18 20:38:23 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:38:23.701] [D] [1794] pushBleMessage():Save a STATUS message [63310] to cache
Jan 18 20:38:23 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:38:23.804] [I] [1794] analyzeState():Start logging ego and other road users data
Jan 18 20:38:23 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:38:23.804] [I] [1794] analyzeState():[CV2X EGO ] [ 1642538303803ms] ID: 0000000000000001 long: 12.365475, lat: 41.939606, heading: 0.000000, speed: 0.000000, s_accur: 0.570000, acc: -0.000000
<<< jump back 224.337 seconds ***
Jan 18 20:34:39 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:34:39.467] [D] [1794] pushBleMessage():Save a STATUS message [61072] to cache
Jan 18 20:34:39 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:34:39.567] [D] [1794] pushBleMessage():Save a STATUS message [61073] to cache
Jan 18 20:34:39 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:34:39.667] [D] [1794] pushBleMessage():Save a STATUS message [61074] to cache
Jan 18 20:34:39 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:34:39.767] [D] [1794] pushBleMessage():Save a STATUS message [61075] to cache
Jan 18 20:34:39 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:34:39.867] [I] [1794] analyzeState():Start logging ego and other road users data
-----------------------------------------------------------------------------------------------------------
Jan 18 20:36:31 sa2150p-nand local0.warn spoke-mw: [2022-01-18 20:36:31.400] [W] [1795] waitingConnection():No connection attempts for longer than 5000 ms
Jan 18 20:36:31 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:36:31.400] [D] [1795] onRunBluetoothLoop():No BLE client yet. Retry after 1 second
Jan 18 20:36:31 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:36:31.488] [D] [1794] pushBleMessage():Save a STATUS message [62190] to cache
Jan 18 20:36:31 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:36:31.588] [I] [1794] analyzeState():Start logging ego and other road users data
Jan 18 20:36:31 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:36:31.588] [I] [1794] analyzeState():[CV2X EGO ] [ 1642538191588ms] ID: 0000000000000001 long: 12.365476, lat: 41.939607, heading: 0.000000, speed: 0.000000, s_accur: 0.460000, acc: -0.000000
<<< jump back 224.151 seconds ***
Jan 18 20:32:47 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:32:47.437] [D] [1794] pushBleMessage():Save a STATUS message [59954] to cache
Jan 18 20:32:47 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:32:47.538] [D] [1794] pushBleMessage():Save a STATUS message [59955] to cache
Jan 18 20:32:47 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:32:47.638] [I] [1794] analyzeState():Start logging ego and other road users data
Jan 18 20:32:47 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:32:47.638] [I] [1794] analyzeState():[CV2X EGO ] [ 1642537967638ms] ID: 0000000000000001 long: 12.365478, lat: 41.939608, heading: 0.000000, speed: 0.000000, s_accur: 0.460000, acc: -0.000000
Jan 18 20:32:47 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:32:47.638] [D] [1794] pushBleMessage():Save a STATUS message [59956] to cache
-----------------------------------------------------------------------------------------------------------
Jan 18 20:34:39 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:34:39.166] [D] [1794] pushBleMessage():Save a STATUS message [61069] to cache
Jan 18 20:34:39 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:34:39.266] [D] [1794] pushBleMessage():Save a STATUS message [61070] to cache
Jan 18 20:34:39 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:34:39.366] [I] [1794] analyzeState():Start logging ego and other road users data
Jan 18 20:34:39 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:34:39.367] [I] [1794] analyzeState():[CV2X EGO ] [ 1642538079367ms] ID: 0000000000000001 long: 12.365477, lat: 41.939608, heading: 0.000000, speed: 0.000000, s_accur: 0.450000, acc: -0.000000
Jan 18 20:34:39 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:34:39.367] [D] [1794] pushBleMessage():Save a STATUS message [61071] to cache
<<< jump back 224.036 seconds ***
Jan 18 20:30:55 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:30:55.331] [D] [1794] pushBleMessage():Save a STATUS message [58835] to cache
Jan 18 20:30:55 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:30:55.431] [I] [1794] analyzeState():Start logging ego and other road users data
Jan 18 20:30:55 sa2150p-nand local0.info spoke-mw: [2022-01-18 20:30:55.431] [I] [1794] analyzeState():[CV2X EGO ] [ 1642537855431ms] ID: 0000000000000001 long: 12.365479, lat: 41.939608, heading: 0.000000, speed: 0.000000, s_accur: 0.450000, acc: -0.000000
Jan 18 20:30:55 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:30:55.431] [D] [1794] pushBleMessage():Save a STATUS message [58836] to cache
Jan 18 20:30:55 sa2150p-nand local0.debug spoke-mw: [2022-01-18 20:30:55.531] [D] [1794] pushBleMessage():Save a STATUS message [58837] to cache
-----------------------------------------------------------------------------------------------------------
メッセージはSave a STATUS message [61069/70/71] to cacheはるかに後で表示されますSave a STATUS message [61072/73/..] to cacheが、スタンプはかなり良い順序に従います。
それ〜らしい問題は完全にsyslog()処理に関するものであり、インターネット検索でも同様の動作の兆候を見つけましたが、これが私の場合にも当てはまるかどうかはわかりません。
問題は、この状況をどのようにデバッグするかです。 「順序が間違ったログ」を持つことは、いくら言っても「不便」です。