Description of problem:
The c.r.persistence.metadata.Model.getQualifiedName method is a
performance hotspot when iterating over a cursor, fetching the
returned data.
See bug 113680 #1 for more details
Version-Release number of selected component (if applicable):
How reproducible:
Steps to Reproduce:
1.
2.
3.
Actual results:
Expected results:
Additional info:

Unfortunately not because the tool i was using didn't let me save its
output. If you profile the Category.removeChild method with optimizeit
or equiv on a database with 15,000 rows in acs_objects you'll quickly
reproduce it.

The simplest solution is likely to replace the constant concatenation
of m_parent.getQualfiedName() + "." + m_name with a constant member
m_qualifedName, created on construction.
My only concern is that while the current method is inefficient, the
isolated performance overhead in a simple test is barely measurable,
on the order of 150ms 15000 calls.
I could believe that the number of calls may be much higher for the
Category.removeChild example, or that it's JVM dependent. Dan, which
JVM did you take these measurements with? And do you memember how many
calls to getQualifiedName it shows?

I instrumented getQualifiedName() (and RDBMSEngine) to collect data
for bug 115042. When publishing an Article with the simple workflow,
one of the requests clocks 608 queries and a quarter of a million
calls to Model.getQualifiedName(). (The exact number is 238230.)

One thing you can do which might have a similar effect would be to
change the DataObjectAdapter class in
com.arsdigita.persistence.Session to store a PropertyMap inside
DataObjectImpl. Currently it always builds a new PropertyMap and
returns it. Since both these classes are in the same package it would
not require making DataObjectImpl public, and since I suspect most of
the getQualifiedName() calls are coming from this conversion process
which is part of constructing the session key it should have a similar
effect.

I'd suggest trying the same trick with
Session$DataObjectAdapter.getObjectType(). In fact it might be
reasonable to just implement it as getProperties().getObjectType().
The only thing you need to make sure of is that the type it returns
correctly reflects whether or not specialize has been called on the
data object, i.e. you need to make sure that if DataObject.specialize
gets called the property map is reconstructed with the correctly
specialized type.

> The only thing you need to make sure of is that the type it returns
> correctly reflects whether or not specialize has been called on the
> data object
I was going to ask you about that. I ran into this in my
proof-of-concept patch. If you take a look at attachment 97572[details],
you'll notice that I special-case the handling of the object type
"ResourceType". Without this special-casing, the patch blows up on
instances of ApplicationType. That's probably because they are
obtained by specializing from ResourceType to ApplicationType.

I propose we mark this ticket as WONTFIX for the following reasons.
1. This is not the most frequently used page.
2. The slowness is due to the large number of db queries and there is
not really any single Java bottleneck that stands out.
Our code accounts for about 37% of the total execution time, as shown
in comment #10.
Oracle's JDBC driver accounts for 31% of the total execution time:
|Total: 31.20% 46963 ms
|--------------------------------------------------------------
|OCIDBAccess.parseExecuteDescribe 9.82% 14369 ms
|OCIDBAccess.executeFetch 7.05% 10314 ms
|OCIDBAccess.fetch 6.37% 9337 ms
|OracleSql.handleODBC 0.80% 1210 ms
|OCIDBAccess.open 0.76% 1121 ms
|OCIDBAccess.parseExecuteFetch 0.57% 852 ms
|OCIDBAccess.close 0.43% 650 ms
|OCIDBAccess.copy_back_to_next_stream 0.42% 642 ms
|OCIDBAccess.commit 0.39% 574 ms
[107 more lines omitted for brevity]
Standard Java libraries:
|Total: 15.56% 24467 ms
|--------------------------------------------------------------
|StreamEncoder$ConverterSE.<init> 2.53% 3708 ms
|SocketInputStream.read 1.63% 2388 ms
|IOException.<init> 0.95% 1395 ms
|SocketOutputStream.socketWrite 0.78% 1146 ms
|ResourceBundle.getLoader 0.76% 1114 ms
|URLEncoder.encode 0.54% 864 ms
|ZipFile.getEntry 0.54% 812 ms
|AbstractList$Itr.hasNext 0.50% 734 ms
[136 more lines omitted for brevity]
Saxon:
|Total: 3.41% 6077 ms
|-----------------------------------------------------------
|DOMDriver.walkNode 0.23% 430 ms
|NamePool.allocate 0.17% 290 ms
|StyleElement.processChildren 0.17% 283 ms
|HTMLEmitter.escapeURL 0.14% 217 ms
|NamePool.allocateNamespaceCode 0.10% 170 ms
Various Jakarta libraries:
|Total: 2.13% 3563 ms
|----------------------------------------------------------
|Category.isDebugEnabled 0.45% 670 ms
|ParentNode.internalInsertBefore 0.29% 472 ms
|AttributeMap.setNamedItem 0.13% 201 ms
| [44 more lines]
Resin:
|Total: 1.91% 3214 ms
|--------------------------------------------------------------
|TcpServer.accept 0.44% 645 ms
|UTF8Writer.write 0.24% 393 ms
|WriteStream$StreamWriter.write 0.16% 258 ms
|WriteStream.print 0.13% 217 ms
|FilePath.canRead 0.10% 149 ms
[47 more lines]
So, 68% of the total execution time is DB-driven. It's split almost
evenly between persistence and the JDBC driver. Overall, persistence
takes up quite a lot of resources. Unfortunately, this slowness is
diffused more or less evenly across a number of classes.
The two worst offenders are Path.get and Session.getSessionKey.
I don't see any way to reduce the number of calls to Path.get.
As far as Session.getSessionKey goes, I don't see a good way to avoid
redundant calls. (In bug 113696 comment #16, I posted a
proof-of-concept patch that shows that the frequency of calls to
getSessionKey _can_ be reduced, but not in a sound way.)
So, one of the takeways from this ticket is that persistence is not a
thin layer on top of JDBC. It roughly doubles the time of our
interactions with the database. It may be worth it to tune
persistence a little further. This would have to happen after the
land of Archit and Rafi's OQL/sqlgen branch.