Adventures in ADF Logging - Part 5
By Duncan Mills on Jun 11, 2011
Unleashing the True Power of the ADFLogger
So far we've seen that the logging facility provided by the ADFLogger and the attendant tools in JDeveloper is all pretty useful and provides a powerful way of implementing and examining your logs. However, lets's take it to the next level (here's where it gets really interesting).
You are, I'm sure, familiar with the -Djbo.debugoutput=console switch which is a command line argument to WebLogic or the ADF/BC tester which provides a bunch of useful trace information such as when bindings are constructed and ADF/BC queries and bind variables are manipulated. It's generally regarded as a key tool in any ADF Hackers toolbox. However, you may have thought to yourself: This is great but it's a pain having to re-run the application (and restart WLS) just to switch this diagnostic on... And you'd be right, it is a pain and certainly not something you would entertain on a production system. But guess what, we can use the logging capabilities to do the same thing without a restart.
Debugoutput Without the Pain
To work this magic, just run your application without the -Djbo.debugoutput flag and once it's running bring up the ODL Configuration Screen (Refer back to Part 3 in this series if you've not already read up on how to do that).
Now switch on FINEST for the following packages:
Here's what it should look like:
Now go back to the web browser and carry out the activity that you're trying to trace (remember - no need to restart, the logging kicks in immediately). Once you're done open up the ODL Analyzer (refer to Part 4 in this series). The main thing that you'll observe is an awful lot of logging has happened. In this case I happen to have added my own logging call into an Entity Object accessor method so I can search the log for the call that is part of the transaction I'm interested in:
Now I can use that Related By Request option that we looked at last time to see all the log messages associated with this one:
Which leads to this more constrained list:
Now scroll down this list of messages and I'll start to encounter useful messages such as this set:
In this case it's the SQL that is being generated to get the rowcount on a VO and I can look at the key information such as the actual count returned, the SQL and the bind variable substitution.
But Wait, There's More
The final piece in the jigsaw is that mysterious Related By ADF Request option that I skipped over last time. Now that we have a full-fat diagnostic log let's use that option instead of plain Related by Request. When you do this you're taken to that By ADF Request tab in the analyzer. This is what you'll see:
What you're seeing here is a complete breakdown of the ADF Request by phase with elapsed times and a really simple to understand view of what happened when, and how log it took. You can view the details of each message in the bottom pane, and in this case again we're looking at an Estimated Row Count call.
At this point I should probably shut up and let you drool. Enjoy!