search

OPCFoundation / UA-.NETStandard

OPC Unified Architecture .NET Standard
Other
1.98k stars 950 forks source link

Siemens TP1200 v14 -- OPCUA Stack v1.5.374.126 #2866

Open MoxxxIT opened 3 weeks ago

MoxxxIT commented 3 weeks ago

Type of issue

Current Behavior

OpcFoundation version:1.5.374.126 DataAccess Client, after success connection to OPCUA Server, on variables subscription, with:

ManufactureName: Siemens AG ProductName: WinCC RT Comfort Panel SoftwareVersion: V14 ProductUri :urn:Siemens:Automation:WinCC:PanelRT

reports this errors in the log file (Quickstarts.DataAccessClient.log.txt, TraceMasks:1):

11/08/2024 08:08:14.560 A smaller minLifetimeInterval 10000ms than session timeout 60000ms configured for subscription 0. 11/08/2024 08:08:14.562 Lifetime 10000ms configured for subscription 0 is less than session timeout 60000ms. 11/08/2024 08:08:15.626 Unexpected error processing response. BadDecodingError 'Cannot determine length of unknown extension object body with type 'i=811'.'

11/08/2024 08:08:15.636 Publish OPCFoundation/UA-.NETStandard-Samples#2, Reconnecting=False, Error: Unexpected error processing response. 11/08/2024 08:08:15.638 PUBLISH OPCFoundation/UA-.NETStandard-Samples#2 - Unhandled error BadDecodingError during Publish. BadDecodingError 'Unexpected error processing response.'

11/08/2024 08:08:21.921 Unexpected error processing response. BadDecodingError 'Cannot determine length of unknown extension object body with type 'i=864'.'

11/08/2024 08:08:28.812 Unexpected error processing response. BadDecodingError 'Cannot determine length of unknown extension object body with type 'i=811'.'

11/08/2024 08:08:28.812 Publish OPCFoundation/UA-.NETStandard-Samples#15, Reconnecting=False, Error: Unexpected error processing response. 11/08/2024 08:08:28.812 PUBLISH OPCFoundation/UA-.NETStandard-Samples#15 - Unhandled error BadDecodingError during Publish. BadDecodingError 'Unexpected error processing response.'

11/08/2024 08:08:29.824 Unexpected error processing response. BadDecodingError 'Cannot determine length of unknown extension object body with type 'i=811'.'

11/08/2024 08:08:29.824 Publish OPCFoundation/UA-.NETStandard-Samples#16, Reconnecting=False, Error: Unexpected error processing response. 11/08/2024 08:08:29.825 PUBLISH OPCFoundation/UA-.NETStandard-Samples#16 - Unhandled error BadDecodingError during Publish. BadDecodingError 'Unexpected error processing response.'

11/08/2024 08:08:30.834 Unexpected error processing response. BadDecodingError 'Cannot determine length of unknown extension object body with type 'i=811'.'

11/08/2024 08:08:30.835 Publish OPCFoundation/UA-.NETStandard-Samples#17, Reconnecting=False, Error: Unexpected error processing response. 11/08/2024 08:08:30.835 PUBLISH OPCFoundation/UA-.NETStandard-Samples#17 - Unhandled error BadDecodingError during Publish. BadDecodingError 'Unexpected error processing response.' ...............................

Expected Behavior

No response

Steps To Reproduce

1) Compile the Samples Stack; 2) Connect to Siemens TP1200 HMI with software; 3) Subscribe to a variable.

Environment

- OS:Windows 10/11
- Environment:Microsoft Visual Studio Community 2022 (64 bit) Versione 17.11.5
- Runtime:.NET 4.8.1
- Nuget Version:
- Component:Opc.Ua.Core
- Server:Siemens AG WinCC RT Comfort Panel V14
- Client: Quickstarts.DataAccessClient

Anything else?

No response

MoxxxIT commented 2 weeks ago

Found it on another post: "The problem seems to be that some servers (in my case a very old version of a Siemens OPCUA server running on a HMI Panel) do not compute the length of the DataChangeNotification body as it can be decoded without the length (it is not free-length, and UAExpert has no issue in decoding it). These servers just fill the field with 0xFFFFFFFF"

mregen commented 3 days ago

Could you provide a Wireshark log of the data change notification? Then we can check which fields need to be adjusted. (Please no security).

MoxxxIT commented 3 days ago

Could you provide a Wireshark log of the data change notification? Then we can check which fields need to be adjusted. (Please no security).

I recive no change notification, the issue happens after subscription:

11/08/2024 08:08:28.812 PUBLISH https://github.com/OPCFoundation/UA-.NETStandard-Samples/issues/15 - Unhandled error BadDecodingError during Publish. BadDecodingError 'Unexpected error processing response.'

this error stop the variable subscription event so there is no change event.

salihgoncu commented 3 days ago

Hello, Then, please record the wireshark tracing for the whole operation, starting from the creation of the session, until the error. We need that trace to understand what is actually being passed.

Best Regards, S.

