Print query result sets + datasource proxy + custom sql formatter

443 views
Skip to first unread message

Noctiluque

unread,
Jun 6, 2010, 10:08:43 PM6/6/10
to log4jdbc
Hi Arthur,

Thanks for log4jdbc, I'm using a modified log4jdbc (based on trunk)
with a Spring + Hibernate application.

The modifications are:
(1) I've added a DataDource proxy that can be plugged into the spring
configuration so that log4jdbc can be used.
(2) I've added a new logger, resultSetTableLogger, to SpyLogFactory.
If resultSetTableLogger is enabled then ResultSetSpy uses a
"ResultSetCollector" to collect the result sets. Each result set is
printed as a table end of the result set.
(3) I've allowed SpyLogFactory to override the default SpyLogDelegator
so that a custom sql formatter can be used. I've created a custom
formatter to format the sql to my liking (but this a minor detail).

The sum total of the above modifications is that I have output that
looks like this (needs a non proportional font to display properly-
hope it works!):

SQL:::select statuses0_.NETWORK_OBJECT_ID as NETWORK4_1_,
statuses0_.ID as ID1_, statuses0_.ID as ID9_0_, statuses0_.ACTIVE as
ACTIVE9_0_, statuses0_.DATE_EFFECTIVE as DATE3_9_0_
from STATUS_DATE statuses0_
where statuses0_.NETWORK_OBJECT_ID=12
|------------|-----|-------|-----------|----------------------|
|NETWORK4_1_ |ID1_ |ID9_0_ |ACTIVE9_0_ |DATE3_9_0_ |
|------------|-----|-------|-----------|----------------------|
|12 |14 |14 |Y |2000-01-01 00:00:00.0 |
|12 |15 |15 |Y |2000-03-01 00:00:00.0 |
|------------|-----|-------|-----------|----------------------|

The result set collector is only active if the logging level is INFO
or above.

It uses the ResultSet meta data for the column titles, calling
getMetaData if the application has not already done so by the end of
the result set.

At logging level INFO, if a value is not read by the application then
it prints [unread],
At logging level DEBUG, if a value is not read by the application then
it reads and prints it.

Would you be interested in a patch for this, or is it a step (or
several?) steps too far?

Tim Azzopardi

Arthur Blake

unread,
Jun 6, 2010, 10:35:37 PM6/6/10
to log4...@googlegroups.com
The most interesting part, to me, is the 
resultSetTableLogger... 
I've thought about doing something like that before, but I never went that far because it seems like it would only be really useful in a narrow set of cases.  Mainly because of how large the log files could become.  Nevertheless, it seems like it could be really useful in certain situations and development environments-- has it been useful for you?  I'd be interested in looking over your code changes.



--
You received this message because you are subscribed to the Google Groups "log4jdbc" group.
To post to this group, send email to log4...@googlegroups.com.
To unsubscribe from this group, send email to log4jdbc+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/log4jdbc?hl=en.


kfuda...@gmail.com

unread,
Jun 7, 2010, 1:50:39 AM6/7/10
to log4...@googlegroups.com, Arthur Blake
I have added something similar to log4jdbc but didn't mention it for the same reason plus my version seemed more of a hack. Tims version actually sounds pretty clean. It is in fact very useful to trace resultset output for debugging.

- Kris

Tim Azzopardi

unread,
Jun 7, 2010, 5:03:39 AM6/7/10
to log4...@googlegroups.com
Wow, I wasn't expecting a reply so quickly! Posted the message and
went to bed ;)

On Jun 7, 3:35 am, Arthur Blake <arthur.bl...@gmail.com> wrote:
> Nevertheless, it seems like it could be really useful in
> certain situations and development environments-- has it been useful for
> you?

My first use case is maintenance of a complex system with
transactional services updating many tables with different parts of
the code reading data back from tables modified within the same
service. When something goes wrong, the whole transaction gets rolled
back and afterwards I can't see the state of the database as it was
when the code broke. With the result set tracing I can see what data
the code has read out of the tables at the time and so have a better
idea about why the code broke.

