Avatar

Please consider registering
guest

sp_LogInOut Log In sp_Registration Register

Register | Lost password?
sp_Search Search
Advanced Search
Advanced Search

— Forum Scope —




— Match —





— Forum Options —





Minimum search word length is 3 characters - maximum search word length is 84 characters

sp_Search Search
Go to Bottom
No permission to create posts
sp_Feed Topic RSS sp_TopicIcon
Bad_TcpSecureChannelUnknown on Server
September 28, 2015
13:38, EEST
Avatar
tobiasg
Member
Members
Forum Posts: 4
Member Since:
September 28, 2015
sp_UserOfflineSmall Offline
Go to Top
1sp_Permalink sp_Print

Hi,
I always get this exception on the server side, but the server is working without problems (connection established,…):
org.opcfoundation.ua.common.ServiceResultException: Bad_TcpSecureChannelUnknown (code=0x807F0000, description=”The SecureChannelId and/or TokenId are not currently in use.”)

Additionally I get this exception on the client side, when I try to disconnect:
org.opcfoundation.ua.common.ServiceResultException: Bad_SecureChannelClosed (code=0x80860000, description=”The secure channel has been closed.”)

I tried to use SecurityMode.BASIC128RSA15_SIGN_ENCRYPT and SecurityMode.NONE (on server and client side), but the behavior was the same. Application Identity is used, but User Identity isn’t. We use CA signed certificates.

Does this problem sound familar to anybody? Like mentioned before, everything is working, but I want to get to the bottom of this exception. Thanks

September 29, 2015
14:39, EEST
Avatar
Jouni Aro
Moderator
Moderators
Forum Posts: 1026
Member Since:
December 21, 2011
sp_UserOfflineSmall Offline
sp_UserWebsite
Go to Top
2sp_Permalink sp_Print

Which version of the SDK are you using?

October 5, 2015
12:32, EEST
Avatar
tobiasg
Member
Members
Forum Posts: 4
Member Since:
September 28, 2015
sp_UserOfflineSmall Offline
Go to Top
3sp_Permalink sp_Print

We are using version 2.1.9-524. Is there any known issue regarding this problem in this version? Thanks

October 6, 2015
8:52, EEST
Avatar
Jouni Aro
Moderator
Moderators
Forum Posts: 1026
Member Since:
December 21, 2011
sp_UserOfflineSmall Offline
sp_UserWebsite
Go to Top
4sp_Permalink sp_Print

Yes, there was one related issue fixed after that:

https://opcfoundation-onlineapplications.org/mantis/view.php?id=3101

The stack was not taking the renewed secure channel in use right away, which caused this kind of problems.

I recommend you upgrade to 2.2.0 – or ask for the latest beta.

October 6, 2015
10:44, EEST
Avatar
tobiasg
Member
Members
Forum Posts: 4
Member Since:
September 28, 2015
sp_UserOfflineSmall Offline
Go to Top
5sp_EditHistory sp_Permalink sp_Print

Thanks, that helped on the client side, but on the server side we still have the same problem. I’m, using 2.2.0-552 right now.

October 6, 2015
14:46, EEST
Avatar
Jouni Aro
Moderator
Moderators
Forum Posts: 1026
Member Since:
December 21, 2011
sp_UserOfflineSmall Offline
sp_UserWebsite
Go to Top
6sp_Permalink sp_Print

Can you post some details about the server problem, e.g. a log that shows more about it – if possible in DEBUG mode?

October 12, 2015
11:42, EEST
Avatar
tobiasg
Member
Members
Forum Posts: 4
Member Since:
September 28, 2015
sp_UserOfflineSmall Offline
Go to Top
7sp_EditHistory sp_Permalink sp_Print

I think that this is the relevant section of the log. I think that the problem is related to the discovery service…

