我有一个使用 Yocto Poky 完全自交叉编译的嵌入式 Linux 安装。
除了许多系统服务之外，我还有一个完全自定义的应用程序作为无头守护程序运行。
如果重要的话，应用程序完全用 C++ 编写。
为了提供有关正在发生的情况的信息，应用程序通常会syslog()使用适当的参数进行调用。
这似乎可以工作，但仔细检查 /var/log/messages 会发现日志块完全不按顺序到达，从而在几分钟内“跳回”。
具体来说，我有一项任务，即每 100 毫秒记录一次序列号（严格递增的计数器，非常愚蠢的代码）（除其他外）。
时间戳和序列号似乎是同步的（即：连续的序列号几乎完全相隔 100 毫秒，漂移与多线程延迟完全兼容），但块看到“扰乱”，意味着一些大的（几分钟的日志，大约一千条消息） ) 块可以出现在另一个所谓的“较早”块“之后”。
如果此描述“不足以”理解问题，请通知我。
这是一小段（经过编辑的）摘录：
-----------------------------------------------------------------------------------------------------------
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()处理，我也在谷歌搜索中发现了类似行为的痕迹，但我不确定它是否适用于我的情况。
问题是：我该如何调试这种情况？至少可以说，拥有“无序日志”是“不方便”的。