search

eclipse / milo

Eclipse Milo™ - an open source implementation of OPC UA (IEC 62541).
http://www.eclipse.org/milo
Eclipse Public License 2.0
1.16k stars 431 forks source link

Getting `Bad_SecurityChecksFailed` followed by `Bad_ConnectionClosed` when using recursion with `OpcUaClient.getAddressSpace().browseNodesAsync(UaNode).thenCompose()` #1267

Closed ThoSap closed 5 months ago

ThoSap commented 6 months ago

Describe the bug Hi, I currently have the issue that I get the following error messages when using recursion with OpcUaClient.getAddressSpace().browseNodesAsync(UaNode).thenCompose(). Basically, I get a ERROR [UascClientMessageHandler] (milo-shared-thread-pool-0) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2626, lastSequenceNumber=2566 followed by a WARN [AddressSpace] (milo-shared-thread-pool-2) Failed to create Node from Reference to ExpandedNodeId{ns=2, id=BRU_ENRG_0001.10_90_129_10.BRU.BAR.S1p2.activeEnergy._Description, serverIndex=0}: java.util.concurrent.CompletionException: UaException: status=Bad_ConnectionClosed, message=connection closed

Expected behavior I should not get the MessageDecodeException with Bad_SecurityChecksFailed, message=bad sequence number

Logs and Packet Captures N/A

Additional context Client e.g. Eclipse Milo version: 0.6.12 Server: KEPserverEX 6.15.154.0

Simplified code where this occurs

package com.example;

import org.eclipse.milo.opcua.sdk.client.OpcUaClient;
import org.eclipse.milo.opcua.sdk.client.SessionActivityListener;
import org.eclipse.milo.opcua.sdk.client.api.UaSession;
import org.eclipse.milo.opcua.sdk.client.model.nodes.objects.ServerTypeNode;
import org.eclipse.milo.opcua.sdk.client.model.nodes.variables.ServerStatusTypeNode;
import org.eclipse.milo.opcua.sdk.client.nodes.UaNode;
import org.eclipse.milo.opcua.stack.core.Identifiers;
import org.eclipse.milo.opcua.stack.core.UaException;
import org.eclipse.milo.opcua.stack.core.security.SecurityPolicy;
import org.eclipse.milo.opcua.stack.core.types.builtin.DateTime;
import org.eclipse.milo.opcua.stack.core.types.builtin.LocalizedText;
import org.eclipse.milo.opcua.stack.core.types.builtin.NodeId;
import org.eclipse.milo.opcua.stack.core.types.enumerated.NodeClass;
import org.eclipse.milo.opcua.stack.core.types.enumerated.ServerState;
import org.eclipse.milo.opcua.stack.core.types.structured.BuildInfo;
import org.eclipse.milo.opcua.stack.core.types.structured.ServerStatusDataType;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.util.Arrays;
import java.util.Iterator;
import java.util.List;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.TimeoutException;
import java.util.stream.Stream;

import static org.eclipse.milo.opcua.stack.core.types.builtin.unsigned.Unsigned.uint;

public class BadSecurityCheckFailedExample {

    private static final Logger log = LoggerFactory.getLogger(BadSecurityCheckFailedExample.class);

    private OpcUaClient client = null;
    private final CompletableFuture<OpcUaClient> future = new CompletableFuture<>();

    /*
     * OPC UA inactive client handling and stopping the thread
     */
    // If true, the Thread pauses as the OPC UA client is not active
    private volatile boolean stop = false;

    private synchronized boolean keepRunning() {
        return !this.stop;
    }

    public static void main(String[] args) {
        BadSecurityCheckFailedExample example = new BadSecurityCheckFailedExample();

        example.connect();
        example.printServerInfo();
        example.scrapeNodes();

        // This infinite loop is needed for connectors of type subscription, as the superscription manager handle threads mustn't lose the parent thread
        while (example.keepRunning()) {
            try {
                //noinspection BusyWait
                Thread.sleep(Integer.MAX_VALUE);
            } catch (InterruptedException e) {
                e.printStackTrace();
            } finally {
                log.info("Stopping parent Schnurfla thread!");
                example.future.complete(example.client);
            }
        }
    }

    private void connect() {
        log.info("Starting OPC UA client for address: opc.tcp://mykepwarevm.example.com:49320");

        boolean connected = false;
        while (!connected) {
            try {
                client = OpcUaClient.create(
                    "opc.tcp://mykepwarevm.example.com:49320",
                    endpoints -> endpoints.stream()
                        .filter(e -> e.getSecurityPolicyUri().equals(SecurityPolicy.None.getUri()))
                        .findFirst(),
                    configBuilder -> configBuilder
                        .setApplicationName(LocalizedText.english("OPC UA to Kafka Gateway"))
                        .setApplicationUri("urn:localhost:UA:SCHNURFLA")
                        .setProductUri("urn:example.com:UA:SCHNURFLA")
                        .setRequestTimeout(uint(60000)) // After how many ms should a single poll request timeout
                        .build()
                );

                connected = true;
            } catch (UaException e) {
                log.error("Could not create the OPC UA client\n{}", e.getMessage());
                log.info("Waiting 5 seconds to make another connection attempt...");
                try {
                    Thread.sleep(5000);
                } catch (InterruptedException e2) {
                    e.printStackTrace();
                }
            }
        }

        client.addSessionActivityListener(new SessionActivityListener() {
            @Override
            public void onSessionActive(UaSession session) {
                log.info("OPC UA Client Session is now active!");
            }

            @Override
            public void onSessionInactive(UaSession session) {
                log.error("OPC UA Client Session is now inactive!");
            }
        });

        try {
            client.connect().get(60, TimeUnit.SECONDS);
            log.info("Successfully connected to opc.tcp://mykepwarevm.example.com:49320");
        } catch (InterruptedException | ExecutionException | TimeoutException e) {
            log.error("Could not connect to opc.tcp://mykepwarevm.example.com:49320 because of {}", e.getMessage());
            e.printStackTrace();
        }
    }

