18:29, EEST
March 16, 2017
Hi,
we have some problems to get a stable connection to a Siemens Sinumerik 840 v4.4 (we connect with the Prosys version 2-3-0_764).
Here the detailed version information of the used OPC UA Server:
2017-09-01 06:44:27,928 DEBUG [main] com.prosysopc.ua.client.AddressSpace: getNode: nodeId=i=45 node=NodeId=i=45, NodeClass=ReferenceType, BrowseName=HasSubtype, IsAbstract=false, Symmetric=false, InverseName=(en_us) HasSupertype
2017-09-01 06:44:27,928 DEBUG [main] com.prosysopc.ua.client.nodes.UaClientReference: getIsInverse: nodeId=i=25 sourceId=nsu=http%3A%2F%2Fopcfoundation.org%2FUA%2F;i=24 targetId=nsu=http%3A%2F%2Fopcfoundation.org%2FUA%2F;i=25
2017-09-01 06:44:28,374 DEBUG [main] com.prosysopc.ua.client.AddressSpace: getNode: nodeId=i=11704 node=null
2017-09-01 06:44:28,390 DEBUG [main] com.prosysopc.ua.client.AddressSpace: classValues: [DataValue(value=(null), statusCode=Bad_AttributeIdInvalid (0x80350000) “The attribute is not supported for the specified Node.”, sourceTimestamp=null, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0), DataValue(value=(null), statusCode=Bad_AttributeIdInvalid (0x80350000) “The attribute is not supported for the specified Node.”, sourceTimestamp=null, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0), DataValue(value=(null), statusCode=Bad_AttributeIdInvalid (0x80350000) “The attribute is not supported for the specified Node.”, sourceTimestamp=null, sourcePicoseconds=0, serverTimestamp=null, serverPicoseconds=0)]
2017-09-01 06:44:28,390 DEBUG [main] com.prosysopc.ua.client.AddressSpace: NodeClass: null
2017-09-01 06:44:28,499 INFO [main] de.znt.services.opcua.OpcUaServiceImpl: ServerStatus: ServerStatusDataType: ServerStatusDataType
StartTime=08/30/17 11:22:14.9980000 GMT
CurrentTime=09/01/17 04:49:36.1880000 GMT
State=ServerState
name=Running
ordinal=0
BuildInfo=BuildInfo
ProductUri=http://automation.siemens.com
ManufacturerName=Siemens AG I DT MC
ProductName=Sinumerik OPC UA
SoftwareVersion=4.4.0
BuildNumber=2
BuildDate=01/24/17 15:17:18.0000000 GMT
SecondsTillShutdown=0
ShutdownReason=null
Basically, every 5 seconds we read items from this OPC UA server. For reading the nodes we use following method from the UaClient:
public ReadResponse read(Double paramDouble, TimestampsToReturn paramTimestampsToReturn, ReadValueId[] paramArrayOfReadValueId) throws ServiceException
we use following procdure to connect to the UA Server:
UaClient _client = new UaClient(_serverUri);
ApplicationDescription appDescription = new ApplicationDescription();
appDescription.setApplicationName(new LocalizedText(“myServiceName”, Locale.ENGLISH));
appDescription.setApplicationUri(“urn:localhost:myCompany:myServiceName”);
appDescription.setProductUri(“urn:myDomain.com:service:myServiceName”);
appDescription.setApplicationType(ApplicationType.Client);
_client.setTimeout(getTimeout());
_client.setStatusCheckTimeout(10000);
_client.setAutoReconnect(true);
_client.setSecurityMode(SecurityMode.NONE);
_client.setSessionName(“myServiceName Session” + ++_sessionCount);
_client.connect();
In general it works, but every 30 seconds up to 3 minutes we get a bad response with ‘org.opcfoundation.ua.common.ServiceResultException: Bad_SecureChannelClosed (code=0x80860000, description=”The secure channel has been closed.”)’ while reading the values of the nodes.
So reading the nodes every 5 seconds works for some time
2017-08-30 10:11:46,325 INFO [Thread-172977] PollOpcUaData ###OpcUa### START read for nodeIdentifiers
2017-08-30 10:11:47,107 INFO [Thread-172977] PollOpcUaData ###OpcUa### END read for nodeIdentifiers
2017-08-30 10:11:47,107 INFO [Thread-172977] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBW0 with value DataValue(value=65535, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:18:17.3430000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:18:18.0480000 GMT, serverPicoseconds=0)
2017-08-30 10:11:47,107 INFO [Thread-172977] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBW2 with value DataValue(value=2993, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:18:17.3610000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:18:18.0480000 GMT, serverPicoseconds=0)
2017-08-30 10:11:47,107 INFO [Thread-172977] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBX4.0 with value DataValue(value=false, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:18:17.3810000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:18:18.0480000 GMT, serverPicoseconds=0)
2017-08-30 10:11:47,107 INFO [Thread-172977] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBX4.1 with value DataValue(value=true, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:18:17.4170000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:18:18.0480000 GMT, serverPicoseconds=0)
but then, we suddenly get a Bad_SecureChannelClosed exception
2017-08-30 10:11:51,329 INFO [Thread-172979] PollOpcUaData ###OpcUa### START read for nodeIdentifiers
2017-08-30 10:12:02,679 DEBUG [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.impl.AsyncResultImpl: error:
2017-08-30 10:12:02,779 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.io.SecureChannelTcp: 51980 Closed
2017-08-30 10:12:02,779 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.io.TcpConnection: /10.3.179.21:4840 Closed
2017-08-30 10:12:02,779 DEBUG [Thread-172979] org.opcfoundation.ua.transport.impl.AsyncResultImpl: error:
org.opcfoundation.ua.common.ServiceResultException: Bad_SecureChannelClosed (code=0x80860000, description=”The secure channel has been closed.”)
at org.opcfoundation.ua.transport.tcp.io.SecureChannelTcp.close(Unknown Source)
at org.opcfoundation.ua.application.SessionChannel.closeSecureChannel(Unknown Source)
at com.prosysopc.ua.client.UaClient.m(Unknown Source)
at com.prosysopc.ua.client.UaClient.reconnect(Unknown Source)
at com.prosysopc.ua.client.UaClient$a.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2017-08-30 10:12:02,780 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.io.TcpConnection: /10.3.179.21:4840 Connecting
2017-08-30 10:12:02,779 INFO [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.io.TcpConnection: /10.3.179.21:4840 Closed (expected)
The UaClient reconnects
2017-08-30 10:12:12,134 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.io.TcpConnection: /10.3.179.21:4840 Connected
2017-08-30 10:12:12,134 DEBUG [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.utils.CryptoUtil: createNonce: bytes=0
2017-08-30 10:12:12,134 DEBUG [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmEncryptSigner: SecurityMode in asymm enc: 1
2017-08-30 10:12:12,136 DEBUG [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmDecryptVerifier: SecurityPolicy in use: http://opcfoundation.org/UA/SecurityPolicy#None
2017-08-30 10:12:12,136 DEBUG [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmDecryptVerifier: SecurityMode in use: None
2017-08-30 10:12:12,138 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] com.prosysopc.ua.client.UaClient: reconnect: Reconnected to server (session reactivated)
and reading the nodes every 5 secs start working again (for a few minutes)
2017-08-30 10:12:16,423 INFO [Thread-172988] PollOpcUaData ###OpcUa### START read for nodeIdentifiers
2017-08-30 10:12:17,254 INFO [Thread-172988] PollOpcUaData ###OpcUa### END read for nodeIdentifiers
2017-08-30 10:12:17,255 INFO [Thread-172988] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBW0 with value DataValue(value=65535, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:18:47.4760000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:18:48.2230000 GMT, serverPicoseconds=0)
2017-08-30 10:12:17,255 INFO [Thread-172988] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBW2 with value DataValue(value=2993, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:18:47.4930000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:18:48.2230000 GMT, serverPicoseconds=0)
2017-08-30 10:12:17,255 INFO [Thread-172988] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBX4.0 with value DataValue(value=false, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:18:47.5330000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:18:48.2230000 GMT, serverPicoseconds=0)
2017-08-30 10:12:17,255 INFO [Thread-172988] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBX4.1 with value DataValue(value=true, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:18:47.5730000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:18:48.2230000 GMT, serverPicoseconds=0)
…..
…..
2017-08-30 10:14:26,578 INFO [Thread-173044] PollOpcUaData ###OpcUa### START read for nodeIdentifiers
2017-08-30 10:14:27,375 INFO [Thread-173044] PollOpcUaData ###OpcUa### END read for nodeIdentifiers
2017-08-30 10:14:27,375 INFO [Thread-173044] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBW0 with value DataValue(value=65535, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:20:57.5900000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:20:58.3360000 GMT, serverPicoseconds=0)
2017-08-30 10:14:27,375 INFO [Thread-173044] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBW2 with value DataValue(value=2993, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:20:57.6080000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:20:58.3360000 GMT, serverPicoseconds=0)
2017-08-30 10:14:27,375 INFO [Thread-173044] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBX4.0 with value DataValue(value=false, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:20:57.6300000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:20:58.3360000 GMT, serverPicoseconds=0)
2017-08-30 10:14:27,375 INFO [Thread-173044] PollOpcUaData ###OpcUa### Read value /Random/Plc/DB310.DBX4.1 with value DataValue(value=true, statusCode=GOOD (0x00000000) “”, sourceTimestamp=08/30/17 08:20:57.6650000 GMT, sourcePicoseconds=0, serverTimestamp=08/30/17 08:20:58.3360000 GMT, serverPicoseconds=0)
until the Bad_SecureChannelClosed happens again
2017-08-30 10:14:31,579 INFO [Thread-173046] PollOpcUaData ###OpcUa### START read for nodeIdentifiers
2017-08-30 10:14:42,759 DEBUG [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.impl.AsyncResultImpl: error:
2017-08-30 10:14:42,859 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.io.SecureChannelTcp: 51981 Closed
2017-08-30 10:14:42,859 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.io.TcpConnection: /10.3.179.21:4840 Closed
2017-08-30 10:14:42,859 INFO [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.io.TcpConnection: /10.3.179.21:4840 Closed (expected)
2017-08-30 10:14:42,859 DEBUG [Thread-173046] org.opcfoundation.ua.transport.impl.AsyncResultImpl: error:
org.opcfoundation.ua.common.ServiceResultException: Bad_SecureChannelClosed (code=0x80860000, description=”The secure channel has been closed.”)
at org.opcfoundation.ua.transport.tcp.io.SecureChannelTcp.close(Unknown Source)
at org.opcfoundation.ua.application.SessionChannel.closeSecureChannel(Unknown Source)
at com.prosysopc.ua.client.UaClient.m(Unknown Source)
at com.prosysopc.ua.client.UaClient.reconnect(Unknown Source)
at com.prosysopc.ua.client.UaClient$a.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2017-08-30 10:14:42,860 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.io.TcpConnection: /10.3.179.21:4840 Connecting
The UaClient connects again
2017-08-30 10:14:52,080 DEBUG [Blocking-Work-Executor-49] org.opcfoundation.ua.utils.CryptoUtil: createNonce: bytes=0
2017-08-30 10:14:52,080 DEBUG [Blocking-Work-Executor-56] org.opcfoundation.ua.utils.CryptoUtil: createNonce: bytes=0
2017-08-30 10:14:52,080 DEBUG [Blocking-Work-Executor-56] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmEncryptSigner: SecurityMode in asymm enc: 1
2017-08-30 10:14:52,080 DEBUG [Blocking-Work-Executor-49] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmEncryptSigner: SecurityMode in asymm enc: 1
2017-08-30 10:14:52,412 DEBUG [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmDecryptVerifier: SecurityPolicy in use: http://opcfoundation.org/UA/SecurityPolicy#None
2017-08-30 10:14:52,412 DEBUG [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmDecryptVerifier: SecurityMode in use: None
2017-08-30 10:14:52,412 DEBUG [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmDecryptVerifier: SecurityPolicy in use: http://opcfoundation.org/UA/SecurityPolicy#None
2017-08-30 10:14:52,412 DEBUG [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmDecryptVerifier: SecurityMode in use: None
2017-08-30 10:14:52,412 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.io.TcpConnection: /10.3.179.21:4840 Connected
2017-08-30 10:14:52,412 DEBUG [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.utils.CryptoUtil: createNonce: bytes=0
2017-08-30 10:14:52,412 DEBUG [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmEncryptSigner: SecurityMode in asymm enc: 1
2017-08-30 10:14:52,412 DEBUG [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmDecryptVerifier: SecurityPolicy in use: http://opcfoundation.org/UA/SecurityPolicy#None
2017-08-30 10:14:52,412 DEBUG [TcpConnection/Read] org.opcfoundation.ua.transport.tcp.impl.ChunkAsymmDecryptVerifier: SecurityMode in use: None
2017-08-30 10:14:52,412 INFO [PublishTask-com.prosysopc.ua.client.UaClient@e4b740] com.prosysopc.ua.client.UaClient: reconnect: Reconnected to server (session reactivated)
and reading of the Nodes is possible for the next minutes ….. and so on ….
Does anybody have an idea what could be the problem?
12:51, EEST
March 16, 2017
16:20, EEST
April 17, 2013
Hi,
The error message states ServiceResultException: Bad_SecureChannelClosed (code=0x80860000, description=”The secure channel has been closed.”)
It seems that the connection initially works but after a certain period the server application closes the connection. You should inspect the server application and find out what is the reason for closing the connection. The reason is not visible from this log file.
Most Users Ever Online: 1919
Currently Online:
16 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: 736
Moderators: 7
Admins: 1
Forum Stats:
Groups: 3
Forums: 15
Topics: 1524
Posts: 6450
Newest Members:
kristiewinkle8, rust, christamcdowall, redaahern07571, nigelbdhmp, travistimmons, AnnelCib, dalenegettinger, howardkennerley, ThomassnismModerators: Jouni Aro: 1026, Pyry: 1, Petri: 0, Bjarne Boström: 1026, Jimmy Ni: 26, Matti Siponen: 346, Lusetti: 0
Administrators: admin: 1