실패 진단과 문의

목표

환경 변수만으로 SDK 프로그램과 시뮬레이터의 진단 로그를 켭니다.
T3 타임아웃을 일부러 만들고, 호스트와 장비 로그에서 같은 트랜잭션을 찾아 원인을 확인합니다.
프로그램 코드에서 로그를 켜고 끄고 상태를 읽습니다.
문의할 때 필요한 최소 재현과 자료를 준비합니다.

준비물

첫 통신을 마친 환경과 터미널 세 개
진단 로그 예제가 들어 있는 예제 묶음(PDCOMM_EXAMPLES)

진단 로그의 특징

기본으로 꺼져 있습니다. 켜면 한 줄에 JSON 객체 하나씩(JSON Lines) 기록합니다.
메시지 본문(body), 인증 정보, 환경 변수 전체는 기록하지 않습니다. 스트림·펑션, 시스템 바이트, 상태 변화, 오류 같은 메타데이터만 남습니다.
기록은 별도 스레드가 큐(queue)에서 꺼내 파일에 씁니다. 큐(1024개)가 가득 차면 기록을 버리고 dropped 수를 늘립니다. 통신 처리를 멈추지 않기 위해서입니다.

1. 환경 변수로 로그를 켭니다

프로그램을 시작하는 터미널에서 다음 변수를 정합니다. 변수는 프로그램이 처음 로그를 쓸 때 한 번 읽으므로 실행 중에 바꾸면 반영되지 않습니다.

변수	값	기본값
`PDCOMM_LOG`	`error`, `warn`, `info`, `debug`, `trace` 중 하나. `off`면 끕니다.	꺼짐
`PDCOMM_LOG_FILE`	로그 파일 경로. 없으면 표준 오류(stderr)에 씁니다.	표준 오류
`PDCOMM_LOG_MAX_BYTES`	파일 하나의 최대 크기(8192 ~ 1 GiB)	10485760(10 MiB)
`PDCOMM_LOG_FILES`	현재 파일을 포함해 보관할 파일 수(1–16)	3

평소에는 info, 통신 문제를 볼 때는 debug, 짧은 시간 자세히 볼 때는 trace를 씁니다. 파일이 최대 크기에 닿으면 <파일>.1, <파일>.2로 이름을 바꾸며 돌려 씁니다(rotation). 값이 잘못되면 로그가 켜지지 않고 상태의 configuration_errors가 늘어납니다.

장비 터미널(A)에서 로그 폴더를 만들고 장비를 시작합니다.

Linux/macOS
Windows

mkdir -p logs
PDCOMM_LOG=debug PDCOMM_LOG_FILE=./logs/equipment.jsonl \
  "$PDCOMM_ROOT/build/pdcomm-tutorial" equipment passive 127.0.0.1:5000

New-Item -ItemType Directory -Force ./logs | Out-Null
$env:PDCOMM_LOG = 'debug'
$env:PDCOMM_LOG_FILE = './logs/equipment.jsonl'
& "$Root\build\pdcomm-tutorial.exe" equipment passive 127.0.0.1:5000

호스트 터미널(B)에서는 같은 폴더에서 파일 이름만 바꿔 호스트를 시작합니다. 프로그램마다 다른 파일을 씁니다.

PDCOMM_LOG=debug PDCOMM_LOG_FILE=./logs/host.jsonl \
  "$PDCOMM_ROOT/build/pdcomm-tutorial" host active 127.0.0.1:5000

시뮬레이터 GUI나 headless 시뮬레이터도 같은 변수를 정한 터미널에서 시작하면 로그를 남깁니다. headless와 MCP 서버의 표준 출력에는 원래 결과만 나옵니다.

2. T3 타임아웃을 만듭니다

호스트에서 establish와 values 1 2를 입력해 정상 응답을 확인합니다. 그다음 세 번째 터미널(C)에서 장비를 일시 정지합니다.

kill -STOP "$(pgrep -f 'pdcomm-tutorial equipment passive 127.0.0.1:5000')"

호스트에서 values 1 2를 한 번 더 입력합니다. 5초 뒤 실패 결과가 나옵니다.

RESULT kind=3 request=3 outcome=0

장비를 다시 실행한 뒤 두 프로그램에서 quit을 입력합니다.

kill -CONT "$(pgrep -f 'pdcomm-tutorial equipment passive 127.0.0.1:5000')"