    private void printServerInfo() {
        try {
            // Get a typed reference to the Server object: ServerNode
            ServerTypeNode serverNode = (ServerTypeNode) client.getAddressSpace().getObjectNode(
                Identifiers.Server,
                Identifiers.ServerType
            );

            // Read properties of the Server object...
            String[] serverArray = serverNode.getServerArray();
            String[] namespaceArray = serverNode.getNamespaceArray();

            log.info("ServerArray={}", Arrays.toString(serverArray));
            log.info("NamespaceArray={}", Arrays.toString(namespaceArray));

            // Read the value of attribute the ServerStatus variable component
            ServerStatusDataType serverStatus = serverNode.getServerStatus();

            log.info("ServerStatus={}", serverStatus);

            // Get a typed reference to the ServerStatus variable
            // component and read value attributes individually
            ServerStatusTypeNode serverStatusNode = serverNode.getServerStatusNode();
            BuildInfo buildInfo = null;
            try {
                buildInfo = serverStatusNode.getBuildInfo();
            } catch (UaException e) {
                log.warn("Could not read the OPC UA Server BuildInfo! {}", e.getMessage());
            }

            DateTime startTime = serverStatusNode.getStartTime();
            DateTime currentTime = serverStatusNode.getCurrentTime();
            ServerState state = serverStatusNode.getState();

            log.info("ServerStatus.BuildInfo={}", buildInfo);
            log.info("ServerStatus.StartTime={}", startTime);
            log.info("ServerStatus.CurrentTime={}", currentTime);
            log.info("ServerStatus.State={}", state);
        } catch (UaException e) {
            log.warn("Could not read the OPC UA ServerTypeNode! {}", e.getMessage());
        }
    }

    private void scrapeNodes() throws IllegalArgumentException {
        // This is coming from a configuration in a loop, simplified here
        NodeId exampleRootNodeId = NodeId.parse("ns=2;s=BRU_ENRG_0001");

        UaNode uaNode;
        try {
            // Get the UA Node, so we know which NodeClass (type Folder, Variable, etc.) the NodeId is
            uaNode = client.getAddressSpace().getNode(exampleRootNodeId);
        } catch (UaException e) {
            log.error("Could not get NodeId {} -> {}", exampleRootNodeId.toString(), e.getMessage());
            return;
        }

        log.info("Browsing the OPC UA tree...");
        Tree tree = new Tree(uaNode, 0, Tree.TreeType.ROOT);

        long startTime = System.nanoTime();
        try {
            this.browseRecursive(client, tree).get(60, TimeUnit.SECONDS);
        } catch (InterruptedException | ExecutionException | TimeoutException e) {
            log.error("Recursive browsing the nodes failed because of {}", e.getMessage());
        }
        long endTime = System.nanoTime();

        log.info(tree.toString());
        log.info("Browse took {}ms -> Found {} nodes", TimeUnit.MILLISECONDS.convert(endTime - startTime, TimeUnit.NANOSECONDS), tree.getChildren().size());
    }

    private CompletableFuture<Void> browseRecursive(OpcUaClient client, Tree tree) {
        log.debug("Tree {} ii={}", tree.getNode().getNodeId(), tree.getIndex());

        return client.getAddressSpace()
            .browseNodesAsync(tree.getNode())
            .thenCompose(nodes -> {
                nodes.forEach(node -> {
                    if (tree.getIndex() < 5 && (node.getBrowseName().getName() != null && !node.getBrowseName().getName().startsWith("_") /* No system Objects starting with _ */)) {
                        switch (tree.getIndex()) {
                            case 0:
                                if (node.getNodeClass().equals(NodeClass.Object)) {
                                    tree.addChild(node, tree.getIndex() + 1, Tree.TreeType.CONNECTION);
                                }
                                break;
                            case 1:
                                if (node.getNodeClass().equals(NodeClass.Object)) {
                                    tree.addChild(node, tree.getIndex() + 1, Tree.TreeType.SITE);
                                }
                                break;
                            case 2:
                                if (node.getNodeClass().equals(NodeClass.Object)) {
                                    tree.addChild(node, tree.getIndex() + 1, Tree.TreeType.GROUP_TYPE);
                                }
                                break;
                            case 3:
                                if (node.getNodeClass().equals(NodeClass.Object)) {
                                    tree.addChild(node, tree.getIndex() + 1, Tree.TreeType.GROUP);
                                }
                                break;
                            case 4:
                                if (node.getNodeClass().equals(NodeClass.Variable)) {
                                    tree.addChild(node, tree.getIndex() + 1, Tree.TreeType.VARIABLE);
                                }
                                break;
                            default:
                                break;
                        }

                    }
                });

                // For each child node browse for its children
                Stream<CompletableFuture<Void>> futures = tree.getChildren().stream()
                    .map(child -> this.browseRecursive(client, child));

                // Return a CompletableFuture that completes when the child browses complete
                return CompletableFuture.allOf(futures.toArray(CompletableFuture[]::new));
            });
    }

    public static class Tree {

        private final int index;
        private final UaNode node;
        private final Tree.TreeType treeType;

        private final List<Tree> children = new CopyOnWriteArrayList<>();

        public Tree(UaNode node, int index, Tree.TreeType treeType) {
            this.node = node;
            this.index = index;
            this.treeType = treeType;
        }

        public int getIndex() {
            return index;
        }

        public UaNode getNode() {
            return node;
        }

        public List<Tree> getChildren() {
            return children;
        }

        public void addChild(UaNode child, int index, Tree.TreeType treeType) {
            children.add(new Tree(child, index, treeType));
        }

        @Override
        public String toString() {
            StringBuilder buffer = new StringBuilder(50);
            print(buffer, "\n", "");
            return buffer.toString();
        }

