[Looking for Charlie's main web site?]

Spying on ORM database interactions: Hibernate, Transfer, etc. on any CFML engine

As people use CF9's ORM feature (or other ORMs like Transfer and Reactor, or indeed Hibernate, on any version of CF6+ or indeed any other CFML engine), they may be left wondering what sort of SQL interactions happen "under the covers" between the ORM framework and the database engine (whether in a given request, or perhaps at startup of CF).

Well, there are several ways you can watch them, as this entry will discuss, and some may be better suited to the job than others. It can be very interesting to discover what's going on, especially if you're having any suspected performance problems which you think may be related to ORM processing (or just if you wonder what all it does for you).

As for spying on the SQL, of course ORM support is just a different way that the CFML engine (through the ORM framework) sends SQL to a database via a regular DSN, just like any other request, so there's nothing really "tricky" about this. It's just about realizing that while you don't write the SQL yourself, it's still generated by the CFML engine/ORM framework, and you may not realize/consider the available tools which can spy on it, just like any other DB processing from within CF. Indeed, some people may not even realize how many options exist to spy on JDBC interactions from their CFML engine to the database engine.

The good news is that there are several approaches, some included in CF (some depending on the edition), and some available separately which would work in any edition of CF or the other CFML engines (Open BlueDragon, Railo, etc.), and with any of the ORM frameworks. And again, some may be better than others for certain challenges.

(FWIW, besides the aforementioned Transfer and Reactor, there are still other ORM solutions for CFML, which I mention in my CF411 list as CFML ORM Frameworks. Indeed, note that you can run Hibernate on CF prior to CF9, if you want to. This is a recovery of a blog entry that no longer exists, recovered via archive.org.)

Built-in ORM Logging Option

First, note that for those using CF9+ ORM, there is indeed a built-in option in the CF ORM setup where one can enable logging, settable in the application.cfc: see the this.ormsettings option and its available key/value pair, logSQL="true".

There are several resources where you can learn more on that (and a related log4j property file approach to logging this). Besides the CF9 docs page on the ORM settings, there is also a blog entry by Adobe engineer Rupesh Kumar.

The default is to log this information to the console, but you can manipulate those log4j settings to tell it to use a file (see the links above). Even so, this will result in quite a lot of data being logged, which you will then need to connect back to your specific requests. The following approaches may be preferable.

Using FusionReactor or SeeFusion

Users of any CF edition (6+) or any CFML engine (Railo, OpenBD, or BD 7+) can use tools like SeeFusion and FusionReactor, which have always had the ability to monitor database interactions by "wrapping" the datasource to be monitored. FusionReactor engineer John Hawksley has posted a recent article specifically on monitoring CF9's ORM interaction, in the FR Devnet site, Using FusionReactor's JDBC Driver Wrapper With ColdFusion 9 ORM. Its concepts would apply to any ORM, of course.

Similarly, I've written generically about FusionReactor's database monitoring feature in What is the FusionReactor datasource monitoring feature? Why would I use it? Powerful stuff. As I point out in that article, the concepts discussed apply as well to SeeFusion's ability to monitor queries by wrapping datasources.

That said, it's worth noting that FusionReactor does have a couple of advantages, in that it provides for the display of all queries for a given request (while viewing the details of that request), whereas SeeFusion only lets you see the slowest query in a given request. FusionReactor also provides a separately available display of all the slowest queries (across all requests). It also logs every query (connecting it to a given request as well), while SeeFusion (Enterprise, at least) can also log the slowest queries to a database.

And note that both of these track any requests coming out of CF, not just those associated with a given request. So if there is ORM SQL that is associated with the startup of CF, that's tracked too. (And for those aware of issues with CF's Client Variables, such DB activity is also tracked, even that done by the hourly purge, which takes place on a background, non-jrpp thread.)

CF Enterprise Server Monitor

Those running CF 8 or 9 (Enterprise only) will find that its available Server Monitor does offer built-in monitoring of the SQL executed against CF datasources, at least, as long as you enable "Start Profiling" (which also enables other features, and overhead, as well). In this way, the Enterprise Server Monitor can monitor database interactivity, including ORM interactions.

Unlike FusionReactor (and like SeeFusion), it focuses only on showing queries that exceed certain limits, and at that it shows them only in a "Slowest Queries" interface, tracking the slowest queries among all requests. The CF Enterprise Server Monitor also has no logging ability at all.

Being able to see every single DB interaction for a given request (or across all requests) may be all the more interesting for discovering/observing what's happening with ORM interactivity.

Another alternative CF feature

Still another little-known feature for spying on JDBC interactions in CF is by way of the JDBC "spy" feature, which does in fact allow logging of all JDBC interactions mde from within CF. This feature was first enabled by way of the DataDirect 3.5 driver update which was made available (as an optional upgrade for 6 and 7) in the CF 7.02 timeframe. I wrote about the Spy feature back back in Aug 2006.

Since then, CF 8 (and now 9) offer it instead as a new "log activity" option in the "advanced settings" for a datasource definition in the CF Admin (which is disabled by default). I pointed this out in another entry from 2007 as one of many easily missed changes for the CF 8 Admin.

This "log activity" output is not as easy to interpret as FusionReactor's logs, and can indeed be voluminous (moreso than FR's), so be careful. Anyway, it's one of the several ways you can monitor JDBC interactions between CFML and your DB engine. Again, any of these may be useful for monitoring any of your CFML/database interactions.

Generic DB Monitoring tools

Indeed, it's worth noting finally that while the focus here has been watching the DB interaction from CF (and the ORM framework) to the database (by watching the JDBC traffic going out of CF and returning), you could just as well watch the DB interactivity from the DB's perspective instead (watching it coming and and being returned).

There are many tools that can monitor database processing, available for each of the major databases (free and commercial). I list several such tools in one of my CF411 section, Database/SQL Monitoring Tools.

Hope all that's helpful, whether you use ORM or not.

Comments
I could/should have added that you can also add JDBC wrapping on your own, using any of many alternatives out there. They all involve some extra steps (putting jars in the right place within CF, modifying datasources to find/wrap the current JDBC URL, and so on). But they do exist. The oldest may be p6spy but there are others. I do list several of them in the CF411 page category I referred to in the last paragraph above.
# Posted By charlie arehart | 8/18/11 4:14 PM
BlogCFC was created by Raymond Camden. This blog is running version 5.005. (Want to validate the html in this page?)

Managed Hosting Services provided by
Managed Dedicated Hosting