Azure / Industrial-IoT

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

Command line option to disable complex type loading. was: OPC Publisher 2.8.4 : WinCC disconnects when loading complex type system (with PCAPs) #1953

Closed Ilheu closed 1 year ago

Ilheu commented 1 year ago

I'm running OPCPublisher and when I try to get some node's value I get this message: :"StatusCode":{"Symbol":"BadMonitoredItemIdInvalid","Code":2151809024}. I never had this problems in other servers.

I use the same nodeId that UaExpert shows: image

My file configurations is the following one: image

I get this message instead of the node value: [{"MessageId":"1","MessageType":"ua-data","PublisherId":"opc.tcp://192.168.xx.xx:xxxx_3182BABF","Messages":[{"DataSetWriterId":"1000","SequenceNumber":1,"MetaDataVersion":{"MajorVersion":1,"MinorVersion":0},"Timestamp":"2023-03-06T10:11:54.503Z","Payload":{"part_counter":{"StatusCode":{"Symbol":"BadMonitoredItemIdInvalid","Code":2151809024}}}}]}]

marcschier commented 1 year ago

There is a special case BadMonitoredItemIdInvalid is emitted by OPC Publisher and that is during a Heartbeat should the value not exist or the monitored item not yet be created. Since from the configuration heartbeat is not configured the only possibility is that this value is reported by the server. Here the possibility is that you used different security or endpoint, or credentials between UA Expert and OPC Publisher (usesecurity = false). Best to make sure to use a unsecure endpoint in UA expert and repro. If that does not help, please could you send a) the command line argument for the publisher, and b) the entire publisher log, including how the monitored items are created on startup.

cristipogacean commented 1 year ago

in addition, it would be interesting to try and subscribe / create a monitored item for this particular node using UA Expert and check it this works. It could be the case that the server does not support subscribing certain nodes, but only allows read access.

Ilheu commented 1 year ago

Best to make sure to use a unsecure endpoint in UA expert and repro.

PRINT1 PRINT2

please could you send a) the command line argument for the publisher


{
"Hostname": "opcpublisher",
"Cmd": [
"--pf=../appdata/pn.json",
"--mm=PubSub",
"--me=Json",
"--fm=true",
"--bs=100",
"--si=1",
"--hb=10",
"--oi=1000",
"--op=1000",
"--di=20",
"--aa"
],
"HostConfig": {
"Binds": [
"/iiotedge:/appdata"
]
}
}

 **and b) the entire publisher log, including how the monitored items are created on startup**

