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()
처리에 관한 것이며, 인터넷 검색에서도 비슷한 동작의 흔적을 찾았지만 이것이 제 경우에도 적용되는지 잘 모르겠습니다.
문제는 이 상황을 어떻게 디버깅할 것인가입니다. "순서가 잘못된 로그"를 갖는 것은 아무리 말해도 "불편합니다".