Log In
Register
Forum
Topic RSS
15:25, EEST
June 8, 2016
Offline
UaServer.init() is awfully slow in our setup, so we paused the VM to see the callstack, and apparently ModelParser / DOMParser does a full Jar Scan.
Any idea on how to influence that?
WinNTFileSystem.getBooleanAttributes(File) line: not available [native method]
File.exists() line: 821
URLClassPath$FileLoader.getResource(String, boolean) line: 1377
URLClassPath$FileLoader.findResource(String, boolean) line: 1344
URLClassPath.findResource(String, boolean) line: 225
URLClassLoader$2.run() line: 572
URLClassLoader$2.run() line: 570
AccessController.doPrivileged(PrivilegedAction, AccessControlContext) line: not available [native method]
Launcher$AppClassLoader(URLClassLoader).findResource(String) line: 569
Launcher$AppClassLoader(ClassLoader).getResource(String) line: 1089
Launcher$AppClassLoader(URLClassLoader).getResourceAsStream(String) line: 233
SecuritySupport$6.run() line: not available
AccessController.doPrivileged(PrivilegedAction) line: not available [native method]
SecuritySupport.getResourceAsStream(ClassLoader, String) line: not available
ObjectFactory.findJarServiceProvider(String) line: not available
ObjectFactory.createObject(String, String, String) line: not available
ObjectFactory.createObject(String, String) line: not available
DOMParser.(SymbolTable, XMLGrammarPool) line: not available
DOMParser.() line: not available
DocumentBuilderImpl.(DocumentBuilderFactoryImpl, Hashtable, Hashtable, boolean) line: not available
DocumentBuilderFactoryImpl.newDocumentBuilder() line: not available
TransformerIdentityImpl.createResultContentHandler(Result) line: 228
TransformerIdentityImpl.startDocument() line: 911
ModelParser(ModelParserBase).c() line: 882
ModelParser(ModelParserBase).startElement(String, String, String, Attributes) line: 2128
ModelParserBase$d.startElement(String, String, String, Attributes) line: 182
SAXParser(AbstractSAXParser).startElement(QName, XMLAttributes, Augmentations) line: not available
XMLNSDocumentScannerImpl.scanStartElement() line: not available
XMLNSDocumentScannerImpl$NSContentDispatcher(XMLDocumentFragmentScannerImpl$FragmentContentDispatcher).dispatch(boolean) line: not available
XMLNSDocumentScannerImpl(XMLDocumentFragmentScannerImpl).scanDocument(boolean) line: not available
XIncludeAwareParserConfiguration(XML11Configuration).parse(boolean) line: not available
XIncludeAwareParserConfiguration(XML11Configuration).parse(XMLInputSource) line: not available
SAXParser(XMLParser).parse(XMLInputSource) line: not available
SAXParser(AbstractSAXParser).parse(InputSource) line: not available
ModelParser(ModelParserBase).parseFile(InputStream, Charset) line: 547
ModelParser(ModelParserBase).parseFile(InputStream) line: 507
ModelParser(ModelParserBase).parseFile(URI) line: 570
NodeManagerTable.loadModel(URI, Collection, boolean) line: 2006
NodeManagerRoot.be() line: 410
NodeManagerRoot.init() line: 624
NodeManagerTable.init() line: 2518
NodeManagementServiceHandler.init() line: 849
UaServer.initServiceHandlers() line: 2649
UaServer.init() line: 1214
Also, we get this logging, telling us to disable DTD, but I guess we cannot influence that either?
2021-05-19T14:08:10,573 INFO [main] ua.server.NodeManagerTable:2000 Loading model from jar:file:/D:/M3_REPO/com/prosysopc/ua/prosys-opc-ua-client-server/4.5.4-1405/prosys-opc-ua-client-server-4.5.4-1405.jar!/com/prosysopc/ua/types/opcua/server/Opc.Ua.NodeSet2.xml
2021-05-19T14:08:10,657 WARN [main] stack.utils.XMLFactoryCache:92 Cannot initialize XML factories to ignore DTD processing (CVE-2018-12585), please update java to newer version or configure manually if custom XML parser framework is in use
15:55, EEST
April 3, 2012
Offline
Hi,
Sorry, but could you define a numerical value in seconds (or does it take minutes?) for “awfully slow”? And what value would be considered as acceptable start time?
What kind of hardward the server is run on?
What version of Java you use to run the server?
The DTD disabling requires a newer than Java 6 (based on what I know, or at least all the ones we have of that version). The disabling was part of security fixes in the “stack” SDK 3.1.4 started to use (https://downloads.prosysopc.com/opcua/Prosys_OPC_UA_Java_SDK_3_Release_Notes.html#version-3-1-4) to prevent https://cheatsheetseries.owasp.org/cheatsheets/XML_External_Entity_Prevention_Cheat_Sheet.html#Java. Mainly affects if you would have nodes that have the XmlElement DataType if I recall it correctly.
The NodeManagerRoot does load the standard model of OPC UA (which is an XML file, which is embedded inside the SDK jar). Per the log, I would expect you not to use any so called “uberjars”, but I do recall that once someone tried to use an “jar of jars” variant of uberjar, and there performance was abysmall to read resources from nested jars inside the jar. So I would doublecheck here that it is not what you have?
And yes, I’m in general aware it is slow, but as long as it has not been a problem per se, we have had other issues that have received more priority (but you asking will give this more, thus why I did ask some numerical value). Though, some things might require “SDK 5” tier changes.
I would assume the “findJarServiceProvider” there in the logic basically internal to java since once we call the standard library of java we cannot control what it does. However, you might be able to do that. Per https://stackoverflow.com/questions/11344031/high-lock-contention-in-sun-misc-urlclasspath-getloader-under-jaxb-unmarshaller maybe you can use that “-Djavax.xml.parsers.SAXParserFactory=org.apache.xerces.jaxp.SAXParserFactoryImpl” to avoid the lookup. Or it might not be the exact one to use, but the same concept might apply. Though, that might not be as portable implementation (though, with the “modern java app distribution” you are expected to pretty much bundle a jvm in the app anyway so it might not anymore be of an issue).
Though, I would find it odd, if this is the true bottleneck of the start, since typically it is not the model loading, but the way we store the references (and that might need the “SDK 5” tier changes, depending on things) after the model has loaded and the nodes are made to the address space.
16:32, EEST
April 3, 2012
Offline
The XML-related Factory objects are cached within XMLFactoryCache, they are available via the static getters getDocumentBuilderFactory, getSAXTransformerFactory, getTransformerFactory, getXMLInputFactory. This is because the process to obtain them was slow enough that we wanted to reuse them (makes sense in general as well), thus that only needs to happen once per factory. And they are basically obtained via XXXFactory.newInstance() and then the parameters set as in the owasp link, but what does newInstance calls do internal is internal to the java standard library or JVM.
Per the sources of java6 I have, yes it would seem to scan the whole classpath for implementations (in general, there “isn’t nothing wrong with this”, since that is a mechanism quite many libs uses, though typically via java.util.ServiceLoader; this is also what we use in SDK 4.x by default to try to locate all codegenerated “models” so that they can be automatically registered to the UaClient/UaServer, in general it normally shouldn’t take _that long_).
You might be able to use other libs (that basically would be initialized most likely via that “jar scan” so the java standard libary knows which implementation to use): https://github.com/FasterXML/woodstox, though it should be noted that we have not tested this. But like I would expect the problem to be elsewhere, since the problem shouldn’t be related to “scan whole classpath” and that by itself should be fast enough. Or it might depend what is like your expectation of “fast” of course. But it is a fraction of the whole UaServer startup time to give some scale to that. But I can try to profile a number of how long that it takes so we have something to compare.
13:09, EEST
June 8, 2016
Offline
Thank you for your thorough reply, Bjarne, I will have a look at it.
I will probably try go by this (since it’s the DOMParser)
https://help.mulesoft.com/s/article/Blocked-thread-on-finding-org-apache-xerces-parsers-DOMParser-service-provider
and make some measurements before/after and let you know what I found.
14:56, EEST
June 8, 2016
Offline
Ok so I went by the above article (the one I linked), and the .init() went from 21s down to 9s. So I investigated further.
I debugged and “shot” some stacks while running over the .init() method.
This is what came out.
Thread [main] (Stepping)
owns: Object (id=257)
owns: Object (id=258)
owns: UaServer (id=196)
owns: Object (id=163)
owns: Object (id=164)
owns: Object (id=165)
String.startsWith(String, int) line: 1417
String.endsWith(String) line: 1449
MetaIndex.mayContain(String) line: 236
URLClassPath$JarLoader.getResource(String, boolean) line: 1044
URLClassPath.getResource(String, boolean) line: 249
URLClassLoader$1.run() line: 366
URLClassLoader$1.run() line: 363
AccessController.doPrivileged(PrivilegedExceptionAction, AccessControlContext) line: not available [native method]
Launcher$ExtClassLoader(URLClassLoader).findClass(String) line: 362
Launcher$ExtClassLoader(ClassLoader).loadClass(String, boolean) line: 418
Launcher$AppClassLoader(ClassLoader).loadClass(String, boolean) line: 405
Launcher$AppClassLoader.loadClass(String, boolean) line: 352
Launcher$AppClassLoader(ClassLoader).loadClass(String) line: 351
GdsServerInformationModel.() line: 37
UaServer.ao() line: 2311
UaServer.init() line: 1213
Thread [main] (Suspended)
owns: Object (id=339)
owns: UaServer (id=196)
owns: Object (id=163)
owns: Object (id=164)
owns: Object (id=165)
WinNTFileSystem.getBooleanAttributes(File) line: not available [native method]
File.exists() line: 821
URLClassPath$FileLoader.getResource(String, boolean) line: 1377
URLClassPath.getResource(String, boolean) line: 249
URLClassLoader$1.run() line: 366
URLClassLoader$1.run() line: 363
AccessController.doPrivileged(PrivilegedExceptionAction, AccessControlContext) line: not available [native method]
Launcher$AppClassLoader(URLClassLoader).findClass(String) line: 362
Launcher$AppClassLoader(ClassLoader).loadClass(String, boolean) line: 418
Launcher$AppClassLoader.loadClass(String, boolean) line: 352
Launcher$AppClassLoader(ClassLoader).loadClass(String) line: 351
Class.getDeclaredConstructors0(boolean) line: not available [native method]
Class.privateGetDeclaredConstructors(boolean) line: 2699
Class.getConstructor0(Class[], int) line: 3103
Class.getDeclaredConstructor(Class…) line: 2206
UaServerNodeFactory.a(Class) line: 240
UaServerNodeFactory.registerNodeClass(NodeClass, Class) line: 181
UaServerNodeFactory.(NodeManagerUaNode) line: 55
NodeManagerRoot(NodeManagerUaNode).initialize() line: 1252
NodeManagerRoot(NodeManagerUaNode).(UaServer, String) line: 88
NodeManagerRoot.(UaServer) line: 143
UaServer.initServiceHandlers() line: 2633
UaServer.init() line: 1214
Thread [main] (Suspended)
owns: URLJarFile (id=374)
owns: NodeManagerTable (id=375)
owns: UaServer (id=196)
owns: Object (id=163)
owns: Object (id=164)
owns: Object (id=165)
Reflection.getCallerClass() line: not available [native method]
Class.getConstructor(Class…) line: 1852
Provider$Service.newInstance(Object) line: 1594
GetInstance.getInstance(Service, Class) line: 236
GetInstance.getInstance(String, Class, String) line: 164
CertificateFactory.getInstance(String) line: 183
PKCS7.parseSignedData(DerValue) line: 300
PKCS7.parse(DerInputStream, boolean) line: 186
PKCS7.parse(DerInputStream) line: 154
PKCS7.(byte[]) line: 136
SignatureFileVerifier.(ArrayList, ManifestDigester, String, byte[]) line: 121
JarVerifier.processEntry(ManifestEntryVerifier) line: 299
JarVerifier.update(int, byte[], int, int, ManifestEntryVerifier) line: 230
URLJarFile(JarFile).initializeVerifier() line: 383
URLJarFile(JarFile).getInputStream(ZipEntry) line: 455
JarURLConnection.getInputStream() line: 164
URL.openStream() line: 1068
ServiceLoader.parse(Class, URL) line: 304
ServiceLoader.access$200(ServiceLoader, Class, URL) line: 185
ServiceLoader$LazyIterator.hasNextService() line: 357
ServiceLoader$LazyIterator.hasNext() line: 393
ServiceLoader$1.hasNext() line: 474
FactoryFinder$1.run() line: 293
AccessController.doPrivileged(PrivilegedAction) line: not available [native method]
FactoryFinder.findServiceProvider(Class) line: 289
FactoryFinder.find(Class, String) line: 267
DocumentBuilderFactory.newInstance() line: 120
TransformerIdentityImpl.createResultContentHandler(Result) line: 215
TransformerIdentityImpl.startDocument() line: 911
ModelParser(ModelParserBase).c() line: 882
ModelParser(ModelParserBase).startElement(String, String, String, Attributes) line: 2128
ModelParserBase$d.startElement(String, String, String, Attributes) line: 182
SAXParser(AbstractSAXParser).startElement(QName, XMLAttributes, Augmentations) line: not available
XMLNSDocumentScannerImpl.scanStartElement() line: not available
XMLNSDocumentScannerImpl$NSContentDispatcher(XMLDocumentFragmentScannerImpl$FragmentContentDispatcher).dispatch(boolean) line: not available
XMLNSDocumentScannerImpl(XMLDocumentFragmentScannerImpl).scanDocument(boolean) line: not available
XIncludeAwareParserConfiguration(XML11Configuration).parse(boolean) line: not available
XIncludeAwareParserConfiguration(XML11Configuration).parse(XMLInputSource) line: not available
SAXParser(XMLParser).parse(XMLInputSource) line: not available
SAXParser(AbstractSAXParser).parse(InputSource) line: not available
ModelParser(ModelParserBase).parseFile(InputStream, Charset) line: 547
ModelParser(ModelParserBase).parseFile(InputStream) line: 507
ModelParser(ModelParserBase).parseFile(URI) line: 570
NodeManagerTable.loadModel(URI, Collection, boolean) line: 2006
NodeManagerRoot.be() line: 410
NodeManagerRoot.init() line: 624
NodeManagerTable.init() line: 2518
NodeManagementServiceHandler.init() line: 849
UaServer.initServiceHandlers() line: 2649
UaServer.init() line: 1214
So yet another shot at avoiding the second scan for DocumentBuilderFactory and – the .init() went down to roughly 3s.
So I’m happy with going from 21s to 3s.
Regards,
Florian
Most Users Ever Online: 1919
Currently Online:
49 Guest(s)
Currently Browsing this Page:
1 Guest(s)
Top Posters:
Heikki Tahvanainen: 402
hbrackel: 144
rocket science: 88
pramanj: 86
Francesco Zambon: 83
Ibrahim: 78
Sabari: 62
kapsl: 57
gjevremovic: 49
Xavier: 43
Member Stats:
Guest Posters: 0
Members: 726
Moderators: 7
Admins: 1
Forum Stats:
Groups: 3
Forums: 15
Topics: 1529
Posts: 6471
Newest Members:
gabriellabachus, Deakin, KTP25Zof, Wojciech Kubala, efrennowell431, wilfredostuart, caitlynfajardo, jeromechubb7, franciscagrimwad, adult_galleryModerators: Jouni Aro: 1026, Pyry: 1, Petri: 0, Bjarne Boström: 1032, Jimmy Ni: 26, Matti Siponen: 349, Lusetti: 0
Administrators: admin: 1
