4.10 라우터 로깅(Logging) 및 상태 진단 기초

4.10 라우터 로깅(Logging) 및 상태 진단 기초

지금까지 Zenoh(제노) 네트워크를 설계하고 다중화하며 플러그인까지 얹어 완벽한 인프라를 구축했다면, 이제 남은 과제는 이 시스템이 “보이지 않는 곳에서 도대체 무슨 짓을 하고 있는지” 두 눈으로 직접 감시하는 것이다.

네트워크 구간에서 패킷이 조용히 증발하거나, 특정 노드의 메모리가 소리 없이 차오를 때, 로그 파일 하나 없이 원인을 규명하려는 시도는 나침반 없이 망망대해를 항해하는 것과 같다. Zenoh는 Rust 생태계의 강력한 로깅 프레임워크와 자체적인 관리(Admin) API를 내장하여, 아주 치밀하면서도 부하가 적은 진단 도구를 제공한다.

본 장에서는 라우터의 핏줄을 흐르는 트래픽의 파동과 오류의 숨결을 포착하기 위한 기초 진단 테크닉을 연마한다. 본격적인 대시보드 구축과 시각화를 다루는 17, 18장으로 넘어가기 전 반드시 짚고 넘어야 할 뼈대 작업이다.

  • RUST_LOG 동적 제어 (4.10.1): 복잡잡다한 환경 변수 설정을 통해 라우터를 껐다 켜지 않고도 로그의 출력 수위를 실시간으로 밸브 조절하듯 제어하는 기법을 다룬다.
  • 로그 레벨의 전략적 활용 (4.10.2): 평상시의 Info 로그, 개발 단계의 Debug 로그, 그리고 영혼까지 끌어 모으는 Trace 로그를 언제 어떻게 구분지어 봐야 하는지 분석한다.
  • 관리 API 기반 상태 진단 (4.10.3): 라우터의 심부에 접근하여 현재 들러붙은 클라이언트 수, 오가는 패킷량 등을 JSON 형태로 찍어보는 백도어(Admin Space) 스캐닝 기술을 배운다.
  • 병목 분석과 패킷 덤핑 (4.10.4): Wireshark의 도움 없이도 Zenoh 스스로 와이어(Wire) 구간의 병목과 드롭(Drop) 지점을 짚어내는 초동 수사 기법을 훈련한다.

1. RUST_LOG 환경 변수를 활용한 동적 로그 레벨 구성

Zenoh(제노) 코어는 Rust로 개발되었으며, Rust 진영의 사실상 표준(De-facto standard)인 env_logger 크레이트(Crate) 기반의 로깅 프레임워크를 심장부에 품고 있다. 따라서 라우터나 피어 데몬이 토해내는 수만 줄의 시스템 메시지를 입맛에 맞게 필터링하는 가장 저수준이면서 확실한 통제 스위치는 바로 RUST_LOG 환경 변수다.

1.1 RUST_LOG의 기본 문법

별도의 로그 설정 파일을 복잡하게 구성할 필요 없이, 라우터 데몬(zenohd)을 터미널에서 띄울 때 환경 변수 하나만 주입하면 로그의 댐 밸브가 열린다.

## 기본: 경고(warn) 이상만 출력
RUST_LOG=warn zenohd 

## 전체 모듈 디버그(debug) 모드
RUST_LOG=debug zenohd

1.2 모듈(Crate) 별 핀셋 필터링 타겟팅

Zenoh 프로젝트의 진정한 강력함은 거대한 모놀리식 로그가 아니라, 수많은 핵심 서브 모듈(net, link, transport, routing 등)별로 로그 레벨을 메스처럼 정밀하게 잘라낼 수 있다는 데 있다. 모든 코어 로직의 debug 로그를 다 켜버리면 콘솔 창이 초당 수천 줄의 텍스트 폭풍에 휩싸여 서버 CPU조차 버틸 수 없다.

만약 다른 라우팅 로직은 다 잘 도는데 ’TCP 네트워크 연결(Link) 단’에서 핑퐁 치는 패킷만 유독 수상하다면, 특정 모듈에만 돋보기를 들이밀어라.

## 전체 시스템은 info로 두되, TCP 링크(link_tcp) 모듈만 trace로 긁기
RUST_LOG=info,zenoh_link_tcp=trace zenohd

