I have a question regarding Bad_ConnectionRejected.

[AppleCitron]

Hello, I have an inquiry. When down, the Subscription Listener receives a Bad_ConnectionClosed event, but the Bad_ConnectionRejected event does not occur. In Milo the operation proceeds and a log entry for Bad_ConnectionRejected is recorded. Is there a condition that causes a Bad_ConnectionRejected to be sent to the Subscription Listener’s onPublishFailure? Why does Milo generate this event while the listener does not receive it?

subscriptionListener = new UaSubscriptionManager.SubscriptionListener() {
public void onPublishFailure(UaException exception) { }
}

13:18:53.184 [OPC-UA-001-shared-thread-pool-3 ] DEBUG [OPC-UA-001] [1] S(Reconnecting) x E(ConnectFailure) = S'(ReconnectWait) - com.digitalpetri.strictmachine.StrictMachine$PollAndEvaluate.run[200]
13:18:53.184 [OPC-UA-001-shared-thread-pool-3 ] TRACE [OPC-UA-001] [1] found 4 matching TransitionActions - com.digitalpetri.strictmachine.StrictMachine$PollAndEvaluate.run[229]
13:18:53.184 [OPC-UA-001-shared-thread-pool-3 ] TRACE [OPC-UA-001] [1] executing TransitionAction: com.digitalpetri.strictmachine.dsl.ActionBuilder$PredicatedTransitionAction@65fff8b3 - com.digitalpetri.strictmachine.StrictMachine$PollAndEvaluate.lambda$run$0[244]
13:18:53.184 [OPC-UA-001-shared-thread-pool-3 ] TRACE [OPC-UA-001] [1] executing TransitionAction: com.digitalpetri.strictmachine.dsl.ActionBuilder$PredicatedTransitionAction@79b01d08 - com.digitalpetri.strictmachine.StrictMachine$PollAndEvaluate.lambda$run$0[244]
13:18:53.184 [OPC-UA-001-shared-thread-pool-3 ] TRACE [OPC-UA-001] [1] executing TransitionAction: com.digitalpetri.strictmachine.dsl.ActionBuilder$PredicatedTransitionAction@7d3e6c88 - com.digitalpetri.strictmachine.StrictMachine$PollAndEvaluate.lambda$run$0[244]
13:18:53.184 [OPC-UA-001-shared-thread-pool-3 ] TRACE [OPC-UA-001] [1] executing TransitionAction: com.digitalpetri.netty.fsm.ChannelFsm$1@6a366ec4 - com.digitalpetri.strictmachine.StrictMachine$PollAndEvaluate.lambda$run$0[244]
13:18:53.184 [OPC-UA-001-shared-thread-pool-2 ] DEBUG [OPC-UA-001] sendRequest() failed, request=CreateSessionRequest, requestHandle=319 - org.eclipse.milo.opcua.stack.client.UaStackClient.lambda$deliverResponse$5[343]
java.util.concurrent.CompletionException: UaException: status=Bad_ConnectionRejected, message=io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /127.0.0.1:49320
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:593) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_222]
at org.eclipse.milo.opcua.stack.client.transport.uasc.ClientChannelFsm$ClientChannelActions.lambda$connect$0(ClientChannelFsm.java:128) ~[stack-client-0.6.16.jar:0.6.16]
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:590) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:583) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:559) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:492) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:636) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.setFailure0(DefaultPromise.java:629) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.tryFailure(DefaultPromise.java:118) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.fulfillConnectPromise(AbstractNioChannel.java:326) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:342) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:784) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:732) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:658) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:998) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
Caused by: org.eclipse.milo.opcua.stack.core.UaException: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /127.0.0.1:49320
at org.eclipse.milo.opcua.stack.client.transport.uasc.ClientChannelFsm$ClientChannelActions.lambda$connect$0(ClientChannelFsm.java:129) ~[stack-client-0.6.16.jar:0.6.16]
... 16 more
Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /127.0.0.1:49320
Caused by: java.net.ConnectException: Connection refused: no further information
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[?:1.8.0_222]
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717) ~[?:1.8.0_222]
at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:336) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:339) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
... 7 more
13:18:53.185 [OPC-UA-001-shared-thread-pool-2 ] DEBUG [OPC-UA-001] [2] CreateSession failed: UaException: status=Bad_ConnectionRejected, message=io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /127.0.0.1:49320 - org.eclipse.milo.opcua.sdk.client.session.SessionFsmFactory.lambda$null$14[306]
java.util.concurrent.CompletionException: UaException: status=Bad_ConnectionRejected, message=io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /127.0.0.1:49320
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:593) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_222]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_222]
at org.eclipse.milo.opcua.stack.client.transport.uasc.ClientChannelFsm$ClientChannelActions.lambda$connect$0(ClientChannelFsm.java:128) ~[stack-client-0.6.16.jar:0.6.16]
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:590) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:583) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:559) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:492) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:636) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.setFailure0(DefaultPromise.java:629) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.DefaultPromise.tryFailure(DefaultPromise.java:118) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.fulfillConnectPromise(AbstractNioChannel.java:326) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:342) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:784) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:732) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:658) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:998) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.119.Final.jar:4.1.119.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
Caused by: org.eclipse.milo.opcua.stack.core.UaException: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /127.0.0.1:49320
at org.eclipse.milo.opcua.stack.client.transport.uasc.ClientChannelFsm$ClientChannelActions.lambda$connect$0(ClientChannelFsm.java:129) ~[stack-client-0.6.16.jar:0.6.16]
... 16 more
Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /127.0.0.1:49320
Caused by: java.net.ConnectException: Connection refused: no further information
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[?:1.8.0_222]
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717) ~[?:1.8.0_222]
at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:336) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:339) ~[netty-transport-4.1.119.Final.jar:4.1.119.Final]
... 7 more

