Diagnose failures and ask for help

Before you begin

• HSMSLearn how SEMI E37 HSMS carries SECS-II messages over TCP/IP, how the Select procedure and connection states work, and what the T3, T5, T6, T7 and T8 timers do.
• SECS-II messagesUnderstand SEMI E5 SECS-II messages, streams and functions, the W-bit and reply rules, and how data items are encoded.

Goal

In this tutorial, you:

• Turn on diagnostics logging for SDK programs and the simulator with environment variables alone.
• Cause a T3 timeout and follow the same transaction through the host and equipment logs to find the cause.
• Turn logging on and off and read its status from your own code.
• Prepare a minimal reproduction and the material support needs.

Before you begin

• Finish First communication, and open three terminals.
• Have the examples bundle with the logging examples (PDCOMM_EXAMPLES).

How diagnostics logging works

• It’s off by default. When it’s on, it writes one JSON object per line (JSON Lines).
• It never records message bodies, credentials or the full environment. It keeps metadata only: streams and functions, system bytes, state changes and errors.
• A background thread takes records from a queue and writes them to the file. When the queue (1,024 records) is full, a record is dropped and dropped goes up, so logging never stalls communication.

1. Turn on logging with environment variables

Set these variables in the terminal that starts the program. The program reads them once, when it writes its first record, so changing them while it runs has no effect.

Variable	Value	Default
PDCOMM_LOG	One of error, warn, info, debug or trace; off turns logging off.	Off
PDCOMM_LOG_FILE	Log file path. Without it, records go to standard error.	Standard error
PDCOMM_LOG_MAX_BYTES	Maximum size of one file (8192 bytes to 1 GiB)	10485760 (10 MiB)
PDCOMM_LOG_FILES	Number of files kept, including the current one (1-16)	3

Use info day to day, debug for communication problems and trace for short, detailed captures. When a file reaches its maximum size, it’s renamed to <file>.1, <file>.2 and so on (rotation). If a value is invalid, logging stays off and configuration_errors in the status goes up.

In the equipment terminal (A), create a logs folder and start the equipment:

Linux/macOS

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

Windows

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

In the host terminal (B), start the host from the same folder with a different file name; every program needs its own file:

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

The simulator GUI and the headless simulator also write logs when you start them from a terminal with these variables. The standard output of the headless simulator and the MCP server stays unchanged.

2. Cause a T3 timeout

In the host, type establish and values 1 2 and check that both succeed. Then suspend the equipment from the third terminal (C):

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

Type values 1 2 in the host again. After five seconds, the request fails:

RESULT kind=3 request=3 outcome=0

Resume the equipment, then type quit in both programs:

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

On Windows, cause the T3 timeout with the session ID experiment in Automate the simulator and reproduce errors instead of suspending a process.

3. Find the cause in the logs

Start with the error-level HSMS records:

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}

In Windows PowerShell, use Select-String -Path logs\host.jsonl -Pattern '"event":"(transaction_failed|protocol_error|transport_error)"'.

The failed transaction has system bytes 103. Search both logs for that value to see the whole transaction:

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

In time order (timestamp_unix_ms is UTC milliseconds):

Time (ms)	Log	Record	What happened
…287697	Host	hsms_transport socket_write, 28 bytes	The host sent S1F3.
…292698	Host	hsms transaction_failed, T3Timeout	No reply for five seconds, so the host ended the request.
…293730	Equipment	hsms received, stream 1, function 3, kind Primary	The equipment read S1F3 only after it resumed.
…293733	Equipment	hsms_transport socket_write, 31 bytes	The equipment answered with S1F4.
…293736	Host	hsms protocol_error, UnexpectedReply	The reply belonged to a finished transaction, so the host dropped it.

The conclusion: the host sent the request on time and the equipment processed it late. With real equipment, you’d investigate a stall on the equipment side. If the equipment had never received the request, its log would have no received record.

Note

Don’t conclude that a message was never sent just because a log line is missing. Records can be lost when the queue is full or a write fails. Check that dropped and write_errors in the logging status are 0.

Record fields

