search

Azure / Industrial-IoT

Azure Industrial IoT Platform
MIT License
524 stars 214 forks source link

opc publisher cannot connect to containerized OPC UA server #377

Closed ghost closed 4 years ago

ghost commented 4 years ago

Describe the bug Telemetry is being received from opc-plc to IoTHub, however telemetry from TKS is not making it to IoTHub. When connecting UAExpert to TKS, telemetry is being read as expected, so the messages seem to be falling down in the publisher module. Publisher logs are showing an exception while processing a new job, screenshots of the logs are below.

To Reproduce Steps to reproduce the behavior:

Expected behavior Publisher should be processing jobs without issue and sending telemetry messages to the IoTHub in the deployment. Currently, no telemetry messages are being received in IoTHub.

Desktop (please complete the following information):

Logs Publisher Logs


[12:39:18 ERR] Exception during worker execution.  Continue... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
Newtonsoft.Json.JsonSerializationException: Error converting value "StatusCode, SourceTimestamp, ServerTimestamp, NodeId, DisplayName, EndpointUrl, ApplicationUri, SubscriptionId, ExtraFields" to type 'System.Nullable`1[Microsoft.Azure.IIoT.OpcUa.Publisher.Models.DataSetFieldContentMask]'. Path 'writerGroup.dataSetWriters[0].dataSetFieldContentMask'.
 ---> System.ArgumentException: Requested value 'StatusCode, SourceTimestamp, ServerTimestamp, NodeId, DisplayName, EndpointUrl, ApplicationUri, SubscriptionId, ExtraFields' was not found.
   at Newtonsoft.Json.Utilities.EnumUtils.ParseEnum(Type enumType, NamingStrategy namingStrategy, String value, Boolean disallowNumber)
   at Newtonsoft.Json.Converters.StringEnumConverter.ReadJson(JsonReader reader, Type objectType, Object existingValue, JsonSerializer serializer)
   --- End of inner exception stack trace ---
   at Newtonsoft.Json.Converters.StringEnumConverter.ReadJson(JsonReader reader, Type objectType, Object existingValue, JsonSerializer serializer)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.DeserializeConvertable(JsonConverter converter, JsonReader reader, Type objectType, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.SetPropertyValue(JsonProperty property, JsonConverter propertyConverter, JsonContainerContract containerContract, JsonProperty containerProperty, JsonReader reader, Object target)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateObject(Object newObject, JsonReader reader, JsonObjectContract contract, JsonProperty member, String id)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateObject(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateValueInternal(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateList(IList list, JsonReader reader, JsonArrayContract contract, JsonProperty containerProperty, String id)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateList(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, Object existingValue, String id)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateValueInternal(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.SetPropertyValue(JsonProperty property, JsonConverter propertyConverter, JsonContainerContract containerContract, JsonProperty containerProperty, JsonReader reader, Object target)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateObject(Object newObject, JsonReader reader, JsonObjectContract contract, JsonProperty member, String id)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateObject(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateValueInternal(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.SetPropertyValue(JsonProperty property, JsonConverter propertyConverter, JsonContainerContract containerContract, JsonProperty containerProperty, JsonReader reader, Object target)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateObject(Object newObject, JsonReader reader, JsonObjectContract contract, JsonProperty member, String id)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateObject(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateValueInternal(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.Deserialize(JsonReader reader, Type objectType, Boolean checkAdditionalContent)
   at Newtonsoft.Json.JsonSerializer.DeserializeInternal(JsonReader reader, Type objectType)
   at Newtonsoft.Json.Linq.JToken.ToObject(Type objectType, JsonSerializer jsonSerializer)
   at Newtonsoft.Json.Linq.JToken.ToObject(Type objectType)
   at Newtonsoft.Json.Linq.JToken.ToObject[T]()
   at Microsoft.Azure.IIoT.Modules.OpcUa.Publisher.Agent.PublisherJobsConfiguration.PublisherJobSerializer.DeserializeJobConfiguration(JToken model, String jobConfigurationType) in D:\a\1\s\modules\src\Microsoft.Azure.IIoT.Modules.OpcUa.Publisher\src\Agent\PublisherJobsConfiguration.cs:line 32
   at Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker.JobProcess..ctor(Worker outer, JobProcessingInstructionModel jobProcessInstruction, ILifetimeScope workerScope, ILogger logger) in D:\a\1\s\common\src\Microsoft.Azure.IIoT.Agent.Framework\src\Agent\Default\Worker.cs:line 262
   at Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker.ProcessAsync(JobProcessingInstructionModel jobProcessInstruction, CancellationToken ct) in D:\a\1\s\common\src\Microsoft.Azure.IIoT.Agent.Framework\src\Agent\Default\Worker.cs:line 212
   at Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker.RunAsync(CancellationToken ct) in D:\a\1\s\common\src\Microsoft.Azure.IIoT.Agent.Framework\src\Agent\Default\Worker.cs:line 185```
marcschier commented 4 years ago

Thanks for letting us know, I assume you deployed from master a 2.7 build against 2.6. modules?

ghost commented 4 years ago

Deployment scripts were used when master was at 2.6 against 2.6 modules

marcschier commented 4 years ago

We released 2.6.146 - can you try with the released module + services as this is a core test case for us this should be working for you with the release version.

ghost commented 4 years ago

I have created deployment that is using 2.6.146 services and edge modules. I am able to activate a TKE server and browse its nodes, however, when try to start publishing nodes I see an error in the publisher module, posted below. I should not that the opc-plc server works as intended - I can monitor telemetry being published.


[20:29:09 INF] 0: Device DataSetWriterV2_uatd1fce0b8f22e02255edafbb96b686699265c1fc7 reconnected due to Connection_Ok. (Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory)
[20:29:11 INF] Trying to create session 8d86b6d50efd6263b2e2bbf7bd80a281b283aaf2... (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager)
[20:29:12 INF] 8d86b6d50efd6263b2e2bbf7bd80a281b283aaf2 took 00:00:00.6319819. (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager)
[20:29:12 ERR] Failed apply monitored items. (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper)
Opc.Ua.ServiceResultException: Error establishing a connection: Error received from remote host: An error occurred verifying security.
   at Opc.Ua.Bindings.ChannelAsyncOperation`1.End(Int32 timeout, Boolean throwOnError)
   at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.SendRequest(IServiceRequest request)
   at Opc.Ua.SessionClient.CreateSession(RequestHeader requestHeader, ApplicationDescription clientDescription, String serverUri, String endpointUrl, String sessionName, Byte[] clientNonce, Byte[] clientCertificate, Double requestedSessionTimeout, UInt32 maxResponseMessageSize, NodeId& sessionId, NodeId& authenticationToken, Double& revisedSessionTimeout, Byte[]& serverNonce, Byte[]& serverCertificate, EndpointDescriptionCollection& serverEndpoints, SignedSoftwareCertificateCollection& serverSoftwareCertificates, SignatureData& serverSignature, UInt32& maxRequestMessageSize)
   at Opc.Ua.Client.Session.Open(String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales, Boolean checkDomain)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, Boolean checkDomain, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.GetOrCreateSessionAsync(ConnectionModel connection, Boolean createIfNotExists) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 70
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscriptionAsync(SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 415
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 162
[20:29:12 ERR] Error processing job uatd1fce0b8f22e02255edafbb96b686699265c1fc7. (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker+JobProcess)
Opc.Ua.ServiceResultException: Error establishing a connection: Error received from remote host: An error occurred verifying security.
   at Opc.Ua.Bindings.ChannelAsyncOperation`1.End(Int32 timeout, Boolean throwOnError)
   at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.SendRequest(IServiceRequest request)
   at Opc.Ua.SessionClient.CreateSession(RequestHeader requestHeader, ApplicationDescription clientDescription, String serverUri, String endpointUrl, String sessionName, Byte[] clientNonce, Byte[] clientCertificate, Double requestedSessionTimeout, UInt32 maxResponseMessageSize, NodeId& sessionId, NodeId& authenticationToken, Double& revisedSessionTimeout, Byte[]& serverNonce, Byte[]& serverCertificate, EndpointDescriptionCollection& serverEndpoints, SignedSoftwareCertificateCollection& serverSoftwareCertificates, SignatureData& serverSignature, UInt32& maxRequestMessageSize)
   at Opc.Ua.Client.Session.Open(String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales, Boolean checkDomain)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, Boolean checkDomain, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.GetOrCreateSessionAsync(ConnectionModel connection, Boolean createIfNotExists) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 70
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscriptionAsync(SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 415
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 162
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 176
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.WriterGroupMessageTrigger.DataSetWriterSubscription.OpenAsync(CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\WriterGroupMessageSource.cs:line 127
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.WriterGroupMessageTrigger.RunAsync(CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\WriterGroupMessageSource.cs:line 63
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine.RunAsync(ProcessMode processMode, CancellationToken cancellationToken) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\DataFlowProcessingEngine.cs:line 105
   at Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker.JobProcess.ProcessAsync() in D:\a\1\s\common\src\Microsoft.Azure.IIoT.Agent.Framework\src\Agent\Default\Worker.cs:line 320
[20:29:12 INF] 1: Device DataSetWriterV2_uatd1fce0b8f22e02255edafbb96b686699265c1fc7 disconnected due to Client_Close - now Disabled... (Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory)
[20:29:12 INF] Worker: linux-gateway_publisher_4, Job: uatd1fce0b8f22e02255edafbb96b686699265c1fc7 processing completed ...  (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)```
pc-avatar-7076 commented 4 years ago

@marcschier I deployed 2.6.146 services and edge modules using your helm chart. I have flowing telemetry using Opc PLC, but hit the same exception as @cstamper-ptc (above) when creating monitored item subscriptions for TKE.

I enabled debug level logging on the publisher but didn't see any useful extra information (see below). It seems odd that the command and control (endpoint discovery, address space discovery) functions work normally, but monitored item subscriptions suffer security related failures on session creation. We will plan to debug this from our (UA server) side. 


[20:24:38 DBG] [GenerateToken] Informational: DeviceAuthenticationWithSakRefresh#61905785 2020-04-28T20:24:38.8008171Z 2020-04-28T21:24:39.0000000Z  (Microsoft.Azure.Devices.Device.Client)
[20:24:38 INF] 0: Device DataSetWriterV2_uat54b84e0bd50c5b8d4b01541aa69637959401f27a reconnected due to Connection_Ok. (Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory)
[20:24:39 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:39 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:39 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:39 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:39 DBG] Sending job processor heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker+JobProcess)
[20:24:40 INF] Trying to create session 94cd98e484d3d6066677fb93a4265825b55c5a28... (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager)
[20:24:41 INF] 94cd98e484d3d6066677fb93a4265825b55c5a28 took 00:00:00.6256206. (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager)
[20:24:41 ERR] Failed apply monitored items. (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper)
Opc.Ua.ServiceResultException: Error establishing a connection: Error received from remote host: An error occurred verifying security.
   at Opc.Ua.Bindings.ChannelAsyncOperation`1.End(Int32 timeout, Boolean throwOnError)
   at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.SendRequest(IServiceRequest request)
   at Opc.Ua.SessionClient.CreateSession(RequestHeader requestHeader, ApplicationDescription clientDescription, String serverUri, String endpointUrl, String sessionName, Byte[] clientNonce, Byte[] clientCertificate, Double requestedSessionTimeout, UInt32 maxResponseMessageSize, NodeId& sessionId, NodeId& authenticationToken, Double& revisedSessionTimeout, Byte[]& serverNonce, Byte[]& serverCertificate, EndpointDescriptionCollection& serverEndpoints, SignedSoftwareCertificateCollection& serverSoftwareCertificates, SignatureData& serverSignature, UInt32& maxRequestMessageSize)
   at Opc.Ua.Client.Session.Open(String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales, Boolean checkDomain)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, Boolean checkDomain, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.GetOrCreateSessionAsync(ConnectionModel connection, Boolean createIfNotExists) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 70
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscriptionAsync(SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 415
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 162
[20:24:41 ERR] Error processing job uat54b84e0bd50c5b8d4b01541aa69637959401f27a. (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker+JobProcess)
Opc.Ua.ServiceResultException: Error establishing a connection: Error received from remote host: An error occurred verifying security.
   at Opc.Ua.Bindings.ChannelAsyncOperation`1.End(Int32 timeout, Boolean throwOnError)
   at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.SendRequest(IServiceRequest request)
   at Opc.Ua.SessionClient.CreateSession(RequestHeader requestHeader, ApplicationDescription clientDescription, String serverUri, String endpointUrl, String sessionName, Byte[] clientNonce, Byte[] clientCertificate, Double requestedSessionTimeout, UInt32 maxResponseMessageSize, NodeId& sessionId, NodeId& authenticationToken, Double& revisedSessionTimeout, Byte[]& serverNonce, Byte[]& serverCertificate, EndpointDescriptionCollection& serverEndpoints, SignedSoftwareCertificateCollection& serverSoftwareCertificates, SignatureData& serverSignature, UInt32& maxRequestMessageSize)
   at Opc.Ua.Client.Session.Open(String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales, Boolean checkDomain)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, Boolean checkDomain, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.GetOrCreateSessionAsync(ConnectionModel connection, Boolean createIfNotExists) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 70
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscriptionAsync(SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 415
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 162
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 176
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.WriterGroupMessageTrigger.DataSetWriterSubscription.OpenAsync(CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\WriterGroupMessageSource.cs:line 127
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.WriterGroupMessageTrigger.RunAsync(CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\WriterGroupMessageSource.cs:line 63
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine.RunAsync(ProcessMode processMode, CancellationToken cancellationToken) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\DataFlowProcessingEngine.cs:line 105
   at Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker.JobProcess.ProcessAsync() in D:\a\1\s\common\src\Microsoft.Azure.IIoT.Agent.Framework\src\Agent\Default\Worker.cs:line 320
[20:24:41 DBG] Update completion status for uat54b84e0bd50c5b8d4b01541aa69637959401f27a. (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker+JobProcess)
[20:24:41 DBG] Sending job processor heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker+JobProcess)
[20:24:41 DBG] [Info] Informational: MqttTransportHandler#3950794 OnTransportClosedGracefully OnTransportClosedGracefully  (Microsoft.Azure.Devices.Device.Client)
[20:24:41 DBG] [Info] Informational: MqttTransportHandler#3950794 OnTransportClosedGracefully OnTransportClosedGracefully  (Microsoft.Azure.Devices.Device.Client)
[20:24:41 DBG] [Info] Informational: RetryDelegatingHandler#12933519 HandleDisconnect Transport disconnected: closed by application.  (Microsoft.Azure.Devices.Device.Client)
[20:24:41 DBG] [Info] Informational: RetryDelegatingHandler#12933519 HandleDisconnect Transport disconnected: closed by application.  (Microsoft.Azure.Devices.Device.Client)
[20:24:41 INF] 1: Device DataSetWriterV2_uat54b84e0bd50c5b8d4b01541aa69637959401f27a disconnected due to Client_Close - now Disabled... (Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory)
[20:24:41 INF] Worker: wheeler-iiot-device_publisher_3, Job: uat54b84e0bd50c5b8d4b01541aa69637959401f27a processing completed ...  (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:41 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:41 DBG] Try querying available job... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:41 INF] Worker: wheeler-iiot-device_publisher_3, no job received, wait 00:00:10 ... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:42 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:42 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:42 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[20:24:42 DBG] Sending heartbeat... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)```
marcschier commented 4 years ago

Hi @cstamper-ptc, @pcameron-ptc - The problem is that the publisher tries resolving the host in the url reported by the server rather than using the actual IP address / host name found during discovery (the one from the container).

You can validate that if a) browse works since twin does not have this issue, and b) Kepserver works as the host name can be resolved. If so this is fixed now in 2.7.

pc-avatar-7076 commented 4 years ago

Hello @marcschier - thank you for your response. I can confirm that "browse" behaves normally when executed against my containerized TKE instance.

Regarding your comment - I will stand up a "standalone" (non-containerized) instance of TKE to test your assertion, but I'm confused as to why Opc PLC doesn't fail in the same way since it's also running in a container.

For both Opc PLC and TKE, I am activating using the 'explicit' (non-port scanning) method of posting to https://{{OPC-SERVICEURL}}/registry/v2/applications using a fully qualified DNS name (static IP)

TKE:
{
    "discoveryUrl": "opc.tcp://<prefix>.eastus.cloudapp.azure.com:49330"
}

OPC PLC:
{
    "discoveryUrl": "opc.tcp://<prefix>.eastus.cloudapp.azure.com:50000"
}
pc-avatar-7076 commented 4 years ago

Update: installed TKE "standalone" on an azure-hosted VM that is separate from the one running the IoT Edge Runtime (though on the same vnet). I hit the same problem when the publisher attempts to create a monitored item subscription on the standalone TKE instance (browse and other twin related activities work normally):


[18:37:57 INF] Worker: wheeler-iiot-device_publisher_3, no job received, wait 00:00:10 ... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[18:37:57 INF] 0: Device DataSetWriterV2_uat55e773f96dabd7cbf0b915a7b23dcf840a0846e6 reconnected due to Connection_Ok. (Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory)
[18:37:57 INF] Worker: wheeler-iiot-device_publisher_1, no job received, wait 00:00:10 ... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[18:37:59 INF] Trying to create session 58466afc89cfe72a28e7f47e37b4cc0fb63d1ebf... (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager)
[18:37:59 INF] 58466afc89cfe72a28e7f47e37b4cc0fb63d1ebf took 00:00:00.6065439. (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager)
[18:37:59 ERR] Failed apply monitored items. (Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper)
Opc.Ua.ServiceResultException: Error establishing a connection: Error received from remote host: An error occurred verifying security.
   at Opc.Ua.Bindings.ChannelAsyncOperation`1.End(Int32 timeout, Boolean throwOnError)
   at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.SendRequest(IServiceRequest request)
   at Opc.Ua.SessionClient.CreateSession(RequestHeader requestHeader, ApplicationDescription clientDescription, String serverUri, String endpointUrl, String sessionName, Byte[] clientNonce, Byte[] clientCertificate, Double requestedSessionTimeout, UInt32 maxResponseMessageSize, NodeId& sessionId, NodeId& authenticationToken, Double& revisedSessionTimeout, Byte[]& serverNonce, Byte[]& serverCertificate, EndpointDescriptionCollection& serverEndpoints, SignedSoftwareCertificateCollection& serverSoftwareCertificates, SignatureData& serverSignature, UInt32& maxRequestMessageSize)
   at Opc.Ua.Client.Session.Open(String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales, Boolean checkDomain)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, Boolean checkDomain, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.GetOrCreateSessionAsync(ConnectionModel connection, Boolean createIfNotExists) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 70
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscriptionAsync(SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 415
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 162
[18:37:59 ERR] Error processing job uat55e773f96dabd7cbf0b915a7b23dcf840a0846e6. (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker+JobProcess)
Opc.Ua.ServiceResultException: Error establishing a connection: Error received from remote host: An error occurred verifying security.
   at Opc.Ua.Bindings.ChannelAsyncOperation`1.End(Int32 timeout, Boolean throwOnError)
   at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.EndSendRequest(IAsyncResult result)
   at Opc.Ua.Bindings.UaSCUaBinaryTransportChannel.SendRequest(IServiceRequest request)
   at Opc.Ua.SessionClient.CreateSession(RequestHeader requestHeader, ApplicationDescription clientDescription, String serverUri, String endpointUrl, String sessionName, Byte[] clientNonce, Byte[] clientCertificate, Double requestedSessionTimeout, UInt32 maxResponseMessageSize, NodeId& sessionId, NodeId& authenticationToken, Double& revisedSessionTimeout, Byte[]& serverNonce, Byte[]& serverCertificate, EndpointDescriptionCollection& serverEndpoints, SignedSoftwareCertificateCollection& serverSoftwareCertificates, SignatureData& serverSignature, UInt32& maxRequestMessageSize)
   at Opc.Ua.Client.Session.Open(String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales, Boolean checkDomain)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, Boolean checkDomain, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Opc.Ua.Client.Session.Create(ApplicationConfiguration configuration, ConfiguredEndpoint endpoint, Boolean updateBeforeConnect, String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.GetOrCreateSessionAsync(ConnectionModel connection, Boolean createIfNotExists) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 70
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscriptionAsync(SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 415
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 162
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ApplyAsync(IEnumerable`1 monitoredItems, SubscriptionConfigurationModel configuration) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 176
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.WriterGroupMessageTrigger.DataSetWriterSubscription.OpenAsync(CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\WriterGroupMessageSource.cs:line 127
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.WriterGroupMessageTrigger.RunAsync(CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\WriterGroupMessageSource.cs:line 63
   at Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine.RunAsync(ProcessMode processMode, CancellationToken cancellationToken) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Edge.Publisher\src\Engine\DataFlowProcessingEngine.cs:line 105
   at Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker.JobProcess.ProcessAsync() in D:\a\1\s\common\src\Microsoft.Azure.IIoT.Agent.Framework\src\Agent\Default\Worker.cs:line 320
[18:37:59 INF] 1: Device DataSetWriterV2_uat55e773f96dabd7cbf0b915a7b23dcf840a0846e6 disconnected due to Client_Close - now Disabled... (Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory)
[18:37:59 INF] Worker: wheeler-iiot-device_publisher_0, Job: uat55e773f96dabd7cbf0b915a7b23dcf840a0846e6 processing completed ...  (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[18:37:59 INF] Worker: wheeler-iiot-device_publisher_0, no job received, wait 00:00:10 ... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[18:38:06 INF] Worker: wheeler-iiot-device_publisher_2, no job received, wait 00:00:10 ... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)
[18:38:07 INF] Worker: wheeler-iiot-device_publisher_4, no job received, wait 00:00:10 ... (Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker)```
pc-avatar-7076 commented 4 years ago

@marcschier it appears that the publisher is generating a new certificate each time a subscription is requested. Kepware does not have an "always accept" option like OPC PLC, so the session creation ultimately fails. We think this is the root cause of this issue.

Here TKE is running standalone (not in a container). This is TKE's certificate administration tool output. In this case, I've used the https://{{OPC-SERVICEURL}}/publisher/v2/publish/<endpoint>/start endpoint to request a monitored item subscription, then used the stop endpoint to stop the subscription. I repeated this operation three times. Trusting the certificate doesn't appear to alter the behavior: multiple-certs-tke

Here is the similar behavior when the publisher is asked to subscribe to a node on the standalone Windows (TKS) server: multiple-certs-tks

Do you know why the publisher is generating a fresh certificate each time a subscription is requested?

marcschier commented 4 years ago

Hi @pcameron-ptc - if the module does not find a certificate it creates a self signed certificate. Certificates are stored in the container certificate stores. Since containers do not have a persistent file system, the own certificate is lost when the module restarts. You can use a module manifest deployment json to configure a bind volume for persistence and point the modules to it using their command line arguments.

An example for the "createOptions" json in the manifest is below (targeting docker linux on windows):

Opc Twin:

{
                "Hostname": "opctwin",
                "Cmd": [
                                "PkiRootPath=/mount/pki"
                ],
                "HostConfig": {
                                "Binds": [
                                                "/host_mnt/c/mount:/mount"
                                ]
                },
                "Mounts": [
                                {
                                                "Type": "bind",
                                                "Source": "/host_mnt/c/mount",
                                                "Destination": "/mount"
                                }
                ]
}

Opc publisher

{
                "Hostname": "opcpublisher",
                "Cmd": [
                                "opcpublisher",
                                "--pf=/mount/publishednodes.json",
                                "--ap=/mount/pki/own",
                                "--tp=/mount/pki/trusted",
                                "--rp=/mount/pki/rejected",
                                "--ip=/mount/pki/issuer",
                                "--lf=/mount/publisher.log",
                                "--tm",
                                "--at=Directory"
                ],
                "HostConfig": {
                                "Binds": [
                                                "/host_mnt/c/mount:/mount"
                                ]
                },
                "Mounts": [
                                {
                                                "Type": "bind",
                                                "Source": "/host_mnt/c/mount",
                                                "Destination": "/mount"
                                }
                ]
}

This is not supported as part of the automatic layered deployment since it is very platform specific.

We are planning to support issuing certificates from OPC Vault in a future release, which would allow configuring a intermediate certificate with chain and long lifetime covering all modules in the TKE which can then resolve the module certificates presented against it. This also has the benefit of us being able to continuously roll the module certificate for increased safety. This would be post 2.7 though.

pc-avatar-7076 commented 4 years ago

@marcschier does the initially generated certificate get persisted (even in a container) if it is unable to successfully create the initial session? I disabled my "layered deployment" and removed the publisher module from my edge. I then ran the publisher "standalone" from the IDE on my Windows host with the following (very basic) command arguments: image

The publisher creates a certificate when it cannot find one in the CurrentUser\My store: image

Note that the certificate is assigned back to the Opc.Ua.CertificateIdentifier instance. Looking at the implementation in the UA stack, that alone doesn't appear to persist the certificate back to disk.

Next, session creation is attempted: image

This fails - because the Kepware server rejects the certificate - resulting in an exception. Unless I'm missing something, the generated certificate is never persisted back to the store: image

Here, we see unique certs passed into each session creation attempt (attempt 0): image

Attempt 1: image

Attempt 2: image

pc-avatar-7076 commented 4 years ago

@marcschier and @cristipogacean heads up that I pulled down your recent certificate hotfix (https://github.com/Azure/Industrial-IoT/pull/423) and can confirm that this addresses the problem by running the publish standalone in my Windows debugger - namely that the generated certificate is now added to the store before the session creation attempt. Please advise when we can expect this feature will be migrated to the mainline version.

cristipogacean commented 4 years ago

@pcameron-ptc #423 was just merged into master. I will close this for now. plesae reopen in case of issues.