High Performance OPC UA Server SDK  1.3.0.231
Troubleshooting

This section contains instructions for trouble shooting different issues.

SDK Trace

The SDK has built-in trace support which is helpful for analyzing problems.

Trace Checklist:

  • Trace support must be enabled during compilation of the SDK. Ensure that the CMake switch TRACE_ENABLED is ON, which is the SDK's default setting.
  • Check what TRACE_BACKEND is selected:
    • stderr: This is the default backend and will print all trace infos to console using fprintf(stderr, ...).
    • file: This will write the traces to the configured file.
    • syslog: This will write trace to the system log using the syslog command (see man(3) syslog). This backend is for Linux and other UNIX like systems.
  • Check that trace is enabled at runtime. The UA application needs to enable the trace by calling trace_openlog(), which allows filtering by facility and trace level.

Our example applications offer command line switches to change the trace settings.

Listing available trace levels:

By default, the applications only enable TRACE_LEVEL_ERROR and TRACE_LEVEL_WARNING. If you want to enable more trace levels, you can use the command line switch -d.

$> ./uaserverhp -d 255

By using the switch -f you can filter the output for the specific component e.g. TRACE_FAC_MEMORY.

$> ./uaserverhp -d 255 -f 32

Note that traces TRACE_LEVEL_ERROR ignore the facility filter and will always be shown.

File Trace

When using the file trace backend, this backend reads in its own configuration file trace.conf. This configures the trace file name, directory, and trace file rotation.

The parameters are described in the file itself.

Example trace.conf:

# The following trace settings only apply for the file-backend.
# Other trace backends will ignore these settings.
[file-trace]
# directory: Directory where the traces should be saved.
# Default is ".", which logs into the current working directory.
directory = "."
# basename: the trace file basename.
# Default is "log", which will create a name like "log.1234.1",
# by appending the process id and the sequential log file no.
basename = "log"
# log file extension
extension = ".txt"
# include the PID into the filename
include_pid = false
# Maximum number of files to create. Older files will be deleted.
max_files = 5
# Maximum number of lines per file. When this limit is reached a new file gets created.
max_lines = 1000000
# force flush after every trace line. This avoids data loss in case of a crash,
# but is much much slower.
force_flush = false
# append to existing file, overwrite when false
append = false

Capturing Network Traffic

If you don't see any trace output, but think the client has sent messages to your server, its best to capture network traffic using Wireshark. This way you can see if there is a TCP connection at all. Often there TCP/IP related issues, e.g. DNS problems, firewalls, etc. so that the client is not able to connect the server. In this case Wireshark can be very helpful.

See section Using Wireshark for more information.

Memory Analysis

If you have memory leaks or other memory errors like buffer overruns there are different possibilities to analyze the problem. First of all you need to understand that the SDK uses its own memory pools, so most memory tools like e.g. Valgrind or address sanitizer will not work as expected.

Using Memory Pool Diagnostics

The SDK memory pools have built in support for memory leak detection which is disabled by default.

This is only for debugging purpose and should not be used in production.

To enable it open the CMake GUI and enabled the switches MEMORY_ENABLE_STAT and MEMORY_ENABLE_TRACK_USED_MEM and then recompile.

This way the SDK will output memory statistics (MEMORY_ENABLE_STAT) which is useful for optimizing memory pools, and will print all memory leaks on shutdown (MEMORY_ENABLE_TRACK_USED_MEM) to detect memory leaks.

Example:

