eclipse / milo

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

Session timed out waiting for secure channel #298

Closed LibertyWalk closed 6 years ago

LibertyWalk commented 6 years ago

I'm developing a OPCUA Apache NIFI processor and service using Milo. I can't seem to get my service to connect to a OPCUA Server. This is the error I'm getting:

io.netty.channel.ChannelPipelineException: org.eclipse.milo.opcua.stack.client.handlers.UaTcpClientMessageHandler.handlerAdded() has thrown an exception; removed. at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:625) at io.netty.channel.DefaultChannelPipeline.addFirst(DefaultChannelPipeline.java:154) at io.netty.channel.DefaultChannelPipeline.addFirst(DefaultChannelPipeline.java:369) at io.netty.channel.DefaultChannelPipeline.addFirst(DefaultChannelPipeline.java:348) at org.eclipse.milo.opcua.stack.client.handlers.UaTcpClientAcknowledgeHandler.lambda$onAcknowledge$1(UaTcpClientAcknowledgeHandler.java:209) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:374) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.NoSuchMethodError: org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.encode(Lorg/eclipse/milo/opcua/stack/core/channel/SerializationQueue$Encoder;)V at org.eclipse.milo.opcua.stack.client.handlers.UaTcpClientMessageHandler.sendOpenSecureChannelRequest(UaTcpClientMessageHandler.java:211) at org.eclipse.milo.opcua.stack.client.handlers.UaTcpClientMessageHandler.handlerAdded(UaTcpClientMessageHandler.java:163) at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:607) ... 8 common frames omitted 2018-07-30 11:18:31,731 ERROR [StandardProcessScheduler Thread-1] o.a.n.c.s.StandardControllerServiceNode StandardMiloOPCUAService[id=d50cc081-0163-1000-eb8c-09517c0aa0de] Failed to invoke @OnEnabled method due to java.util.concurrent.ExecutionException: UaException: status=Bad_Timeout, message=timed out waiting for secure channel: {} java.util.concurrent.ExecutionException: UaException: status=Bad_Timeout, message=timed out waiting for secure channel at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357) at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1895) at com.hashmapinc.tempus.processors.StandardMiloOPCUAService.createClient(StandardMiloOPCUAService.java:80) at com.hashmapinc.tempus.processors.StandardMiloOPCUAService.onEnabled(StandardMiloOPCUAService.java:102) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:137) at org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:125) at org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:70) at org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotation(ReflectionUtils.java:47) at org.apache.nifi.controller.service.StandardControllerServiceNode$2.run(StandardControllerServiceNode.java:400) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: org.eclipse.milo.opcua.stack.core.UaException: timed out waiting for secure channel at org.eclipse.milo.opcua.stack.client.handlers.UaTcpClientMessageHandler.lambda$handlerAdded$2(UaTcpClientMessageHandler.java:151) at io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:581) at io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:655) at io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:367) ... 1 common frames omitted

I tried debugging and I think it fails while trying to get the server's endpoints. This is the code I'm using for that

private OpcUaClient createClient() throws Exception {

    EndpointDescription[] endpoints = UaTcpStackClient
            .getEndpoints("opc.tcp://theaddress:12324")
            .get();

    EndpointDescription endpoint = endpoints[0];
    OpcUaClientConfig config = OpcUaClientConfig.builder()
            .setApplicationName(LocalizedText.english("MinimalClient"))
            .setApplicationUri("theurn)
            .setCertificate(null)
            .setKeyPair(null)
            .setEndpoint(endpoint)
            .setMaxResponseMessageSize(uint(50000))
            .setIdentityProvider(new AnonymousProvider())
            .setRequestTimeout(uint(5000))
            .build();
    return new OpcUaClient(config);
}

The debugger stops following the function after the 5th line, at .get(). I'm not even sure what the problem is. The logs state that some method SerializationQueue.encode() doesn't exist. Does that mean I'm missing some dependency?

Thanks for your help.

kevinherron commented 6 years ago

What version of Milo are you trying to use and how are you managing your dependencies? Seeing this means something is certainly screwed up:

Caused by: java.lang.NoSuchMethodError: org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.encode(Lorg/eclipse/milo/opcua/stack/core/channel/SerializationQueue$Encoder;)V

If I had to guess I'd say maybe you have some mix of 0.1 and 0.2 Milo jars on your classpath.

LibertyWalk commented 6 years ago

I just checked and everything Milo is at 0.2.2.

kevinherron commented 6 years ago

I don't know enough about NiFi development to suggest any thing helpful, but the fact that you're getting a NoSuchMethodError suggest there's something wrong with your dependencies or classpath.

Are you running this out of an IDE or trying to load it into NiFi to test? Can you get debug information about the classpath or inspect the contents of whatever "bundle" gets built and installed into NiFi?

LibertyWalk commented 6 years ago

This is being developed inside an IDE, then I use mvn clean install to generate a nar file. I then copy that nar file to the lib directory of NIFI. Then I start NIFI and it's there. It just seems to be missing the stack.core... I tried getting the dependency list and the class-path list with "mvn dependency:build-classpath", but that shows that everything is there. I'm gonna try again tomorrow, for today I'm outta juice.

Thanks for your help so far !

kevinherron commented 6 years ago

My best guess would be that a stack-core version 0.1.x jar is somehow making its way onto your classpath at runtime.

The encode method on SerializationQueue changed between 0.1 and 0.2.

kevinherron commented 6 years ago

Feel free use the mailing list to continue this if you haven't already figured it out.