6.8 C++ Zenoh 시스템 로깅, 디버깅 및 트러블슈팅

6.8 C++ Zenoh 시스템 로깅, 디버깅 및 트러블슈팅

아무리 코드를 예쁘게 짰어도 “현장(Field)에 나가면 무조건 통신이 터진다“는 사실이 백엔드 엔지니어링의 진리다. 공유기가 벽을 막아서 끊겼는지, C++ 메모리가 새어나가서 프로세스가 죽었는지, 아니면 Zenoh 콜백 스레드가 데드락(Deadlock)에 빠져서 멈췄는지 알아내지 못하면 당신의 밤은 길어진다.

이 섹션은 Zenoh C++ 라이브러리가 뱉어내는 수천 줄의 로그를 가로채고, Valgrind와 AddressSanitizer로 메모리 누수의 혈를 뚫으며, GDB와 프로파일러를 동원해 목을 조이는 스레드 교착 상태를 풀어내는 가장 차갑고 현실적인 야전 트러블슈팅 런북이다. printf 에 의존하는 아마추어 짓을 멈추고 시스템의 배를 갈라라.

1. Zenoh 내부 로깅 레벨 설정 및 사용자 정의 로그 핸들러(Log Handler) 등록

“패킷이 증발했다!“고 불평하기 전에, Zenoh가 터미널에 뱉는 로그를 볼 줄 알아야 한다. Zenoh는 C++ 래퍼를 타고 내려가기 전 Rust 코어 계층에서 엄청난 양의 진단 로그를 뿜어낸다.

1.0.1 [Runbook] 프로덕션 로깅 파이프라인 우회(Hook) 전술

Zenoh의 내장 로그를 무지성 스크린 출력이 아닌, 내부 C++ 로깅 프레임워크(spdlog, glog)나 파일로 가로채어(Intercept) 기록해야 사후 포렌식이 가능해진다.

1. 로깅 레벨 환경변수 주입 (가장 빠른 디버깅)
코드 수정 없이 터미널 로깅을 켜는 법 (개발 모드 전용).

## Zenoh 내부 네트워크(transport) 계층의 가장 깊숙한 TCP 송수신 이력을 전부 출력하라!
RUST_LOG=zenoh=debug,zenoh_transport=trace ./my_cpp_app

2. [핵심] C++ 커스텀 로그 핸들러 가로채기
프로덕션 환경에서는 Zenoh의 로그가 시스템 표준 로그(Syslog)나 Splunk로 들어가야 한다.

#include "zenoh.hxx"
#include <iostream>
#include <fstream>

// 전역 로그 파일 스트림
std::ofstream g_log_file("zenoh_core.log", std::ios::app);

void my_custom_zenoh_logger(zenoh::ext::Log::Level lvl, const char* msg) {
    std::string level_str;
    switch(lvl) {
        case zenoh::ext::Log::Level::Z_ERROR: level_str = "[ERR]"; break;
        case zenoh::ext::Log::Level::Z_WARN:  level_str = "[WRN]"; break;
        case zenoh::ext::Log::Level::Z_INFO:  level_str = "[INF]"; break;
        case zenoh::ext::Log::Level::Z_DEBUG: level_str = "[DBG]"; break;
        case zenoh::ext::Log::Level::Z_TRACE: level_str = "[TRC]"; break;
    }
    
    // 이 순간 Zenoh의 모든 코어 로그는 화면이 아니라 내 디스크 파일로 저장된다!
    g_log_file << level_str << " " << msg << std::endl;
}

int main() {
    // 1. Zenoh 부팅 전에 로깅 엔진부터 교체해야 한다!
    zenoh::ext::Log::init();
    zenoh::ext::Log::set_level(zenoh::ext::Log::Level::Z_DEBUG);
    
    // 라이브러리의 표준 출력을 빼앗아 내가 만든 콜백으로 영구 연결(Hooking)
    zenoh::ext::Log::set_callback(my_custom_zenoh_logger);
    
    // 이후부터 발생하는 세션의 모든 내부 에러 로그가 저장됨
    auto session = zenoh::Session::open(zenoh::Config::create_default());
}