[kevinherron]

I think what you're seeing when you get a callback is an in-flight PublishRequest failing:

milo/opc-ua-sdk/sdk-client/src/main/java/org/eclipse/milo/opcua/sdk/client/subscriptions/OpcUaSubscriptionManager.java

Lines 518 to 533 in bd15067

	StatusCode statusCode = UaException.extract(ex)
	.map(UaException::getStatusCode)
	.orElse(StatusCode.BAD);
	logger.debug("Publish service failure (requestHandle={}): {}", requestHandle, statusCode, ex);
	pendingCount.getAndUpdate(p -> (p > 0) ? p - 1 : 0);
	if (statusCode.getValue() != StatusCodes.Bad_NoSubscription &&
	statusCode.getValue() != StatusCodes.Bad_TooManyPublishRequests) {
	maybeSendPublishRequests();
	}
	UaException uax = UaException.extract(ex).orElse(new UaException(ex));
	subscriptionListeners.forEach(l -> l.onPublishFailure(uax));

Subsequent attempts to send PublishRequests will not continue to make callbacks:

milo/opc-ua-sdk/sdk-client/src/main/java/org/eclipse/milo/opcua/sdk/client/subscriptions/OpcUaSubscriptionManager.java

Lines 453 to 470 in bd15067

	client.getSession().thenAccept(session -> {
	AtomicLong pendingCount = pendingCountMap.computeIfAbsent(
	session.getSessionId(), id -> new AtomicLong(0L));
	for (long i = pendingCount.get(); i < maxPendingPublishes; i++) {
	if (pendingCount.incrementAndGet() <= maxPendingPublishes) {
	sendPublishRequest(session, pendingCount);
	} else {
	pendingCount.getAndUpdate(p -> (p > 0) ? p - 1 : 0);
	}
	}
	if (pendingCountMap.size() > 1) {
	// Prune any old sessions...
	pendingCountMap.entrySet().removeIf(e ->
	!e.getKey().equals(session.getSessionId()));
	}
	});

client.getSession() will not complete successfully while you are not connected, so thenAccept will not run.

It's not expected that events happening in the SessionFsm are constantly relayed to your subscription listeners.