## 스카우팅(Multicast Discovery) 모듈 관련 디버그만 켜기
RUST_LOG=error,zenoh_scout=debug zenohd

이러한 콤마(,) 구분 문법을 활용하면, 노이즈 속에 파묻힌 단 한 줄의 세션 드롭(Session Drop) 원인을 단숨에 건져 올릴 수 있다.

1.3 동적 런타임 제어의 한계와 대안

유의할 점은 RUST_LOG는 애플리케이션 ’기동 시점’에 단 한 번 주입되는 정적 환경 변수라는 것이다. 즉 레벨을 바꾸려면 프로세스를 죽이고 다시 띄워야 하므로 프로덕션의 가용성을 깎아먹는다.

이러한 한계를 극복하기 위해 Zenoh는 4.10.3절에서 다룰 관리 API(Admin Space) 백도어를 열어두었다. 운영 중인 무중단 라우터 내부의 특정 모듈 로그 레벨만 REST API 콜 하나로 조용히 켜고 끄는 마법 같은 동적 런타임 제어(Dynamic Runtime Level Control)가 그 대안이다.

2. 추적(Trace), 디버그(Debug), 정보(Info) 레벨의 활용

서버가 다운되는 심각한 Error나 Warn 로그만 쳐다보고 있는 것은 병리학자에 가깝다. 훌륭한 시스템 아키텍트는 겉보기에 멀쩡하게 돌아가는 평온한 네트워크 위에서도 Info, Debug, Trace라는 세 가지 채를 걸러내며 다가올 병목과 암초를 미리 내다볼 줄 알아야 한다.

Zenoh(제노) 코어 파이프라인 전역에는 이 세 가지 로그 레벨이 철저히 의도된 목적으로 촘촘히 박혀 있다.

2.1 노드의 심장 박동: Info 레벨

RUST_LOG=info는 프로덕션 환경의 기본(Default) 세팅이다. 이곳에는 밀리초 단위의 데이터 교환 내용은 전혀 찍히지 않는다. 대신 라우터 데몬의 거시적인 생로병사를 관장한다.

  • 관전 포인트: “새로운 스토리지 볼륨이 마운트 됨”, “포트 7447 리스너 시작”, “특정 MAC 주소를 가진 피어 192.168.0.5 접속 승인”
  • 활용법: 운영자가 시스템 부팅 직후 라우터가 설계한 토폴로지대로 주변 노드들을 정상적으로 찾아냈는지(Discovery) 스냅샷을 찍듯 확인할 때 주로 본다. 로그가 몇 분에 한 줄씩 올라오는 것이 정상이다.

2.2 세션의 지문 감식: Debug 레벨

RUST_LOG=debug부터는 시스템의 혈관을 흐르는 메시지 뭉치들의 흔적이 보이기 시작한다.

  • 관전 포인트: 특정 클라이언트가 /factory/sensor/temp 토픽을 Subscription 하겠다고 선언(Declare)하는 과정, 라우팅 테이블이 업데이트되어 링크 스테이트 알고리즘(Link State)이 경로 비용을 재계산하는 흐름.
  • 활용법: 퍼블리셔(Publisher)가 쏜 데이터가 서브스크라이버(Subscriber)에게 도착하지 않을 때, 라우터가 중간에서 구독자 명단을 잊어버린 것인지 아니면 라우팅 테이블 트리 연산이 꼬인 것인지 가려낼 때(Sub-tree propagation tracing) 이 레벨의 탐조등을 켠다.

2.3 와이어 구간의 현미경: Trace 레벨

RUST_LOG=trace를 켜는 순간, Zenoh 엔진이 패킷을 조각내고 다시 조립하는 프레이밍(Framing)의 나부낌까지 콘솔에 쏟아진다. 성능을 갉아먹기 때문에 라이브 서비스에서는 절대 금기시된다.

  • 관전 포인트: 2.6절 와이어 프로토콜 단위의 메타데이터 교환, 1바이트 헤더 디코딩 실패, TCP 소켓 버퍼의 단편화(Fragmentation) 조각 도착 알림 등.
  • 활용법: LPWAN망의 극한 지연 탓에 패킷 송출 지연이 발생하거나, 커스텀 플러그인(4.8.4절)을 직접 짜다가 페이로드 직렬화(Serialization) 단계에서 세그멘테이션 폴트 급의 미궁에 빠졌을 때, 엔진 코드가 어느 라인에서 죽었는지 바이트 레이어 레벨에서 역추적(Backtrace)할 때만 단발적으로 가동한다.