Windows에서는 프로세스를 일시 정지하는 대신 시뮬레이터 자동화와 오류 재현의 세션 ID 실험으로 T3를 만듭니다.

3. 로그에서 원인을 찾습니다

먼저 오류 수준의 HSMS 기록만 고릅니다.

grep -E '"event":"(transaction_failed|protocol_error|transport_error)"' logs/host.jsonl

{"arch":"aarch64","build_id":"...","component":"hsms","event":"transaction_failed","fields":{"connection_id":1,"detail":{"generation":1,"reason":"T3Timeout","system_bytes":103},"generation":1},"instance_id":"11622-1791997285239456000","level":"error","monotonic_us":7458609,"os":"macos","pid":11622,"protocol":"secsgem","request_id":0,"schema_version":1,"sdk_version":"0.1.0","sequence":20,"thread":"ThreadId(2)","timestamp_unix_ms":1791997292698}
{"arch":"aarch64","build_id":"...","component":"hsms","event":"protocol_error","fields":{"connection_id":1,"detail":{"error":"UnexpectedReply","generation":1,"system_bytes":103},"generation":1},...,"timestamp_unix_ms":1791997293736}

Windows PowerShell에서는 Select-String -Path logs\host.jsonl -Pattern '"event":"(transaction_failed|protocol_error|transport_error)"'을 씁니다.

실패한 트랜잭션의 시스템 바이트(system bytes)는 103입니다. 같은 값으로 두 로그를 함께 찾으면 트랜잭션 하나의 흐름이 보입니다.

grep '"system_bytes":103' logs/host.jsonl logs/equipment.jsonl

시간 순서로 정리하면 다음과 같습니다. timestamp_unix_ms는 UTC 기준 밀리초입니다.

시각(ms)	로그	기록	의미
…287697	호스트	`hsms_transport` `socket_write`, 28바이트	S1F3을 보냈습니다.
…292698	호스트	`hsms` `transaction_failed`, `T3Timeout`	5초 동안 응답이 없어 요청을 끝냈습니다.
…293730	장비	`hsms` `received`, `stream` 1, `function` 3, `kind` `Primary`	장비가 다시 실행된 뒤에야 S1F3을 읽었습니다.
…293733	장비	`hsms_transport` `socket_write`, 31바이트	장비가 S1F4로 응답했습니다.
…293736	호스트	`hsms` `protocol_error`, `UnexpectedReply`	이미 끝난 트랜잭션의 응답이므로 받지 않았습니다.

결론: 호스트는 요청을 제때 보냈고, 장비가 요청을 늦게 처리했습니다. 실제 장비라면 장비 쪽 처리 지연이나 정지를 조사합니다. 장비가 요청을 아예 받지 못했다면 장비 로그에 received 기록이 없습니다.

기록의 필드

필드	설명
`timestamp_unix_ms`	기록 시각(UTC 밀리초). 컴퓨터 사이의 비교에는 시간 동기화가 필요합니다.
`monotonic_us`	같은 프로세스 안에서만 비교할 수 있는 단조 증가 시간(마이크로초)
`sequence`	프로세스 안의 기록 번호. 빠진 번호가 있으면 기록이 버려진 것입니다.
`instance_id`, `pid`, `thread`	프로세스와 스레드 식별
`build_id`, `sdk_version`, `os`, `arch`	라이브러리 빌드와 실행 환경
`level`, `protocol`, `component`, `event`	수준, 프로토콜(`secsgem`), 구성 요소(`hsms`, `hsms_transport`, `ffi` 등), 사건 이름
`fields`	사건별 세부 값. `connection_id`, `generation`, `detail` 등

자주 보는 사건은 다음과 같습니다.

`component` / `event`	수준	내용
`hsms` / `start`, `stop`	info	끝점 시작과 정지. `mode`, `address`
`hsms` / `state_changed`	info	연결 상태 변화. `detail.from`, `detail.to`(예: `NotSelected` → `Selected`)
`hsms` / `received`	debug	받은 메시지의 스트림, 펑션, 시스템 바이트, 본문 크기
`hsms` / `transaction_failed`	error	`T3Timeout`, `T6Timeout`, `Disconnected`, `Rejected` 등으로 끝난 트랜잭션
`hsms` / `protocol_error`	error	`UnexpectedReply`, `WrongSession`, `IncomingPrimaryLimit` 등
`hsms` / `transport_error`	error	소켓 오류. 예: `operation` `Connect`, `error_kind` `ConnectionRefused`
`hsms_transport` / `socket_read`, `socket_write`	debug	소켓 입출력 크기
`secs1` / `received`, `sent`, `send_failed`, `fault`		SECS-I 끝점의 송수신과 장애

