Logging & Tracing

Contents

• Developer Logging
• Tracing About
• Tracing - Windows

Developer Logging

ONNX Runtime has built-in cross-platform internal printf style logging LOGS(). This logging is available to configure in production builds for a dev using the API.

There will likely be a performance penalty for using the default sink output (stdout) with higher log severity levels.

log_severity_level

Python (below) - C/C++ CreateEnv / OrtLoggingLevel - .NET/C#

sess_opt = SessionOptions()
sess_opt.log_severity_level = 0 // Verbose
sess = ort.InferenceSession('model.onnx', sess_opt)

Note

Note that log_verbosity_level is a separate setting and only available in DEBUG custom builds.

Tracing About

Tracing is a super-set of logging in that tracing

• Includes the previously mentioned logging
• Adds tracing events that are more structured than printf style logging
• Can be integrated with a larger tracing eco-system of the OS, such that
  • Tracing from multiple systems with ONNX, OS system level, and user-mode software that uses ONNX can be combined
  • Timestamps are high resolution and consistent with other traced components
  • Can log at high performance with a high number of events / second.
  • Events are not logged via stdout, but instead usually via a high performance in memory sink
  • Can be enabled dynamically at run-time to investigate issues including in production systems

Currently, only Tracelogging combined with Windows ETW is supported, although TraceLogging is cross-platform and support for other OSes instrumentation systems could be added.

Tracing - Windows

There are 2 main ONNX Runtime TraceLogging providers that can be enabled at run-time that can be captured with Windows ETW

Quickstart Tracing with WPR

On Windows, you can use Windows Performance Recorder (WPR) to capture a trace. The 2 providers covered below are already configured in these WPR profiles.

• Download ort.wprp and etw_provider.wprp (these could also be combined later)

wpr -start ort.wprp -start etw_provider.wprp
echo Repro the issue allowing ONNX to run
wpr -stop onnx.etl -compress

ONNXRuntimeTraceLoggingProvider

Beginning in ONNX Runtime 1.17 the ONNXRuntimeTraceLoggingProvider can also be enabled.

This will dynamically trace with high-performance the previously mentioned LOGS() macro printf logs that were previously only controlled by log_severity_level. A user or developer tracing with this provider will have the log severity level set dynamically with what ETW level they provide at run-time.

Provider Name: ONNXRuntimeTraceLoggingProvider
Provider GUID: 929DD115-1ECB-4CB5-B060-EBD4983C421D
Keyword: Logs (0x2) keyword per logging.h
Level: 1 (CRITICAL ) through 5 (VERBOSE) per TraceLoggingLevel

Microsoft.ML.ONNXRuntime

The Microsoft.ML.ONNXRuntime provider provides structured logging.

Provider Name: Microsoft.ML.ONNXRuntime
Provider GUID: 3a26b1ff-7484-7484-7484-15261f42614d
Keywords: Multiple per logging.h
Level: 1 (CRITICAL ) through 5 (VERBOSE) per TraceLoggingLevel
Note: This provider supports ETW CaptureState (Rundown) for logging state for example when a trace is saved

ORT 1.17 includes new events logging session options and EP provider options

Profiling

Microsoft.ML.ONNXRuntime can also output profiling events. That is covered in profiling

WinML

WindowsML has it’s own tracing providers that be enabled in addition the providers above

• Microsoft.Windows.WinML - d766d9ff-112c-4dac-9247-241cf99d123f
• Microsoft.Windows.AI.MachineLearning - BCAD6AEE-C08D-4F66-828C-4C43461A033D