Field	Description
timestamp_unix_ms	When the record was made, in UTC milliseconds. Comparing computers requires synchronized clocks.
monotonic_us	Monotonic time in microseconds; compare it only within one process.
sequence	Record number within the process. A gap means records were dropped.
instance_id, pid, thread	Identify the process and thread.
build_id, sdk_version, os, arch	The library build and the platform
level, protocol, component, event	Level, protocol (secsgem), component (hsms, hsms_transport, ffi and so on) and event name
fields	Event-specific values such as connection_id, generation and detail

The events you’ll see most often:

component / event	Level	Content
hsms / start, stop	info	Endpoint start and stop, with mode and address
hsms / state_changed	info	Connection state change in detail.from and detail.to, for example NotSelected to Selected
hsms / received	debug	Stream, function, system bytes and body size of a received message
hsms / transaction_failed	error	A transaction that ended with T3Timeout, T6Timeout, Disconnected, Rejected and so on
hsms / protocol_error	error	UnexpectedReply, WrongSession, IncomingPrimaryLimit and so on
hsms / transport_error	error	Socket errors, for example operation Connect with error_kind ConnectionRefused
hsms_transport / socket_read, socket_write	debug	Socket I/O sizes
secs1 / received, sent, send_failed, fault		SECS-I endpoint traffic and faults

4. Control logging from code

To turn logging on and off while a program runs, use the public API. In C, pass UTF-8 JSON to pdcomm_logging_configure, read the status JSON with pdcomm_logging_status and drain the queue with pdcomm_logging_flush. C++ and C# provide DiagnosticLogging wrappers.

The configuration JSON accepts the keys enabled, level, file, max_bytes, files and forensics. With debug or higher, forensics also records slow processing stages and resource samples. Any other key rejects the whole configuration and keeps the previous one.

diagnostics/secsgem/logging.cpp

#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;
}

diagnostics/secsgem/Program.cs

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;

diagnostics/secsgem/LoggingExample.csproj

<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>

Build and run the examples:

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

The C++ command is for macOS. On Linux, use g++ instead of c++ and drop -Wl,-rpath,...; on Windows, link pdcomm_ffi.dll.lib as in the cl command from Set up your environment.

Each example prints the status JSON twice: first with logging on, then after turning it off.

{"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}

All is well when enabled changes from true to false, written is at least 1, and dropped, write_errors and configuration_errors are 0. Configuring and flushing can wait up to two seconds, so call them outside time-critical communication paths. Flush before your program exits.

5. Ship logs to a collector

Collectors such as Fluent Bit, Vector or the OpenTelemetry Collector can read the JSON Lines files. The Fluent Bit configuration in the examples bundle follows rotated files and keeps its read position. Check it against the documentation of your Fluent Bit version and adjust the paths.

diagnostics/collector/fluent-bit.conf

[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

diagnostics/collector/parsers.conf

[PARSER]
    Name   pdcomm_json
    Format json

ingested_at is when the collector read the record; timestamp_unix_ms is when the SDK event happened. Keep the two apart. In stores such as Loki, search high-cardinality fields such as request_id, connection_id and sequence as JSON fields instead of turning them into labels.

6. Build a minimal reproduction

1. Use the SDK, examples and simulator from the same bundle.
2. Stop all earlier sessions and start on a fresh port.
3. With default settings, only establish communication, identify the equipment and read variables.
4. If that works, add only the capability that failed. Record the first failing input, the time and the state.
5. Check whether a headless scenario or an example for the same area reproduces it. Don’t overwrite the original failure record with a success from another environment.
6. Change one setting at a time.

7. Collect what support needs

• The commands you ran, the console output and the exit codes
• The diagnostics log files, including rotated .1 and .2 files, and any trace JSON exported from the simulator
• Library identity: build_id from the logging status JSON and the SHA-256 of the native library

Windows

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

Linux

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

macOS

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

Logs contain no message bodies, but the hex bodies in traces or console output can include equipment names, lots or recipes. Mask them before you share anything, and say what you masked. The support form is on the Troubleshooting page.

Clean up

To turn logging off, unset PDCOMM_LOG or set it to off, and restart the program. Make sure no suspended process is left behind. Keep the logs folder until your support case is closed.

Next steps

• Status codes and results
• Connection and timeout problems