4. 코드에서 로그를 제어합니다

실행 중에 로그를 켜고 끄려면 공개 API를 씁니다. C에서는 pdcomm_logging_configure에 UTF-8 JSON을, pdcomm_logging_status로 상태 JSON을 읽고, pdcomm_logging_flush로 큐를 비웁니다. C++와 C#은 DiagnosticLogging 래퍼를 제공합니다.

설정 JSON의 키는 enabled, level, file, max_bytes, files, forensics입니다. forensics는 debug 이상에서 느린 처리 단계와 자원 사용 표본을 추가로 기록합니다. 다른 키가 있으면 설정 전체가 거부되고 이전 설정이 유지됩니다.

#include <pdcomm.hpp>
#include <pdcomm_logging.hpp>
#include <iostream>
int main(int argc, char **argv) {
  if (argc != 2) return 2;
  try {
    pdcomm::DiagnosticLogging::configure(argv[1]);
    const uint8_t data[] = {1, 2, 3};
    { pdcomm::Buffer buffer(data, sizeof(data), 1024); }
    pdcomm::DiagnosticLogging::flush();
    std::cout << pdcomm::DiagnosticLogging::status() << '\n';
    pdcomm::DiagnosticLogging::configure(R"({"enabled":false})");
    std::cout << pdcomm::DiagnosticLogging::status() << '\n';
  } catch (const std::exception &error) {
    std::cerr << error.what() << '\n';
    return 1;
  }
  return 0;
}

if (args.Length != 2 || !Path.IsPathFullyQualified(args[0])) return 2;
PDComm.PdcommRuntime.Initialize(args[0]);
PDComm.DiagnosticLogging.Configure(new { enabled = true, level = "debug", file = args[1] });
using (var buffer = PDComm.PdcommBuffer.Create(new byte[] { 1, 2, 3 }, 1024)) { }
PDComm.DiagnosticLogging.Flush();
Console.WriteLine(PDComm.DiagnosticLogging.Status());
PDComm.DiagnosticLogging.Configure(new { enabled = false });
Console.WriteLine(PDComm.DiagnosticLogging.Status());
return 0;

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup><OutputType>Exe</OutputType><TargetFramework>net10.0</TargetFramework><ImplicitUsings>enable</ImplicitUsings><Nullable>enable</Nullable><TreatWarningsAsErrors>true</TreatWarningsAsErrors></PropertyGroup>
  <ItemGroup><Reference Include="PDComm"><HintPath>$(PDCommSdk)/managed/PDComm.dll</HintPath></Reference></ItemGroup>
</Project>

예제를 빌드하고 실행합니다.

mkdir -p logs
c++ -std=c++14 -Wall -Wextra -Werror -pedantic -I "$PDCOMM_SDK/include" \
  "$PDCOMM_EXAMPLES/diagnostics/secsgem/logging.cpp" \
  -L "$PDCOMM_SDK/lib" -lpdcomm_ffi -Wl,-rpath,"$PDCOMM_SDK/lib" -o logging-example
./logging-example '{"level":"debug","file":"./logs/secsgem-cpp.jsonl"}'

dotnet build "$PDCOMM_EXAMPLES/diagnostics/secsgem/LoggingExample.csproj" -c Release "-p:PDCommSdk=$PDCOMM_SDK" -o ./logging-dotnet
dotnet ./logging-dotnet/LoggingExample.dll "$PDCOMM_NATIVE" ./logs/secsgem.jsonl

위 C++ 명령은 macOS 기준입니다. Linux에서는 c++ 대신 g++를 쓰고 -Wl,-rpath,...를 빼며, Windows에서는 개발 환경 준비의 cl 명령처럼 pdcomm_ffi.dll.lib를 링크합니다.

각 예제는 상태 JSON을 두 번 출력합니다. 첫 줄은 로그를 켠 상태, 둘째 줄은 끈 뒤의 상태입니다.

