ORM - Logging and Debugging
ORM - Logging and Debugging
When something goes wrong with ORM, the first step is to see what Hibernate is actually doing.
The Lucee 5.6 Hibernate Extension added native logging integration that pipes Hibernate's internal logging through Lucee's log system.
Logging Settings
All logging settings go in this.ormSettings in your ORM - Configuration. They all default to false:
this.ormSettings = {
logSQL: true,
logParams: true,
formatSQL: true,
logCache: true,
logVerbose: true
};
| Setting | What it logs | Minimum log level |
|---|---|---|
logSQL |
SQL statements generated by Hibernate | DEBUG |
logParams |
Parameter bindings — the actual values bound to ? placeholders. (new in 5.6) |
TRACE |
formatSQL |
Pretty-prints SQL with indentation and line breaks. (new in 5.6) | — |
logCache |
L2 cache and query cache activity — hits, misses, puts, evictions. (new in 5.6) | DEBUG |
logVerbose |
Hibernate internals — session lifecycle, entity loading, dirty checking, schema tools. Produces a LOT of output. (new in 5.6) | TRACE/DEBUG |
The "Hibernate log level" column shows the minimum orm log level needed for each setting to produce output. For example, setting logSQL: true with the log at DEBUG will show SQL, but logParams: true needs TRACE.
Where Logs Go
ORM logs write to the Lucee orm log. If no orm log is defined (neither at server level nor via this.logs in Application.cfc), no ORM logging occurs at all — even with ormSettings flags enabled.
The location depends on your Lucee configuration:
- Default:
{lucee-server}/logs/orm.logor{lucee-web}/logs/orm.log - Lucee Admin: Configure log appenders and levels under Settings > Logging
- Console output: Set the environment variable
LUCEE_LOGGING_FORCE_APPENDER=consoleto redirect to stdout (useful for development and CI)
Log Levels
There are two kinds of ORM log messages:
- Extension messages (lifecycle, warnings, mapping issues) — these always log, subject only to the orm log level. No ormSettings flags needed.
- Hibernate-internal messages (SQL, params, cache, verbose) — these require both the relevant ormSettings flag and a low enough log level. When
logSQL: false, Hibernate never even formats the SQL string.
The minimum log level you need depends on what you're after:
- DEBUG — gets you
logSQLandlogCacheoutput, plus extension lifecycle messages - TRACE — gets you everything, including
logParamsandlogVerbose
Setting the Log Level (Lucee 7.0+)
Use this.logs in Application.cfc to configure the orm log per-application:
this.logs = {
"orm": {
"appender": "console",
"level": "trace"
}
};
This is the recommended approach — it only affects your application, not other apps on the same server.
Setting the Log Level (Lucee 6.2 / server-wide)
Use configImport to set the server-level orm log. This affects all applications on the server:
function onApplicationStart() {
configImport( type: "server", data: {
loggers: {
orm: {
level: "TRACE",
appender: "console"
}
}
});
}
Settings are read at ORM init
The ormSettings flags are read once when ORM initialises (application startup or ormReload()). Changing logSQL in your Application.cfc and reloading the page won't take effect — you need to call ormReload() or restart the application.
Extension Lifecycle Logging
The Hibernate extension logs its own lifecycle messages at DEBUG level, independent of the ormSettings flags.
These appear whenever the orm log level is DEBUG or lower:
ORM initializing for application [myApp], dbcreate [update]
ORM initialized [12] entities for application [myApp], OrmLoggingSettings[logSQL=true, logParams=false, logCache=false, formatSQL=false, logVerbose=false]
On ormReload(), you'll also see:
ormReload() for application [myApp]
The extension also logs warnings at WARN level for issues it encounters during mapping and schema operations — skipped CFCs, type mismatches, schema export problems.
Inspecting Generated Mappings
savemapping
Set savemapping: true to write the generated .hbm.xml mapping files to disk alongside your entity CFCs:
this.ormSettings = {
savemapping: true
};
This creates files like User.cfc.hbm.xml next to your User.cfc. Inspect these to see exactly what Hibernate thinks your entities look like — column types, relationships, cascade settings, etc.
Dev only. Files are written on every application startup.
Reading Mapping Files
When something maps unexpectedly (wrong column type, missing relationship, incorrect cascade), check the generated .hbm.xml:
<property name="price" type="big_decimal">
<column name="price" precision="12" scale="4"/>
</property>
If the mapping doesn't match your intent, adjust the property attributes in your CFC and check again.
Debugging Techniques
Check the SQL First
When data isn't saving, loading, or updating correctly, enable logSQL and logParams to see the actual SQL:
this.ormSettings = {
logSQL: true,
logParams: true,
formatSQL: true
};
Look for:
- Missing INSERT/UPDATE statements (entity wasn't dirty, or flush didn't happen)
- Wrong column values (mapping issue)
- Unexpected WHERE clauses (filter or discriminator issue)
- Duplicate SQL (missing
inverse="true"on a bidirectional relationship)
Session Diagnostics
The native Hibernate session exposes useful state:
sess = ORMGetSession();
// Are there pending changes?
if ( sess.isDirty() ) {
systemOutput( "Session has unflushed changes", true );
}
// How many entities are cached in this session?
stats = sess.getStatistics();
systemOutput( "Entities: #stats.getEntityCount()#", true );
systemOutput( "Collections: #stats.getCollectionCount()#", true );
Get an Entity's PK Dynamically
When writing generic utility code:
pk = ORMGetSession().getIdentifier( entity );
Inspect Entity Metadata
Get Hibernate's metadata for any entity — property names, types, identifier info:
meta = ORMGetSessionFactory().getClassMetadata( "User" );
systemOutput( "Properties: #arrayToList( meta.getPropertyNames() )#", true );
systemOutput( "ID property: #meta.getIdentifierPropertyName()#", true );
Check the Active Dialect
Verify which SQL dialect Hibernate is using:
dialect = ORMGetSessionFactory().getDialect();
systemOutput( "Dialect: #dialect.getClass().getName()#", true );
Using Log Markers
Write a marker to the orm log before an operation, then search the log file for everything after the marker:
marker = createUUID();
cflog( text: marker, log: "orm" );
// ... your ORM operations here ...
// later, read the log and find your section
This is useful when the log contains output from many requests and you need to isolate one.
Common Debugging Scenarios
"Why isn't my entity saving?"
- Enable
logSQL: true— is an INSERT being generated? - Check
flushAtRequestEnd— iffalse, are you callingormFlush()or using a transaction? - Check
ORMGetSession().isDirty()— does Hibernate think anything changed? - Check
ORMGetSession().contains( entity )— is the entity persistent?
"Why am I getting extra UPDATE statements?"
- Enable
logSQL: trueand count the statements - Check for missing
inverse="true"on bidirectional relationships — see ORM - Relationships - Check for entities loaded and modified unintentionally (dirty checking)
"Why is this query slow?"
- Enable
logSQL: true, logParams: true— check the generated SQL - Look for N+1 patterns — the same SELECT repeated with different IDs
- Enable
logCache: trueif using L2 cache — check hit/miss ratios - Consider
batchsize,fetch="join", or HQL JOIN FETCH — see ORM - Relationships
What's Next?
- ORM - Troubleshooting — common error messages and what they mean
- ORM - Configuration — all logging settings
- ORM - Caching —
logCacheto monitor cache behaviour