2015-10-12 13:31:47.830 DEBUG [OpcTcpServerConnection] – handleOpenSecureChannelRequest: endpointServer=OpcTcpServer(opc.tcp(/192.168.154.1:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))opc.tcp(/192.168.75.1:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))opc.tcp(/192.168.56.1:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))opc.tcp(/192.168.176.36:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))opc.tcp(/127.0.0.1:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))) SecureChannelId=1
2015-10-12 13:31:47.830 DEBUG [CryptoUtil] – createNonce: bytes=0
2015-10-12 13:31:47.831 DEBUG [OpcTcpServerSecureChannel] – tokenLifetime: 3600000
2015-10-12 13:31:47.831 DEBUG [AbstractServerSecureChannel] – Switching to new security token 1
2015-10-12 13:31:47.832 DEBUG [AbstractServerSecureChannel] – pruneInvalidTokens: tokens(1)=[SecurityToken(Id=1, secureChannelId=1, creationTime=12.10.2015 13:31:47, lifetime=3600000)]
2015-10-12 13:31:47.834 DEBUG [ChunkAsymmEncryptSigner] – SecurityMode in asymm enc: 1
2015-10-12 13:31:47.835 INFO [OpcTcpServerSecureChannel] – SecureChannel opened; SecurityToken(Id=1, secureChannelId=1, creationTime=12.10.2015 13:31:47, lifetime=3600000)
2015-10-12 13:31:47.835 DEBUG [AbstractServerSecureChannel] – tokens(1)=[SecurityToken(Id=1, secureChannelId=1, creationTime=12.10.2015 13:31:47, lifetime=3600000)]
2015-10-12 13:31:47.836 DEBUG [OpcTcpServerConnection] – handleSymmChunk: token=org.opcfoundation.ua.transport.security.SecurityConfiguration@40141f42, secureChannelId=0, more=false
2015-10-12 13:31:47.836 DEBUG [SecureInputMessageBuilder] – SecureInputMessageBuilder: expectedSequenceNumber=2
2015-10-12 13:31:47.836 DEBUG [OpcTcpServerConnection] – handleSymmChunk: secureMessageBuilder=token=SecurityToken(Id=1, secureChannelId=1, creationTime=12.10.2015 13:31:47, lifetime=3600000), secureChannelId=null, more=true
2015-10-12 13:31:47.836 DEBUG [SecureInputMessageBuilder] – addChunk: expectedSequenceNumber=2
2015-10-12 13:31:47.836 DEBUG [SecureInputMessageBuilder] – token: SecurityToken(Id=1, secureChannelId=1, creationTime=12.10.2015 13:31:47, lifetime=3600000)
2015-10-12 13:31:47.842 DEBUG [OpcTcpServerConnection] – GetEndpointsRequest
2015-10-12 13:31:47.842 DEBUG [OpcTcpServerSecureChannel] – onSecureMessage: server=Server urn:LT346.iteratec.de:UA:i2subst
2015-10-12 13:31:47.842 DEBUG [OpcTcpServerSecureChannel] – onSecureMessage: endpoint= [[http://opcfoundation.org/UA/SecurityPolicy#None,None], [http://opcfoundation.org/UA/SecurityPolicy#Basic128Rsa15,Sign], [http://opcfoundation.org/UA/SecurityPolicy#Basic128Rsa15,SignAndEncrypt], [http://opcfoundation.org/UA/SecurityPolicy#Basic256,Sign], [http://opcfoundation.org/UA/SecurityPolicy#Basic256,SignAndEncrypt]]
2015-10-12 13:31:47.842 DEBUG [ServiceHandlerComposition] – serve: GetEndpointsRequest
2015-10-12 13:31:47.842 DEBUG [ServiceHandlerComposition] – serve: handlerMap=[class org.opcfoundation.ua.core.GetEndpointsRequest]
2015-10-12 13:31:47.842 DEBUG [ServiceHandlerComposition] – serve: handler=org.opcfoundation.ua.application.ServiceHandlerComposition$1@7e9224cc
2015-10-12 13:31:47.842 DEBUG [EndpointDiscoveryService] – onGetEndpoints: requestAddress=/192.168.176.36:52520
2015-10-12 13:31:47.842 DEBUG [EndpointDiscoveryService] – onGetEndpoints: requestUrl=opc.tcp://192.168.176.36:52520/i2subst
2015-10-12 13:31:47.842 DEBUG [EndpointDiscoveryService] – onGetEndpoints: host=192.168.176.36
2015-10-12 13:31:47.842 DEBUG [EndpointDiscoveryService] – onGetEndpoints: serverName=i2subst
2015-10-12 13:31:47.843 DEBUG [EndpointDiscoveryService] – onGetEndpoints: profileUris=[http://opcfoundation.org/UA-Profile/Transport/uatcp-uasc-uabinary]
2015-10-12 13:31:47.844 DEBUG [EndpointDiscoveryService] – ed.TransportProfileUri=http://opcfoundation.org/UA-Profile/Transport/uatcp-uasc-uabinary
2015-10-12 13:31:47.844 DEBUG [EndpointDiscoveryService] – ed.EndpointUrl=opc.tcp://LT346.iteratec.de:52520/i2subst
2015-10-12 13:31:47.845 DEBUG [EndpointDiscoveryService] – ed.TransportProfileUri=http://opcfoundation.org/UA-Profile/Transport/uatcp-uasc-uabinary
2015-10-12 13:31:47.845 DEBUG [EndpointDiscoveryService] – ed.EndpointUrl=opc.tcp://LT346.iteratec.de:52520
2015-10-12 13:31:47.845 DEBUG [EndpointDiscoveryService] – onGetEndpoints: no matching endpoints for requested hostname, checking all with the same serverName
2015-10-12 13:31:47.846 DEBUG [EndpointDiscoveryService] – ed.EndpointUrl=opc.tcp://LT346.iteratec.de:52520/i2subst
2015-10-12 13:31:47.850 DEBUG [OpcTcpServerConnection] – onStateTransition: Open->Closing
2015-10-12 13:31:47.850 INFO [OpcTcpServerSecureChannel] – Secure Channel closed, token=SecurityToken(Id=1, secureChannelId=1, creationTime=12.10.2015 13:31:47, lifetime=3600000)
2015-10-12 13:31:47.867 INFO [AbstractServerSecureChannel] – Channel closed: Id=1
2015-10-12 13:31:47.867 DEBUG [ListenableSocketChannel] – close: channel.isRegistered()=true
2015-10-12 13:31:47.874 DEBUG [ListenableSocketChannel] – close: channel.isOpen()=true
2015-10-12 13:31:47.874 DEBUG [ListenableSocketChannel] – closed
2015-10-12 13:31:47.874 DEBUG [ListenableSocketChannel] – close: ownsSelector=false
2015-10-12 13:31:47.874 DEBUG [OpcTcpServerConnection] – onStateTransition: Closing->Closed
2015-10-12 13:31:47.875 INFO [OpcTcpServerConnection] – Error in handleChunk
org.opcfoundation.ua.common.ServiceResultException: Bad_TcpSecureChannelUnknown (code=0x807F0000, description=”The SecureChannelId and/or TokenId are not currently in use.”)
at org.opcfoundation.ua.transport.tcp.nio.OpcTcpServerConnection.handleSymmChunk(Unknown Source)
at org.opcfoundation.ua.transport.tcp.nio.OpcTcpServerConnection.handleChunk(Unknown Source)
at org.opcfoundation.ua.transport.tcp.nio.OpcTcpServerConnection$3.onStateTransition(Unknown Source)
at org.opcfoundation.ua.transport.tcp.nio.OpcTcpServerConnection$3.onStateTransition(Unknown Source)
at org.opcfoundation.ua.utils.AbstractState$1.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2015-10-12 13:31:47.878 DEBUG [OpcTcpServerConnection] – onStateTransition: Closed->Closing
2015-10-12 13:31:47.878 DEBUG [ListenableSocketChannel] – close: channel.isRegistered()=false
2015-10-12 13:31:47.878 DEBUG [ListenableSocketChannel] – close: channel.isOpen()=false
2015-10-12 13:31:47.878 DEBUG [ListenableSocketChannel] – close: ownsSelector=false
2015-10-12 13:31:47.878 DEBUG [OpcTcpServerConnection] – onStateTransition: Closing->Closed
2015-10-12 13:31:47.875 DEBUG [ListenableSocketChannel] – ListenableSocketChannel: channel=java.nio.channels.SocketChannel[connected local=/192.168.176.36:52520 remote=/192.168.176.36:59573]
2015-10-12 13:31:47.879 INFO [OpcTcpServer] – OpcTcpServer(opc.tcp(/192.168.154.1:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))opc.tcp(/192.168.75.1:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))opc.tcp(/192.168.56.1:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))opc.tcp(/192.168.176.36:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))opc.tcp(/127.0.0.1:52520, (opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]])(opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]))): /192.168.176.36:59573 connected
2015-10-12 13:31:47.879 DEBUG [OpcTcpServerConnection] – onStateTransition: Closed->Opening
2015-10-12 13:31:47.880 DEBUG [OpcTcpServerConnection] – addConnectionListener: listener=org.opcfoundation.ua.transport.tcp.nio.OpcTcpServer$1$1@430334d8
2015-10-12 13:31:47.880 DEBUG [OpcTcpServerConnection] – onHello: url=opc.tcp://LT346.iteratec.de:52520/i2subst
2015-10-12 13:31:47.880 DEBUG [OpcTcpServerConnection] – endpoints=[opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]], opc.tcp://LT346.iteratec.de:52520 [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]]
2015-10-12 13:31:47.880 DEBUG [OpcTcpServerConnection] – endpoint=opc.tcp://LT346.iteratec.de:52520/i2subst [[http://opcfoundation.org/UA/SecurityPolicy#None,None]]
2015-10-12 13:31:47.881 DEBUG [OpcTcpServerConnection] – onStateTransition: Opening->Open