{"build_id":"<build>","configuration_errors":0,"dropped":0,"enabled":true,"files":3,"forensic_sample_errors":0,"forensic_sample_interval_ms":1000,"forensic_samples":0,"forensics":false,"instance_id":"20780-1791997444103400000","level":4,"level_name":"debug","max_bytes":10485760,"queue_capacity":1024,"record_limit":8192,"schema_version":1,"sink":"file","write_errors":0,"written":1}
{"build_id":"<build>","configuration_errors":0,"dropped":0,"enabled":false,...,"level":0,"level_name":"off",...,"sink":"stderr","write_errors":0,"written":1}

enabled가 true에서 false로 바뀌고, written이 1 이상이며, dropped, write_errors, configuration_errors가 0이면 정상입니다. 설정과 flush는 최대 2초를 기다릴 수 있으므로 통신을 처리하는 시간 민감한 경로 밖에서 호출합니다. 프로그램을 끝내기 전에 flush를 호출합니다.

5. 로그를 수집 도구로 보냅니다

JSON Lines 파일은 Fluent Bit, Vector, OpenTelemetry Collector 같은 수집 도구로 읽을 수 있습니다. 예제 묶음의 Fluent Bit 설정은 회전 파일을 따라 읽고 읽은 위치를 보존합니다. 사용하는 Fluent Bit 버전의 문서와 대조해 경로를 바꿔 씁니다.

[SERVICE]
    Flush           1
    Parsers_File    parsers.conf

[INPUT]
    Name            tail
    Path            /var/log/pdcomm/*.jsonl*
    Tag             pdcomm
    Parser          pdcomm_json
    DB              /var/lib/fluent-bit/pdcomm-offsets.db
    DB.Sync         Full
    DB.Compare_Filename Off
    Refresh_Interval 1
    Rotate_Wait     30
    Mem_Buf_Limit   10MB
    Buffer_Chunk_Size 16k
    Buffer_Max_Size 16k
    Skip_Long_Lines Off
    Read_From_Head  On

[OUTPUT]
    Name            stdout
    Match           pdcomm
    Format          json_lines
    Json_date_key   ingested_at
    Json_date_format double

[PARSER]
    Name   pdcomm_json
    Format json

ingested_at은 수집 시각이고 timestamp_unix_ms가 SDK의 원래 사건 시각입니다. 둘을 혼동하지 않습니다. Loki 같은 저장소에서는 request_id, connection_id, sequence처럼 값이 많은 필드를 레이블(label)로 만들지 말고 JSON 필드로 검색합니다.

6. 최소 재현을 만듭니다

같은 묶음의 SDK, 예제, 시뮬레이터를 씁니다.
이전 세션을 모두 끝내고 새 포트에서 시작합니다.
기본 설정으로 통신 수립, 장비 확인, 변수 읽기만 해 봅니다.
성공하면 문제가 된 기능 하나만 더합니다. 처음 실패한 입력과 시각, 상태를 기록합니다.
같은 영역의 headless 시나리오나 예제로 재현되는지 확인합니다. 다른 환경에서 성공했다고 원래 실패 기록을 지우지 않습니다.
설정은 한 번에 하나씩 바꿉니다.

7. 문의 자료를 모읍니다

실행한 명령, 콘솔 출력, 종료 코드
진단 로그 파일(회전된 .1, .2 포함)과 시뮬레이터에서 내보낸 추적 JSON
라이브러리 정보: 로그 상태 JSON의 build_id, 네이티브 라이브러리의 SHA-256

Get-FileHash "$Sdk\lib\pdcomm_ffi.dll" -Algorithm SHA256
dotnet --info

sha256sum "$PDCOMM_NATIVE"
dotnet --info
uname -a

shasum -a 256 "$PDCOMM_NATIVE"
dotnet --info
uname -a

로그에는 메시지 본문이 없지만, 추적이나 콘솔 출력의 16진수 본문에는 장비 이름, 로트(lot), 레시피 같은 정보가 들어 있을 수 있습니다. 공유하기 전에 가리고, 무엇을 가렸는지 적습니다. 문의 양식은 문제 해결에 있습니다.

정리

로그를 끄려면 터미널에서 PDCOMM_LOG 변수를 지우거나 off로 정하고 프로그램을 다시 시작합니다. 일시 정지한 프로세스가 남아 있지 않은지 확인합니다. logs 폴더는 문의가 끝날 때까지 보관합니다.