        private void print(StringBuilder buffer, String prefix, String childrenPrefix) {
            buffer.append(prefix);
            switch (this.treeType) {
                case ROOT -> buffer.append("(R) ");
                case CONNECTION -> buffer.append("(C) ");
                case SITE -> buffer.append("(S) ");
                case GROUP_TYPE -> buffer.append("(T) ");
                case GROUP -> buffer.append("(G) ");
                case VARIABLE -> buffer.append("(V) ");
            }
            buffer.append(this.node.getBrowseName().getName());
            buffer.append('\n');

            for (Iterator<Tree> it = this.children.iterator(); it.hasNext(); ) {
                Tree next = it.next();
                if (it.hasNext()) {
                    next.print(buffer, childrenPrefix + " ├── ", childrenPrefix + " │   ");
                } else {
                    next.print(buffer, childrenPrefix + " └── ", childrenPrefix + "     ");
                }
            }
        }

        public enum TreeType {
            ROOT,
            CONNECTION,
            SITE,
            GROUP_TYPE,
            GROUP,
            VARIABLE
        }

    }

}

Error logs

__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2024-04-30T12:58:38.057Z INFO  [kafka] (smallrye-kafka-producer-thread-0) SRMSG18258: Kafka producer kafka-producer-message, connected to Kafka brokers 'kafka-bootstrap.example.com:443', is configured to write records to 'message'
2024-04-30T12:58:38.063Z INFO  [StartupOpcUaClient] (main) Starting OPC UA client for address: opc.tcp://mykepwarevm.example.com:49320
2024-04-30T12:58:38.204Z INFO  [StartupOpcUaClient] (main) Trying to connect to advertised OPC UA host opc.tcp://mykepwarevm.example.com:49320
2024-04-30T12:58:38.227Z INFO  [NonceUtil] (milo-nonce-util-secure-random) SecureRandom seeded in 0ms.
2024-04-30T12:58:38.238Z INFO  [StartupOpcUaClient] (milo-shared-thread-pool-1) OPC UA Client Session is now active!
2024-04-30T12:58:38.238Z INFO  [StartupOpcUaClient] (main) Successfully connected to opc.tcp://mykepwarevm.example.com:49320
2024-04-30T12:58:38.247Z INFO  [StartupOpcUaClient] (main) ServerArray=[urn:mykepwarevm.example.com:Kepware.KEPServerEX.V6:UA%20Server]
2024-04-30T12:58:38.247Z INFO  [StartupOpcUaClient] (main) NamespaceArray=[http://opcfoundation.org/UA/, urn:mykepwarevm.example.com:Kepware.KEPServerEX.V6:UA%20Server, KEPServerEX]
2024-04-30T12:58:38.252Z INFO  [StartupOpcUaClient] (main) ServerStatus=ServerStatusDataType(startTime=DateTime{utcTime=133589549240146646, javaDate=Tue Apr 30 12:48:44 GMT 2024}, currentTime=DateTime{utcTime=133589555180469307, javaDate=Tue Apr 30 12:58:38 GMT 2024}, state=Running, buildInfo=BuildInfo(productUri=urn:mykepwarevm.example.com:Kepware.KEPServerEX.V6:UA%20Server, manufacturerName=Kepware, productName=KEPServerEX, softwareVersion=6.15, buildNumber=154, buildDate=DateTime{utcTime=133506712000000000, javaDate=Thu Jan 25 15:46:40 GMT 2024}), secondsTillShutdown=0, shutdownReason=LocalizedText{text=null, locale=null})
2024-04-30T12:58:38.259Z WARN  [StartupOpcUaClient] (main) Could not read the OPC UA Server BuildInfo! java.util.concurrent.ExecutionException: java.lang.ClassCastException: org.eclipse.milo.opcua.sdk.client.nodes.UaVariableNode cannot be cast to org.eclipse.milo.opcua.sdk.client.model.nodes.variables.BuildInfoTypeNode
2024-04-30T12:58:38.271Z INFO  [StartupOpcUaClient] (main) ServerStatus.BuildInfo=null
2024-04-30T12:58:38.271Z INFO  [StartupOpcUaClient] (main) ServerStatus.StartTime=DateTime{utcTime=133589549240146646, javaDate=Tue Apr 30 12:48:44 GMT 2024}
2024-04-30T12:58:38.271Z INFO  [StartupOpcUaClient] (main) ServerStatus.CurrentTime=DateTime{utcTime=133589555180619254, javaDate=Tue Apr 30 12:58:38 GMT 2024}
2024-04-30T12:58:38.271Z INFO  [StartupOpcUaClient] (main) ServerStatus.State=Running
2024-04-30T12:58:38.276Z INFO  [SchnurflaConfigurator] (Schnurfla Configurator) The Schnurfla Configurator thread is running
2024-04-30T12:58:38.276Z INFO  [SchnurflaConfigurator] (Schnurfla Configurator) Configured connectors:
        - Polling -> [Energy]
        - Subscription -> []
        - Hybrid -> []
2024-04-30T12:58:38.277Z INFO  [quarkus] (main) ee_schnurfla 1.2.1 native (powered by Quarkus 3.8.2) started in 0.652s. Listening on: http://0.0.0.0:8080
2024-04-30T12:58:38.277Z INFO  [quarkus] (main) Profile prod activated.
2024-04-30T12:58:38.277Z INFO  [quarkus] (main) Installed features: [cdi, config-yaml, kafka-client, kubernetes, micrometer, scheduler, smallrye-context-propagation, smallrye-health, smallrye-reactive-messaging, smallrye-reactive-messaging-kafka, vertx]
2024-04-30T12:58:38.279Z INFO  [Schnurfla] (Polling connector -> Energy) Browsing the OPC UA tree...
2024-04-30T12:58:40.322Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-0) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2626, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:302)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2626, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.322Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-5) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2629, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:273)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2629, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.322Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-5) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2630, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:302)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2630, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.323Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-1) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2663, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:273)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2663, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.323Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-1) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2788, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:302)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2788, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.323Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-2) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2801, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:273)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2801, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.323Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-2) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2811, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:302)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2811, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.323Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-5) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2812, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:273)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2812, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.323Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-5) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2813, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:302)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2813, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.323Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-1) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2814, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:273)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2814, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

