Lucee ORM Performance Problem

Ozgur · February 20, 2020, 9:44pm

I’m moving my Railo 4.5 application to Lucee 5 (using 5.3.4.77). In Lucee, orm, seems to be performing worse than Railo. In my test environments, testing from the browser side, a single select call:

ORMExecuteQuery('select Name from Institution i where i.Id = :id',{ id: 1 }, true)

takes around 40 ms in Railo and 150 ms in Lucee. I traced the problem to see:

With each request, Lucee ends up in the createMappings call and it spends more than 90% of the time in this call. I looked into the code a bit and it seems to be creating mapping files based on CFC files. This looked to me like sth that would be cached.

Can anybody tell me if this behaviour, calling this function with each request is normal? Is there anyway to improve this by any type of configuration or anything?

cfmitrah · February 21, 2020, 7:34am

@Ozgur, I’ve checked this in my local, very first time only it takes above 100 ms. And next time it took less than 10ms. Can you please check again?

Ozgur · February 24, 2020, 4:27pm

@cfmitrah thanks for your feedback. Unfortunately I did check this many times as I expected the behavior you mentioned and the results of my performance tests are also consistent with this finding. Each request results on the above call stack. But as you explained it works correctly for your environment, I’ll create an empty sample project and review the behavior there. This, then, is probably sth that is a result of my existing codebase. I’d appreciate any pointers about what might cause this issue.

Ozgur · April 13, 2020, 10:41pm

We analyzed this problem further and found that there’s an issue in code that results in Lucee 5 to not cache the entity configurations at all. This means each entity file is parsed and related mappings are read with every request. @cfmitrah if you tried this in an application with few entities that might not have been visible. But our application has about 200+ entities and makes Lucee 5 unusable in terms of performance.

Here’s the details of the problem:
The first screenshot is from the source code of Railo. (railo/HibernateORMEngine.java at ca2389a7abbfeeddbcdba6d4e78a194287f60a04 · getrailo/railo · GitHub)

where it uses the saved and cached configuration.
Same code in Lucee 5 codebase has been updated to be (extension-hibernate/HibernateORMEngine.java at da26629d6cc18a6d61c53f14ad3bc2e4dfc701e9 · lucee/extension-hibernate · GitHub)

which simply removes the line that returns the cached data.

@micstriit the related code seems to be checked in by you. Was there a reason for this change? Should I create a bug ticket to revert this?

Zackster · April 14, 2020, 7:20am

please file a bug!

also, rather than screenshots from github, if you click the line number, you’ll get a url which will automatically embed the code snippet

i.e

github.com

lucee/extension-hibernate/blob/master/source/java/src/org/lucee/extension/orm/hibernate/HibernateORMEngine.java#L173


      
          		// ...
          
          
		Log log = pc.getConfig().getLog("orm");
          
          
		Iterator<Entry<Key, String>> it = HibernateSessionFactory.createMappings(ormConf, data).entrySet().iterator();
          		Entry<Key, String> e;
          		while (it.hasNext()) {
          			e = it.next();
          			if (data.getConfiguration(e.getKey()) != null) continue;
          
          
			DatasourceConnection dc = CommonUtil.getDatasourceConnection(pc, data.getDataSource(e.getKey()));
          			try {
          				data.setConfiguration(log, e.getValue(), dc);
          			}
          			catch (Exception ex) {
          				throw CommonUtil.toPageException(ex);
          			}
          			finally {
          				CommonUtil.releaseDatasourceConnection(pc, dc);
          			}
          			addEventListeners(pc, data, e.getKey());

github.com

getrailo/railo/blob/master/railo-java/railo-core/src/railo/runtime/orm/hibernate/HibernateORMEngine.java#L191


      
          				}
          			}
          		}
          		finally {
          			data.tmpList=null;
          		}
          				
          		// already initialized for this application context
          		if(data.getConfiguration()!=null) return data;
          
          
		//MUST
          		//cacheconfig
          		//cacheprovider
          		//...
          		
          		String mappings=HibernateSessionFactory.createMappings(ormConf,data);
          		
          		DatasourceConnection dc = CommonUtil.getDatasourceConnection(pc,ds);
          		try{
          			data.setConfiguration(mappings,dc);
          		}