Skip site navigation (1)Skip section navigation (2)

FreeBSD Manual Pages


home | help
DBIx::Log4perl(3)     User Contributed Perl Documentation    DBIx::Log4perl(3)

       DBIx::Log4perl -	Perl extension for DBI to selectively log DBI methods,
       SQL, parameters,	result-sets, transactions etc to a Log::Log4perl

	 use Log::Log4perl;
	 use DBIx::Log4perl;

	 my $dbh = DBIx::Log4perl->connect('DBI:odbc:mydsn', $user, $pass);


	 use DBIx::Log4perl;
	 my $dbh = DBIx::Log4perl->connect('dbi:ODBC:mydsn', $user, $pass,
					   {dbix_l4p_init => "/etc/mylog.conf",
					    dbix_l4p_class => "My::Package"});

       NOTE: The names of DBIx::Log4perl "ATTRIBUTES" have changed in version
       0.18. They are now all lowercased as per	the DBI	specification.

       "DBIx::Log4perl"	is a wrapper over DBI which adds logging of your DBI
       activity	via a Log::Log4perl handle. Log::Log4perl has many advantages
       for logging but the ones	probably most attractive are:

       The ability to turn logging on or off or	change the logging you see
       without changing	your code (or even without restarting your programs if
       you use "init_and_watch").

       Different log levels allowing you to separate warnings, errors and
       fatals to different files.

       The ability to capture all the information available via	DBI when an
       error occurs.

       DBIx::Log4perl adds the following methods over DBI.


       Returns the value for a DBIx::Log4perl attribute	(see "ATTRIBUTES").

	$h->dbix_l4p_setattr('dbix_l4p_logmask', 1);

       Set the value of	the specified DBIx::Log4perl attribute (see


       Calls the internal _error_handler method	with the message $message then
       dies with Carp::confess.

       The internal error handler is inserted into DBI's HandleError if
       "DBIX_L4P_LOG_ERRCAPTURE" is enabled. It	attempts to log	as much
       information about the SQL you were executing, parameters	etc.

       As an example, you might	be checking a $dbh->do which attempts to
       update a	row really does	update a row and want to die with all possible
       information about the problem if	the update fails. Failing to update a
       row would not ordinarily	cause DBI's error handler to be	called.

	 $affected = $dbh->do(q/update table set column	= 1 where column = 2/);
	 $dbh->dbix_logdie("Update failed") if ($affected != 1);

       This variable controls the amount of logging logged to the
       Log::Log4perl handle. There are a number	of constants defined which may
       be ORed together	to obtain the logging level you	require:

       The following constants may be imported via the ":masks"	group

	 use DBIx::Log4perl qw(:masks);

	   By default LogMask is set to	DBIX_L4P_LOG_DEFAULT which is

	   Log everything, all possible	masks ORed together which also
	   includes delaying the logging of bind_param (see

	   Log at Log4perl debug level input SQL to "do", "prepare", select*
	   methods and any value returned from "last_insert_id". In addition,
	   if the SQL is an insert/update/delete statement the rows affected
	   will	be logged.

	   NOTE: Many databases	return 0 rows affected for DDL statements like
	   create, drop	etc.

	   Log at Log4perl debug level the result-sets generated by select* or
	   fetch* methods. Be careful, this could produce a lot	of output if
	   you produce large result-sets.

	   Log at Log4perl debug level any call	to the "connect" and
	   "disconnect"	methods	and their arguments.

	   On connect the DBI version, DBIx::Log4perl version, the driver name
	   and version will be logged at Log4perl info level.

	   Log at Log4perl debug level all calls to "begin_work", "commit" and

	   Log at Log4perl error level any method which	fails which is not
	   caught by RaiseError. Currently this	is only	the execute_array

	   Log at Log4perl warning level any calls to do which return no
	   affected rows on an insert, update or delete	opertion.

	   Install a DBI error handler which logs at Log4perl fatal level as
	   much	information as it can about any	trapped	error. This includes
	   some	or all of the following	depending on what is available:

	     Handle type being used
	     Number of statements under	the current connection
	     Name of database
	     Username for connection to	database
	     Any SQL being executed at the time
	     The error message text
	     Any parameters in ParamValues
	     Any parameters in ParamArrays
	     A stack trace of the error

	   If you install your own error handler in the	"connect" call it will
	   be replaced when "connect" is called	in DBI but run from
	   "DBIx::Log4perl"'s error handler.

	   "DBIx::Log4perl" always returns 0 from the error handler if it is
	   the only handler which causes the error to be passed	on. If you
	   have	defined	your own error handler then whatever your handler
	   returns is passed on.

	   This	logging	depends	on the DBD you are using:

		 Use DBD::Oracle's methods for obtaining the buffer containing
		 "dbms_output.put_line output".	Whenever "$dbh->execute" is
		 called	DBIx::Log4perl will use
		 "$dbh->func('dbms_output_get')" to obtain an array of lines
		 written to the	buffer with "put_line".	These will be written
		 to the	log (prefixed with "dbms") at level DEBUG for the
		 execute method.

		 NOTE: If "DBIX_L4P_LOG_DBDSPECIFIC" is	enabled,
		 DBIx::Log4perl	calls "$dbh->func(dbms_output_enable)" after
		 the connect method has	succeeded. This	will use DBD::Oracle's
		 default buffer	size. If you want to change the	buffer size
		 see DBD::Oracle and change it after the connect method	has

		 As useful as this may seem you	are warned against using it as
		 when the dbms_output buffer is	full it	will generate an
		 Oracle	exception which	is probably not	what you want. This
		 can happen if the procedure you call calls
		 dbms_output.put_line too often	and fills the buffer before
		 returning to DBI.

	   If set (and it is not the default) this prevents the	logging	of
	   bind_param method calls and instead the bound parameters and
	   parameter types (if available) are logged with the execute method
	   instead. Example output for:

	       my $st =	$ph->prepare(q/insert into mje2	values(?,?)/);
	       $st->bind_param(1, 1);
	       $st->bind_param(2, "fred");

	   will	output something like:

	       DEBUG - prepare(0.1): 'insert into mje values(?,?)'
	       DEBUG - $execute(0.1) = [{':p1' => 1,':p2' => 'fred'},undef];
	       DEBUG - affected(0.1): 1

	   instead of the more usual:

	       DEBUG - prepare(0.1): 'insert into mje values(?,?)'
	       DEBUG - $bind_param(0.1)	= [1,1];
	       DEBUG - $bind_param(0.1)	= [2,'fred'];
	       DEBUG - execute(0.1)
	       DEBUG - affected(0.1): 1

	   where the parameter names and values	are displayed in the {}	after
	   execute and the parameter types are the next	argument. Few DBDs
	   support the ParamTypes attribute in DBI and hence mostly these are
	   displayed as	"undef"	as in the above	case which was using
	   DBD::Oracle.	Most (if not all) DBDs support ParamValues but you
	   might want to check that before setting this	flag.

	   If set this logs the	SQL passed to the do, prepare and select*
	   methods. This just separates	SQL logging from what
	   "DBIX_L4P_LOG_INPUT"	does and is generally most useful when
	   combined with DBIX_L4P_LOG_DELAYBINDPARAM.

       When you	call connect you may add "DBIx::Log4perl" attributes to	those
       which you are passing to	DBI. You may also get and set attributes after
       connect using "dbix_l4p_getattr()" and "dbix_l4p_setattr()".
       "DBIx::Log4perl"	supports the following attributes:

	   This	is the string to pass on to Log::Log4Perl's "init" method. It
	   is the name of the Log::Log4perl configuration file to use. e.g.


	   See Log::Log4perl.

	   This	is the string to pass on to Log::Log4Perl's "get_logger"
	   method e.g.

	     $logger = Log::Log4perl->get_logger('mysys.dbi');

	   See Log::Log4perl.

	   If you have already initialised and created your own	Log::Log4perl
	   handle you can pass it in as	"dbix_l4p_logger" and "DBIx::Log4perl"
	   will	ignore "dbix_l4p_log" and "dbix_l4p_init".

	   A mask of the flags defined under "CONSTANTS".

	   A regular expression	which will be matched against $DBI::err	in the
	   error handler and execute and if it matches no diagnostics will be
	   output; the handler will just return	(maybe causing the next
	   handler in the chain	to be called if	there is one).

	   An example of where this can	be useful is if	you are	raising
	   application errors in your procedures (e.g.,
	   RAISE_APPLICATION_ERROR in Oracle) where the	error indicates
	   something that is expected. Say you validate	a web session by
	   looking for the session ID via a procedure and raise	an error when
	   the session is not found. You probably don't	want all the
	   information DBIx::Log4perl normally outputs to the error log	about
	   this	error in which case you	set the	regular	expression to match
	   your	error number and it will no longer appear in the log.

       Although	these attributes are supported the recommended way to use
       DBIx::Log4perl it to use	Log::Log4perl in your application and call the
       "Log::Log4Perl->init" to	define your log4perl configuration file.
       DBIx::Log4perl will then	call
       "Log::Log4perl->get_logger("DBIx::Log4perl")" (as was intended by the
       authors of Log::Log4perl) and all you need is a
       "log4perl.logger.DBIx.Log4perl" entry in	your configuration file.

       Please see Log::Log4perl	for full details of the	configuration file and
       appenders. DBIx::Log4perl contains a sample configuration file you may
       use to get started. It looks like this:

	 log4perl.logger = FATAL, LOGFILE

	 log4perl.appender.LOGFILE.Threshold = ERROR

	 log4perl.appender.LOGFILE.layout.ConversionPattern=[%r] %F %L %c - %m%n

	 log4perl.logger.DBIx.Log4perl=DEBUG, A1

       This is perhaps the most	simple configuration. It says fatal errors go
       to /tmp/log and debug and above go to /tmp/xlog.	It also	uses the
       SimpleLayout which prefixes each	line with the log level. You can use:

	 log4perl.appender.A1.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n

       to make Log::Log4perl prefix the	line with a timestamp, module name and
       filename. DBIx::Log4perl	sets $Log::Log4perl::caller_depth in each
       method so when Log4perl outputs the module/file DBIx::Log4perl is
       ignored.	This is	extremely useful if you	need to	see where a DBI	method
       is called from.

   Example output
       For a connect the log will contain something like:

	 DEBUG - connect(0): DBI:mysql:mjetest,	bet
	 INFO -	DBI: 1.50, DBIx::Log4perl: 0.01, Driver: mysql(3.0002_4)


	 $sth =	$dbh->prepare('insert into mytest values (?,?)');
	 $sth->execute(1, 'one');

       you will	get:

	 DEBUG - prepare(0.1): 'insert into mytest values (?,?)'
	 DEBUG - $execute(0.1) (insert into mytest values (?,?)) = [1,'one'];

       In this latter case the SQL is repeated for convenience but this	only
       occurs if "execute" is called with parameters. If "execute" is called
       without any arguments the SQL is	not repeated in	the "execute". Also
       note the	output will include bind_param calls if	you bound parameters
       seperately but how this is logged depends on

       The numbers in the () after a method name indicate which	connection or
       statement handle	the operation was performed on.	The first connection
       your application	makes will be connection 0 (see	"connect(0)" above).
       Each statement method will show the connection number followed by a '.'
       and the statement number	(e.g., "prepare(0.1)" above is the second
       statement handle	on the first connection).

       NOTE: Some DBI methods are combinations of various methods e.g.
       selectrow_* methods. For	some of	these methods DBI does not actually
       call all	the lower methods because the driver implements	selectrow_*
       methods in C. For these cases, DBIx::Log4perl will only be able to log
       the selectrow_* method, the SQL,	any parameters and any returned
       result-set and you will not necessarily see a prepare, execute and
       fetch in	the log. e.g.,

	 $dbh->selectrow_array('select b from mytest where a = ?',undef,1);

       results in:

	 DEBUG - $selectrow_array = ['select b from mytest where a = ?',undef,1];

       with no evidence	prepare/execute/fetch was called.

       If "DBIX_L4P_LOG_ERRCAPTURE" is set all possible	information about an
       error is	written	to the log by the error	handler. In addition a few
       method calls will attempt to write a separate log entry containing
       information which may not be available in the error handler e.g.

	 $sth =	$dbh->prepare(q/insert into mytest values (?,?)/);
	 $sth->bind_param_array(1, [51,1,52,53]);
	 $sth->bind_param_array(2, ['fiftyone',	'one', 'fiftythree', 'fiftytwo']);
	 $inserted = $sth->execute_array( { ArrayTupleStatus =>	\@tuple_status } );

       when the	mytest table has a primary key on the first column and a row
       with 1 already exists will result in:

	 ERROR - $Error	= [1062,'Duplicate entry \'1\' for key 1','S1000'];
	 ERROR -	  for 1,fiftytwo

       because the @tuple_status is not	available in the error handler.	In
       this output 1062	is the native database error number, the second
       argument	is the error text, the third argument the state	and the
       additional lines	attempt	to highlight the parameters which caused the

   Example captured error
       By default, DBIx::Log4perl replaces any DBI error handler you have with
       its own error handler which first logs all possible information about
       the SQL that was	executing when the error occurred, the parameters
       involved, the statement handle and a stack dump of where	the error
       occurred.  Once DBIx::Log4perl's	error handler is executed it continues
       to call any error handler you have specifically set in you Perl DBI

       Assuming	you'd just run the following script:

	 use Log::Log4perl qw(get_logger :levels);
	 my $dbh = DBIx::Log4perl->connect('dbi:Oracle:XE', 'user', 'password) or
	     die "$DBD::errstr";
	 $dbh->do("insert into mytable values(?, ?)", undef, 1,
		  'string too long for column -	will be	truncated which	is an error');

       but the string argument to the insert is	too big	for the	column then
       DBIx::Log4perl would provide error output similar to the	following:

	 FATAL -   ============================================================
	 DBD::Oracle::db do failed: ORA-12899: value too large for column
	  "BET"."MYTABLE"."B" (actual: 64, maximum: 10)	(DBD ERROR: error possibly
	  near <*> indicator at	char 32	in 'insert into	martin values(:p1, :<*>p2)')
	  [for Statement "insert into martin values(?, ?)"]
	 lasth Statement (DBIx::Log4perl::db=HASH(0x974cf64)):
	   insert into martin values(?,	?)
	 DB: XE, Username: user
	 handle	type: db
	 SQL: Possible SQL: /insert into mytable values(?, ?)/
	 db Kids=0, ActiveKids=0
	 DB errstr: ORA-12899: value too large for column "BET"."MYTABLE"."B"
	  (actual: 64, maximum:	10) (DBD ERROR:	error possibly near <*>	indicator
	  at char 32 in	'insert	into mytable values(:p1, :<*>p2)')
	 ParamValues captured in HandleSetErr:
	   1,'string too long for column - will	be truncated which is an error',
	 0 sub statements:
	 DBI error trap	at /usr/lib/perl5/site_perl/5.8.8/DBIx/Log4perl/ line 32
	       'insert into mytable values(?, ?)', 'undef', 1, 'string too long	for
		column - will be truncated which is an error') called at
		line 12

       What this shows is:

       o the error reported by the DBD and the method called (do in this

       o the last handle used and the SQL for the last statement executed

       o the connection	the error occurred in

       o the handle type the error occurred on,	db or stmt (db in this case)

       o Other possible	SQL that may be	in error under this db connection e.g.
       if you were executing multiple statements on a single db	connection

       o the Kids and ActiveKids value for this	db - (see DBI docs)

       o the error message text	in "DBI::errstr"

       o any sql parameters passed to DBI (see DBI for ParamValues)

       o a trace of where the problem occurred In this case the	final problem
	 was in but as this is DBIx::Log4perl's do method, the real
	 issue was in the stack	element	below this which was line

   Use of Data::Dumper
       DBIx::log4perl makes extensive use of Data::Dumper to output arguments
       passed to DBI methods. In some cases it combines	the method called with
       the data	it is logging e.g.

	 DEBUG - $execute = [2,'two'];

       This means the execute method was called	with placeholder arguments of
       2 and 'two'. The	'$' prefixing execute is because Data::Dumper was
       called like this:

	 Data::Dumper->dump( [ \@execute_args ], [ 'execute'] )

       so Data::Dumper believes	it is dumping $execute.	DBIx::Log4perl uses
       this method extensively to log the method and arguments - just ignore
       the leading '$' in the log.

       During the development of this module I came across of large number of
       issues in DBI and various DBDs. I've tried to list them here but	in
       some cases I cannot give	the version the	problem	was fixed in because
       it was not released at the time of writing.

   DBI and $h->{Username}
       If you get an error like:

	 Can't get DBI::dr=HASH(0x83cbbc4)->{Username}:	unrecognised attribute name

       in the error handler it is because it was missing from DBI's XS code.

       This is fixed in	DBI 1.51.

   DBI and $h->{ParamArrays}
       This is the same	issue as above for $h->{Username}.

   DBD::ODBC and ParamValues
       In DBD::ODBC 1.13 you cannot obtain ParamValues after an	execute	has
       failed. I believe this is because DBD::ODBC insists on describing a
       result-set before returning ParamValues and that	is not necessary for

       Fixed in	1.14.

   DBD::mysql and ParamArrays
       DBD::mysql 3.002_4 does not support ParamArrays.

       I had to	add the	following to dbdimp.c to make it work:

	 case 'P':
	   if (strEQ(key, "PRECISION"))
	   /* +	insert the following block */
	   if (strEQ(key, "ParamValues")) {
	       HV *pvhv	= newHV();
	       if (DBIc_NUM_PARAMS(imp_sth)) {
		   unsigned int	n;
		   SV *sv;
		   char	key[100];
		   I32 keylen;
		   for (n = 0; n < DBIc_NUM_PARAMS(imp_sth); n++) {
		       keylen =	sprintf(key, "%d", n);
		       hv_store(pvhv, key, keylen, newSVsv(imp_sth->params[n].value), 0);
	       retsv = newRV_noinc((SV*)pvhv);
	   /* -	end of inserted	block */

       I believe this code is now added	in DBD::mysql 3.0003_1.

       There are six main ways you may help with the development and
       maintenance of this module:

       Submitting patches
	   Please get the latest version from CPAN and submit any patches
	   against that.

       Reporting installs
	   Install CPAN::Reporter and report you installations.	This is	easy
	   to do - see "CPAN Testers Reporting".

       Report bugs
	   If you find what you	believe	is a bug then enter it into the
	   <> system.
	   Where possible include code which reproduces	the problem including
	   any schema required and the versions	of software you	are using.

	   If you are unsure whether you have found a bug report it anyway.

       pod comments and	corrections
	   If you find inaccuracies in the DBIx::Log4perl pod or have a
	   comment which you think should be added then	go to
	   <> and submit them there.	I get an email for
	   every comment added and will	review each one	and apply any changes
	   to the documentation.

       Review DBIx::Log4perl
	   Add your review of DBIx::Log4perl on	<>.

       submit test cases
	   The test suite for DBIx::Log4perl is	pitifully small. Any test
	   cases would be gratefully received. In particular, it would be
	   really nice to add support for Test::Database.

CPAN Testers Reporting
       Please, please, please (is that enough),	consider installing
       CPAN::Reporter so that when you install perl modules a report of	the
       installation success or failure can be sent to cpan testers. In this
       way module authors 1) get feedback on the fact that a module is being
       installed 2) get	to know	if there are any installation problems.	Also
       other people like you may look at the test reports to see how
       successful they are before choosing the version of a module to install.

       CPAN::Reporter is easy to install and configure like this:

	 perl -MCPAN -e	shell
	 cpan> install CPAN::Reporter
	 cpan> reload cpan
	 cpan> o conf init test_report

       Simply answer the questions to configure	CPAN::Reporter.

       You can find the	CPAN testers wiki at <>
       and the installation guide for CPAN::Reporter at

       better testing

       You will	need at	least Log::Log4perl 1.04 and DBI 1.50.

       DBI-1.51	contains the changes listed under "NOTES".

       Versions	of Log::Log4perl before	1.04 work but unfortunately you	will
       get code	references in some of the log output where DBIx::Log4perl

	 $log->logwarn(sub {Data::Dumper->Dump(something)})

       The same	applies	to logdie. See the Log4perl mailing list for details.



       M. J. Evans, <>

       Copyright (C) 2006 - 2012 by M. J. Evans

       This library is free software; you can redistribute it and/or modify it
       under the same terms as Perl itself, either Perl	version	5.8.7 or, at
       your option, any	later version of Perl 5	you may	have available.

perl v5.32.0			  2012-07-18		     DBIx::Log4perl(3)


Want to link to this manual page? Use this URL:

home | help