2024-04-30T12:58:40.323Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-1) Error decoding symmetric message: org.eclipse.milo.opcua.stack.core.channel.MessageDecodeException: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2815, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:100)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:623)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:302)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_SecurityChecksFailed, message=bad sequence number: 2815, lastSequenceNumber=2566
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder$AbstractDecoder.decode(ChunkDecoder.java:203)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:92)
        ... 10 more

// ### many more of these Bad_SecurityChecksFailed exceptions ###

2024-04-30T12:58:40.427Z WARN  [AddressSpace] (milo-shared-thread-pool-2) Failed to create Node from Reference to ExpandedNodeId{ns=2, id=BRU_ENRG_0001.10_90_129_10.BRU.BAR.S1p2.activeEnergy._ScalingClampLow, serverIndex=0}: java.util.concurrent.CompletionException: UaException: status=Bad_ConnectionClosed, message=connection closed
        at java.base@21.0.2/java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:368)
        at java.base@21.0.2/java.util.concurrent.CompletableFuture.completeRelay(CompletableFuture.java:377)
        at java.base@21.0.2/java.util.concurrent.CompletableFuture$UniRelay.tryFire(CompletableFuture.java:1097)
        at java.base@21.0.2/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base@21.0.2/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2194)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$channelInactive$3(UascClientMessageHandler.java:162)
        at java.base@21.0.2/java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4783)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.channelInactive(UascClientMessageHandler.java:160)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274)
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:301)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
        at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901)
        at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:813)
        at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:566)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_ConnectionClosed, message=connection closed
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.channelInactive(UascClientMessageHandler.java:153)
        ... 18 more

2024-04-30T12:58:40.427Z WARN  [AddressSpace] (milo-shared-thread-pool-3) Failed to create Node from Reference to ExpandedNodeId{ns=2, id=BRU_ENRG_0001.10_90_129_10.BRU.BAR.S1p2.activeEnergy._ScalingRawHigh, serverIndex=0}: java.util.concurrent.CompletionException: UaException: status=Bad_ConnectionClosed, message=connection closed
        at java.base@21.0.2/java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:368)
        at java.base@21.0.2/java.util.concurrent.CompletableFuture.completeRelay(CompletableFuture.java:377)
        at java.base@21.0.2/java.util.concurrent.CompletableFuture$UniRelay.tryFire(CompletableFuture.java:1097)
        at java.base@21.0.2/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base@21.0.2/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2194)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$channelInactive$3(UascClientMessageHandler.java:162)
        at java.base@21.0.2/java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4783)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.channelInactive(UascClientMessageHandler.java:160)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:303)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:274)
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:301)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:281)
        at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901)
        at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:813)
        at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:566)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: UaException: status=Bad_ConnectionClosed, message=connection closed
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.channelInactive(UascClientMessageHandler.java:153)
        ... 18 more

// ### many more connection closed exceptions ###

2024-04-30T13:09:25.892Z ERROR [Schnurfla] (Polling connector -> Energy) Recursive browsing the nodes failed because of null
2024-04-30T13:09:25.892Z INFO  [Schnurfla] (Polling connector -> Energy)
(R) BRU_ENRG_0001
 ├── (C) 10_110_128_5_5
 │    └── (S) PLANT1
 │         └── (T) ENV
 │              ├── (G) buyHeat
 │              │    ├── (V) energy
 │              │    └── (V) power
 │              └── (G) sellHeat
 │                   ├── (V) energy
 │                   └── (V) power
 ├── (C) 10_90_129_10
 │    └── (S) PLANT1
 │         ├── (T) BAR
 │         │    ├── (G) formingSinter1
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) formingSinter2
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) ftl
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) heatTreatment
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) maintenanceBuilding
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) newMachining
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) office
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) oldToolShop
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) S1p2
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) S1p3
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) S2p1
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    ├── (G) S2p2
 │         │    │    ├── (V) activeEnergy
 │         │    │    ├── (V) apparentEnergy
 │         │    │    └── (V) reactiveEnergy
 │         │    └── (G) toolShop
 │         │         ├── (V) activeEnergy
 │         │         ├── (V) apparentEnergy
 │         │         └── (V) reactiveEnergy
 │         └── (T) MEC
 │              └── (G) electricity
 │                   └── (V) activeEnergy
 ├── (C) 10_90_129_2
 │    └── (S) PLANT1
 │         └── (T) BAR
 │              ├── (G) a
 │              │    ├── (V) activeEnergy
 │              │    ├── (V) apparentEnergy
 │              │    └── (V) reactiveEnergy
 │              ├── (G) b
 │              │    ├── (V) activeEnergy
 │              │    ├── (V) apparentEnergy
 │              │    └── (V) reactiveEnergy
 │              ├── (G) c
 │              │    ├── (V) activeEnergy
 │              │    ├── (V) apparentEnergy
 │              │    └── (V) reactiveEnergy
 │              ├── (G) compressor
 │              │    ├── (V) activeEnergy
 │              │    ├── (V) apparentEnergy
 │              │    └── (V) reactiveEnergy
 │              ├── (G) emergency
 │              │    ├── (V) activeEnergy
 │              │    ├── (V) apparentEnergy
 │              │    └── (V) reactiveEnergy
 │              ├── (G) powderExhaust
 │              │    ├── (V) activeEnergy
 │              │    ├── (V) apparentEnergy
 │              │    └── (V) reactiveEnergy
 │              └── (G) shipping
 │                   ├── (V) activeEnergy
 │                   ├── (V) apparentEnergy
 │                   └── (V) reactiveEnergy
 ├── (C) 10_90_129_24
 │    └── (S) PLANT1
 │         └── (T) MEC
 │              └── (G) gas
 │                   └── (V) mainCounter
 └── (C) 10_95_132_15
      └── (S) PLANT2
           ├── (T) BAR
           │    ├── (G) NSHV1Q12p2
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q13p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q13p2
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q19p2
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q20p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q20p2
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q21p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q21p2
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q3p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV1Q6p2
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q10p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q15p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q19p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q21p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q23p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q29p2
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q30p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q3p1
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q6p2
           │    │    └── (V) activeEnergy
           │    ├── (G) NSHV2Q7p1
           │    │    └── (V) activeEnergy
           │    └── (G) NSHV2Q8p1
           │         └── (V) activeEnergy
           └── (T) MEC
                ├── (G) electricity
                │    └── (V) activeEnergy
                └── (G) gas
                     └── (V) mainCounter