이 코드를 넣지 않고서 “원인 불명의 네트워크 단절“을 보고서에 적어 올리는 것은 엔지니어 직무 유기다. 장애 발생 시각의 Z_DEBUG 로그 한 줄이 100장의 기획서보다 낫다.

2. C++ 애플리케이션에서의 메모리 누수 점검 (Valgrind, AddressSanitizer)

서버(Router)는 한 달째 살아서 패킷을 나르는데, 내 C++ 클라이언트 프로세스만 하루를 못 버티고 “Out Of Memory (OOM) 킬러“에게 참수당하고 있다면, 범인은 100% zenoh::Subscriber 람다 내부나 직렬화 코드 어딘가에서 잊혀진 할당(new)이다.

2.0.1 [Runbook] VRAM 및 메모리 혈전(Leak) 색출 훈련

이 챕터는 컴파일 스크립트와 터미널 프로파일러를 돌리는 시스템 해킹 런북이다.

1. AddressSanitizer(ASan) 무장 컴파일
Valgrind 구시대의 유물은 느리다. 모던 C++ 의 구원자인 컴파일러 내장 버그 색출기 ASan 을 켜라.

## CMakeLists.txt 내에 삽입! (Release 테스트 시에도 켜야 함)
set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -fsanitize=address -g -fno-omit-frame-pointer")

이 상태로 프로그램을 돌리고, 만약 subscriber 람다 안에서 char* buf = new char[1024]; 해놓고 delete 를 안 했다?
앱이 종료되자마자 빨간색 에러 로그가 소스코드 main.cpp:52줄을 정확히 지목하며 메모리 출혈 지점을 고발할 것이다.

2. 댕글링 포인터(Dangling Pointer) 및 Use-After-Free 추적
가장 악랄한 Zenoh C++ 버그는 “Zenoh가 Payload 메모리를 회수했는데, 내 메인 스레드가 그 주소를 아직도 읽고 있을 때” 터진다.
ASan 은 이 짓을 귀신같이 잡아낸다.

uint8_t* g_bad_ptr = nullptr;

auto sub = session.declare_subscriber("camera/feed", [](const%20zenoh::Sample&%20s) {
    // [최악의 짓] 수신 블록이 끝나면 파괴될 메모리의 주소를 훔쳐서 밖으로 빼낸다.
    g_bad_ptr = const_cast<uint8_t*>(s.get_payload().as_vector().data());
});

// ...메인 스레드에서...
// "ERROR: AddressSanitizer: heap-use-after-free on address 0x..." 폭발!
if (g_bad_ptr[0] == 0xFF) { }

메모리를 빼내고 싶으면 딥카피(memcpy나 std::vector 복사본 생성)를 하거나 앞 장(6.5.3)에서 배운 공유 메모리 참조 기술을 써야 한다. ASan 없이는 이 버그를 잡는 데 일주일이 걸린다.

3. 멀티스레드 교착 상태(Deadlock) 분석 및 콜백 지연 해결

“Subscriber 람다가 갑자기 호출되지 않아요. 프로그램은 켜져 있는데 데이터가 안 들어옵니다.”
이는 네트워크 단절이 아니라, 당신이 작성한 C++ 람다 블록 안에서 어떤 스레드가 Mutex 자물쇠를 쥐고 놓지 않았거나 무한 루프에 빠져 Zenoh의 데이터 펌프 스레드 전체가 숨통이 막힌 상황(Deadlock) 이다.

3.0.1 [Runbook] 데드락 자물쇠 깨기 전술

Zenoh는 I/O 성능 극대화를 위해 C++ 콜백 람다를 풀(ThreadPool) 기반으로 동시 호출한다.

[안티 패턴: Zenoh 스레드의 목을 조르는 짓]

std::mutex g_db_lock;