MoxxxIT commented 3 days ago 
************************* Logging started at 11/28/2024 16:32:57
11/28/2024 16:33:00.813 ChannelId 0: Token #0 created. CreatedAt=15:33:00.813. Lifetime=3600000.
11/28/2024 16:33:00.828 Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None
11/28/2024 16:33:00.828 Sender Certificate: (none)
11/28/2024 16:33:00.847 SECURE CHANNEL CREATED [UA.NETStandard ClientChannel UA-TCP 1.5.374.126] [ID=23265] Connected To: opc.tcp://192.168.0.2:4870/ [None/None/Binary]
11/28/2024 16:33:00.850 ChannelId 23265: Token #1 activated. CreatedAt=15:33:00.813. Lifetime=3600000.
11/28/2024 16:33:00.852 ChannelId 23265: Token Expiry 11/28/2024 16:33:00, renewal scheduled in 2699970 ms.
11/28/2024 16:33:00.881 ChannelId 23265: CLIENTCHANNEL SOCKET CLOSED: 00BF7771
11/28/2024 16:33:00.912 Deprecated Security Policy Basic128Rsa15 requested - Not recommended.
11/28/2024 16:33:00.939 ChannelId 0: Token #0 created. CreatedAt=15:33:00.939. Lifetime=3600000.
11/28/2024 16:33:00.939 Security Policy: http://opcfoundation.org/UA/SecurityPolicy#None
11/28/2024 16:33:00.939 Sender Certificate: (none)
11/28/2024 16:33:00.939 SECURE CHANNEL CREATED [UA.NETStandard ClientChannel UA-TCP 1.5.374.126] [ID=23266] Connected To: opc.tcp://192.168.0.2:4870/ [None/None/Binary]
11/28/2024 16:33:00.939 ChannelId 23266: Token #1 activated. CreatedAt=15:33:00.939. Lifetime=3600000.
11/28/2024 16:33:00.939 ChannelId 23266: Token Expiry 11/28/2024 16:33:00, renewal scheduled in 2699999 ms.
11/28/2024 16:33:00.956 Revised session timeout value: 60000. 
11/28/2024 16:33:00.956 Max response message size value: 4194304. Max request message size: 0 
11/28/2024 16:33:00.956 Server signature is null or empty.
11/28/2024 16:33:01.188 Failed to read operation limits from server. Using configuration defaults.
 InvalidCastException 'Cast specificato non valido.'

========================================
Id: Bad
Description: [InvalidCastException] Cast specificato non valido.
>>> Cast specificato non valido.
---    in Opc.Ua.Client.Session.<FetchOperationLimitsAsync>d__324.MoveNext()
========================================

11/28/2024 16:33:01.200 Deprecated Security Policy Basic128Rsa15 requested - Not recommended.
11/28/2024 16:33:02.025 ManagedBrowse failed
 BadTooManyOperations 'BadTooManyOperations'

========================================
Id: BadTooManyOperations
Description: BadTooManyOperations
>>> BadTooManyOperations
---    in Opc.Ua.ClientBase.ValidateResponse(ResponseHeader header)
---    in Opc.Ua.SessionClient.<BrowseAsync>d__46.MoveNext()
--- --- Fine traccia dello stack da posizione precedente dove è stata generata l'eccezione ---
---    in System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
---    in Opc.Ua.SessionClientBatched.<BrowseAsync>d__13.MoveNext()
--- --- Fine traccia dello stack da posizione precedente dove è stata generata l'eccezione ---
---    in System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
---    in System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
---    in Opc.Ua.Client.Session.<BrowseAsync>d__331.MoveNext()
--- --- Fine traccia dello stack da posizione precedente dove è stata generata l'eccezione ---
---    in System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
---    in System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
---    in Opc.Ua.Client.Session.<BrowseWithBrowseNextAsync>d__335.MoveNext()
--- --- Fine traccia dello stack da posizione precedente dove è stata generata l'eccezione ---
---    in System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
---    in Opc.Ua.Client.Session.<ManagedBrowseAsync>d__333.MoveNext()
========================================

11/28/2024 16:33:02.048 A smaller minLifetimeInterval 10000ms than session timeout 60000ms configured for subscription 0.
11/28/2024 16:33:02.048 Lifetime 10000ms configured for subscription 0 is less than session timeout 60000ms.
11/28/2024 16:33:02.048 Adjusted LifetimeCount from value=10, to value=30, for subscription 0. 
11/28/2024 16:33:02.056 For subscription 1, Lifetime count was revised from 10 to 30
11/28/2024 16:33:03.131 Unexpected error processing response.
 BadDecodingError 'Cannot determine length of unknown extension object body with type 'i=811'.'

========================================
Id: BadDecodingError
Description: Cannot determine length of unknown extension object body with type 'i=811'.
>>> Cannot determine length of unknown extension object body with type 'i=811'.
---    in Opc.Ua.BinaryDecoder.ReadExtensionObject()
---    in Opc.Ua.BinaryDecoder.ReadExtensionObjectArray(String fieldName)
---    in Opc.Ua.NotificationMessage.Decode(IDecoder decoder)
---    in Opc.Ua.BinaryDecoder.ReadEncodeable(String fieldName, Type systemType, ExpandedNodeId encodeableTypeId)
---    in Opc.Ua.PublishResponse.Decode(IDecoder decoder)
---    in Opc.Ua.BinaryDecoder.ReadEncodeable(String fieldName, Type systemType, ExpandedNodeId encodeableTypeId)
---    in Opc.Ua.BinaryDecoder.DecodeMessage(Type expectedType)
---    in Opc.Ua.BinaryDecoder.DecodeMessage(Stream stream, Type expectedType, IServiceMessageContext context)
---    in Opc.Ua.Bindings.UaSCUaBinaryClientChannel.ParseResponse(BufferCollection chunksToProcess)
---    in Opc.Ua.Bindings.UaSCUaBinaryClientChannel.ProcessResponseMessage(UInt32 messageType, ArraySegment`1 messageChunk)
========================================

11/28/2024 16:33:03.131 Publish #2, Reconnecting=False, Error: Unexpected error processing response.
11/28/2024 16:33:03.131 PUBLISH #2 - Unhandled error BadDecodingError during Publish.
 BadDecodingError 'Unexpected error processing response.'

========================================
mregen commented 2 days ago

811 is the binary encoding of the DataChangeNotification. There is indeed a new exact length check which was added when the decoder was fuzz tested. Maybe we can special case this check for legacy servers.

Spec says: The length shall be specified if the body is encoded.