= Full Query Logging =

Propel provides a '''DebugPDO''' subclass of PHP's `PDO`, which provides various logging facilities related the the active database connection, and includes full query logging.

== Configuring Propel to use DebugPDO ==

To enable full query logging, you must tell Propel that you wish to use the `DebugPDO` class (instead of the default `PropelPDO` class). This is accomplished in the `runtime-conf.xml` file, in the `<classname>` tag of a given datasource connection (see the [wiki:Users/Documentation/1.4/Runtime-Configuration runtime configuration reference] for more details).

{{{
#!xml
<?xml version="1.0"?>
<config>
  <propel>
    <datasources default="bookstore">
      <datasource id="bookstore">
        <adapter>sqlite</adapter>
        <connection>
          <!-- the classname that Propel should instantiate, must be PropelPDO subclass -->
          <classname>DebugPDO</classname>
}}}

That's all. After this change, Propel logs all the queries executed at runtime in its default log file:

{{{
Oct 04 00:00:18 propel-bookstore [debug] INSERT INTO publisher (`ID`,`NAME`) VALUES (NULL,'William Morrow')
Oct 04 00:00:18 propel-bookstore [debug] INSERT INTO author (`ID`,`FIRST_NAME`,`LAST_NAME`) VALUES (NULL,'J.K.','Rowling')
Oct 04 00:00:18 propel-bookstore [debug] INSERT INTO book (`ID`,`TITLE`,`ISBN`,`PRICE`,`PUBLISHER_ID`,`AUTHOR_ID`) VALUES (NULL,'Harry Potter and the Order of the Phoenix','043935806X',10.99,53,58)
Oct 04 00:00:18 propel-bookstore [debug] INSERT INTO review (`ID`,`REVIEWED_BY`,`REVIEW_DATE`,`RECOMMENDED`,`BOOK_ID`) VALUES (NULL,'Washington Post','2009-10-04',1,52)
...
Oct 04 00:00:18 propel-bookstore [debug] SELECT bookstore_employee_account.EMPLOYEE_ID, bookstore_employee_account.LOGIN FROM `bookstore_employee_account` WHERE bookstore_employee_account.EMPLOYEE_ID=25
}}}

Tip: The `PropelPDO` class is intended for development use only. Do not use it in production environment, it logs too much information for a production server, and adds a small overhead to the database queries.

== Query Counting ==

The `DebugPDO` class keeps track of the number of queries that are executed.  You can get the number of queries at the end of the request from the connection object:

{{{
#!php
<?php
// At end of request
$con = Propel::getConnection(MyObjPeer::DATABASE_NAME);
if ($con instanceof DebugPDO) {
  print "Number of queries executed: " . $con->getQueryCount();
}
}}}

Tip: You cannot use persistent connections if you want the query count to work (actually, `DebugPDO` in general requires that you not use persistent connections in order for it to correctly log bound values and count executed statements).

== Retrieving The Latest Executed Query ==

For debuggin purposes, you may need the SQL code of the latest executed query. It is available at runtime using `DebugPDO::getLastExecutedQuery()`, as follows:

{{{
#!php
<?php
// At end of request
$con = Propel::getConnection(MyObjPeer::DATABASE_NAME);
if ($con instanceof DebugPDO) {
  print "Lastest query: " . $con->getLastExecutedQuery();
}
}}}

== Configuring DebugPDO ==

=== Where To Configure DebugPDO ===

`DebugPDO` can be configured either in the `runtime-conf.xml` configuration file, or using the runtime configuration API.

In `runtime-conf.xml`, tweak `DebugPDO` by adding a `<debugpdo>` tag under `<propel>`:

{{{
#!xml
<?xml version="1.0"?>
<config>
  <log>
    ...
  </log>
  <propel>
    <datasources default="bookstore">
      ...
    </datasources>
    <debugpdo>
      <logging>
        <details>
          <method>
            <enabled>true</enabled>
          </method>
          <time>
            <enabled>true</enabled>
          </time>
          <mem>
            <enabled>true</enabled>
          </mem>
        </details>
      </logging>
    </debugpdo>
  </propel>
</config>
}}}

To accomplish the same configuration as above at runtime, change the settings in your main include file, after `Propel::init()`, as follows:

{{{
#!php
<?php
$config = Propel::getConfiguration(PropelConfiguration::TYPE_OBJECT);
$config->setParameter('debugpdo.logging.details.method.enabled', true);
$config->setParameter('debugpdo.logging.details.time.enabled', true);
$config->setParameter('debugpdo.logging.details.mem.enabled', true);
}}}

=== DebugPDO Settings ===

The following settings can be customized at runtime or in the configuration file:

||'''Parameter'''||'''Default'''||'''Meaning'''||
||`debugpdo.logging.enabled`||`true`||Should any logging take place||
||`debugpdo.logging.innerglue`||`": "`||String to use for combining the title of a detail and its value||
||`debugpdo.logging.outerglue`||`" | "`||String to use for combining details together on a log line||
||`debugpdo.logging.realmemoryusage`||`false`||Parameter to [http://www.php.net/manual/en/function.memory-get-usage.php memory_get_usage()] and [http://www.php.net/manual/en/function.memory-get-peak-usage.php memory_get_peak_usage()] calls||
||`debugpdo.logging.methods`||[http://propel.phpdb.org/trac/browser/branches/1.4/runtime/classes/propel/util/DebugPDO.php#L151 array(...)]||An array of method names `Class::method`) to be included in method call logging||
||`debugpdo.logging.details.slow.enabled`||`false`||Enables flagging of slow method calls||
||`debugpdo.logging.details.slow.threshold`||`0.1`||Method calls taking more seconds than this threshold are considered slow||
||`debugpdo.logging.details.time.enabled`||`false`||Enables logging of method execution times||
||`debugpdo.logging.details.time.precision`||`3`||Determines the precision of the execution time logging||
||`debugpdo.logging.details.time.pad`||`10`||How much horizontal space to reserve for the execution time on a log line||
||`debugpdo.logging.details.mem.enabled`||`false`||Enables logging of the instantaneous PHP memory consumption||
||`debugpdo.logging.details.mem.precision`||`1`||Determines the precision of the memory consumption logging||
||`debugpdo.logging.details.mem.pad`||`9`||How much horizontal space to reserve for the memory consumption on a log line||
||`debugpdo.logging.details.memdelta.enabled`||`false`||Enables logging differences in memory consumption before and after the method call||
||`debugpdo.logging.details.memdelta.precision`||`1`||Determines the precision of the memory difference logging||
||`debugpdo.logging.details.memdelta.pad`||`10`||How much horizontal space to reserve for the memory difference on a log line||
||`debugpdo.logging.details.mempeak.enabled`||`false`||Enables logging the peak memory consumption thus far by the currently executing PHP script||
||`debugpdo.logging.details.mempeak.precision`||`1`||Determines the precision of the memory peak logging||
||`debugpdo.logging.details.mempeak.pad`||`9`||How much horizontal space to reserve for the memory peak on a log line||
||`debugpdo.logging.details.querycount.enabled`||`false`||Enables logging of the number of queries performed by the DebugPDO instance thus far||
||`debugpdo.logging.details.querycount.pad`||`2`||How much horizontal space to reserve for the query count on a log line||
||`debugpdo.logging.details.method.enabled`||`false`||Enables logging of the name of the method call||
||`debugpdo.logging.details.method.pad`||`28`||How much horizontal space to reserve for the method name on a log line||

The order in which the logging details are enabled is significant, since it determines the order in which they will appear in the log file.

=== Example ===

Enabling the options shown above, you get log output along the lines of:

{{{
Feb 23 16:41:04 Propel [debug] method: DebugPDO::__construct        | time:  0.002 sec | mem:    1.4 MB | 
Feb 23 16:41:04 Propel [debug] method: DebugPDO::exec               | time:  0.000 sec | mem:    1.4 MB | SET NAMES 'utf8'
Feb 23 16:41:04 Propel [debug] method: DebugPDO::prepare            | time:  0.000 sec | mem:    1.6 MB | SELECT images.IMAGEID, images.FILENAME, ...
Feb 23 16:41:04 Propel [debug] method: DebugPDOStatement::bindValue | time:  0.000 sec | mem:    1.7 MB | Binding '1428' at position :p1 w/ PDO ty...
Feb 23 16:41:04 Propel [debug] method: DebugPDOStatement::execute   | time:  0.000 sec | mem:    1.7 MB | 
Feb 23 16:41:04 Propel [debug] method: DebugPDO::prepare            | time:  0.000 sec | mem:    2.1 MB | SELECT tagsToImages.IMAGEID, tagsToImage...
Feb 23 16:41:04 Propel [debug] method: DebugPDOStatement::bindValue | time:  0.000 sec | mem:    2.1 MB | Binding 1428 at position :p1 w/ PDO type...
Feb 23 16:41:04 Propel [debug] method: DebugPDOStatement::execute   | time:  0.000 sec | mem:    2.1 MB | 
Feb 23 16:41:04 Propel [debug] method: DebugPDO::prepare            | time:  0.000 sec | mem:    2.4 MB | SELECT COUNT(*), tags.TAGID, tags.NAME, ...
Feb 23 16:41:04 Propel [debug] method: DebugPDOStatement::bindValue | time:  0.000 sec | mem:    2.4 MB | Binding 201 at position :p1 w/ PDO type ...
Feb 23 16:41:04 Propel [debug] method: DebugPDOStatement::execute   | time:  0.003 sec | mem:    2.4 MB | 
Feb 23 16:41:04 Propel [debug] method: DebugPDO::__destruct         | time:  0.000 sec | mem:    3.7 MB |
}}}

Tip: You can also get a decent representation of the criteria being used in a SELECT query by using the `Criteria->toString()` method.

== Changing the Log Level ==

By default the log messages will be logged at the `Propel::LOG_DEBUG` level.  This can be changed by calling a setter method on the connection.
{{{
#!php
<?php
$con = Propel::getConnection(MyObjPeer::DATABASE_NAME);
if ($con instanceof DebugPDO) {
  $con->setLogLevel(Propel::LOG_INFO);
}
}}}

Now all queries & bind param values will be logged at INFO level.

== Custom PDO Object ==

While this document describes the '''DebugPDO''' object, you can also specify your own '''PropelPDO''' subclass in the {{{runtime-conf.xml}}}.  Note the rules, mentioned above, about the class being already included or autoload-able. 

Tip: Propel requires certain fixes to PDO API that are provided by the '''PropelPDO''' subclass. Make sure your custom connection class extends `PropelPDO` and not only `PDO`.

== Configuring a Different Logger ==

By default the `DebugPDO` connection logs queries and binds param values using the `Propel::log()` static method. This method uses the log storage configured by the `<log>` tag in the `runtime-conf.xml` file.

If you would like the queries to be logged using a different logger (e.g. to a different file, or with different ident, etc.), you can set a logger explicitly on the connection at runtime, using `Propel::setLogger()`:

{{{
#!php
<?php

$con = Propel::getConnection(MyObjPeer::DATABASE_NAME);
if ($con instanceof DebugPDO) {
  $logger = Log::singleton(...);
  $con->setLogger($logger);
}
}}}

The same rules that apply to the [wiki:Users/Documentation/1.4/ConfigureLogging general logging configuration] apply here too. You can use a PEAR logger or a logger that implements Propel's `BasicLogger` interface.