3. Zenoh 관리 API를 통한 라우터 내부 상태 조회 (Chapter 17, 18 대비)

콘솔 터미널에 쏟아지는 방대한 텍스트 로그 파일(zenohd.log)을 tail -f나 grep으로 뚫어지게 노려보는 방식은 클래식하지만 우아하지 않다. 현대의 분산 컴퓨팅 인프라는 수시로 상태를 폴링(Polling)하고 스크래핑할 수 있는 기계 친화적(Machine-readable)인 관측 지점이 필요하다.

Zenoh(제노) 설계자들은 이 점을 간파하고 라우터 심장부 상태를 REST API와 자체 프로토콜로 훤히 까발려 보여주는 관리 공간(Admin Space, @) 기능을 코어에 내장했다. 추후 모니터링(17장)과 시각화(18장) 대시보드 구축의 핵심 뼈대가 되는 이 기술의 기초 맵핑을 살핀다.

3.1 특권 영역: Admin Space의 개념

데이터 센터에 떠 있는 Zenoh 라우터 하나에 수백 대의 로봇들이 각기 다른 데이터를 Publish 하고 있다고 가정해 보자. 이 라우터가 지금 총 몇 개의 클라이언트를 거느리고 있는지, 메모리는 얼마나 물고 있는지 궁금하다면 어떻게 해야 할까?

비밀은 URI 공간 최상단에 자리 잡은 골뱅이 기호(@)에 있다. 일반적인 비즈니스 데이터가 /factory/sensor 경로를 탄다면, 라우터 스스로의 진단 상태는 모두 @/<라우터 고유 스코프>/... 경로 트리에 JSON 형태로 주렁주렁 매달려 있다.

3.2 실시간 진단 쿼리(Query) 던지기

4.8.2절에서 다룬 REST 플러그인을 라우터에 올려두었다면, 그 자리에서 바로 cURL 명령어 하나로 라우터의 내장을 꺼내볼 수 있다.

## 라우터의 기본 설정 및 버전 정보 긁어오기
curl -X GET http://<라우터IP>:8000/@/router/local/config

## 현재 라우터와 끈덕지게 연결(Session)되어 있는 모든 클라이언트 리스트 쿼리
curl -X GET http://<라우터IP>:8000/@/router/local/sessions

이 호출을 때려보면 zenoh::client::192.168.0.5와 같은 각 노드별 식별자와 연결 지속 시간, 소모 대역폭 정보가 아름다운 구조의 JSON 파일 포맷으로 반환된다. 관리자는 이를 jq 도구로 파싱(Parsing)하여 장애가 난 클라이언트를 색출할 수 있다.

3.3 동적 런타임 구성 변경(Hot Config)의 묘미

Admin Space는 단순히 읽기 전용의 돋보기가 아니다. 시스템을 재시작하지 않고 라우터의 뇌수를 실시간으로 주무르는 마취 수술(Hot Swap)도 지원한다.

만약 프로덕션 장애가 터져 지금 당장 특정 플러그인의 로그(Trace)를 꺼내봐야 한다면? 라우터를 죽일 필요 없이, Admin 경로로 들어가 PUT 요청을 쏴서 로깅 밸브의 볼륨 변수를 조절하면 된다.

## 동적 로그 레벨 지시자 업데이트
curl -X PUT -H "Content-Type: application/json" \
     -d '{"zenoh_link_tcp":"trace"}' \
     http://<라우터IP>:8000/@/router/local/config/logging/modules

이러한 API의 뒷문 개방 덕분에, DevOps 엔지니어들은 Grafana나 Prometheus 스크래퍼를 엮어 무중단 인프라 패트롤 봇(Patrol Bot) 군단을 17장, 18장에서 화려하게 창설할 수 있게 된다.

4. 패킷 덤프 및 네트워크 병목 구간 기초 분석

