Logging
The library provides highly-contextual logging using the tracing crate. If you're using Rust, refer to the tracing documentation for details.
In comparison, the bindings use a rigid logging interface with a single callback method to record a message. Configurable options include:
LogLevel
that controls which messages are generated- How and if to print the time as part of the message
- Line or JSON based output
The LogLevel is set to Info by default. This will record Info, Warn, and Error messages. The Debug and Trace levels are generally only useful if debugging an issue with the underlying runtime.
Protocol decoding is always logged at the Info level and is configured separately on a per session basis.
Configuration
- Rust
- C
- C++
- Java
- C#
// initialize logging
tracing_subscriber::fmt()
.with_max_level(tracing::Level::INFO)
.with_target(false)
.init();
// callback which will receive log messages
void on_log_message(dnp3_log_level_t level, const char *msg, void *ctx) { printf("%s", msg); }
dnp3_logger_t get_logger()
{
return (dnp3_logger_t){
// function pointer where log messages will be sent
.on_message = &on_log_message,
// no context to free
.on_destroy = NULL,
// optional context argument applied to all log callbacks
.ctx = NULL,
};
}
// initialize logging with the default configuration
dnp3_configure_logging(dnp3_logging_config_init(), get_logger());
class Logger : public dnp3::Logger {
void on_message(dnp3::LogLevel level, const char *message) override
{
std::cout << message;
}
};
dnp3::Logging::configure(dnp3::LoggingConfig(), std::make_unique<Logger>());
// callback interface used to receive log messages
class ConsoleLogger implements Logger {
@Override
public void onMessage(LogLevel level, String message) {
System.out.print(message);
}
}
Logging.configure(new LoggingConfig(), new ConsoleLogger());
// callback interface used to receive log messages
class ConsoleLogger : ILogger
{
public void OnMessage(LogLevel level, string message)
{
Console.Write($"{message}");
}
}
// Initialize logging with the default configuration
// This may only be called once during program initialization
Logging.Configure(
new LoggingConfig(),
new ConsoleLogger()
);
The bindings use the tracing_subscriber crate internally. If you use Rust, you can pick which tracing backend to use.
Example Output
The logs provide a wealth of contextual metadata so you can:
- Determine which communication session produced the message
- Understand what state the software was in when the event occurred
INFO DNP3-Master-TCP{endpoint="127.0.0.1:20000"}: connected to 127.0.0.1:20000
INFO DNP3-Master-TCP{endpoint="127.0.0.1:20000"}:Task{type=Function(DisableUnsolicited) dest=1024}: APP TX - ctrl: [fir: true fin: true con: false uns: false seq: 0] func: DisableUnsolicited ... (len = 9)
INFO DNP3-Master-TCP{endpoint="127.0.0.1:20000"}:Task{type=Function(DisableUnsolicited) dest=1024}: APP RX - ctrl: [fir: true fin: true con: true uns: true seq: 0] func: UnsolicitedResponse iin1: [DEVICE_RESTART] iin2: [] ... (len = 0)
WARN DNP3-Master-TCP{endpoint="127.0.0.1:20000"}:Task{type=Function(DisableUnsolicited) dest=1024}: device restart detected (address == 1024)
INFO DNP3-Master-TCP{endpoint="127.0.0.1:20000"}:Task{type=Function(DisableUnsolicited) dest=1024}: APP TX - ctrl: [fir: true fin: true con: false uns: true seq: 0] func: Confirm ... (len = 0)
INFO DNP3-Master-TCP{endpoint="127.0.0.1:20000"}:Task{type=Function(DisableUnsolicited) dest=1024}: APP RX - ctrl: [fir: true fin: true con: false uns: false seq: 0] func: Response iin1: [DEVICE_RESTART] iin2: [] ... (len = 0)
Protocol Decoding
Protocol decoding is configurable on a per-communication channel basis, such as all traffic on a TCP socket or a serial port. You can specify the
DecodeLevel
when you create a master or outstation or adjust it at runtime. This struct controls the level of decoding (including none) that takes place for each layer of the
protocol stack, including:
- Application-layer headers, object headers, and object values
- Transport-layer header and payload
- Link-layer header and payload
- Physical-layer length and data bytes
Refer to the language-specific API documentation for the meaning of each enumeration value. The decoding can even show the value of individual fields within objects:
APP TX - ctrl: [fir: true fin: true con: false uns: false seq: 1] func: Write ... (len = 6)
g80v1 : Internal Indications - Packed Format - 1-byte start/stop - [7, 7]
index: 7 false
Protocol decoding is always output at the Info log level. If left enabled, it can be too verbose in a production system. When you're debugging a communication issue, try adjusting the application-layer decoding first to gain visibility into the messages exchanged.