$> ./uaserverhp -f 32 -d 255
I|11:05:31.459942|3858| Allocated 9765 KB of ipc memory for memory pools.
I|11:05:31.460008|3858| Using 3231 KB for memory pools (shared).
I|11:05:31.460026|3858| Using 1070 KB for memory pools (private).
I|11:05:31.460043|3858| pool configuration:
I|11:05:31.460062|3858| heap....................................................6691392 bytes (shared)
I|11:05:31.460079|3858| queues......................................................616 bytes (shared)
I|11:05:31.460094|3858| messages...................................................3256 bytes (shared)
I|11:05:31.460111|3858| services..................................................10456 bytes (shared)
I|11:05:31.460127|3858| buffers.................................................3278456 bytes (shared)
I|11:05:31.460142|3858| sessions...................................................1256 bytes (private)
I|11:05:31.460157|3858| session_service_calls......................................6856 bytes (private)
I|11:05:31.460174|3858| session_channels...........................................1376 bytes (private)
I|11:05:31.460193|3858| uatcpmsg_ctxt.............................................15256 bytes (private)
I|11:05:31.460211|3858| uatcpmsg_connection........................................4280 bytes (private)
I|11:05:31.460230|3858| subscriptionbases..........................................2856 bytes (private)
I|11:05:31.460249|3858| subscriptions.............................................81336 bytes (private)
I|11:05:31.460267|3858| notificationmessages......................................17552 bytes (private)
I|11:05:31.460285|3858| monitoreditems...........................................960056 bytes (private)
I|11:05:31.460304|3858| securechannel..............................................5336 bytes (shared)
I|11:05:31.460322|3858| clients.....................................................136 bytes (shared)
I|11:05:31.460340|3858| clients_private............................................9176 bytes (shared)
I|11:05:31.460358|3858| client_subcriptions.........................................616 bytes (shared)
I|11:05:31.460377|3858| eventnotifiers..............................................696 bytes (private)
I|11:05:31.460395|3858| eventfields................................................4856 bytes (private)
I|11:05:31.460412|3858| ipc memory area: 0x0x7ff8572f8010 - 0x0x7ff857c81690
I|11:05:31.460430|3858| pool addresses:
I|11:05:31.460448|3858| heap............................0x7ff8572f8240 - 0x7ff857959c47 (shared)
I|11:05:31.464205|3858| queues..........................0x7ff857959c48 - 0x7ff857959eaf (shared)
I|11:05:31.464238|3858| messages........................0x7ff857959eb0 - 0x7ff85795ab67 (shared)
I|11:05:31.464258|3858| services........................0x7ff85795ab68 - 0x7ff85795d43f (shared)
I|11:05:31.464285|3858| buffers.........................0x7ff85795d440 - 0x7ff857c7dab7 (shared)
I|11:05:31.466117|3858| sessions........................0x5644d1942cf0 - 0x5644d19431d7 (private)
I|11:05:31.466142|3858| session_service_calls...........0x5644d19431e0 - 0x5644d1944ca7 (private)
I|11:05:31.466162|3858| session_channels................0x5644d1944cb0 - 0x5644d194520f (private)
I|11:05:31.466191|3858| uatcpmsg_ctxt...................0x5644d1945220 - 0x5644d1948db7 (private)
I|11:05:31.466211|3858| uatcpmsg_connection.............0x5644d1948dc0 - 0x5644d1949e77 (private)
I|11:05:31.466233|3858| subscriptionbases...............0x5644d1949e80 - 0x5644d194a9a7 (private)
I|11:05:31.466299|3858| subscriptions...................0x5644d194a9b0 - 0x5644d195e767 (private)
I|11:05:31.466343|3858| notificationmessages............0x5644d195e770 - 0x5644d1962bff (private)
I|11:05:31.466920|3858| monitoreditems..................0x7ff858dbb010 - 0x7ff858ea5647 (private)
I|11:05:31.467088|3858| securechannel...................0x7ff857c7dab8 - 0x7ff857c7ef8f (shared)
I|11:05:31.467122|3858| clients.........................0x7ff857c7ef90 - 0x7ff857c7f017 (shared)
I|11:05:31.467141|3858| clients_private.................0x7ff857c7f018 - 0x7ff857c813ef (shared)
I|11:05:31.467163|3858| client_subcriptions.............0x7ff857c813f0 - 0x7ff857c81657 (shared)
I|11:05:31.467188|3858| eventnotifiers..................0x5644d1962c10 - 0x5644d1962ec7 (private)
I|11:05:31.467206|3858| eventfields.....................0x5644d1962ed0 - 0x5644d19641c7 (private)
Server is up and running.
Listening on opc.tcp://ws-gergap.ascolab.com:4840
^C
I|11:05:34.218070|3858| objectpool -1(nodepool): Maximum number of used objects was 2008/2018 (64256/64576 Bytes)
I|11:05:34.218113|3858| objectpool -1(nodepool): No memory leaks.
I|11:05:34.218135|3858| objectpool -1(varpool): Maximum number of used objects was 1284/1294 (30816/31056 Bytes)
I|11:05:34.218172|3858| objectpool -1(varpool): No memory leaks.
I|11:05:34.218198|3858| objectpool -1(vartypepool): Maximum number of used objects was 37/37 (592/592 Bytes)
I|11:05:34.218217|3858| objectpool -1(vartypepool): No memory leaks.
I|11:05:34.218987|3858| objectpool -1(refpool): Maximum number of used objects was 4834/4913 (116016/117912 Bytes)
I|11:05:34.219012|3858| objectpool -1(refpool): No memory leaks.
I|11:05:34.219043|3858| objectpool -1(nodepool): Maximum number of used objects was 0/1 (0/32 Bytes)
I|11:05:34.219080|3858| objectpool -1(nodepool): No memory leaks.
I|11:05:34.219101|3858| objectpool -1(varpool): Maximum number of used objects was 0/1 (0/24 Bytes)
I|11:05:34.219125|3858| objectpool -1(varpool): No memory leaks.
I|11:05:34.219152|3858| objectpool -1(refpool): Maximum number of used objects was 0/1 (0/24 Bytes)
I|11:05:34.219174|3858| objectpool -1(refpool): No memory leaks.
I|11:05:34.219211|3858| objectpool -1(nodepool): Maximum number of used objects was 607/793 (19424/25376 Bytes)
I|11:05:34.219235|3858| objectpool -1(nodepool): No memory leaks.
I|11:05:34.219258|3858| objectpool -1(varpool): Maximum number of used objects was 467/558 (11208/13392 Bytes)
I|11:05:34.219285|3858| objectpool -1(varpool): No memory leaks.
I|11:05:34.219308|3858| objectpool -1(vartypepool): Maximum number of used objects was 1/101 (16/1616 Bytes)
I|11:05:34.219328|3858| objectpool -1(vartypepool): No memory leaks.
I|11:05:34.219871|3858| objectpool -1(guidpool): Maximum number of used objects was 0/10 (0/160 Bytes)
I|11:05:34.219902|3858| objectpool -1(guidpool): No memory leaks.
I|11:05:34.219938|3858| objectpool -1(refpool): Maximum number of used objects was 1258/1453 (30192/34872 Bytes)
I|11:05:34.219964|3858| objectpool -1(refpool): No memory leaks.
I|11:05:34.220002|3858| objectpool -1(authorization_names): Maximum number of used objects was 7/20 (112/320 Bytes)
I|11:05:34.220032|3858| objectpool -1(authorization_names): No memory leaks.
I|11:05:34.220059|3858| objectpool -1(authorization_user_ctx): Maximum number of used objects was 5/10 (40/80 Bytes)
I|11:05:34.220085|3858| objectpool -1(authorization_user_ctx): No memory leaks.
I|11:05:34.220113|3858| objectpool -1(authorization_gids): Maximum number of used objects was 2/10 (16/80 Bytes)
I|11:05:34.220140|3858| objectpool -1(authorization_gids): No memory leaks.
I|11:05:34.220172|3858| objectpool -1(authenticaion_username): Maximum number of used objects was 4/10 (64/160 Bytes)
I|11:05:34.220200|3858| objectpool -1(authenticaion_username): No memory leaks.
I|11:05:34.220228|3858| objectpool -1(authenticaion_passwd): Maximum number of used objects was 4/10 (160/400 Bytes)
I|11:05:34.220255|3858| objectpool -1(authenticaion_passwd): No memory leaks.
I|11:05:34.220607|3858| Maximum used memory was 1306848 Bytes.
I|11:05:34.220641|3858| No memory leaks.
I|11:05:34.220667|3858| objectpool 1(queues): Maximum number of used objects was 1/10 (56/560 Bytes)
I|11:05:34.220693|3858| objectpool 1(queues): No memory leaks.
I|11:05:34.220719|3858| objectpool 2(messages): Maximum number of used objects was 0/100 (0/3200 Bytes)
I|11:05:34.220746|3858| objectpool 2(messages): No memory leaks.
I|11:05:34.220772|3858| objectpool 3(services): Maximum number of used objects was 0/100 (0/10400 Bytes)
I|11:05:34.220799|3858| objectpool 3(services): No memory leaks.
I|11:05:34.220824|3858| objectpool 4(buffers): Maximum number of used objects was 2/50 (131136/3278400 Bytes)
I|11:05:34.220850|3858| objectpool 4(buffers): No memory leaks.
I|11:05:34.220876|3858| objectpool 5(sessions): Maximum number of used objects was 0/10 (0/1200 Bytes)
I|11:05:34.220903|3858| objectpool 5(sessions): No memory leaks.
I|11:05:34.220929|3858| objectpool 6(session_service_calls): Maximum number of used objects was 0/50 (0/6800 Bytes)
I|11:05:34.220956|3858| objectpool 6(session_service_calls): No memory leaks.
I|11:05:34.220982|3858| objectpool 7(session_channels): Maximum number of used objects was 0/15 (0/1320 Bytes)
I|11:05:34.221008|3858| objectpool 7(session_channels): No memory leaks.
I|11:05:34.221034|3858| objectpool 8(uatcpmsg_ctxt): Maximum number of used objects was 1/50 (304/15200 Bytes)
I|11:05:34.221060|3858| objectpool 8(uatcpmsg_ctxt): No memory leaks.
I|11:05:34.221086|3858| objectpool 9(uatcpmsg_connection): Maximum number of used objects was 2/16 (528/4224 Bytes)
I|11:05:34.221112|3858| objectpool 9(uatcpmsg_connection): No memory leaks.
I|11:05:34.221137|3858| objectpool 10(subscriptionbases): Maximum number of used objects was 0/10 (0/2800 Bytes)
I|11:05:34.221164|3858| objectpool 10(subscriptionbases): No memory leaks.
I|11:05:34.221189|3858| objectpool 11(subscriptions): Maximum number of used objects was 0/20 (0/81280 Bytes)
I|11:05:34.221217|3858| objectpool 11(subscriptions): No memory leaks.
I|11:05:34.221243|3858| objectpool 12(notificationmessages): Maximum number of used objects was 0/81 (0/17496 Bytes)
I|11:05:34.221265|3858| objectpool 12(notificationmessages): No memory leaks.
I|11:05:34.221284|3858| objectpool 13(monitoreditems): Maximum number of used objects was 0/5000 (0/960000 Bytes)
I|11:05:34.221311|3858| objectpool 13(monitoreditems): No memory leaks.
I|11:05:34.221337|3858| objectpool 14(securechannel): Maximum number of used objects was 0/15 (0/5280 Bytes)
I|11:05:34.221365|3858| objectpool 14(securechannel): No memory leaks.
I|11:05:34.221389|3858| objectpool 16(clients): Maximum number of used objects was 0/10 (0/80 Bytes)
I|11:05:34.221416|3858| objectpool 16(clients): No memory leaks.
I|11:05:34.221441|3858| objectpool 17(clients_private): Maximum number of used objects was 0/10 (0/9120 Bytes)
I|11:05:34.221468|3858| objectpool 17(clients_private): No memory leaks.
I|11:05:34.221495|3858| objectpool 18(client_subcriptions): Maximum number of used objects was 0/10 (0/560 Bytes)
I|11:05:34.221521|3858| objectpool 18(client_subcriptions): No memory leaks.
I|11:05:34.221547|3858| objectpool 19(eventnotifiers): Maximum number of used objects was 7/20 (224/640 Bytes)
I|11:05:34.221573|3858| objectpool 19(eventnotifiers): No memory leaks.
I|11:05:34.221598|3858| objectpool 20(eventfields): Maximum number of used objects was 152/200 (3648/4800 Bytes)
I|11:05:34.221626|3858| objectpool 20(eventfields): No memory leaks.