2024-04-30T13:09:25.893Z INFO  [Schnurfla] (Polling connector -> Energy) Browse took 60000ms -> Found 5 nodes
kevinherron commented 6 months ago

This doesn't look like a bug on the Milo side of things to me, it looks like a bug in the server, likely triggered by your unbounded recursive browse attempt.

Get a Wireshark capture of the whole thing with security disabled and we'll be able to see if the sequence numbers error is legit or not.

ThoSap commented 6 months ago

Do you have a basic how to guide on how you want the Wireshark log to be filtered? This could also be added to the GitHub issue template, so it is easier for people to report such issues.

kevinherron commented 6 months ago

Usually it’s enough to just filter on the IP addresses and optionally port (49320 by default for Kepware). I don’t usually care if it’s filtered or not because I can do it as well, but it can help keep the file size down in some cases.

ThoSap commented 6 months ago

I will provide you a Wireshark log on Thursday, I'm on PTO tomorrow.

Do you have a suggestion on how I could improve the small recursive method BadSecurityCheckFailedExample#browseRecursive or could you suggest a better/proper solution?

kevinherron commented 6 months ago

Recursion is okay, it's the unbounded parallelism that becomes a problem for many servers.

ThoSap commented 5 months ago

Here you have the Wireshark .pcap dump file, created with eldadru/ksniff as follows. KEPServerEX_knsiff_dump.zip

Also, I give you my OPC UA client log that uses the simplified Java code from above, with Eclipse Milo 0.6.12 in DEBUG log mode. https://gist.github.com/ThoSap/c2254a949804bca3b5d1c6035801fe25 I restarted the container to have a complete dump and on 2024-05-02T08:32:36.614Z (time reported by my OPC UA Client) the connection was established to the KEPserverEX 6.15.154.0 (see the log Gist above). In the Wireshark dump, you can see the connection establishment at 2024-05-02T08:32:36.83059Z.

[myuser@myk8svm ~]$ kubectl sniff my-k8s-pod -n my-k8s-namespace -c my-container -p -f "tcp port 49320" -o KEPServerEX.pcap
INFO[0000] sniffing method: privileged pod
INFO[0000] sniffing on pod: 'my-k8s-pod' [namespace: 'my-k8s-namespace', container: 'my-container', filter: 'tcp port 49320', interface: 'any']
INFO[0000] creating privileged pod on node: 'myk8svm'
INFO[0000] pod: 'ksniff-972zt' created successfully in namespace: 'my-k8s-namespace'
INFO[0000] waiting for pod successful startup
INFO[0002] pod: 'ksniff-972zt' created successfully on node: 'myk8svm'
INFO[0002] output file option specified, storing output in: 'KEPServerEX.pcap'
INFO[0002] starting remote sniffing using privileged pod
# tcpdump config is here ⬇️
INFO[0002] executing command: '[docker --host unix:///var/run/docker.sock run --rm --name=ksniff-container-PFymuGXh --net=container:8c478e520d6044ed920fb36eba2041fd73bae301a9bdc545abb5b9bd99e152cb maintained/tcpdump -i any -U -w - tcp port 49320]'
ThoSap commented 5 months ago

I found a similar issue where you tracked down the root cause: https://forum.inductiveautomation.com/t/anyone-know-of-a-way-to-dump-all-the-current-tag-values-from-the-opc-ua-server/74481/16

kevinherron commented 5 months ago

Thanks, the capture and logs are perfect, I'm looking at this now.

I suspect the problem is that you sending and receiving thousands of requests/responses concurrently and triggering this logic that was added to prevent DoS attacks: https://github.com/eclipse/milo/issues/1147

You could effectively disable it and revert to previous behavior by setting the milo.stack.serialization.maxQueueSize property, e.g. -Dmilo.stack.serialization.maxQueueSize=2147483647

ThoSap commented 5 months ago

Unfortunately setting -Dmilo.stack.serialization.maxQueueSize=2147483647 did not help, I get the same exceptions. image

My client may be able to handle more requests as I compiled this Java 21.0.2 code AoT using GraalVM native-image.

The funny thing is, that I suddenly got this error without changing the Eclipse Milo version (0.6.11) or KEPserverEX version, even though the same code (same container image hash) ran for half a year (even with some container restarts in between K8s node maintenance -> e.g. move POD to other worker nodes).

We also did not add any new OPC UA Objects or Variables in this time frame, so literally nothing changed in this time frame, and then suddenly this issue appeared. Also, this previous version using Eclipse Milo version 0.6.11 ran for months and was also AoT compiled using GraalVM native-image and Java 17.0.8.1+1.

Now these exceptions appear when starting the client, even though this worked before without such issues.

To try to mitigate this issue, I then updated everything (Eclipse Milo 0.6.12, Java 21.0.2, Quarkus, KEPserverEX 6.15.154.0, etc.) to see if this fixes this issue (possible bugfix in any of these components), but no luck as you can see.

