Avatar

Please consider registering
guest

sp_LogInOut Log In sp_Registration Register

Register | Lost password?
Advanced Search

— Forum Scope —




— Match —





— Forum Options —





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

sp_Feed Topic RSS sp_TopicIcon
InitTypeDictionaryOnConnect performance
November 24, 2020
11:26, EET
Avatar
Xavier
Member
Members
Forum Posts: 43
Member Since:
March 26, 2014
sp_UserOfflineSmall Offline

Hi,

I have a question regarding this functionnality of SDK4, I use the client and server with SDK 4.4.2 but I had the same issue before with the 4.3.0. My server has my own ObjectTypes, VariableTypes and some structured datatypes generated with the CodeGen.

If my server has only a few instances the client connection is not really impacted by the InitTypeDictionaryOnConnect parameter, this is a log with TypeDictionary at TRACE log level and we can see it takes around 500ms total (I remove some parts of the log to make it readable) :

2020-11-24 09:29:49,430 DEBUG (SourceFile:1174) : Resolving all types, starting ids size: 541, ids: [i=18774, i=1, i=2391, i=2, i=344, …
2020-11-24 09:29:49,430 TRACE (SourceFile:1184) : Unvisited count: 541, nodes: [i=18774, i=1, i=2391, i=2, i=344, i=3, i=4, i=2052, …
2020-11-24 09:29:49,678 TRACE (SourceFile:1184) : Unvisited count: 25, nodes: [ns=2;i=1039, ns=2;i=4001, ns=2;i=4002, ns=2;i=3001, …
2020-11-24 09:29:49,686 TRACE (SourceFile:1184) : Unvisited count: 24, nodes: [ns=2;i=1016, ns=2;i=1027, ns=2;i=1028, ns=2;i=1029, …
2020-11-24 09:29:49,692 TRACE (SourceFile:1184) : Unvisited count: 10, nodes: [ns=2;i=1017, ns=2;i=1018, ns=2;i=1019, ns=2;i=1021, …
2020-11-24 09:29:49,695 TRACE (SourceFile:1184) : Unvisited count: 7, nodes: [ns=2;i=1020, ns=2;i=1023, ns=2;i=1024, ns=2;i=1033, …
2020-11-24 09:29:49,699 DEBUG (SourceFile:1212) : Number of Types for getNodes: 607, initialset: [i=18774, i=1, i=2391, i=2, i=344, …
2020-11-24 09:29:49,699 DEBUG (SourceFile:1217) : Number of ServiceRequests needed, Browse: 5, BrowseNext: 10
2020-11-24 09:29:49,929 DEBUG (SourceFile:1224) : Number of Types found: 603, types : [i=18774, ns=2;i=1016, i=1, i=2391, ns=2;i=1017,…
2020-11-24 09:29:49,930 DEBUG (SourceFile:1226) : Number of ServiceRequests needed, Read: 3, Browse: 0, BrowseNext: 0
2020-11-24 09:29:49,930 DEBUG (SourceFile:1266) : Resolving all Enumeration DataTypes
2020-11-24 09:29:49,931 DEBUG (SourceFile:1275) : Number of Enumerations: 25
2020-11-24 09:29:49,932 DEBUG (SourceFile:1300) : Unknown Enumerations (via DataTypeDefinition): []
2020-11-24 09:29:49,932 DEBUG (SourceFile:1301) : Known Enumerations (via DataTypeDefinition): [http://opcfoundation.org/UA/:11293, …
2020-11-24 09:29:49,933 DEBUG (SourceFile:1311) : Resolving all Structure DataTypes
2020-11-24 09:29:49,941 DEBUG (SourceFile:1104) : All encodings were cached as part DataType getNodes, can skip Browsing of EncodingIds
2020-11-24 09:29:49,942 DEBUG (SourceFile:1354) : Unknown Structures (via DataTypeDefinition): []
2020-11-24 09:29:49,942 DEBUG (SourceFile:1355) : Known Structures (via DataTypeDefinition): [http://opcfoundation.org/UA/:15645, …
2020-11-24 09:29:49,942 DEBUG (SourceFile:400) : Resolved all Structure and Enumeration DataTypes via DataTypeDefinition, skipping DataTypeDictionaries
2020-11-24 09:29:49,942 INFO (SourceFile:417) : TypeDictionary initialized successfully

If I use the same model but with thousands of instances (but the same number of types) it seems stuck (at least for dozens of minutes) here:

2020-11-24 10:10:33,215 DEBUG (SourceFile:1174) : Resolving all types, starting ids size: 541, ids: [i=18774, i=1, i=2391, i=2, i=344, …
2020-11-24 10:10:33,216 TRACE (SourceFile:1184) : Unvisited count: 541, nodes: [i=18774, i=1, i=2391, i=2, i=344, i=3, i=4, i=2052, …

In my use case it’s not a big deal, I just disable this feature but I wonder if it is “normal” or if it showing some problem somewhere, maybe with my model? The server uses the default UaNode implementation and I have no problem with UaExpert or the other functions of the client (read/write, subscriptions, …).

Thank you,

November 24, 2020
14:33, EET
Avatar
Bjarne Boström
Moderator
Moderators
Forum Posts: 983
Member Since:
April 3, 2012
sp_UserOfflineSmall Offline

Hi,

It is complicated. It will take longer if you have a lot of instances, but it should not take _that_ long. Some version 4.x before 4.3.0 might have taken a long time, like 10s of minutes, but 4.3.0 and later should be faster at least). And I probably need a separate explantion for this, since it sort of might be a bug.

In general the connection typically takes few seconds, but there are some edge-cases. If the server is running on a very low-powered CPU there might be addtional slowdowns, but connecting to them usually takes 10s of seconds usually anyway. What kind of hardware the server is running on?

Basically with defaults the (quite new releases of) 4.x will read all types on connect. In the case of our SDK-made server, that includes the inverse HasTypeDefinition References from the types. Though, in general it should not be _that_ big of an impact, since our default OperationLimits is to pack 10000 in one Browse result, so it should be like 1-2 more ServiceRequests more.

Can you check the logs for debug level string “Number of ServiceRequests” and list the number of Browse, BrowseNext and Read those indicate (there is multiple lines)?

November 24, 2020
18:20, EET
Avatar
Xavier
Member
Members
Forum Posts: 43
Member Since:
March 26, 2014
sp_UserOfflineSmall Offline

Hi,

I don’t think it’s a CPU problem, it’s a classical server with 8 cores, 32 GB of RAM and I don’t see the CPU usage really increasing while my client is connecting. At the moment I may have a slow network as I’m using a VPN but I can test locally tomorrow (but I really think it was the same issue).

When I test with my light configuration (I have 50 instances of my main object but I realize that inside it I have an alarm which contains some VariableTypes, and so on) I have in total:
– 8 BrowseResponse
– 10 BrowseNextResponse
– 9 ReadReponse
Number of Types for getNodes: 607, initialset: [i=18774, i=1, i=2391, i=2, …]
Number of ServiceRequests needed, Browse: 5, BrowseNext: 10

I tried with my bigger configuration (around 15 000 instances I believe) but it seems to just loop on browses forever. With this big configuration and UaExpert if I ask reverseReferences on one of my ObjectType I can see it logs 1 “Browse succeeded” + 166 times “BrowseNext succeeded.” in 20 seconds.
Does this mean 166 * 10 000 references?? That would be crazy Surprised

November 25, 2020
15:00, EET
Avatar
Xavier
Member
Members
Forum Posts: 43
Member Since:
March 26, 2014
sp_UserOfflineSmall Offline

With my bigger configuration and DEBUG logs for the SDK it took 1.5 hour to go from the start to the end of TypeDictionary init:
2020-11-25 09:26:38 UaApplication [INFO] Prosys OPC UA SDK for Java v4.4.2-1266

2020-11-25 10:55:00 TypeDictionary [INFO] TypeDictionary initialized successfully

During this period I have in total:
– 130 BrowseResponse
– 1714 BrowseNextResponse
– 133 ReadReponse
2020-11-25 10:53:48 TypeDictionary [DEBUG] Number of Types for getNodes: 607, initialset: [i=18774, i=1, i=2391, i=2,…
2020-11-25 10:53:48 TypeDictionary [DEBUG] Number of ServiceRequests needed, Browse: 5, BrowseNext: 1714
2020-11-25 10:55:00 TypeDictionary [DEBUG] Number of ServiceRequests needed, Read: 3, Browse: 0, BrowseNext: 0

I can also count 329 852 this log “UaNodeImpl [DEBUG] addReference: ReferenceType=HasTypeDefinition “…

As I said, I just have to disable this feature, it’s not necessary in my use case, but I think I have maybe something wrong with my model if there are 330k HasTypeDefinition references.

November 25, 2020
15:58, EET
Avatar
Bjarne Boström
Moderator
Moderators
Forum Posts: 983
Member Since:
April 3, 2012
sp_UserOfflineSmall Offline

This is a reply for the amount of references, adding a second one addressing your later post soon.

Sorry, I think I said it a bit incorrect. It should be that we do 10k operations within a Browse, but each operation only has 1k References returned (this is configurable, this is our default for the AddressSpace). So 166*1000 at most, note that if a node has 1001 references, it still needs a BrowseNext for the 1 reference. However it will pack multiple operations for the BrowseNext as well.

Since it also happens to be the one AddressSpace.setMaxReferencesPerNode(int) configures, you can test e.g. 10000, but there is also limits how big of an OPC UA Message can be in binary.

That sounds about right (the corrected 166*1000), since there are typically also other referenfes as well. A normal init also does like Read 30k operations (since there are 27 potential Attributes for a note). Though it is smart in a way that if we did resolve an Attribute with the Browse (since it has few of them), those are not Read (and also it determines per NodeClass what it should read, so we resolve that at some point). This is also one of the reasons why it sort of works best to do all types at once, since it is possible to pack the requests whereas getting the same data recursively one-by-one on the first getNode call is slower (but yes, it might not have had to read that much). Also if this starts to have too much trouble we might need to investigate more alternatives, though the DataTypeDefinition Attribute can still be a problem.

Additionally any individual DataTypeDictionary node are read one-by-one, since the values can be huge. But that is also skipped if all Structure and Enumeration types were resolved purely by DataTypeDefinition. Also any namespaces that are detected to be codegenerated can be skipped for the DataTypeDefinition as well.

November 25, 2020
16:02, EET
Avatar
Bjarne Boström
Moderator
Moderators
Forum Posts: 983
Member Since:
April 3, 2012
sp_UserOfflineSmall Offline

Uh oh. It is also possible that it is not this, but is worth of testing. It is also possible that there is an error in your model, and if this work it could then mask the issue.

Could you try calling UaClient.getAddressSpace().getCache().setMaxQueueLength(int) to some big number, to like e.g. 100000 and/or setNodeMaxAgeInMillis(long milliseconds) to e.g. 10000 or 100000.

The cache is by default 5000 nodes, but any type node is not counted for that, as they are cached permanently.

However, since we sort of are resolving all nodes related to the TypeDictionary (plus all other type nodes as well, since well it might be even faster to do it like that, but depends, and needs an explanation that might take a half a day to write). However, the encoding nodes are not type nodes, thus it is possible that we lose them from the cache and thus we are re-reading it from the server. Though in general I would not expect that to give such large impact.

I guess the easiest would be if you can create a standalone example with sampleconsoleserver and sampleconsoleclient (though that will probably be fine just as-is) that can reproduce this and send your model to us, if possible.

Also linking an other forum chain: https://forum.prosysopc.com/forum/opc-ua-java-sdk/source-code-does-not-match-the-bytecode/, since that is partially the same thing at least and I did write some explanations to that why we do this. It probably could be still a lot better, sorry.

Forum Timezone: Europe/Helsinki

Most Users Ever Online: 518

Currently Online:
17 Guest(s)

Currently Browsing this Page:
1 Guest(s)

Top Posters:

hbrackel: 135

pramanj: 86

Francesco Zambon: 81

rocket science: 77

ibrahim: 75

Sabari: 62

kapsl: 57

gjevremovic: 49

Xavier: 43

fred: 41

Member Stats:

Guest Posters: 0

Members: 680

Moderators: 16

Admins: 1

Forum Stats:

Groups: 3

Forums: 15

Topics: 1467

Posts: 6259

Newest Members:

sagarchau, elviralangwell4, Donnavek, Eddiefauth, DonaldPooma, fidelduke938316, Jan-Pfizer, DavidROunc, fen.pang@woodside.com, aytule

Moderators: Jouni Aro: 1009, Otso Palonen: 32, Tuomas Hiltunen: 5, Pyry: 1, Petri: 0, Bjarne Boström: 983, Heikki Tahvanainen: 402, Jukka Asikainen: 1, moldzh08: 0, Jimmy Ni: 26, Teppo Uimonen: 21, Markus Johansson: 42, Niklas Nurminen: 0, Matti Siponen: 321, Lusetti: 0, Ari-Pekka Soikkeli: 5

Administrators: admin: 1