auto sub = session.declare_subscriber("sensor/data", [](const%20zenoh::Sample&%20s) {
    std::lock_guard<std::mutex> lock(g_db_lock);
    
    // [치명적 데드락 유발] DB 접속에 3초가 걸린다. 
    // 이 3초 동안 Zenoh 백그라운드 스레드 하나가 완전히 멈춘 채로(Blocked) 바보가 된다!
    write_to_slow_database(s.get_payload().as_string());
});

이 짓거리를 수십 번 반복하면 Zenoh의 모든 워커 스레드가 DB 락에 걸려 파업하고, 새로운 메시지가 쌓이다가 통신 버퍼가 터져버린다.

해결 1. TSAN (ThreadSanitizer) 투입
컴파일 옵션에 -fsanitize=thread 를 걸고 프로그램을 켜라.
락을 두 번 연거푸 잡으려 하거나 꼬인 경로를 발견하면 TSAN이 “WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock)” 이라는 경고를 때리며 즉시 자물쇠 오류 포인트를 알려준다.

해결 2. Lock-free 큐 브릿지 전술 (아키텍처 변경)
제발 콜백 람다 안에서 write를 치지 마라.

  1. 콜백 안에서는 오직 100마이크로초 만에 boost::lockfree::queue 나 std::queue(가벼운 락) 에 Payload 복사본만 집어 던진다.
  2. 메인 스레드나 백그라운드 비워커(Worker Thread)가 그 큐에서 값을 빼내서 아득바득 DB에 쓰게 만들어라.

이 원칙(Producer-Consumer 분리)만 지켜도 C++ 분산 망에서 겪는 멈춤 현상(Freeze)의 99%가 증발한다.

4. 성능 프로파일링 도구를 활용한 병목 구간 최적화

“데이터가 초당 1,000개 나와야 하는데 C++ 클라이언트에서 확인해보면 300초밖에 못 받습니다!”
이건 Zenoh의 잘못이 아니다. 높은 확률로 당신의 루프 안에서 비효율적인 메모리 복사(std::string 계속 생성)나 std::cout I/O 오버헤드가 CPU 캐시를 박살 내고 있는 것이다.

어디가 문제인지 눈대중으로 찍지 말고, 리눅스 커널이 제공하는 궁극의 메스(Perf)를 들이대야 한다.

4.0.1 [Runbook] 불 뿜는 CPU 병목(Hotspot) 해부 작전

perf와 FlameGraph를 활용하여 C++ 로직과 Zenoh 코어 사이의 시간 점유율을 그래프로 그려내는 전술이다.

1. 프로파일링 덤프 코어 채집
최종 프로덕션 바이너리(O3 가 켜져 있고 디버깅 심볼 -g 만 살아있는 상태)를 준비한다.

## 10초 동안 내 피투성이 프로그램(pid 1234)이 어느 함수에서 CPU를 불태우는지 초당 99번 스캔하라!
sudo perf record -F 99 -p 1234 -g -- sleep 10

2. FlameGraph 추출
채집된 perf.data 파일을 화염 방사기처럼 아름다운 차트로 굽는다.

git clone https://github.com/brendangregg/FlameGraph
sudo perf script | ./FlameGraph/stackcollapse-perf.pl | ./FlameGraph/flamegraph.pl > perf_result.svg

3. 스나이핑 (차트 해석)
크롬 브라우저로 perf_result.svg 차트를 열어라.
가장 너비가 넓은 네모(CPU 점유율 1위)가 어디인지 봐라.

  • 만약 zenoh::Session::put 내부 깊숙한 곳에서 병목이 탔다면? -> 당신이 Batching(모아 쏘기)을 안 하고 패킷을 1픽셀 단위로 발주하고 있다는 증거다.
  • 만약 당신 소스의 std::basic_string::operator= 에서 병목이 탔다면? -> 무지성 contiguous().as_string() 으로 매번 10MB짜리 문자열 복사를 일으켰다는 증거다. 6.5.1장의 참조형(Reference View) 코드로 변경하라.

분산 시스템 엔지니어의 몸값은 이 FireGraph의 가장 넓은 네모칸을 “마이크로 아키텍처 재설계“로 절반 이하로 압착해 내는 역량에서 결정된다. 숫자는 절대 거짓말을 하지 않는다.