ThoSap commented 5 months ago

After these same exceptions, the cron schedule that runs the BadSecurityCheckFailedExample#scrapeNodes ran again and there I got the new error message Could not get NodeId NodeId{ns=2, id=BRU_ENRG_0001} -> status=Bad_SecureChannelIdInvalid, description=The specified secure channel is no longer valid. ➡️ try/catch from line client.getAddressSpace().getNode(exampleRootNodeId);.

kevinherron commented 5 months ago

I'm pretty sure that's the issue... it's the only thing I can see that would cause it. I don't have any logging in place that can prove it, but I can add some if you're able to build and test against snapshot/dev releases.

The problem is that as of 0.6.11 SerializationQueue::decode can return false if it rejected the message, and the client isn't checking that: https://github.com/eclipse/milo/blob/7bd466ecae599f7651286e5d75709eb96edc0e08/opc-ua-stack/stack-client/src/main/java/org/eclipse/milo/opcua/stack/client/transport/uasc/UascClientMessageHandler.java#L617

Not that a check would do much good, because the only thing that can be done in that case it shut the channel down, and that ends up happening anyway.

The whole thing is non-deterministic and timing based.

ThoSap commented 5 months ago

So I guess it would probably be best to throttle the async browse recursion BadSecurityCheckFailedExample#scrapeNodes using a Semaphore, right?

kevinherron commented 5 months ago

If you can get something like that working, yes.

The absolute safest thing to do is not use concurrency at all, like the other browse examples do. KEPServerEX happens to be able to handle this concurrent load well enough, but if you did this against a server in a PLC or something it would certainly fail.

kevinherron commented 5 months ago

I am a bit curious why the maxQueueSize system property didn't work. Was it the exact same errors about sequence numbers that preceded other errors? Are you sure it took effect?

ThoSap commented 5 months ago

I am a bit curious why the maxQueueSize system property didn't work. Was it the exact same errors about sequence numbers that preceded other errors? Are you sure it took effect?

I just figured out why the "fix" with the system property did not work. As I did not runtime initialize class org.eclipse.milo.opcua.stack.core.channel.SerializationQueue in the GraalVM AoT compiled native-image, the private static final int MAX_QUEUE_SIZE = Integer.getInteger("milo.stack.serialization.maxQueueSize", 256); was effectively inlined in the GraalVM native-image.

After configuring the class org.eclipse.milo.opcua.stack.core.channel.SerializationQueue to be runtime initialized by GraalVM native-image, I no longer get the exceptions above when I use -Dmilo.stack.serialization.maxQueueSize=2147483647 (instead of the default of 256). https://www.graalvm.org/jdk21/reference-manual/native-image/optimizations-and-performance/ClassInitialization/ https://www.graalvm.org/jdk21/reference-manual/native-image/guides/specify-class-initialization/ https://medium.com/graalvm/updates-on-class-initialization-in-graalvm-native-image-generation-c61faca461f7

If you find it worthwhile you could add a check if this class was AoT compiled by GraalVM native-image without runtime initializing it using this approach: https://github.com/FasterXML/jackson-databind/blob/jackson-databind-2.17.0/src/main/java/com/fasterxml/jackson/databind/util/NativeImageUtil.java

https://github.com/eclipse/milo/blob/v0.6.12/opc-ua-stack/stack-core/src/main/java/org/eclipse/milo/opcua/stack/core/channel/SerializationQueue.java#L23 https://github.com/eclipse/milo/blob/v0.6.12/opc-ua-sdk/sdk-server/src/main/java/org/eclipse/milo/opcua/sdk/server/Session.java#L67

The GraalVM technology is now part of the OpenJDK (called Project Galahad and Project Leyden), so this check could be important. https://www.graalvm.org/2022/openjdk-announcement/ https://www.infoworld.com/article/3661359/project-leyden-set-to-bring-faster-startups-to-java.html

ThoSap commented 5 months ago

To get Eclipse Milo to work with in a GraalVM AoT compiled native-image I added the following runtime initialization and reflection config:

Runtime initialization

The org.google.common.* classes are needed to be runtime initialized for Guava used in Eclipse Milo. Quarkus specific: Don't forget to escape , with \\, if you are using application.properties instead of application.yaml.

--initialize-at-run-time=com.digitalpetri.netty.fsm.ChannelFsmConfigBuilder$SharedExecutor,com.google.common.cache.LongAddables,com.google.common.cache.Striped64,com.google.common.cache.Striped64$Cell,org.eclipse.milo.opcua.stack.core.channel.SerializationQueue,org.eclipse.milo.opcua.stack.core.util.BufferUtil,org.eclipse.milo.opcua.stack.core.util.NonceUtil

Also add the following classes for the server/client configuration to also print the Eclipse Milo and Java version in the native-image also add the following to the list above:

Reflection

To register necessary classes for reflection in the native-image, else the client won't work:

import io.quarkus.runtime.annotations.RegisterForReflection;