Zenoh(제노) 네트워크 위에서 서비스가 잘 돌다가 특정 시간대만 되면 지연(Latency)이 튀거나, 드론에서 보내는 비디오 스트림 프레임이 깨지기 시작한다면 어떻게 해야 할까?

4.10.2절의 RUST_LOG=trace가 시스템 ’내부’의 혈류를 들여다보는 내시경이었다면, 이 절에서 다룰 네트워크 병목 분석은 라우터 ’외부’의 거친 도로 사정을 파악하는 교통 통제실 시스템이다. Zenoh는 Wireshark 등 무거운 서드파티 스니퍼(Sniffer) 없이도, 자체적으로 네트워크 병목 구간을 진단할 수 있는 경량화된 기초 도구들을 제공한다.

4.1 지연 시간(Latency) 추적의 오해와 진실

대부분의 주니어 엔지니어들은 네트워크가 느리다고 판단되면 터미널을 열고 대뜸 ping 8.8.8.8부터 날려본다. 하지만 이는 ICMP 프로토콜 레벨의 핑퐁일 뿐, 실제 Zenoh 애플리케이션의 엔드-투-엔드(End-to-End) 지연 시간을 전혀 대변하지 못한다.

Zenoh가 겪는 진짜 지연 시간은 다음 세 가지 구간의 합이다.

  1. 직렬화(Serialization) 시간: 클라이언트가 구조체를 와이어 바이트로 쪼개는 시간
  2. 네트워크 전파 시간(Propagation Time): 케이블이나 무선망을 타고 패킷이 날아가는 물리적 시간 (여기서만 Ping과 일치)
  3. 라우터 처리 및 큐 대기 시간(Queueing Time): 4.9.4절에서 다룬 무거운 로드 밸런싱이나 링크 스테이트 연산 때문에 라우터 메모리 큐(Queue)에서 잠자고 있는 시간

4.2 Zenoh Ping 유틸리티를 통한 엔드-투-엔드 검증

위의 세션을 모두 통과하는 순수한 통신 지연을 측정하기 위해, Zenoh 코어 팀은 zenoh-ping 이라는 네이티브 예제 바이너리를 제공한다.

퍼블리셔 로봇에 z_ping을, 구독자 관제 센터에 z_pong을 띄워두고 수만 킬로미터(km) 떨어진 라우터 홉(Hop)을 물리적으로 가로질러 왕복 시간(Round-Trip Time, RTT)을 마이크로초(us) 단위로 정확히 계측하라. 만약 ICMP Ping은 10ms인데 Zenoh Ping이 500ms가 뜬다면, 그것은 물리망 문제가 아니라 라우터 내부에 패킷이 쌓여 터지기 직전인 병목(Congestion) 임계를 의미한다.

4.3 L4 레벨의 패킷 덤프와 MTU 트러블슈팅

그렇다면 라우터가 왜 패킷을 버거워하는가? 가장 빈번한 원인은 2.6절에서 배운 단편화(Fragmentation) 폭풍이다.
특히 VPN 터널링이나 LPWAN 같은 특수 망을 탈 때, 망의 물리적 **최대 전송 단위(MTU)**가 1500바이트 이하로 토막 나 있다면, Zenoh가 보내는 64KB짜리 단일 메시지가 IP 계층에서 수십 개의 조각으로 잘게 부서진다.
라우터는 이 부서진 조각을 메모리에 쌓아두고 재조립(Reassembly) 하느라 CPU와 메모리를 비정상적으로 소모하게 된다.

이 현상을 짚어내기 위해서는 리눅스의 tcpdump 툴을 사용하여 포트 7447번 트래픽만 정확히 캡쳐(Capture)해야 한다.

## eth0 인터페이스에서 Zenoh 포트를 오가는 패킷 헤더만 덤핑
sudo tcpdump -i eth0 port 7447 -n -v

덤프를 떴을 때, length 1480 (혹은 네트워크 MTU 최댓값)짜리 패킷이 기관총처럼 쏟아지고 있다면, 그것은 애플리케이션 페이로드가 너무 무겁다는 뜻이다. 즉시 4.7.4절의 기법을 적용하여 페이로드 다이어트를 단행하거나, 라우터 스펙을 스케일 업(Scale-up)해야만 병목 구간을 탈출할 수 있다.