A memory leak will be printed like this:

I|11:09:52.615179|5232| Maximum used memory was 1306896 Bytes.
W|11:09:52.615210|5232| 48 Bytes leaked!

Finding Memory Leak Origins

The memory pools can even track down where this leaked memory was allocated. Therefor you need to enable the switch MEMORY_ENABLE_TRACE. This can log up to MEMORY_TRACE_LOG_SIZE entries, which can be configured in src/memory/memory_config.h.in, so this buffer must be big enough to hold all active memory allocations. Obviously this requires additional memory, which can be a problem on small embedded systems.

When enabled you will see this additional information:

I|11:20:54.697793|18974| Maximum used memory was 1342936 Bytes.
W|11:20:54.697826|18974| 56 Bytes leaked!
G|11:20:54.697863|18974| Chunk with 56 bytes leaked: allocated in /home/john/work/embeddedstack/examples/server_demo/server_main.c:306(14556)

The new trace line contains file name and line number of the leaked allocation. The number in parentheses contains the allocation number. This can be helpful if the line is reached multiple times to set conditional breakpoints.

This number is also needed for mempool_set_alloc_break(). You can use the function mempool_set_alloc_break() to force allocation to fail on this allocation number. This is useful in writing unit tests.

When to use this: On a PC it is often easier to use existing tools like Valgrind to track down memory leaks as shown in the next section. If such tools are not available on your target system, you can use the SDK's built-in memory leak detection.

Using Standard Malloc and Standard Leak Detectors

To make standard tools like Valgrind and GCC's/Clangs's address sanitizer working you can configure the SDK to use standard malloc/free from the C library. Therefor you need to enable the switches MEMORY_MEMPOOL_USE_MALLOC and MEMORY_OBJECTPOOL_USE_MALLOC in the CMake GUI. Note that these options are marked as 'advanced' and are not shown be default in the GUI. You need to check the 'Advanced' checkbox first.

This is only for debugging purpose and should not be used in production.

Of course, you need to recompile again after changing these CMake options.

The SDK even provides CMake switches to enable the address sanitizer for GCC and Clang. Depending on the used compiler you will find the options ENABLE_GCC_SANITIZER_ADDRESS or ENABLE_CLANG_SANITIZER_ADDRESS in the CMake GUI.