/**

}


- For a plain Java or Spring Boot project with GraalVM
  Add `native-image` switch `-H:ReflectionConfigurationFiles=reflection-config.json`
  Write the following file in `src/main/rersources/reflection-config.json`
  Spring Boot: https://docs.spring.io/spring-boot/docs/current/reference/html/native-image.html
```json
[
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.ApplicationType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.ApplicationType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.AxisScaleEnumeration",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.AxisScaleEnumeration$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.BrowseDirection",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.BrowseDirection$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.BrowseResultMask",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.BrowseResultMask$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.DataChangeTrigger",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.DataChangeTrigger$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.DeadbandType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.DeadbandType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.ExceptionDeviationFormat",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.ExceptionDeviationFormat$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.FilterOperator",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.FilterOperator$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.HistoryUpdateType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.HistoryUpdateType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.IdType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.IdType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.MessageSecurityMode",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.MessageSecurityMode$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.ModelChangeStructureVerbMask",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.ModelChangeStructureVerbMask$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.MonitoringMode",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.MonitoringMode$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.NamingRuleType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.NamingRuleType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.NodeAttributesMask",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.NodeAttributesMask$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.NodeClass",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.NodeClass$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.OpenFileMode",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.OpenFileMode$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.PerformUpdateType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.PerformUpdateType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.RedundancySupport",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.RedundancySupport$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.SecurityTokenRequestType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.SecurityTokenRequestType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.ServerState",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.ServerState$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.StructureType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.StructureType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.TimestampsToReturn",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.TimestampsToReturn$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.TrustListMasks",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.TrustListMasks$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.UserTokenType",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  },
  {
    "name": "org.eclipse.milo.opcua.stack.core.types.enumerated.UserTokenType$Codec",
    "allDeclaredConstructors": true,
    "allPublicConstructors": true,
    "allDeclaredMethods": true,
    "allPublicMethods": true,
    "allDeclaredFields": true,
    "allPublicFields": true
  }
]
kevinherron commented 5 months ago

Why do the enums to need get registered for anything to do with reflection? Is that because your application may use reflection to instantiate them?

ThoSap commented 5 months ago

If I do not add these to the reflection config I will get the following error when connecting as a client. This is probably due to how GraalVM optimizes the Bytecode to a Linux ELF native-image, see https://www.graalvm.org/latest/reference-manual/native-image/#native-image-and-third-party-libraries.

@ctron probably registered the same UaEnumeration classes here in this issue. https://github.com/quarkusio/quarkus/issues/13114#issuecomment-1257630131 image

https://github.com/eclipse/milo/blob/v0.6.12/opc-ua-stack/stack-core/src/main/java/org/eclipse/milo/opcua/stack/core/types/enumerated/ApplicationType.java

You use Java reflection here to call the org.eclipse.milo.opcua.stack.core.types.enumerated.*#from method. https://github.com/eclipse/milo/blob/v0.6.12/opc-ua-stack/stack-core/src/main/java/org/eclipse/milo/opcua/stack/core/serialization/OpcUaBinaryStreamDecoder.java#L679-L691

__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2024-05-03T14:33:53.815Z INFO  [kafka] (smallrye-kafka-producer-thread-0) SRMSG18258: Kafka producer kafka-producer-message, connected to Kafka brokers 'kafka-bootstrap.example.com:443', is configured to write records to 'message'
2024-05-03T14:33:53.818Z INFO  [StartupOpcUaClient] (main) Eclipse Milo milo.stack.serialization.maxQueueSize: 2147483647
2024-05-03T14:33:53.818Z INFO  [StartupOpcUaClient] (main) Starting OPC UA client for address: opc.tcp://mykepwarevm.example.com:49320
2024-05-03T14:33:53.819Z INFO  [OpcUaClient] (main) Java version: 21.0.2
2024-05-03T14:33:53.819Z INFO  [OpcUaClient] (main) Eclipse Milo OPC UA Stack version: 0.6.12
2024-05-03T14:33:53.819Z INFO  [OpcUaClient] (main) Eclipse Milo OPC UA Client SDK version: 0.6.12
2024-05-03T14:33:53.885Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-0) Error decoding UaResponseMessage: org.eclipse.milo.opcua.stack.core.UaSerializationException: java.lang.NoSuchMethodException: org.eclipse.milo.opcua.stack.core.types.enumerated.ApplicationType.from(int)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readEnum(OpcUaBinaryStreamDecoder.java:689)
        at org.eclipse.milo.opcua.stack.core.types.structured.ApplicationDescription$Codec.decode(ApplicationDescription.java:119)
        at org.eclipse.milo.opcua.stack.core.types.structured.ApplicationDescription$Codec.decode(ApplicationDescription.java:108)
        at org.eclipse.milo.opcua.stack.core.serialization.codecs.GenericDataTypeCodec$GenericBinaryDataTypeCodec.decode(GenericDataTypeCodec.java:47)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readStruct(OpcUaBinaryStreamDecoder.java:700)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.lambda$readStruct$0(OpcUaBinaryStreamDecoder.java:712)
        at java.base@21.0.2/java.util.Optional.map(Optional.java:260)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readStruct(OpcUaBinaryStreamDecoder.java:712)
        at org.eclipse.milo.opcua.stack.core.types.structured.EndpointDescription$Codec.decode(EndpointDescription.java:125)
        at org.eclipse.milo.opcua.stack.core.types.structured.EndpointDescription$Codec.decode(EndpointDescription.java:116)
        at org.eclipse.milo.opcua.stack.core.serialization.codecs.GenericDataTypeCodec$GenericBinaryDataTypeCodec.decode(GenericDataTypeCodec.java:47)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readStructArray(OpcUaBinaryStreamDecoder.java:1207)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readStructArray(OpcUaBinaryStreamDecoder.java:1222)
        at org.eclipse.milo.opcua.stack.core.types.structured.GetEndpointsResponse$Codec.decode(GetEndpointsResponse.java:78)
        at org.eclipse.milo.opcua.stack.core.types.structured.GetEndpointsResponse$Codec.decode(GetEndpointsResponse.java:69)
        at org.eclipse.milo.opcua.stack.core.serialization.codecs.GenericDataTypeCodec$GenericBinaryDataTypeCodec.decode(GenericDataTypeCodec.java:47)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readMessage(OpcUaBinaryStreamDecoder.java:669)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:654)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:273)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: java.lang.NoSuchMethodException: org.eclipse.milo.opcua.stack.core.types.enumerated.ApplicationType.from(int)
        at java.base@21.0.2/java.lang.Class.checkMethod(DynamicHub.java:1075)
        at java.base@21.0.2/java.lang.Class.getDeclaredMethod(DynamicHub.java:1165)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readEnum(OpcUaBinaryStreamDecoder.java:685)
        ... 25 more

2024-05-03T14:33:53.951Z ERROR [UascClientMessageHandler] (milo-shared-thread-pool-2) Error decoding UaResponseMessage: org.eclipse.milo.opcua.stack.core.UaSerializationException: java.lang.NoSuchMethodException: org.eclipse.milo.opcua.stack.core.types.enumerated.ApplicationType.from(int)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readEnum(OpcUaBinaryStreamDecoder.java:689)
        at org.eclipse.milo.opcua.stack.core.types.structured.ApplicationDescription$Codec.decode(ApplicationDescription.java:119)
        at org.eclipse.milo.opcua.stack.core.types.structured.ApplicationDescription$Codec.decode(ApplicationDescription.java:108)
        at org.eclipse.milo.opcua.stack.core.serialization.codecs.GenericDataTypeCodec$GenericBinaryDataTypeCodec.decode(GenericDataTypeCodec.java:47)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readStruct(OpcUaBinaryStreamDecoder.java:700)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.lambda$readStruct$0(OpcUaBinaryStreamDecoder.java:712)
        at java.base@21.0.2/java.util.Optional.map(Optional.java:260)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readStruct(OpcUaBinaryStreamDecoder.java:712)
        at org.eclipse.milo.opcua.stack.core.types.structured.EndpointDescription$Codec.decode(EndpointDescription.java:125)
        at org.eclipse.milo.opcua.stack.core.types.structured.EndpointDescription$Codec.decode(EndpointDescription.java:116)
        at org.eclipse.milo.opcua.stack.core.serialization.codecs.GenericDataTypeCodec$GenericBinaryDataTypeCodec.decode(GenericDataTypeCodec.java:47)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readStructArray(OpcUaBinaryStreamDecoder.java:1207)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readStructArray(OpcUaBinaryStreamDecoder.java:1222)
        at org.eclipse.milo.opcua.stack.core.types.structured.GetEndpointsResponse$Codec.decode(GetEndpointsResponse.java:78)
        at org.eclipse.milo.opcua.stack.core.types.structured.GetEndpointsResponse$Codec.decode(GetEndpointsResponse.java:69)
        at org.eclipse.milo.opcua.stack.core.serialization.codecs.GenericDataTypeCodec$GenericBinaryDataTypeCodec.decode(GenericDataTypeCodec.java:47)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readMessage(OpcUaBinaryStreamDecoder.java:669)
        at org.eclipse.milo.opcua.stack.client.transport.uasc.UascClientMessageHandler.lambda$onSecureMessage$14(UascClientMessageHandler.java:654)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$decode$1(SerializationQueue.java:63)
        at org.eclipse.milo.opcua.stack.core.util.TaskQueue$TaskWrapper.run(TaskQueue.java:273)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base@21.0.2/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base@21.0.2/java.lang.Thread.runWith(Thread.java:1596)
        at java.base@21.0.2/java.lang.Thread.run(Thread.java:1583)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
Caused by: java.lang.NoSuchMethodException: org.eclipse.milo.opcua.stack.core.types.enumerated.ApplicationType.from(int)
        at java.base@21.0.2/java.lang.Class.checkMethod(DynamicHub.java:1075)
        at java.base@21.0.2/java.lang.Class.getDeclaredMethod(DynamicHub.java:1165)
        at org.eclipse.milo.opcua.stack.core.serialization.OpcUaBinaryStreamDecoder.readEnum(OpcUaBinaryStreamDecoder.java:685)
        ... 25 more

2024-05-03T14:33:53.951Z ERROR [StartupOpcUaClient] (main) Could not create the OPC UA client
java.util.concurrent.ExecutionException: org.eclipse.milo.opcua.stack.core.UaSerializationException: java.lang.NoSuchMethodException: org.eclipse.milo.opcua.stack.core.types.enumerated.ApplicationType.from(int)
2024-05-03T14:33:53.951Z INFO  [StartupOpcUaClient] (main) Waiting 5 seconds to make another connection attempt...
kevinherron commented 5 months ago

Ah, because of this: https://github.com/eclipse/milo/blob/7bd466ecae599f7651286e5d75709eb96edc0e08/opc-ua-stack/stack-core/src/main/java/org/eclipse/milo/opcua/stack/core/serialization/OpcUaBinaryStreamDecoder.java#L679-L691

I don't think this will be an issue in 1.0. The enum decoding, at least in this spot, no longer uses reflection: https://github.com/eclipse/milo/blob/a79fe4613e346db08c2f3bef96f34c6b00e10420/opc-ua-stack/stack-core/src/main/java/org/eclipse/milo/opcua/stack/core/encoding/binary/OpcUaBinaryDecoder.java#L689-L691

ThoSap commented 5 months ago

But I guess the classes that need to be runtime-initialized with a GraalVM native-image will not change.

kevinherron commented 5 months ago

Yes that pattern is pretty widely used. If there is some kind of Graal configuration file projects can provide that might be worth pursuing for the 1.0 release. I'm interested in supporting Graal native image, but not currently a user, so I'm not familiar with this and wouldn't able to verify anything.

ThoSap commented 5 months ago

The metadata can be gathered automatically and then published in the official GraalVM Reachability Metadata Repository.

"Manual" using the Tracing Agent https://www.graalvm.org/latest/reference-manual/native-image/metadata/AutomaticMetadataCollection/ https://www.graalvm.org/latest/reference-manual/native-image/guides/configure-with-tracing-agent/

Using the Maven plugin (enable the native-image-agent here) https://graalvm.github.io/native-build-tools/latest/maven-plugin.html https://graalvm.github.io/native-build-tools/latest/index.html https://github.com/graalvm/native-build-tools

GraalVM Reachability Metadata Repository https://github.com/oracle/graalvm-reachability-metadata https://github.com/oracle/graalvm-reachability-metadata/tree/master/metadata