October 13, 2015
12:03, EEST
Avatar
Jouni Aro
Moderator
Moderators
Forum Posts: 1026
Member Since:
December 21, 2011
sp_UserOfflineSmall Offline
sp_UserWebsite
Go to Top
8sp_Permalink sp_Print

It seems that the channel is closed and the error is logger after that. Since it is logged at INFO level, I would say that it’s “normal” in this context – especially if everything seems to work without problems.

The normal sequence when the connection is made is that the client opens a non-secure channel where it makes the GetEndpoints request; then it closes that one and finally opens a new channel for the actual session, which is then used during the rest of the communication.

No permission to create posts
sp_Feed All RSS
Go to top
Forum Timezone: Europe/Helsinki

Most Users Ever Online: 1919

Currently Online:
14 Guest(s)

Currently Browsing this Page:
1 Guest(s)

Top Posters:

Heikki Tahvanainen: 402

hbrackel: 144

rocket science: 88

pramanj: 86

Francesco Zambon: 83

Ibrahim: 78

Sabari: 62

kapsl: 57

gjevremovic: 49

Xavier: 43

Member Stats:

Guest Posters: 0

Members: 738

Moderators: 7

Admins: 1

Forum Stats:

Groups: 3

Forums: 15

Topics: 1524

Posts: 6451

Newest Members:

jonathonmcintyre, fannielima, kristiewinkle8, rust, christamcdowall, redaahern07571, nigelbdhmp, travistimmons, AnnelCib, dalenegettinger

Moderators: Jouni Aro: 1026, Pyry: 1, Petri: 0, Bjarne Boström: 1026, Jimmy Ni: 26, Matti Siponen: 346, Lusetti: 0

Administrators: admin: 1