My second use case is related to the first: as I'm stepping through
the debugger, seeing the table results directly on my console just
saves me having to look at variables and therefore thinking time.

My third use case is as an aid to creating dbunit tests: The system I
am working on is/was sorely lacking unit test. I wanted to create
dbunit tests, based on the idea that existing functionality is correct
and changes I make must not break the existing functionality. By being
able to see whether the result sets are empty or not, I am able to
work out which tables I need to set up to be initialized by dbunit.
Not a huge deal but it did help.

> I'd be interested in looking over your code changes.

See attached patch, I hope its the right format. Its got all the
modifications in it.

Caveats:

(1) Its jdbc4 only.

(2) The code does not warn about bi-directional result sets. It does
not deal with previous(), first(), last() etc, just next(). There is
no warning either so duplicate result rows would be seen if, for
example, previous() followed by next() is used by the application
(although I've not tested this). It would theoretically possible to
deal with this scenario or at least give a warning about an
unsupported operation. I just didn't need to do it in my application.

(3) You'll see my custom Slf4jSpyLogDelegator called
Log4JdbcCustomFormatter in package net.sf.log4jdbc.tools.
Thats just an example/for convenience for the patch. There is no need
for it to be in that package. Its specific to my use of log4jdbc, so
it would normally live elsewhere. I'm not expecting you to include
this in log4jdbc. However my SpyLogFactory modification adding
setSpyLogDelegator makes it possible for any application to set a
custom sql formatter, so that would be a useful change to log4jdb IMO.

(4) The log4j config is set as follows. As I said before, level debug
will fill in unread values in the result set.

log4j
<!-- log4jdbc option log the jdbc results as a table -->
<logger name="jdbc.resultsettable" additivity="false">
<level value="info" />
<appender-ref ref="console-log4jdbc" />
</logger>


(5) The javadoc for Log4jdbcProxyDataSource shows an example of how to
configure the DataSource proxy in spring configuration. My config is
slightly extended for my custom sql logger and I repeat it here for
information

<bean id="dataSourceSpied"
class="com.mchange.v2.c3p0.ComboPooledDataSource">
.. as in the javadoc...
</bean>

<bean id="dataSource" class="net.sf.log4jdbc.Log4jdbcProxyDataSource">
<constructor-arg ref="dataSourceSpied" />
<property name="logFormatter">
<bean class="net.sf.log4jdbc.tools.Log4JdbcCustomFormatter">
<property name="loggingType" value="MULTI_LINE" />
<property name="margin" value="19" />
<property name="sqlPrefix" value="SQL:::" />
</bean>
</property>
</bean>

(6) The tiny JdbcUtils class is taken from the Spring framework (which
is also apache2 licensed), and has Oracle specific code in it. My
understanding is that it works for all other databases too, it just
has a couple of Oracle specific bits of code in it because Oracle does
things in such a strange way compared to every one else.

if you need me to explain or do anything else let me know!

Cheers
Tim Azzopardi

log4-jdbc-patch.txt

Arthur Blake

unread,
Jun 7, 2010, 10:14:19 AM6/7/10
to log4...@googlegroups.com
Thanks for your patch.  I'll take a look at it when I have time.
I can't guarantee I'll use any of it but I will see.
In general I prefer an SVN patch (svn diff command.)  I'm not used to using an "Eclipse Workspace patch" but I'm sure I can figure it out.

Tim Azzopardi

unread,
Jun 7, 2010, 10:29:52 AM6/7/10
to log4...@googlegroups.com
> In general I prefer an SVN patch (svn diff command.)

Attachment created with TortoiseSVN create patch which has no eclipse header.

> Thanks for your patch. I'll take a look at it when I have time.
> I can't guarantee I'll use any of it but I will see.

Understood

Cheers

patch.diff
Reply all
Reply to author
Forward
0 new messages