[2023-03-07 15:01:45.617 INF Root] Module exits... [2023-03-07 15:01:45.622 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.WorkerSupervisor] Stopping worker supervisor [2023-03-07 15:01:45.624 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Stopping worker... [2023-03-07 15:01:45.624 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] Disposing processing engine opc.tcp://192.168.18.36:4861_3182BABF [2023-03-07 15:01:45.627 INF OpcUa] Subscription PUBLISHING DISABLED, Id=2, LastNotificationTime=15:01:44, GoodPublishRequestCount=1, PublishingInterval=1000, KeepAliveCount=10, PublishingEnabled=False, MonitoredItemCount=1 [2023-03-07 15:01:45.628 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Subscription '1000' unregistered from session 'opc.tcp://192.168.18.36:4861_3182BABF' in state Running [2023-03-07 15:01:45.628 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Closing subscription '1000' in session 'opc.tcp://192.168.18.36:4861_3182BABF'... [2023-03-07 15:01:45.628 INF OpcUa] Subscription DELETE, Id=2, LastNotificationTime=15:01:44, GoodPublishRequestCount=1, PublishingInterval=1000, KeepAliveCount=10, PublishingEnabled=False, MonitoredItemCount=1 [2023-03-07 15:01:45.631 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Subscription '1000' in session 'opc.tcp://192.168.18.36:4861_3182BABF' successfully closed (Remaining: 0). [2023-03-07 15:01:45.632 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Worker StandalonePublisher_0 cancellation received ... [2023-03-07 15:01:45.632 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Worker: StandalonePublisher_0, Job: opc.tcp://192.168.18.36:4861_3182BABF processing completed ...
[2023-03-07 15:01:45.632 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Worker StandalonePublisher_0 stopping... [2023-03-07 15:01:45.632 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Worker stopped. [2023-03-07 15:01:45.632 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.WorkerSupervisor] Worker supervisor successfully stopped [2023-03-07 15:01:45.636 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Stopping all sessions [2023-03-07 15:01:45.637 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Successfully stopped all sessions [2023-03-07 15:01:45.647 INF Microsoft.Azure.IIoT.Http.HealthChecks.HealthCheckManager] Health checks stopped. [2023-03-07 15:01:45.654 INF Root] Stopped prometheus metric server [2023-03-07 15:01:45.657 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Stopping Module Host... [2023-03-07 15:01:45.663 INF Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory] 102: Module railesIoTedge_mcm_00_OPCPublisher disconnected due to Client_Close - now Disabled... [2023-03-07 15:01:45.668 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Module Host stopped. [2023-03-07 15:01:45.671 INF Root] Module stopped. [2023-03-07 15:01:45.675 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Stopping all sessions [2023-03-07 15:01:45.675 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Successfully stopped all sessions [2023-03-07 15:01:46.391 INF OpcUa] ChannelId 27131: in Closing state. [2023-03-07 15:01:46.400 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.WorkerSupervisor] Stopping worker supervisor [2023-03-07 15:01:46.400 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.WorkerSupervisor] Worker supervisor successfully stopped [2023-03-07 15:01:46.406 WRN OpcUa] ChannelId 27131: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' [2023-03-07 15:01:46.407 INF OpcUa] ChannelId 27131: in Closed state. [2023-03-07 15:01:46.407 INF OpcUa] ChannelId 27131: CLIENTCHANNEL SOCKET CLOSED: 02819C2C [2023-03-07 15:01:46.407 ERR OpcUa] Publish #2834, Subscription count = 0, Error: Object reference not set to an instance of an object. [2023-03-07 15:01:46.407 ERR OpcUa] Publish abandoned after error because session id changed: Old ns=1;i=1678170367 != New null [2023-03-07 15:01:47.532 INF Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory] Connecting all clients to railesedge using MqttOverTcp. [2023-03-07 15:01:47.610 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.StandaloneJobOrchestrator] File ../appdata/pn.json has changed, last known hash , new hash 46BD7DFE8393D0F9B173F78D3FC4EB5C86FC1E36316E929CE09D031D890BBBF2, reloading... [2023-03-07 15:01:47.611 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.StandaloneJobOrchestrator] Validation schema file does not exist or is disabled, ignoring validation of ../appdata/pn.json file. [2023-03-07 15:01:47.753 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Models.PublishedNodesJobConverter] Read 1 entry models from published nodes file in 00:00:00.1415005 [2023-03-07 15:01:47.801 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Models.PublishedNodesJobConverter] Total count of OpcNodes after job conversion: 1 [2023-03-07 15:01:47.801 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Models.PublishedNodesJobConverter] Converted published nodes entry models to jobs in 00:00:00.0414449 [2023-03-07 15:01:47.807 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.StandaloneJobOrchestrator] Job opc.tcp://192.168.18.36:4861_0A075253 loaded with dataSetGroup null with dataSetWriters 1000 [2023-03-07 15:01:47.928 INF Root] Starting module OpcPublisher version 2.8.4.8. [2023-03-07 15:01:47.928 INF Root] Initiating prometheus at port 9702/metrics [2023-03-07 15:01:47.946 INF Root] Prometheus metric server started. [2023-03-07 15:01:47.952 INF Microsoft.Azure.IIoT.Http.HealthChecks.HealthCheckManager] Health checks started. [2023-03-07 15:01:47.956 WRN Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory] Bypassing certificate validation for client. [2023-03-07 15:01:47.961 INF Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory] Running in iotedge context. [2023-03-07 15:01:48.567 INF Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory] 0: Module railesIoTedge_mcm_00_OPCPublisher reconnected due to Connection_Ok. [2023-03-07 15:01:48.849 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Initialize device twin for railesIoTedge_mcm_00 - OPCPublisher [2023-03-07 15:01:48.923 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Applying initial desired state. [2023-03-07 15:01:48.927 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Reporting currently initial state. [2023-03-07 15:01:49.121 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Module Host started. [2023-03-07 15:01:49.132 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.WorkerSupervisor] Creating new worker with id StandalonePublisher_0 [2023-03-07 15:01:49.133 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.WorkerSupervisor] Starting worker 'StandalonePublisher_0'... [2023-03-07 15:01:49.136 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Starting worker StandalonePublisher_0: {} [2023-03-07 15:01:49.218 INF OpcUa] Imported the PFX private key for [XXXXXXXXXXXXXXXXXXXXXX]. [2023-03-07 15:01:49.225 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Own certificate Subject 'CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge' (thumbprint: XXXXXXXXXXXXXXXXXXXXXXXXXXX) loaded. [2023-03-07 15:01:49.228 INF OpcUa] Checking application instance certificate. [2023-03-07 15:01:49.237 INF OpcUa] Imported the PFX private key for [XXXXXXXXXXXXXXXXXXXXXXXX]. [2023-03-07 15:01:49.238 INF OpcUa] Check certificate: [CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge] [XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX] [2023-03-07 15:01:49.240 INF OpcUa] Check application instance certificate. [CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge] [XXXXXXXXXXXXXXXXXXXXXXXXXXX] [2023-03-07 15:01:49.288 INF OpcUa] Using the ApplicationUri: urn:railesedge:Microsoft.Azure.IIoT:microsoft: [2023-03-07 15:01:49.302 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Application own certificate store contains 1 certs. [2023-03-07 15:01:49.302 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] 01: Subject 'CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge' (thumbprint: AE563D773F4CA0ABD31F56786706B5F76AC441AA) [2023-03-07 15:01:49.302 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Trusted issuer store contains 0 certs. [2023-03-07 15:01:49.303 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Trusted issuer store has 0 CRLs. [2023-03-07 15:01:49.304 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Trusted peer store contains 1 certs. [2023-03-07 15:01:49.304 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] 01: Subject 'CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge' (thumbprint: AE563D773F4CA0ABD31F56786706B5F76AC441AA) [2023-03-07 15:01:49.304 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Trusted peer store has 0 CRLs. [2023-03-07 15:01:49.304 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Rejected certificate store contains 0 certs. [2023-03-07 15:01:49.326 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Worker StandalonePublisher_0 processing job opc.tcp://192.168.18.36:4861_0A075253, mode: Active [2023-03-07 15:01:49.401 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Subscription '1000' registered/updated in session 'opc.tcp://192.168.18.36:4861_0A075253' in state Init [2023-03-07 15:01:49.414 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Subscription '1000' registered/updated in session 'opc.tcp://192.168.18.36:4861_0A075253' in state Init [2023-03-07 15:01:49.435 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker+JobProcess] Job opc.tcp://192.168.18.36:4861_0A075253 started. [2023-03-07 15:01:49.570 INF OpcUa] ChannelId 0: in Connecting state. [2023-03-07 15:01:49.596 INF OpcUa] ChannelId 0: in Opening state. [2023-03-07 15:01:49.598 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=15:01:49.597. Lifetime=3600000. [2023-03-07 15:01:49.616 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None [2023-03-07 15:01:49.616 INF OpcUa] Sender Certificate: (none) [2023-03-07 15:01:49.624 INF OpcUa] ChannelId 27136: Token #1 activated. CreatedAt=15:01:49.597. Lifetime=3600000. [2023-03-07 15:01:49.624 INF OpcUa] ChannelId 27136: in Open state. [2023-03-07 15:01:49.625 INF OpcUa] ChannelId 27136: Token Expiry 03/07/2023 16:01:49, renewal scheduled in 2699979 ms. [2023-03-07 15:01:49.651 INF OpcUa] ChannelId 27136: in Closing state. [2023-03-07 15:01:49.659 WRN OpcUa] ChannelId 27136: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' [2023-03-07 15:01:49.661 INF OpcUa] ChannelId 27136: in Closed state. [2023-03-07 15:01:49.662 INF OpcUa] ChannelId 27136: CLIENTCHANNEL SOCKET CLOSED: 033D9735 [2023-03-07 15:01:49.663 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Creating session 'opc.tcp://192.168.18.36:4861_0A075253' for endpoint 'opc.tcp://192.168.18.36:4861'... [2023-03-07 15:01:49.671 INF OpcUa] ChannelId 0: in Connecting state. [2023-03-07 15:01:49.677 INF OpcUa] ChannelId 0: in Opening state. [2023-03-07 15:01:49.677 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=15:01:49.677. Lifetime=3600000. [2023-03-07 15:01:49.679 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None [2023-03-07 15:01:49.680 INF OpcUa] Sender Certificate: (none) [2023-03-07 15:01:49.680 INF OpcUa] ChannelId 27137: Token #1 activated. CreatedAt=15:01:49.677. Lifetime=3600000. [2023-03-07 15:01:49.680 INF OpcUa] ChannelId 27137: in Open state. [2023-03-07 15:01:49.680 INF OpcUa] ChannelId 27137: Token Expiry 03/07/2023 16:01:49, renewal scheduled in 2699997 ms. [2023-03-07 15:01:49.687 INF OpcUa] ChannelId 27137: in Closing state. [2023-03-07 15:01:49.690 WRN OpcUa] ChannelId 27137: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' [2023-03-07 15:01:49.690 INF OpcUa] ChannelId 27137: in Closed state. [2023-03-07 15:01:49.690 INF OpcUa] ChannelId 27137: CLIENTCHANNEL SOCKET CLOSED: 03E6DAAA [2023-03-07 15:01:49.715 INF OpcUa] ChannelId 0: in Connecting state. [2023-03-07 15:01:49.721 INF OpcUa] ChannelId 0: in Opening state. [2023-03-07 15:01:49.722 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=15:01:49.722. Lifetime=3600000. [2023-03-07 15:01:49.724 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None [2023-03-07 15:01:49.724 INF OpcUa] Sender Certificate: (none) [2023-03-07 15:01:49.724 INF OpcUa] ChannelId 27138: Token #1 activated. CreatedAt=15:01:49.722. Lifetime=3600000. [2023-03-07 15:01:49.724 INF OpcUa] ChannelId 27138: in Open state. [2023-03-07 15:01:49.724 INF OpcUa] ChannelId 27138: Token Expiry 03/07/2023 16:01:49, renewal scheduled in 2699997 ms. [2023-03-07 15:01:49.730 INF OpcUa] Revised session timeout value: 60000.
[2023-03-07 15:01:49.731 INF OpcUa] Max response message size value: 4194304. Max request message size: 0
[2023-03-07 15:01:49.731 INF OpcUa] Server signature is null or empty. [2023-03-07 15:01:49.740 INF OpcUa] Empty results were received for the ActivateSession call. [2023-03-07 15:01:50.615 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_0A075253' created, loading complex type system ...
[2023-03-07 15:01:52.109 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_0A075253' complex type system loaded [2023-03-07 15:01:52.111 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Azure IIoT opc.tcp://192.168.18.36:4861_0A075253 took 00:00:02.4471385. [2023-03-07 15:01:52.111 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Connected to 'opc.tcp://192.168.18.36:4861' [2023-03-07 15:01:52.122 WRN OpcUa] A smaller lifeTime 10000ms than session timeout 60000ms configured for subscription 0. [2023-03-07 15:01:52.141 INF OpcUa] Subscription CREATED, Id=2, LastNotificationTime=15:01:52, GoodPublishRequestCount=1, PublishingInterval=1000, KeepAliveCount=10, PublishingEnabled=False, MonitoredItemCount=0 [2023-03-07 15:01:52.162 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Added 1 monitored items to subscription '1000'/'opc.tcp://192.168.18.36:4861_0A075253' [2023-03-07 15:01:52.177 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Now monitoring 1 nodes in subscription '1000'/'opc.tcp://192.168.18.36:4861_0A075253' [2023-03-07 15:01:52.184 INF OpcUa] Subscription PUBLISHING ENABLED, Id=2, LastNotificationTime=15:01:52, GoodPublishRequestCount=1, PublishingInterval=1000, KeepAliveCount=10, PublishingEnabled=True, MonitoredItemCount=1 [2023-03-07 15:01:52.184 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Subscription '1000'/'opc.tcp://192.168.18.36:4861_0A075253' state actual(revised)/desired: PublishingEnabled True/True, PublishingInterval 1000/1000, KeepAliveCount 10/10, LifetimeCount 10000/10000 [2023-03-07 15:01:52.191 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Set monitoring to Reporting for 1 items in subscription '1000'/'opc.tcp://192.168.18.36:4861_0A075253'. [2023-03-07 15:02:02.417 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Keep alive for subscription '1000'/'opc.tcp://192.168.18.36:4861_0A075253' with sequenceNumber 1, publishTime 03/07/2023 15:02:11 [2023-03-07 15:02:13.286 INF OpcUa] Subscription PUBLISHING RECOVERED, Id=2, LastNotificationTime=15:02:02, GoodPublishRequestCount=0, PublishingInterval=1000, KeepAliveCount=10, PublishingEnabled=True, MonitoredItemCount=1 [2023-03-07 15:02:13.287 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Keep alive for subscription '1000'/'opc.tcp://192.168.18.36:4861_0A075253' with sequenceNumber 1, publishTime 03/07/2023 15:02:22 [2023-03-07 15:02:22.431 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] DIAGNOSTICS INFORMATION for : opc.tcp://192.168.18.36:4861_0A075253 Ingestion duration : 00:00:00:20 (dd:hh:mm:ss) Ingress DataChanges (from OPC) : 2 (All time ~0.1/s; 02 in last 60s ~0.1/s) Ingress ValueChanges (from OPC) : 2 (All time ~0.1/s; 02 in last 60s ~0.1/s) Ingress BatchBlock buffer size : 0 Encoding Block input/output size : 0 | 0 Encoder Notifications processed : 2 Encoder Notifications dropped : 0 Encoder IoT Messages processed : 2 Encoder avg Notifications/Message : 1 Encoder avg IoT Message body size : 348 (0%) Encoder avg IoT Chunk (4 KB) usage : 0.1 Estimated IoT Chunks (4 KB) per day: 8,638 Outgress Batch Block buffer size : 0 Outgress input buffer count : 0 Outgress input buffer dropped : 0 Outgress IoT message count : 2 (0.1/s) Connection retries : 0 Opc endpoint connected? : True Monitored Opc nodes succeeded count: 1 Monitored Opc nodes failed count : 0

[2023-03-07 15:02:24.201 INF OpcUa] Subscription PUBLISHING RECOVERED, Id=2, LastNotificationTime=15:02:13, GoodPublishRequestCount=0, PublishingInterval=1000, KeepAliveCount=10, PublishingEnabled=True, MonitoredItemCount=1 [2023-03-07 15:02:24.203 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Keep alive for subscription '1000'/'opc.tcp://192.168.18.36:4861_0A075253' with sequenceNumber 1, publishTime 03/07/2023 15:02:33 [2023-03-07 15:02:35.124 INF OpcUa] Subscription PUBLISHING RECOVERED, Id=2, LastNotificationTime=15:02:24, GoodPublishRequestCount=0, PublishingInterval=1000, KeepAliveCount=10, PublishingEnabled=True, MonitoredItemCount=1 [2023-03-07 15:02:35.128 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Keep alive for subscription '1000'/'opc.tcp://192.168.18.36:4861_0A075253' with sequenceNumber 1, publishTime 03/07/2023 15:02:44 [2023-03-07 15:02:42.427 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] DIAGNOSTICS INFORMATION for : opc.tcp://192.168.18.36:4861_0A075253 Ingestion duration : 00:00:00:40 (dd:hh:mm:ss) Ingress DataChanges (from OPC) : 4 (All time ~0.1/s; 04 in last 60s ~0.1/s) Ingress ValueChanges (from OPC) : 4 (All time ~0.1/s; 04 in last 60s ~0.1/s) Ingress BatchBlock buffer size : 0 Encoding Block input/output size : 0 | 0 Encoder Notifications processed : 4 Encoder Notifications dropped : 0 Encoder IoT Messages processed : 4 Encoder avg Notifications/Message : 1 Encoder avg IoT Message body size : 348 (0%) Encoder avg IoT Chunk (4 KB) usage : 0.1 Estimated IoT Chunks (4 KB) per day: 8,640 Outgress Batch Block buffer size : 0 Outgress input buffer count : 0 Outgress input buffer dropped : 0 Outgress IoT message count : 4 (0.1/s) Connection retries : 0 Opc endpoint connected? : True Monitored Opc nodes succeeded count: 1 Monitored Opc nodes failed count : 0

Ilheu commented 1 year ago

in addition, it would be interesting to try and subscribe / create a monitored item for this particular node using UA Expert and check it this works. It could be the case that the server does not support subscribing certain nodes, but only allows read access.

Thank you for the reply! Can you explain me how to do it? How do I check if the server does not support subscribing?

cristipogacean commented 1 year ago

in addition, it would be interesting to try and subscribe / create a monitored item for this particular node using UA Expert and check it this works. It could be the case that the server does not support subscribing certain nodes, but only allows read access.

Thank you for the reply! Can you explain me how to do it? How do I check if the server does not support subscribing?

You did exactly what I was looking for in the print-screen in your comment above with the Data Access View. So the node can be properly monitored.

On the other hand, looking at the publisher's traces it looks the item is properly monitored now and value-changes are properly generated. Do you still see the BadMonitoredItemIdInvalid StatusCode in payload?

Ilheu commented 1 year ago

On the other hand, looking at the publisher's traces it looks the item is properly monitored now and value-changes are properly generated. Do you still see the BadMonitoredItemIdInvalid StatusCode in payload?

Yes, the payload is still the same...

Ilheu commented 1 year ago

@marcschier Does the information I sent help?

marcschier commented 1 year ago

This error is injected when the heartbeat (which is tied to keep alive) is supposed to be sent, but no previous value has ever been received by publisher or the monitored item has not yet successfully been created. I would suggest removing "--hb" command line argument and see if you still see the status code. Please let us know if this helped.

Ilheu commented 1 year ago

Now I Don't receive any message, but it is still working in UaExpert

  DIAGNOSTICS INFORMATION for          : opc.tcp://192.168.18.36:4861_CD019476
  -# Ingestion duration                 :    00:00:00:00 (dd:hh:mm:ss)
  -# Ingress DataChanges (from OPC)     :              0 
  -# Ingress ValueChanges (from OPC)    :              0 
  -# Ingress BatchBlock buffer size     :              0
  -# Encoding Block input/output size   :              0 | 0
  -# Encoder Notifications processed    :              0
  -# Encoder Notifications dropped      :              0
  -# Encoder IoT Messages processed     :              0
  -# Encoder avg Notifications/Message  :              0
  -# Encoder avg IoT Message body size  :              0 (0%)
  -# Encoder avg IoT Chunk (4 KB) usage :              0
  -# Estimated IoT Chunks (4 KB) per day:              0
  -# Outgress Batch Block buffer size   :              0
  -# Outgress input buffer count        :              0
  -# Outgress input buffer dropped      :              0
  -# Outgress IoT message count         :              0 
  -# Connection retries                 :              0
  -# Opc endpoint connected?            :           True
  -# Monitored Opc nodes succeeded count:              0
  -# Monitored Opc nodes failed count   :              0

[2023-03-09 11:24:23.464 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-09 11:24:23.464 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=11:24:23.464. Lifetime=3600000. 
[2023-03-09 11:24:23.469 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-09 11:24:23.469 INF OpcUa] Sender Certificate: (none) 
[2023-03-09 11:24:23.472 INF OpcUa] ChannelId 27497: Token #1 activated. CreatedAt=11:24:23.464. Lifetime=3600000. 
[2023-03-09 11:24:23.472 INF OpcUa] ChannelId 27497: in Open state. 
[2023-03-09 11:24:23.472 INF OpcUa] ChannelId 27497: Token Expiry 03/09/2023 12:24:23, renewal scheduled in 2699994 ms. 
[2023-03-09 11:24:23.477 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Failed to refresh session 'opc.tcp://192.168.18.36:4861_CD019476' 
Opc.Ua.ServiceResultException: BadSessionIdInvalid
   at Opc.Ua.ClientBase.ValidateResponse(ResponseHeader header)
   at Opc.Ua.SessionClient.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.SessionClientBatched.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.Client.Session.FetchNamespaceTables()
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.HandleRefreshAsync(ConnectionIdentifier id, SessionWrapper wrapper, CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 512
[2023-03-09 11:24:23.478 WRN OpcUa] ChannelId 27497: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-09 11:24:23.478 INF OpcUa] ChannelId 27497: in Closed state. 
[2023-03-09 11:24:23.478 INF OpcUa] ChannelId 27497: CLIENTCHANNEL SOCKET CLOSED: 01CBD75F 
[2023-03-09 11:24:24.519 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-09 11:24:24.535 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-09 11:24:24.536 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=11:24:24.536. Lifetime=3600000. 
[2023-03-09 11:24:24.545 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-09 11:24:24.546 INF OpcUa] Sender Certificate: (none) 
[2023-03-09 11:24:24.546 INF OpcUa] ChannelId 27498: Token #1 activated. CreatedAt=11:24:24.536. Lifetime=3600000. 
[2023-03-09 11:24:24.546 INF OpcUa] ChannelId 27498: in Open state. 
[2023-03-09 11:24:24.546 INF OpcUa] ChannelId 27498: Token Expiry 03/09/2023 12:24:24, renewal scheduled in 2699991 ms. 
[2023-03-09 11:24:24.552 ERR OpcUa] Unexpected keep alive error occurred: BadSessionIdInvalid 
[2023-03-09 11:24:24.554 WRN OpcUa] ChannelId 27498: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-09 11:24:24.554 INF OpcUa] ChannelId 27498: in Closed state. 
[2023-03-09 11:24:24.554 INF OpcUa] ChannelId 27498: CLIENTCHANNEL SOCKET CLOSED: 019251CF 
[2023-03-09 11:24:33.482 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_CD019476' missed 1 Keepalive(s) due to BadNoCommunication, waiting to reconnect... 
[2023-03-09 11:24:33.493 INF OpcUa] Session RECONNECT starting. 
[2023-03-09 11:24:33.493 INF OpcUa] Session REPLACING channel. 
[2023-03-09 11:24:33.497 INF OpcUa] Session RE-ACTIVATING session. 
[2023-03-09 11:24:33.497 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-09 11:24:33.509 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-09 11:24:33.509 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=11:24:33.509. Lifetime=3600000. 
[2023-03-09 11:24:33.514 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-09 11:24:33.515 INF OpcUa] Sender Certificate: (none) 
[2023-03-09 11:24:33.515 INF OpcUa] ChannelId 27499: Token #1 activated. CreatedAt=11:24:33.509. Lifetime=3600000. 
[2023-03-09 11:24:33.515 INF OpcUa] ChannelId 27499: in Open state. 
[2023-03-09 11:24:33.515 INF OpcUa] ChannelId 27499: Token Expiry 03/09/2023 12:24:33, renewal scheduled in 2699995 ms. 
[2023-03-09 11:24:33.520 INF OpcUa] Session RECONNECT completed successfully. 
[2023-03-09 11:24:33.523 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-09 11:24:43.455 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] 
  DIAGNOSTICS INFORMATION for          : opc.tcp://192.168.18.36:4861_CD019476
  -# Ingestion duration                 :    00:00:00:00 (dd:hh:mm:ss)
  -# Ingress DataChanges (from OPC)     :              0 
  -# Ingress ValueChanges (from OPC)    :              0 
  -# Ingress BatchBlock buffer size     :              0
  -# Encoding Block input/output size   :              0 | 0
  -# Encoder Notifications processed    :              0
  -# Encoder Notifications dropped      :              0
  -# Encoder IoT Messages processed     :              0
  -# Encoder avg Notifications/Message  :              0
  -# Encoder avg IoT Message body size  :              0 (0%)
  -# Encoder avg IoT Chunk (4 KB) usage :              0
  -# Estimated IoT Chunks (4 KB) per day:              0
  -# Outgress Batch Block buffer size   :              0
  -# Outgress input buffer count        :              0
  -# Outgress input buffer dropped      :              0
  -# Outgress IoT message count         :              0 
  -# Connection retries                 :              0
  -# Opc endpoint connected?            :           True
  -# Monitored Opc nodes succeeded count:              0
  -# Monitored Opc nodes failed count   :              0

[2023-03-09 11:24:43.465 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
Ilheu commented 1 year ago

Please let us know if this helped.

It did not help... Now I don't receive any message...

Ilheu commented 1 year ago

I'm trying troubleshoot the opc server with discovery and opc-twin module, but I can't use opc-twin without other services(microservices, etc) is there any way to do it with just the modules?? I've read the documentation and can't find any solution.

@marcschier @cristipogacean can you give me any tip or hint?

JohannesM24 commented 1 year ago

Hi @Ilheu ,

from my personal experience regarding those problems, you could try to create a wireshark capture of the (unencrypted) OPC UA communication. You would then be able to compare the working setup of using UA-Expert and the one using opc-publisher. Find a manual on capturing OPC UA packets here https://opcconnect.opcfoundation.org/2017/02/analyzing-opc-ua-communications-with-wireshark/

Ilheu commented 1 year ago

Hi @Ilheu ,

from my personal experience regarding those problems, you could try to create a wireshark capture of the (unencrypted) OPC UA communication. You would then be able to compare the working setup of using UA-Expert and the one using opc-publisher. Find a manual on capturing OPC UA packets here https://opcconnect.opcfoundation.org/2017/02/analyzing-opc-ua-communications-with-wireshark/

Thank for your hint! I tried and got these logs...

image

I get this Error Message in loop, but when I try with UaExpert it works well... Can you help me? If it is a server problem, it was not supposed to work in UaExpert...

@marcschier @cristipogacean What more information do you need?!

marcschier commented 1 year ago

Many thanks for digging so deep into it. Super helpful. The server errors on the transport channel layer after server returns the read response. There might be an issue with us sending a namespace read that the server does not like. Possible issue could be operation limits. Could you share the pcap for UA expert and OPC publisher session starting from open secure channel including initial reads? Btw 2.8.5 uses an updated OPC UA stack and should you need to redo the capture it would be awesome to do it with 2.8.5.

Ilheu commented 1 year ago

Many thanks for digging so deep into it. Super helpful. The server errors on the transport channel layer after server returns the read response. There might be an issue with us sending a namespace read that the server does not like. Possible issue could be operation limits. Could you share the pcap for UA expert and OPC publisher session starting from open secure channel including initial reads? Btw 2.8.5 uses an updated OPC UA stack and should you need to redo the capture it would be awesome to do it with 2.8.5.

I will make the pcap as soon as possible! I think the server only has the most basic methods, I made a python script to get the data but besides that I just get errors. Unfortunately I have no control over the server.

Ilheu commented 1 year ago

Many thanks for digging so deep into it. Super helpful. The server errors on the transport channel layer after server returns the read response. There might be an issue with us sending a namespace read that the server does not like. Possible issue could be operation limits. Could you share the pcap for UA expert and OPC publisher session starting from open secure channel including initial reads? Btw 2.8.5 uses an updated OPC UA stack and should you need to redo the capture it would be awesome to do it with 2.8.5.

@marcschier

I tested with the latest version 2.8.5.1.

[2023-03-22 10:28:06.130 INF Root] Starting module OpcPublisher version 2.8.5.1. 
[2023-03-22 10:28:06.130 INF Root] Initiating prometheus at port 9702/metrics 
[2023-03-22 10:28:06.149 INF Root] Prometheus metric server started. 
[2023-03-22 10:28:06.158 INF Microsoft.Azure.IIoT.Http.HealthChecks.HealthCheckManager] Health checks started. 
[2023-03-22 10:28:06.162 WRN Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory] Bypassing certificate validation for client. 
[2023-03-22 10:28:06.168 INF Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory] Running in iotedge context. 
[2023-03-22 10:28:07.131 INF Microsoft.Azure.IIoT.Module.Framework.Client.IoTSdkFactory] 0: Module railesIoTedge_mcm_00_OPCPublisher reconnected due to Connection_Ok. 
[2023-03-22 10:28:07.436 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Initialize device twin for railesIoTedge_mcm_00 - OPCPublisher 
[2023-03-22 10:28:07.525 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Applying initial desired state. 
[2023-03-22 10:28:07.530 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Reporting currently initial state. 
[2023-03-22 10:28:07.711 INF Microsoft.Azure.IIoT.Module.Framework.Hosting.ModuleHost] Module Host started. 
[2023-03-22 10:28:07.719 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.WorkerSupervisor] Creating new worker with id StandalonePublisher_0 
[2023-03-22 10:28:07.720 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.WorkerSupervisor] Starting worker 'StandalonePublisher_0'... 
[2023-03-22 10:28:07.721 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Starting worker StandalonePublisher_0: {} 
[2023-03-22 10:28:07.800 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] No application own certificate found. Creating a self-signed own certificate valid since yesterday for 12 months, with a 2048 bit key and 256 bit hash. 
[2023-03-22 10:28:07.808 INF OpcUa] Checking application instance certificate. 
[2023-03-22 10:28:07.813 INF OpcUa] Creating application instance certificate. 
[2023-03-22 10:28:08.481 INF OpcUa] Adding application certificate to trusted peer store. [CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge] [AF363EF054C185B23114632DF05AFFFD8EA06B4C] 
[2023-03-22 10:28:08.482 INF OpcUa] Added application certificate to trusted peer store. 
[2023-03-22 10:28:08.573 INF OpcUa] Imported the PFX private key for [AF363EF054C185B23114632DF05AFFFD8EA06B4C]. 
[2023-03-22 10:28:08.584 INF OpcUa] Certificate created for urn:railesedge:Microsoft.Azure.IIoT:microsoft:. [CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge] [AF363EF054C185B23114632DF05AFFFD8EA06B4C] 
[2023-03-22 10:28:08.585 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Own certificate Subject 'CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge' (thumbprint: AF363EF054C185B23114632DF05AFFFD8EA06B4C) created. 
[2023-03-22 10:28:08.595 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Application own certificate store contains 1 certs. 
[2023-03-22 10:28:08.595 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] 01: Subject 'CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge' (thumbprint: AF363EF054C185B23114632DF05AFFFD8EA06B4C) 
[2023-03-22 10:28:08.596 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Trusted issuer store contains 0 certs. 
[2023-03-22 10:28:08.597 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Trusted issuer store has 0 CRLs. 
[2023-03-22 10:28:08.598 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Trusted peer store contains 1 certs. 
[2023-03-22 10:28:08.598 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] 01: Subject 'CN=Microsoft.Azure.IIoT, C=DE, S=Bav, O=Microsoft, DC=railesedge' (thumbprint: AF363EF054C185B23114632DF05AFFFD8EA06B4C) 
[2023-03-22 10:28:08.598 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Trusted peer store has 0 CRLs. 
[2023-03-22 10:28:08.598 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Rejected certificate store contains 0 certs. 
[2023-03-22 10:28:08.629 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker] Worker StandalonePublisher_0 processing job opc.tcp://192.168.18.36:4861_79E4FF2A, mode: Active 
[2023-03-22 10:28:08.718 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Subscription '500' registered/updated in session 'opc.tcp://192.168.18.36:4861_79E4FF2A' in state Init 
[2023-03-22 10:28:08.726 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Subscription '500' registered/updated in session 'opc.tcp://192.168.18.36:4861_79E4FF2A' in state Init 
[2023-03-22 10:28:08.738 INF Microsoft.Azure.IIoT.Agent.Framework.Agent.Worker+JobProcess] Job opc.tcp://192.168.18.36:4861_79E4FF2A started. 
[2023-03-22 10:28:08.932 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:28:09.761 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:28:09.763 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:28:09.763. Lifetime=3600000. 
[2023-03-22 10:28:09.817 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:28:09.818 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:28:09.840 INF OpcUa] ChannelId 25055: Token #1 activated. CreatedAt=10:28:09.763. Lifetime=3600000. 
[2023-03-22 10:28:09.840 INF OpcUa] ChannelId 25055: in Open state. 
[2023-03-22 10:28:09.840 INF OpcUa] ChannelId 25055: Token Expiry 03/22/2023 11:28:09, renewal scheduled in 2699941 ms. 
[2023-03-22 10:28:09.899 INF OpcUa] ChannelId 25055: in Closing state. 
[2023-03-22 10:28:09.914 WRN OpcUa] ChannelId 25055: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:28:09.918 INF OpcUa] ChannelId 25055: in Closed state. 
[2023-03-22 10:28:09.918 INF OpcUa] ChannelId 25055: CLIENTCHANNEL SOCKET CLOSED: 03B843B5 
[2023-03-22 10:28:09.921 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Creating session 'opc.tcp://192.168.18.36:4861_79E4FF2A' for endpoint 'opc.tcp://192.168.18.36:4861'... 
[2023-03-22 10:28:09.940 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:28:09.971 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:28:09.971 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:28:09.971. Lifetime=3600000. 
[2023-03-22 10:28:09.980 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:28:09.981 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:28:09.981 INF OpcUa] ChannelId 25056: Token #1 activated. CreatedAt=10:28:09.971. Lifetime=3600000. 
[2023-03-22 10:28:09.981 INF OpcUa] ChannelId 25056: in Open state. 
[2023-03-22 10:28:09.981 INF OpcUa] ChannelId 25056: Token Expiry 03/22/2023 11:28:09, renewal scheduled in 2699991 ms. 
[2023-03-22 10:28:09.994 INF OpcUa] ChannelId 25056: in Closing state. 
[2023-03-22 10:28:10.022 WRN OpcUa] ChannelId 25056: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:28:10.022 INF OpcUa] ChannelId 25056: in Closed state. 
[2023-03-22 10:28:10.023 INF OpcUa] ChannelId 25056: CLIENTCHANNEL SOCKET CLOSED: 0007134F 
[2023-03-22 10:28:10.061 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:29:08.757 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] 
  DIAGNOSTICS INFORMATION for          : opc.tcp://192.168.18.36:4861_79E4FF2A
  - Ingestion duration                 :    00:00:00:00 (dd:hh:mm:ss)
  - Ingress DataChanges (from OPC)     :              0 
  - Ingress ValueChanges (from OPC)    :              0 
  - Ingress BatchBlock buffer size     :              0
  - Encoding Block input/output size   :              0 | 0
  - Encoder Notifications processed    :              0
  - Encoder Notifications dropped      :              0
  - Encoder IoT Messages processed     :              0
  - Encoder avg Notifications/Message  :              0
  - Encoder avg IoT Message body size  :              0 (0%)
  - Encoder avg IoT Chunk (4 KB) usage :              0
  - Estimated IoT Chunks (4 KB) per day:              0
  - Outgress Batch Block buffer size   :              0
  - Outgress input buffer count        :              0
  - Outgress input buffer dropped      :              0
  - Outgress IoT message count         :              0 
  - Connection retries                 :              0
  - Opc endpoint connected?            :          False
  - Monitored Opc nodes succeeded count:              0
  - Monitored Opc nodes failed count   :              0

[2023-03-22 10:30:08.735 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] 
  DIAGNOSTICS INFORMATION for          : opc.tcp://192.168.18.36:4861_79E4FF2A
  - Ingestion duration                 :    00:00:00:00 (dd:hh:mm:ss)
  - Ingress DataChanges (from OPC)     :              0 
  - Ingress ValueChanges (from OPC)    :              0 
  - Ingress BatchBlock buffer size     :              0
  - Encoding Block input/output size   :              0 | 0
  - Encoder Notifications processed    :              0
  - Encoder Notifications dropped      :              0
  - Encoder IoT Messages processed     :              0
  - Encoder avg Notifications/Message  :              0
  - Encoder avg IoT Message body size  :              0 (0%)
  - Encoder avg IoT Chunk (4 KB) usage :              0
  - Estimated IoT Chunks (4 KB) per day:              0
  - Outgress Batch Block buffer size   :              0
  - Outgress input buffer count        :              0
  - Outgress input buffer dropped      :              0
  - Outgress IoT message count         :              0 
  - Connection retries                 :              0
  - Opc endpoint connected?            :          False
  - Monitored Opc nodes succeeded count:              0
  - Monitored Opc nodes failed count   :              0

[2023-03-22 10:30:10.332 INF OpcUa] Create session failed with client certificate NULL. Error establishing a connection: BadRequestTimeout 
[2023-03-22 10:30:10.334 INF OpcUa] ChannelId 0: in Closed state. 
[2023-03-22 10:30:10.334 INF OpcUa] ChannelId 0: CLIENTCHANNEL SOCKET CLOSED: FFFFFFFF 
[2023-03-22 10:30:10.335 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Azure IIoT opc.tcp://192.168.18.36:4861_79E4FF2A took 00:02:00.4132665. 
[2023-03-22 10:30:10.335 WRN Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Failed to create session 'opc.tcp://192.168.18.36:4861_79E4FF2A' due to One or more errors occurred. (BadConnectionClosed) 
[2023-03-22 10:30:18.803 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:19.021 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:19.022 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:19.022. Lifetime=3600000. 
[2023-03-22 10:30:19.030 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:19.031 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:19.031 INF OpcUa] ChannelId 25057: Token #1 activated. CreatedAt=10:30:19.022. Lifetime=3600000. 
[2023-03-22 10:30:19.031 INF OpcUa] ChannelId 25057: in Open state. 
[2023-03-22 10:30:19.031 INF OpcUa] ChannelId 25057: Token Expiry 03/22/2023 11:30:19, renewal scheduled in 2699992 ms. 
[2023-03-22 10:30:19.042 INF OpcUa] ChannelId 25057: in Closing state. 
[2023-03-22 10:30:19.049 WRN OpcUa] ChannelId 25057: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:19.049 INF OpcUa] ChannelId 25057: in Closed state. 
[2023-03-22 10:30:19.049 INF OpcUa] ChannelId 25057: CLIENTCHANNEL SOCKET CLOSED: 02E0EEB2 
[2023-03-22 10:30:19.050 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Creating session 'opc.tcp://192.168.18.36:4861_79E4FF2A' for endpoint 'opc.tcp://192.168.18.36:4861'... 
[2023-03-22 10:30:19.050 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:19.062 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:19.063 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:19.063. Lifetime=3600000. 
[2023-03-22 10:30:19.077 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:19.077 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:19.077 INF OpcUa] ChannelId 25058: Token #1 activated. CreatedAt=10:30:19.063. Lifetime=3600000. 
[2023-03-22 10:30:19.077 INF OpcUa] ChannelId 25058: in Open state. 
[2023-03-22 10:30:19.077 INF OpcUa] ChannelId 25058: Token Expiry 03/22/2023 11:30:19, renewal scheduled in 2699988 ms. 
[2023-03-22 10:30:19.094 INF OpcUa] ChannelId 25058: in Closing state. 
[2023-03-22 10:30:19.103 WRN OpcUa] ChannelId 25058: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:19.103 INF OpcUa] ChannelId 25058: in Closed state. 
[2023-03-22 10:30:19.103 INF OpcUa] ChannelId 25058: CLIENTCHANNEL SOCKET CLOSED: 01A7CB99 
[2023-03-22 10:30:19.106 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:19.123 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:19.123 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:19.123. Lifetime=3600000. 
[2023-03-22 10:30:19.131 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:19.131 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:19.131 INF OpcUa] ChannelId 25059: Token #1 activated. CreatedAt=10:30:19.123. Lifetime=3600000. 
[2023-03-22 10:30:19.131 INF OpcUa] ChannelId 25059: in Open state. 
[2023-03-22 10:30:19.131 INF OpcUa] ChannelId 25059: Token Expiry 03/22/2023 11:30:19, renewal scheduled in 2699994 ms. 
[2023-03-22 10:30:19.382 INF OpcUa] Revised session timeout value: 100000.  
[2023-03-22 10:30:19.383 INF OpcUa] Max response message size value: 4194304. Max request message size: 0  
[2023-03-22 10:30:19.387 INF OpcUa] Server signature is null or empty. 
[2023-03-22 10:30:19.409 INF OpcUa] Empty results were received for the ActivateSession call. 
[2023-03-22 10:30:19.925 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_79E4FF2A' created, loading complex type system ...  
[2023-03-22 10:30:20.151 WRN OpcUa] ChannelId 25059: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:20.151 INF OpcUa] ChannelId 25059: in Closed state. 
[2023-03-22 10:30:20.151 INF OpcUa] ChannelId 25059: CLIENTCHANNEL SOCKET CLOSED: 03783D37 
[2023-03-22 10:30:20.153 ERR OpcUa] Could not fetch nodes from server: Reason='BadTooManyOperations'. 
[2023-03-22 10:30:20.153 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:20.193 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:20.193 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:20.193. Lifetime=3600000. 
[2023-03-22 10:30:20.200 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:20.200 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:20.200 INF OpcUa] ChannelId 25060: Token #1 activated. CreatedAt=10:30:20.193. Lifetime=3600000. 
[2023-03-22 10:30:20.200 INF OpcUa] ChannelId 25060: in Open state. 
[2023-03-22 10:30:20.200 INF OpcUa] ChannelId 25060: Token Expiry 03/22/2023 11:30:20, renewal scheduled in 2699994 ms. 
[2023-03-22 10:30:20.206 WRN OpcUa] ChannelId 25060: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:20.207 INF OpcUa] ChannelId 25060: in Closed state. 
[2023-03-22 10:30:20.207 INF OpcUa] ChannelId 25060: CLIENTCHANNEL SOCKET CLOSED: 03C1CB7A 
[2023-03-22 10:30:20.207 ERR OpcUa] Could not fetch nodes from server: Reason='BadSessionIdInvalid'. 
[2023-03-22 10:30:20.207 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:20.226 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:20.226 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:20.226. Lifetime=3600000. 
[2023-03-22 10:30:20.233 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:20.233 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:20.233 INF OpcUa] ChannelId 25061: Token #1 activated. CreatedAt=10:30:20.226. Lifetime=3600000. 
[2023-03-22 10:30:20.233 INF OpcUa] ChannelId 25061: in Open state. 
[2023-03-22 10:30:20.234 INF OpcUa] ChannelId 25061: Token Expiry 03/22/2023 11:30:20, renewal scheduled in 2699994 ms. 
[2023-03-22 10:30:20.274 ERR OpcUa] Could not fetch nodes from server: Reason='BadSessionIdInvalid'. 
[2023-03-22 10:30:20.277 WRN OpcUa] ChannelId 25061: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:20.277 INF OpcUa] ChannelId 25061: in Closed state. 
[2023-03-22 10:30:20.277 INF OpcUa] ChannelId 25061: CLIENTCHANNEL SOCKET CLOSED: 014A33E3 
[2023-03-22 10:30:20.284 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_79E4FF2A' complex type system loaded 
[2023-03-22 10:30:20.285 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Azure IIoT opc.tcp://192.168.18.36:4861_79E4FF2A took 00:00:01.2345495. 
[2023-03-22 10:30:20.285 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Connected to 'opc.tcp://192.168.18.36:4861' 
[2023-03-22 10:30:20.292 WRN OpcUa] A smaller lifeTime 10000ms than session timeout 100000ms configured for subscription 0. 
[2023-03-22 10:30:20.293 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:21.079 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:21.079 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:21.079. Lifetime=3600000. 
[2023-03-22 10:30:21.092 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:21.092 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:21.092 INF OpcUa] ChannelId 25062: Token #1 activated. CreatedAt=10:30:21.079. Lifetime=3600000. 
[2023-03-22 10:30:21.092 INF OpcUa] ChannelId 25062: in Open state. 
[2023-03-22 10:30:21.092 INF OpcUa] ChannelId 25062: Token Expiry 03/22/2023 11:30:21, renewal scheduled in 2699989 ms. 
[2023-03-22 10:30:21.146 WRN OpcUa] ChannelId 25062: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:21.146 INF OpcUa] ChannelId 25062: in Closed state. 
[2023-03-22 10:30:21.146 INF OpcUa] ChannelId 25062: CLIENTCHANNEL SOCKET CLOSED: 03519B61 
[2023-03-22 10:30:21.147 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to enable subscription 
Opc.Ua.ServiceResultException: BadSecureChannelClosed
   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.CreateSubscription(RequestHeader requestHeader, Double requestedPublishingInterval, UInt32 requestedLifetimeCount, UInt32 requestedMaxKeepAliveCount, UInt32 maxNotificationsPerPublish, Boolean publishingEnabled, Byte priority, UInt32& subscriptionId, Double& revisedPublishingInterval, UInt32& revisedLifetimeCount, UInt32& revisedMaxKeepAliveCount)
   at Opc.Ua.Client.Subscription.Create()
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 750
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.EnableAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 241
[2023-03-22 10:30:21.159 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:30:28.815 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:29.077 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:29.077 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:29.077. Lifetime=3600000. 
[2023-03-22 10:30:29.084 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:29.084 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:29.085 INF OpcUa] ChannelId 25063: Token #1 activated. CreatedAt=10:30:29.077. Lifetime=3600000. 
[2023-03-22 10:30:29.085 INF OpcUa] ChannelId 25063: in Open state. 
[2023-03-22 10:30:29.085 INF OpcUa] ChannelId 25063: Token Expiry 03/22/2023 11:30:29, renewal scheduled in 2699994 ms. 
[2023-03-22 10:30:29.098 WRN OpcUa] ChannelId 25063: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:29.098 INF OpcUa] ChannelId 25063: in Closed state. 
[2023-03-22 10:30:29.099 INF OpcUa] ChannelId 25063: CLIENTCHANNEL SOCKET CLOSED: 038BBC52 
[2023-03-22 10:30:29.100 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Failed to refresh session 'opc.tcp://192.168.18.36:4861_79E4FF2A' 
Opc.Ua.ServiceResultException: BadSessionIdInvalid
   at Opc.Ua.ClientBase.ValidateResponse(ResponseHeader header)
   at Opc.Ua.SessionClient.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.SessionClientBatched.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.Client.Session.FetchNamespaceTables()
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.HandleRefreshAsync(ConnectionIdentifier id, SessionWrapper wrapper, CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 512
[2023-03-22 10:30:29.930 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:29.943 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:29.943 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:29.943. Lifetime=3600000. 
[2023-03-22 10:30:29.949 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:29.949 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:29.950 INF OpcUa] ChannelId 25064: Token #1 activated. CreatedAt=10:30:29.943. Lifetime=3600000. 
[2023-03-22 10:30:29.950 INF OpcUa] ChannelId 25064: in Open state. 
[2023-03-22 10:30:29.950 INF OpcUa] ChannelId 25064: Token Expiry 03/22/2023 11:30:29, renewal scheduled in 2699994 ms. 
[2023-03-22 10:30:29.970 ERR OpcUa] Unexpected keep alive error occurred: BadSessionIdInvalid 
[2023-03-22 10:30:29.970 WRN OpcUa] ChannelId 25064: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:29.970 INF OpcUa] ChannelId 25064: in Closed state. 
[2023-03-22 10:30:29.971 INF OpcUa] ChannelId 25064: CLIENTCHANNEL SOCKET CLOSED: 0395821B 
[2023-03-22 10:30:38.795 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:38.838 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:38.838 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:38.838. Lifetime=3600000. 
[2023-03-22 10:30:38.848 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:38.848 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:38.848 INF OpcUa] ChannelId 25065: Token #1 activated. CreatedAt=10:30:38.838. Lifetime=3600000. 
[2023-03-22 10:30:38.848 INF OpcUa] ChannelId 25065: in Open state. 
[2023-03-22 10:30:38.848 INF OpcUa] ChannelId 25065: Token Expiry 03/22/2023 11:30:38, renewal scheduled in 2699992 ms. 
[2023-03-22 10:30:38.855 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Failed to refresh session 'opc.tcp://192.168.18.36:4861_79E4FF2A' 
Opc.Ua.ServiceResultException: BadSessionIdInvalid
   at Opc.Ua.ClientBase.ValidateResponse(ResponseHeader header)
   at Opc.Ua.SessionClient.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.SessionClientBatched.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.Client.Session.FetchNamespaceTables()
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.HandleRefreshAsync(ConnectionIdentifier id, SessionWrapper wrapper, CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 512
[2023-03-22 10:30:38.902 WRN OpcUa] ChannelId 25065: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:38.903 INF OpcUa] ChannelId 25065: in Closed state. 
[2023-03-22 10:30:38.903 INF OpcUa] ChannelId 25065: CLIENTCHANNEL SOCKET CLOSED: 0107A4C2 
[2023-03-22 10:30:39.925 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:39.981 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:30:39.981 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:30:39.981. Lifetime=3600000. 
[2023-03-22 10:30:39.993 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:30:39.993 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:30:39.994 INF OpcUa] ChannelId 25066: Token #1 activated. CreatedAt=10:30:39.981. Lifetime=3600000. 
[2023-03-22 10:30:39.994 INF OpcUa] ChannelId 25066: in Open state. 
[2023-03-22 10:30:39.994 INF OpcUa] ChannelId 25066: Token Expiry 03/22/2023 11:30:39, renewal scheduled in 2699990 ms. 
[2023-03-22 10:30:40.003 WRN OpcUa] ChannelId 25066: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:30:40.003 INF OpcUa] ChannelId 25066: in Closed state. 
[2023-03-22 10:30:40.003 INF OpcUa] ChannelId 25066: CLIENTCHANNEL SOCKET CLOSED: 0206D2E2 
[2023-03-22 10:30:40.004 ERR OpcUa] Unexpected keep alive error occurred: BadSessionIdInvalid 
[2023-03-22 10:30:48.824 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_79E4FF2A' missed 1 Keepalive(s) due to BadNoCommunication, waiting to reconnect... 
[2023-03-22 10:30:48.835 INF OpcUa] Session RECONNECT starting. 
[2023-03-22 10:30:48.836 INF OpcUa] Session REPLACING channel. 
[2023-03-22 10:30:48.838 INF OpcUa] Session RE-ACTIVATING session. 
[2023-03-22 10:30:48.838 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:30:56.343 WRN OpcUa] WARNING: ACTIVATE SESSION timed out. 0/0 
[2023-03-22 10:31:08.744 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] 
  DIAGNOSTICS INFORMATION for          : opc.tcp://192.168.18.36:4861_79E4FF2A
  - Ingestion duration                 :    00:00:00:00 (dd:hh:mm:ss)
  - Ingress DataChanges (from OPC)     :              0 
  - Ingress ValueChanges (from OPC)    :              0 
  - Ingress BatchBlock buffer size     :              0
  - Encoding Block input/output size   :              0 | 0
  - Encoder Notifications processed    :              0
  - Encoder Notifications dropped      :              0
  - Encoder IoT Messages processed     :              0
  - Encoder avg Notifications/Message  :              0
  - Encoder avg IoT Message body size  :              0 (0%)
  - Encoder avg IoT Chunk (4 KB) usage :              0
  - Estimated IoT Chunks (4 KB) per day:              0
  - Outgress Batch Block buffer size   :              0
  - Outgress input buffer count        :              0
  - Outgress input buffer dropped      :              0
  - Outgress IoT message count         :              0 
  - Connection retries                 :              1
  - Opc endpoint connected?            :          False
  - Monitored Opc nodes succeeded count:              0
  - Monitored Opc nodes failed count   :              0

[2023-03-22 10:32:08.738 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] 
  DIAGNOSTICS INFORMATION for          : opc.tcp://192.168.18.36:4861_79E4FF2A
  - Ingestion duration                 :    00:00:00:00 (dd:hh:mm:ss)
  - Ingress DataChanges (from OPC)     :              0 
  - Ingress ValueChanges (from OPC)    :              0 
  - Ingress BatchBlock buffer size     :              0
  - Encoding Block input/output size   :              0 | 0
  - Encoder Notifications processed    :              0
  - Encoder Notifications dropped      :              0
  - Encoder IoT Messages processed     :              0
  - Encoder avg Notifications/Message  :              0
  - Encoder avg IoT Message body size  :              0 (0%)
  - Encoder avg IoT Chunk (4 KB) usage :              0
  - Estimated IoT Chunks (4 KB) per day:              0
  - Outgress Batch Block buffer size   :              0
  - Outgress input buffer count        :              0
  - Outgress input buffer dropped      :              0
  - Outgress IoT message count         :              0 
  - Connection retries                 :              1
  - Opc endpoint connected?            :          False
  - Monitored Opc nodes succeeded count:              0
  - Monitored Opc nodes failed count   :              0

[2023-03-22 10:32:48.844 WRN Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Failed to reconnect session 'opc.tcp://192.168.18.36:4861_79E4FF2A' due to BadRequestTimeout, will retry later 
[2023-03-22 10:32:58.831 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_79E4FF2A' missed 2 Keepalive(s) due to BadNoCommunication, waiting to reconnect... 
[2023-03-22 10:32:58.832 INF OpcUa] Session RECONNECT starting. 
[2023-03-22 10:32:58.832 INF OpcUa] Session REPLACING channel. 
[2023-03-22 10:32:58.835 INF OpcUa] TransportChannel RECONNECT: Reconnecting to opc.tcp://192.168.18.36:4861/. 
[2023-03-22 10:32:58.836 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:32:58.880 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:32:58.880 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:32:58.880. Lifetime=3600000. 
[2023-03-22 10:32:59.830 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:32:59.831 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:32:59.832 INF OpcUa] ChannelId 25067: Token #1 activated. CreatedAt=10:32:58.880. Lifetime=3600000. 
[2023-03-22 10:32:59.832 INF OpcUa] ChannelId 25067: in Open state. 
[2023-03-22 10:32:59.832 INF OpcUa] ChannelId 25067: Token Expiry 03/22/2023 11:32:58, renewal scheduled in 2699285 ms. 
[2023-03-22 10:32:59.833 INF OpcUa] CLIENTCHANNEL SOCKET CONNECTED: 0116D04B, ChannelId=25067 
[2023-03-22 10:32:59.834 INF OpcUa] ChannelId 0: in Closed state. 
[2023-03-22 10:32:59.834 INF OpcUa] ChannelId 0: CLIENTCHANNEL SOCKET CLOSED: FFFFFFFF 
[2023-03-22 10:32:59.836 INF OpcUa] Session RE-ACTIVATING session. 
[2023-03-22 10:32:59.880 WRN Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Failed to reconnect session 'opc.tcp://192.168.18.36:4861_79E4FF2A' due to BadSessionIdInvalid,  disposing and trying to create new 
[2023-03-22 10:32:59.887 INF OpcUa] ChannelId 25067: in Closing state. 
[2023-03-22 10:32:59.896 WRN OpcUa] ChannelId 25067: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:32:59.896 INF OpcUa] ChannelId 25067: in Closed state. 
[2023-03-22 10:32:59.896 INF OpcUa] ChannelId 25067: CLIENTCHANNEL SOCKET CLOSED: 0116D04B 
[2023-03-22 10:32:59.896 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:32:59.909 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:32:59.909 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:32:59.909. Lifetime=3600000. 
[2023-03-22 10:32:59.919 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:32:59.919 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:32:59.919 INF OpcUa] ChannelId 25068: Token #1 activated. CreatedAt=10:32:59.909. Lifetime=3600000. 
[2023-03-22 10:32:59.919 INF OpcUa] ChannelId 25068: in Open state. 
[2023-03-22 10:32:59.919 INF OpcUa] ChannelId 25068: Token Expiry 03/22/2023 11:32:59, renewal scheduled in 2699991 ms. 
[2023-03-22 10:32:59.927 INF OpcUa] ChannelId 25068: in Closing state. 
[2023-03-22 10:32:59.940 WRN OpcUa] ChannelId 25068: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:32:59.940 INF OpcUa] ChannelId 25068: in Closed state. 
[2023-03-22 10:32:59.940 INF OpcUa] ChannelId 25068: CLIENTCHANNEL SOCKET CLOSED: 030B03BF 
[2023-03-22 10:32:59.940 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Creating session 'opc.tcp://192.168.18.36:4861_79E4FF2A' for endpoint 'opc.tcp://192.168.18.36:4861'... 
[2023-03-22 10:32:59.941 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:32:59.953 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:32:59.953 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:32:59.953. Lifetime=3600000. 
[2023-03-22 10:32:59.959 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:32:59.959 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:32:59.959 INF OpcUa] ChannelId 25069: Token #1 activated. CreatedAt=10:32:59.953. Lifetime=3600000. 
[2023-03-22 10:32:59.959 INF OpcUa] ChannelId 25069: in Open state. 
[2023-03-22 10:32:59.959 INF OpcUa] ChannelId 25069: Token Expiry 03/22/2023 11:32:59, renewal scheduled in 2699994 ms. 
[2023-03-22 10:32:59.969 INF OpcUa] ChannelId 25069: in Closing state. 
[2023-03-22 10:32:59.984 WRN OpcUa] ChannelId 25069: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:32:59.984 INF OpcUa] ChannelId 25069: in Closed state. 
[2023-03-22 10:32:59.984 INF OpcUa] ChannelId 25069: CLIENTCHANNEL SOCKET CLOSED: 025020AA 
[2023-03-22 10:32:59.986 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:00.003 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:00.004 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:00.004. Lifetime=3600000. 
[2023-03-22 10:33:00.011 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:00.011 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:00.011 INF OpcUa] ChannelId 25070: Token #1 activated. CreatedAt=10:33:00.004. Lifetime=3600000. 
[2023-03-22 10:33:00.012 INF OpcUa] ChannelId 25070: in Open state. 
[2023-03-22 10:33:00.012 INF OpcUa] ChannelId 25070: Token Expiry 03/22/2023 11:33:00, renewal scheduled in 2699994 ms. 
[2023-03-22 10:33:00.017 INF OpcUa] Revised session timeout value: 100000.  
[2023-03-22 10:33:00.017 INF OpcUa] Max response message size value: 4194304. Max request message size: 0  
[2023-03-22 10:33:00.017 INF OpcUa] Server signature is null or empty. 
[2023-03-22 10:33:00.023 INF OpcUa] Empty results were received for the ActivateSession call. 
[2023-03-22 10:33:00.043 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_79E4FF2A' created, loading complex type system ...  
[2023-03-22 10:33:00.160 WRN OpcUa] ChannelId 25070: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:33:00.160 INF OpcUa] ChannelId 25070: in Closed state. 
[2023-03-22 10:33:00.160 INF OpcUa] ChannelId 25070: CLIENTCHANNEL SOCKET CLOSED: 0219D33D 
[2023-03-22 10:33:00.161 ERR OpcUa] Could not fetch nodes from server: Reason='BadTooManyOperations'. 
[2023-03-22 10:33:00.161 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:00.183 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:00.183 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:00.183. Lifetime=3600000. 
[2023-03-22 10:33:00.189 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:00.189 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:00.189 INF OpcUa] ChannelId 25071: Token #1 activated. CreatedAt=10:33:00.183. Lifetime=3600000. 
[2023-03-22 10:33:00.189 INF OpcUa] ChannelId 25071: in Open state. 
[2023-03-22 10:33:00.189 INF OpcUa] ChannelId 25071: Token Expiry 03/22/2023 11:33:00, renewal scheduled in 2699994 ms. 
[2023-03-22 10:33:00.195 WRN OpcUa] ChannelId 25071: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:33:00.196 INF OpcUa] ChannelId 25071: in Closed state. 
[2023-03-22 10:33:00.196 INF OpcUa] ChannelId 25071: CLIENTCHANNEL SOCKET CLOSED: 01C4898D 
[2023-03-22 10:33:00.196 ERR OpcUa] Could not fetch nodes from server: Reason='BadSessionIdInvalid'. 
[2023-03-22 10:33:00.196 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:00.208 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:00.208 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:00.208. Lifetime=3600000. 
[2023-03-22 10:33:00.214 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:00.215 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:00.215 INF OpcUa] ChannelId 25072: Token #1 activated. CreatedAt=10:33:00.208. Lifetime=3600000. 
[2023-03-22 10:33:00.215 INF OpcUa] ChannelId 25072: in Open state. 
[2023-03-22 10:33:00.215 INF OpcUa] ChannelId 25072: Token Expiry 03/22/2023 11:33:00, renewal scheduled in 2699994 ms. 
[2023-03-22 10:33:00.221 WRN OpcUa] ChannelId 25072: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:33:00.221 INF OpcUa] ChannelId 25072: in Closed state. 
[2023-03-22 10:33:00.221 INF OpcUa] ChannelId 25072: CLIENTCHANNEL SOCKET CLOSED: 001D5FB2 
[2023-03-22 10:33:00.221 ERR OpcUa] Could not fetch nodes from server: Reason='BadSessionIdInvalid'. 
[2023-03-22 10:33:00.222 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_79E4FF2A' complex type system loaded 
[2023-03-22 10:33:00.222 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Azure IIoT opc.tcp://192.168.18.36:4861_79E4FF2A took 00:00:00.2813023. 
[2023-03-22 10:33:00.222 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Connected to 'opc.tcp://192.168.18.36:4861' 
[2023-03-22 10:33:00.222 WRN OpcUa] A smaller lifeTime 10000ms than session timeout 100000ms configured for subscription 0. 
[2023-03-22 10:33:00.222 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:00.234 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:00.234 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:00.234. Lifetime=3600000. 
[2023-03-22 10:33:00.240 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:00.240 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:00.240 INF OpcUa] ChannelId 25073: Token #1 activated. CreatedAt=10:33:00.234. Lifetime=3600000. 
[2023-03-22 10:33:00.240 INF OpcUa] ChannelId 25073: in Open state. 
[2023-03-22 10:33:00.240 INF OpcUa] ChannelId 25073: Token Expiry 03/22/2023 11:33:00, renewal scheduled in 2699994 ms. 
[2023-03-22 10:33:00.246 WRN OpcUa] ChannelId 25073: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:33:00.246 INF OpcUa] ChannelId 25073: in Closed state. 
[2023-03-22 10:33:00.247 INF OpcUa] ChannelId 25073: CLIENTCHANNEL SOCKET CLOSED: 00D5C8A9 
[2023-03-22 10:33:00.247 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to enable subscription 
Opc.Ua.ServiceResultException: BadSecureChannelClosed
   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.CreateSubscription(RequestHeader requestHeader, Double requestedPublishingInterval, UInt32 requestedLifetimeCount, UInt32 requestedMaxKeepAliveCount, UInt32 maxNotificationsPerPublish, Boolean publishingEnabled, Byte priority, UInt32& subscriptionId, Double& revisedPublishingInterval, UInt32& revisedLifetimeCount, UInt32& revisedMaxKeepAliveCount)
   at Opc.Ua.Client.Subscription.Create()
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 750
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.EnableAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 241
[2023-03-22 10:33:00.248 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:33:08.737 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] 
  DIAGNOSTICS INFORMATION for          : opc.tcp://192.168.18.36:4861_79E4FF2A
  - Ingestion duration                 :    00:00:00:00 (dd:hh:mm:ss)
  - Ingress DataChanges (from OPC)     :              0 
  - Ingress ValueChanges (from OPC)    :              0 
  - Ingress BatchBlock buffer size     :              0
  - Encoding Block input/output size   :              0 | 0
  - Encoder Notifications processed    :              0
  - Encoder Notifications dropped      :              0
  - Encoder IoT Messages processed     :              0
  - Encoder avg Notifications/Message  :              0
  - Encoder avg IoT Message body size  :              0 (0%)
  - Encoder avg IoT Chunk (4 KB) usage :              0
  - Estimated IoT Chunks (4 KB) per day:              0
  - Outgress Batch Block buffer size   :              0
  - Outgress input buffer count        :              0
  - Outgress input buffer dropped      :              0
  - Outgress IoT message count         :              0 
  - Connection retries                 :              3
  - Opc endpoint connected?            :           True
  - Monitored Opc nodes succeeded count:              0
  - Monitored Opc nodes failed count   :              0

[2023-03-22 10:33:08.840 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:08.879 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:08.879 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:08.879. Lifetime=3600000. 
[2023-03-22 10:33:08.887 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:08.887 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:08.887 INF OpcUa] ChannelId 25074: Token #1 activated. CreatedAt=10:33:08.879. Lifetime=3600000. 
[2023-03-22 10:33:08.887 INF OpcUa] ChannelId 25074: in Open state. 
[2023-03-22 10:33:08.888 INF OpcUa] ChannelId 25074: Token Expiry 03/22/2023 11:33:08, renewal scheduled in 2699993 ms. 
[2023-03-22 10:33:08.902 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Failed to refresh session 'opc.tcp://192.168.18.36:4861_79E4FF2A' 
Opc.Ua.ServiceResultException: BadSessionIdInvalid
   at Opc.Ua.ClientBase.ValidateResponse(ResponseHeader header)
   at Opc.Ua.SessionClient.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.SessionClientBatched.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.Client.Session.FetchNamespaceTables()
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.HandleRefreshAsync(ConnectionIdentifier id, SessionWrapper wrapper, CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 512
[2023-03-22 10:33:08.903 WRN OpcUa] ChannelId 25074: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:33:08.903 INF OpcUa] ChannelId 25074: in Closed state. 
[2023-03-22 10:33:08.903 INF OpcUa] ChannelId 25074: CLIENTCHANNEL SOCKET CLOSED: 03A38E7D 
[2023-03-22 10:33:10.045 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:10.447 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:10.447 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:10.447. Lifetime=3600000. 
[2023-03-22 10:33:10.463 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:10.463 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:10.463 INF OpcUa] ChannelId 25075: Token #1 activated. CreatedAt=10:33:10.447. Lifetime=3600000. 
[2023-03-22 10:33:10.463 INF OpcUa] ChannelId 25075: in Open state. 
[2023-03-22 10:33:10.463 INF OpcUa] ChannelId 25075: Token Expiry 03/22/2023 11:33:10, renewal scheduled in 2699987 ms. 
[2023-03-22 10:33:10.472 WRN OpcUa] ChannelId 25075: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:33:10.472 INF OpcUa] ChannelId 25075: in Closed state. 
[2023-03-22 10:33:10.472 INF OpcUa] ChannelId 25075: CLIENTCHANNEL SOCKET CLOSED: 031567E4 
[2023-03-22 10:33:10.473 ERR OpcUa] Unexpected keep alive error occurred: BadSessionIdInvalid 
[2023-03-22 10:33:18.846 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:18.894 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:18.894 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:18.894. Lifetime=3600000. 
[2023-03-22 10:33:18.911 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:18.912 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:18.912 INF OpcUa] ChannelId 25076: Token #1 activated. CreatedAt=10:33:18.894. Lifetime=3600000. 
[2023-03-22 10:33:18.912 INF OpcUa] ChannelId 25076: in Open state. 
[2023-03-22 10:33:18.912 INF OpcUa] ChannelId 25076: Token Expiry 03/22/2023 11:33:18, renewal scheduled in 2699986 ms. 
[2023-03-22 10:33:18.923 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Failed to refresh session 'opc.tcp://192.168.18.36:4861_79E4FF2A' 
Opc.Ua.ServiceResultException: BadSessionIdInvalid
   at Opc.Ua.ClientBase.ValidateResponse(ResponseHeader header)
   at Opc.Ua.SessionClient.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.SessionClientBatched.Read(RequestHeader requestHeader, Double maxAge, TimestampsToReturn timestampsToReturn, ReadValueIdCollection nodesToRead, DataValueCollection& results, DiagnosticInfoCollection& diagnosticInfos)
   at Opc.Ua.Client.Session.FetchNamespaceTables()
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager.HandleRefreshAsync(ConnectionIdentifier id, SessionWrapper wrapper, CancellationToken ct) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\DefaultSessionManager.cs:line 512
[2023-03-22 10:33:18.924 WRN OpcUa] ChannelId 25076: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:33:18.924 INF OpcUa] ChannelId 25076: in Closed state. 
[2023-03-22 10:33:18.924 INF OpcUa] ChannelId 25076: CLIENTCHANNEL SOCKET CLOSED: 004D5AEB 
[2023-03-22 10:33:20.048 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:20.086 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:20.086 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:20.086. Lifetime=3600000. 
[2023-03-22 10:33:20.093 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:20.094 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:20.094 INF OpcUa] ChannelId 25077: Token #1 activated. CreatedAt=10:33:20.086. Lifetime=3600000. 
[2023-03-22 10:33:20.094 INF OpcUa] ChannelId 25077: in Open state. 
[2023-03-22 10:33:20.094 INF OpcUa] ChannelId 25077: Token Expiry 03/22/2023 11:33:20, renewal scheduled in 2699993 ms. 
[2023-03-22 10:33:20.145 WRN OpcUa] ChannelId 25077: Force reconnect reason=BadConnectionClosed 'Remote side closed connection' 
[2023-03-22 10:33:20.146 INF OpcUa] ChannelId 25077: in Closed state. 
[2023-03-22 10:33:20.146 INF OpcUa] ChannelId 25077: CLIENTCHANNEL SOCKET CLOSED: 034458F2 
[2023-03-22 10:33:20.146 ERR OpcUa] Unexpected keep alive error occurred: BadSessionIdInvalid 
[2023-03-22 10:33:28.846 INF Microsoft.Azure.IIoT.OpcUa.Protocol.Services.DefaultSessionManager] Session 'opc.tcp://192.168.18.36:4861_79E4FF2A' missed 1 Keepalive(s) due to BadNoCommunication, waiting to reconnect... 
[2023-03-22 10:33:28.848 INF OpcUa] Session RECONNECT starting. 
[2023-03-22 10:33:28.848 INF OpcUa] Session REPLACING channel. 
[2023-03-22 10:33:28.850 INF OpcUa] Session RE-ACTIVATING session. 
[2023-03-22 10:33:28.850 INF OpcUa] ChannelId 0: in Connecting state. 
[2023-03-22 10:33:28.869 INF OpcUa] ChannelId 0: in Opening state. 
[2023-03-22 10:33:28.869 INF OpcUa] ChannelId 0: Token #0 created. CreatedAt=10:33:28.869. Lifetime=3600000. 
[2023-03-22 10:33:28.877 INF OpcUa] Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None 
[2023-03-22 10:33:28.877 INF OpcUa] Sender Certificate: (none) 
[2023-03-22 10:33:28.877 INF OpcUa] ChannelId 25078: Token #1 activated. CreatedAt=10:33:28.869. Lifetime=3600000. 
[2023-03-22 10:33:28.877 INF OpcUa] ChannelId 25078: in Open state. 
[2023-03-22 10:33:28.877 INF OpcUa] ChannelId 25078: Token Expiry 03/22/2023 11:33:28, renewal scheduled in 2699993 ms. 
[2023-03-22 10:33:28.884 INF OpcUa] Session RECONNECT completed successfully. 
[2023-03-22 10:33:28.888 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:33:40.351 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:33:48.865 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:34:02.111 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:34:08.737 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] 
  DIAGNOSTICS INFORMATION for          : opc.tcp://192.168.18.36:4861_79E4FF2A
  - Ingestion duration                 :    00:00:00:00 (dd:hh:mm:ss)
  - Ingress DataChanges (from OPC)     :              0 
  - Ingress ValueChanges (from OPC)    :              0 
  - Ingress BatchBlock buffer size     :              0
  - Encoding Block input/output size   :              0 | 0
  - Encoder Notifications processed    :              0
  - Encoder Notifications dropped      :              0
  - Encoder IoT Messages processed     :              0
  - Encoder avg Notifications/Message  :              0
  - Encoder avg IoT Message body size  :              0 (0%)
  - Encoder avg IoT Chunk (4 KB) usage :              0
  - Estimated IoT Chunks (4 KB) per day:              0
  - Outgress Batch Block buffer size   :              0
  - Outgress input buffer count        :              0
  - Outgress input buffer dropped      :              0
  - Outgress IoT message count         :              0 
  - Connection retries                 :              3
  - Opc endpoint connected?            :           True
  - Monitored Opc nodes succeeded count:              0
  - Monitored Opc nodes failed count   :              0

[2023-03-22 10:34:09.801 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:34:19.441 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:34:29.552 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:34:40.631 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:34:52.098 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:34:58.866 ERR Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices+SubscriptionWrapper] Failed to activate subscription 
Opc.Ua.ServiceResultException: Subscription has not been created.
   at Opc.Ua.Client.Subscription.VerifySubscriptionState(Boolean created)
   at Opc.Ua.Client.Subscription.SetPublishingMode(Boolean enabled)
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.GetSubscription(Session session, SubscriptionConfigurationModel configuration, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 821
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ReapplyAsync(Session session, Boolean activate) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 289
   at Microsoft.Azure.IIoT.OpcUa.Protocol.Services.SubscriptionServices.SubscriptionWrapper.ActivateAsync(Session session) in D:\a\1\s\components\opc-ua\src\Microsoft.Azure.IIoT.OpcUa.Protocol\src\Services\SubscriptionServices.cs:line 259
[2023-03-22 10:35:08.739 INF Microsoft.Azure.IIoT.OpcUa.Edge.Publisher.Engine.DataFlowProcessingEngine] 

pcap for UA expert image image image image image

pcap for OPC publisher

image image image image

marcschier commented 1 year ago

@mregen , this looks like an issue in complex type loading in OPC stack. We have seen this before, but here it looks like it could be an issue where we do not honor operation limits on ReadNodes in Fetch nodes in INodeCache from cursory code inspection.

marcschier commented 1 year ago

It would be great to give OPC Publisher Preview 4 a try (mcr.microsoft.com/iotedge/opc-publisher:2.9.0-preview4), it contains the latest OPC UA stack which has a lot of fixes around max number of nodes. This item now covers a way to start OPC Publisher without loading complex type system to get around any misbehavior.