Subversion-Projekte lars-tiefland.php_share

Revision

Details | Letzte Änderung | Log anzeigen | RSS feed

Revision Autor Zeilennr. Zeile
1 lars 1
<?php
2
/*
3
 *  $Id: DebugPDO.php 1343 2009-11-29 22:36:48Z david $
4
 *
5
 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
6
 * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
7
 * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
8
 * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
9
 * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
10
 * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
11
 * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
12
 * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
13
 * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
14
 * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
15
 * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
16
 *
17
 * This software consists of voluntary contributions made by many individuals
18
 * and is licensed under the LGPL. For more information please see
19
 * <http://propel.phpdb.org>.
20
 */
21
 
22
/**
23
 * PDO connection subclass that provides some basic support for query counting and logging.
24
 *
25
 * This class is ONLY intended for development use.  This class is also a work in-progress
26
 * and, as such, it should be expected that this class' API may change.
27
 *
28
 * The following runtime configuration items affect the behaviour of this class:
29
 *
30
 * - debugpdo.logging.enabled (default: true)
31
 *   Should any logging take place
32
 *
33
 * - debugpdo.logging.innerglue (default: ": ")
34
 *   String to use for combining the title of a detail and its value
35
 *
36
 * - debugpdo.logging.outerglue (default: " | ")
37
 *   String to use for combining details together on a log line
38
 *
39
 * - debugpdo.logging.realmemoryusage (default: false)
40
 *   Parameter to memory_get_usage() and memory_get_peak_usage() calls
41
 *
42
 * - debugpdo.logging.methods (default: DebugPDO::$defaultLogMethods)
43
 *   An array of method names ("Class::method") to be included in method call logging
44
 *
45
 * - debugpdo.logging.onlyslow (default: false)
46
 *   Suppress logging of non-slow queries.
47
 *
48
 * - debugpdo.logging.details.slow.enabled (default: false)
49
 *   Enables flagging of slow method calls
50
 *
51
 * - debugpdo.logging.details.slow.threshold (default: 0.1)
52
 *   Method calls taking more seconds than this threshold are considered slow
53
 *
54
 * - debugpdo.logging.details.time.enabled (default: false)
55
 *   Enables logging of method execution times
56
 *
57
 * - debugpdo.logging.details.time.precision (default: 3)
58
 *   Determines the precision of the execution time logging
59
 *
60
 * - debugpdo.logging.details.time.pad (default: 10)
61
 *   How much horizontal space to reserve for the execution time on a log line
62
 *
63
 * - debugpdo.logging.details.mem.enabled (default: false)
64
 *   Enables logging of the instantaneous PHP memory consumption
65
 *
66
 * - debugpdo.logging.details.mem.precision (default: 1)
67
 *   Determines the precision of the memory consumption logging
68
 *
69
 * - debugpdo.logging.details.mem.pad (default: 9)
70
 *   How much horizontal space to reserve for the memory consumption on a log line
71
 *
72
 * - debugpdo.logging.details.memdelta.enabled (default: false)
73
 *   Enables logging differences in memory consumption before and after the method call
74
 *
75
 * - debugpdo.logging.details.memdelta.precision (default: 1)
76
 *   Determines the precision of the memory difference logging
77
 *
78
 * - debugpdo.logging.details.memdelta.pad (default: 10)
79
 *   How much horizontal space to reserve for the memory difference on a log line
80
 *
81
 * - debugpdo.logging.details.mempeak.enabled (default: false)
82
 *   Enables logging the peak memory consumption thus far by the currently executing PHP script
83
 *
84
 * - debugpdo.logging.details.mempeak.precision (default: 1)
85
 *   Determines the precision of the memory peak logging
86
 *
87
 * - debugpdo.logging.details.mempeak.pad (default: 9)
88
 *   How much horizontal space to reserve for the memory peak on a log line
89
 *
90
 * - debugpdo.logging.details.querycount.enabled (default: false)
91
 *   Enables logging of the number of queries performed by the DebugPDO instance thus far
92
 *
93
 * - debugpdo.logging.details.querycount.pad (default: 2)
94
 *   How much horizontal space to reserve for the query count on a log line
95
 *
96
 * - debugpdo.logging.details.method.enabled (default: false)
97
 *   Enables logging of the name of the method call
98
 *
99
 * - debugpdo.logging.details.method.pad (default: 28)
100
 *   How much horizontal space to reserve for the method name on a log line
101
 *
102
 * The order in which the logging details are enabled is significant, since it determines the order in
103
 * which they will appear in the log file.
104
 *
105
 * @example    // Enable simple query profiling, flagging calls taking over 1.5 seconds as slow:
106
 *             $config = Propel::getConfiguration(PropelConfiguration::TYPE_OBJECT);
107
 *             $config->setParameter('debugpdo.logging.details.slow.enabled', true);
108
 *             $config->setParameter('debugpdo.logging.details.slow.threshold', 1.5);
109
 *             $config->setParameter('debugpdo.logging.details.time.enabled', true);
110
 *
111
 * @author     Francois Zaninotto
112
 * @author     Cameron Brunner <cameron.brunner@gmail.com>
113
 * @author     Hans Lellelid <hans@xmpl.org>
114
 * @author     Christian Abegg <abegg.ch@gmail.com>
115
 * @author     Jarno Rantanen <jarno.rantanen@tkk.fi>
116
 * @since      2006-09-22
117
 * @package    propel.util
118
 */
119
class DebugPDO extends PropelPDO
120
{
121
	const DEFAULT_SLOW_THRESHOLD        = 0.1;
122
	const DEFAULT_ONLYSLOW_ENABLED      = false;
123
 
124
	/**
125
	 * Count of queries performed.
126
	 *
127
	 * @var        int
128
	 */
129
	protected $queryCount = 0;
130
 
131
	/**
132
	 * SQL code of the latest performed query.
133
	 *
134
	 * @var        string
135
	 */
136
	protected $lastExecutedQuery;
137
 
138
	/**
139
	 * The statement class to use.
140
	 *
141
	 * @var        string
142
	 */
143
	protected $statementClass = 'DebugPDOStatement';
144
 
145
	/**
146
	 * Configured BasicLogger (or compatible) logger.
147
	 *
148
	 * @var        BasicLogger
149
	 */
150
	protected $logger;
151
 
152
	/**
153
	 * The log level to use for logging.
154
	 *
155
	 * @var        int
156
	 */
157
	private $logLevel = Propel::LOG_DEBUG;
158
 
159
	/**
160
	 * The default value for runtime config item "debugpdo.logging.methods".
161
	 *
162
	 * @var        array
163
	 */
164
	protected static $defaultLogMethods = array(
165
		'DebugPDO::exec',
166
		'DebugPDO::query',
167
		'DebugPDOStatement::execute',
168
	);
169
 
170
	/**
171
	 * Creates a DebugPDO instance representing a connection to a database.
172
	 *
173
	 * This method is overridden in order to specify a custom PDOStatement class and to implement logging.
174
	 *
175
	 * @param      string $dsn Connection DSN.
176
	 * @param      string $username (optional) The user name for the DSN string.
177
	 * @param      string $password (optional) The password for the DSN string.
178
	 * @param      array $driver_options (optional) A key=>value array of driver-specific connection options.
179
	 * @throws     PDOException if there is an error during connection initialization.
180
	 */
181
	public function __construct($dsn, $username = null, $password = null, $driver_options = array())
182
	{
183
		$debug = $this->getDebugSnapshot();
184
 
185
		parent::__construct($dsn, $username, $password, $driver_options);
186
 
187
		$this->configureStatementClass($suppress=true);
188
		$this->log('', null, __METHOD__, $debug);
189
	}
190
 
191
	/**
192
	 * Configures the PDOStatement class for this connection.
193
	 *
194
	 * @param      boolean $suppressError Whether to suppress an exception if the statement class cannot be set.
195
	 * @throws     PropelException if the statement class cannot be set (and $suppressError is false).
196
	 */
197
	protected function configureStatementClass($suppressError = false)
198
	{
199
		// extending PDOStatement is not supported with persistent connections
200
		if (!$this->getAttribute(PDO::ATTR_PERSISTENT)) {
201
			$this->setAttribute(PDO::ATTR_STATEMENT_CLASS, array($this->getStatementClass(), array($this)));
202
		} elseif (!$suppressError) {
203
			throw new PropelException('Extending PDOStatement is not supported with persistent connections.');
204
		}
205
	}
206
 
207
	/**
208
	 * Sets the custom classname to use for PDOStatement.
209
	 *
210
	 * It is assumed that the specified classname has been loaded (or can be loaded
211
	 * on-demand with autoload).
212
	 *
213
	 * @param      string $classname Name of the statement class to use.
214
	 */
215
	public function setStatementClass($classname)
216
	{
217
		$this->statementClass = $classname;
218
		$this->configureStatementClass();
219
	}
220
 
221
	/**
222
	 * Gets the custom classname to use for PDOStatement.
223
	 *
224
	 * @return     string
225
	 */
226
	public function getStatementClass()
227
	{
228
		return $this->statementClass;
229
	}
230
 
231
	/**
232
	 * Returns the number of queries this DebugPDO instance has performed on the database connection.
233
	 *
234
	 * When using DebugPDOStatement as the statement class, any queries by DebugPDOStatement instances
235
	 * are counted as well.
236
	 *
237
	 * @return     int
238
	 * @throws     PropelException if persistent connection is used (since unable to override PDOStatement in that case).
239
	 */
240
	public function getQueryCount()
241
	{
242
		// extending PDOStatement is not supported with persistent connections
243
		if ($this->getAttribute(PDO::ATTR_PERSISTENT)) {
244
			throw new PropelException('Extending PDOStatement is not supported with persistent connections. ' .
245
																'Count would be inaccurate, because we cannot count the PDOStatment::execute() calls. ' .
246
																'Either don\'t use persistent connections or don\'t call PropelPDO::getQueryCount()');
247
		}
248
		return $this->queryCount;
249
	}
250
 
251
	/**
252
	 * Increments the number of queries performed by this DebugPDO instance.
253
	 *
254
	 * Returns the original number of queries (ie the value of $this->queryCount before calling this method).
255
	 *
256
	 * @return     int
257
	 */
258
	public function incrementQueryCount()
259
	{
260
		$this->queryCount++;
261
	}
262
 
263
	/**
264
	 * Get the SQL code for the latest query executed by Propel
265
	 *
266
	 * @return string Executable SQL code
267
	 */
268
	public function getLastExecutedQuery()
269
	{
270
		return $this->lastExecutedQuery;
271
	}
272
 
273
	/**
274
	 * Set the SQL code for the latest query executed by Propel
275
	 *
276
	 * @param string $query Executable SQL code
277
	 */
278
	public function setLastExecutedQuery($query)
279
	{
280
		$this->lastExecutedQuery = $query;
281
	}
282
 
283
	/**
284
	 * Prepares a statement for execution and returns a statement object.
285
	 *
286
	 * Overrides PDO::prepare() to add logging and query counting.
287
	 *
288
	 * @param      string $sql This must be a valid SQL statement for the target database server.
289
	 * @param      array One or more key=>value pairs to set attribute values for the PDOStatement object that this method returns.
290
	 * @return     PDOStatement
291
	 */
292
	public function prepare($sql, $driver_options = array())
293
	{
294
		$debug	= $this->getDebugSnapshot();
295
		$return	= parent::prepare($sql, $driver_options);
296
 
297
		$this->log($sql, null, __METHOD__, $debug);
298
 
299
		return $return;
300
	}
301
 
302
	/**
303
	 * Execute an SQL statement and return the number of affected rows.
304
	 *
305
	 * Overridden for query counting and logging.
306
	 *
307
	 * @return     int
308
	 */
309
	public function exec($sql)
310
	{
311
		$debug	= $this->getDebugSnapshot();
312
		$return	= parent::exec($sql);
313
 
314
		$this->log($sql, null, __METHOD__, $debug);
315
		$this->setLastExecutedQuery($sql);
316
		$this->incrementQueryCount();
317
 
318
		return $return;
319
	}
320
 
321
	/**
322
	 * Executes an SQL statement, returning a result set as a PDOStatement object.  Despite its signature here,
323
	 * this method takes a variety of parameters.
324
	 *
325
	 * Overridden for query counting and logging.
326
	 *
327
	 * @see        http://php.net/manual/en/pdo.query.php for a description of the possible parameters.
328
	 * @return     PDOStatement
329
	 */
330
	public function query()
331
	{
332
		$debug	= $this->getDebugSnapshot();
333
		$args	= func_get_args();
334
		if (version_compare(PHP_VERSION, '5.3', '<')) {
335
			$return	= call_user_func_array(array($this, 'parent::query'), $args);
336
		} else {
337
			$return	= call_user_func_array('parent::query', $args);
338
		}
339
 
340
		$sql = $args[0];
341
		$this->log($sql, null, __METHOD__, $debug);
342
		$this->setLastExecutedQuery($sql);
343
		$this->incrementQueryCount();
344
 
345
		return $return;
346
	}
347
 
348
	/**
349
	 * Sets the logging level to use for logging method calls and SQL statements.
350
	 *
351
	 * @param      int $level Value of one of the Propel::LOG_* class constants.
352
	 */
353
	public function setLogLevel($level)
354
	{
355
		$this->logLevel = $level;
356
	}
357
 
358
	/**
359
	 * Sets a logger to use.
360
	 *
361
	 * The logger will be used by this class to log various method calls and their properties.
362
	 *
363
	 * @param      BasicLogger $logger A Logger with an API compatible with BasicLogger (or PEAR Log).
364
	 */
365
	public function setLogger($logger)
366
	{
367
		$this->logger = $logger;
368
	}
369
 
370
	/**
371
	 * Logs the method call or SQL using the Propel::log() method or a registered logger class.
372
	 *
373
	 * @uses       self::getLogPrefix()
374
	 * @see        self::setLogger()
375
	 *
376
	 * @param      string $msg Message to log.
377
	 * @param      int $level (optional) Log level to use; will use self::setLogLevel() specified level by default.
378
	 * @param      string $methodName (optional) Name of the method whose execution is being logged.
379
	 * @param      array $debugSnapshot (optional) Previous return value from self::getDebugSnapshot().
380
	 */
381
	public function log($msg, $level = null, $methodName = null, array $debugSnapshot = null)
382
	{
383
		// If logging has been specifically disabled, this method won't do anything
384
		if (!$this->getLoggingConfig('enabled', true))
385
			return;
386
 
387
		// If the method being logged isn't one of the ones to be logged, bail
388
		if (!in_array($methodName, $this->getLoggingConfig('methods', self::$defaultLogMethods)))
389
			return;
390
 
391
		// If a logging level wasn't provided, use the default one
392
		if ($level === null)
393
			$level = $this->logLevel;
394
 
395
        // Determine if this query is slow enough to warrant logging
396
        if ($this->getLoggingConfig("onlyslow", self::DEFAULT_ONLYSLOW_ENABLED))
397
        {
398
            $now = $this->getDebugSnapshot();
399
            if ($now['microtime'] - $debugSnapshot['microtime'] < $this->getLoggingConfig("details.slow.threshold", self::DEFAULT_SLOW_THRESHOLD)) return;
400
        }
401
 
402
		// If the necessary additional parameters were given, get the debug log prefix for the log line
403
		if ($methodName && $debugSnapshot)
404
			$msg = $this->getLogPrefix($methodName, $debugSnapshot) . $msg;
405
 
406
		// We won't log empty messages
407
		if (!$msg)
408
			return;
409
 
410
		// Delegate the actual logging forward
411
		if ($this->logger)
412
			$this->logger->log($msg, $level);
413
		else
414
			Propel::log($msg, $level);
415
	}
416
 
417
	/**
418
	 * Returns a snapshot of the current values of some functions useful in debugging.
419
	 *
420
	 * @return     array
421
	 */
422
	public function getDebugSnapshot()
423
	{
424
		return array(
425
			'microtime'				=> microtime(true),
426
			'memory_get_usage'		=> memory_get_usage($this->getLoggingConfig('realmemoryusage', false)),
427
			'memory_get_peak_usage'	=> memory_get_peak_usage($this->getLoggingConfig('realmemoryusage', false)),
428
			);
429
	}
430
 
431
	/**
432
	 * Returns a named configuration item from the Propel runtime configuration, from under the
433
	 * 'debugpdo.logging' prefix.  If such a configuration setting hasn't been set, the given default
434
	 * value will be returned.
435
	 *
436
	 * @param      string $key Key for which to return the value.
437
	 * @param      mixed $defaultValue Default value to apply if config item hasn't been set.
438
	 * @return     mixed
439
	 */
440
	protected function getLoggingConfig($key, $defaultValue)
441
	{
442
		return Propel::getConfiguration(PropelConfiguration::TYPE_OBJECT)->getParameter("debugpdo.logging.$key", $defaultValue);
443
	}
444
 
445
	/**
446
	 * Returns a prefix that may be prepended to a log line, containing debug information according
447
	 * to the current configuration.
448
	 *
449
	 * Uses a given $debugSnapshot to calculate how much time has passed since the call to self::getDebugSnapshot(),
450
	 * how much the memory consumption by PHP has changed etc.
451
	 *
452
	 * @see        self::getDebugSnapshot()
453
	 *
454
	 * @param      string $methodName Name of the method whose execution is being logged.
455
	 * @param      array $debugSnapshot A previous return value from self::getDebugSnapshot().
456
	 * @return     string
457
	 */
458
	protected function getLogPrefix($methodName, $debugSnapshot)
459
	{
460
		$prefix		= '';
461
		$now		= $this->getDebugSnapshot();
462
		$logDetails	= array_keys($this->getLoggingConfig('details', array()));
463
		$innerGlue	= $this->getLoggingConfig('innerglue', ': ');
464
		$outerGlue	= $this->getLoggingConfig('outerglue', ' | ');
465
 
466
		// Iterate through each detail that has been configured to be enabled
467
		foreach ($logDetails as $detailName) {
468
 
469
			if (!$this->getLoggingConfig("details.$detailName.enabled", false))
470
				continue;
471
 
472
			switch ($detailName) {
473
 
474
				case 'slow';
475
					$value = $now['microtime'] - $debugSnapshot['microtime'] >= $this->getLoggingConfig("details.$detailName.threshold", self::DEFAULT_SLOW_THRESHOLD) ? 'YES' : ' NO';
476
					break;
477
 
478
				case 'time':
479
					$value = number_format($now['microtime'] - $debugSnapshot['microtime'], $this->getLoggingConfig("details.$detailName.precision", 3)) . ' sec';
480
					$value = str_pad($value, $this->getLoggingConfig("details.$detailName.pad", 10), ' ', STR_PAD_LEFT);
481
					break;
482
 
483
				case 'mem':
484
					$value = self::getReadableBytes($now['memory_get_usage'], $this->getLoggingConfig("details.$detailName.precision", 1));
485
					$value = str_pad($value, $this->getLoggingConfig("details.$detailName.pad", 9), ' ', STR_PAD_LEFT);
486
					break;
487
 
488
				case 'memdelta':
489
					$value = $now['memory_get_usage'] - $debugSnapshot['memory_get_usage'];
490
					$value = ($value > 0 ? '+' : '') . self::getReadableBytes($value, $this->getLoggingConfig("details.$detailName.precision", 1));
491
					$value = str_pad($value, $this->getLoggingConfig("details.$detailName.pad", 10), ' ', STR_PAD_LEFT);
492
					break;
493
 
494
				case 'mempeak':
495
					$value = self::getReadableBytes($now['memory_get_peak_usage'], $this->getLoggingConfig("details.$detailName.precision", 1));
496
					$value = str_pad($value, $this->getLoggingConfig("details.$detailName.pad", 9), ' ', STR_PAD_LEFT);
497
					break;
498
 
499
				case 'querycount':
500
					$value = $this->getQueryCount();
501
					$value = str_pad($value, $this->getLoggingConfig("details.$detailName.pad", 2), ' ', STR_PAD_LEFT);
502
					break;
503
 
504
				case 'method':
505
					$value = $methodName;
506
					$value = str_pad($value, $this->getLoggingConfig("details.$detailName.pad", 28), ' ', STR_PAD_RIGHT);
507
					break;
508
 
509
				default:
510
					$value = 'n/a';
511
					break;
512
 
513
			}
514
 
515
			$prefix .= $detailName . $innerGlue . $value . $outerGlue;
516
 
517
		}
518
 
519
		return $prefix;
520
	}
521
 
522
	/**
523
	 * Returns a human-readable representation of the given byte count.
524
	 *
525
	 * @param      int $bytes Byte count to convert.
526
	 * @param      int $precision How many decimals to include.
527
	 * @return     string
528
	 */
529
	protected function getReadableBytes($bytes, $precision)
530
	{
531
		$suffix	= array('B', 'kB', 'MB', 'GB', 'TB', 'PB', 'EB', 'ZB', 'YB');
532
	    $total	= count($suffix);
533
 
534
	    for ($i = 0; $bytes > 1024 && $i < $total; $i++)
535
	    	$bytes /= 1024;
536
 
537
	    return number_format($bytes, $precision) . ' ' . $suffix[$i];
538
	}
539
 
540
	/**
541
	 * If so configured, makes an entry to the log of the state of this DebugPDO instance just prior to its destruction.
542
	 *
543
	 * @see        self::log()
544
	 */
545
	public function __destruct()
546
	{
547
		$this->log('', null, __METHOD__, $this->getDebugSnapshot());
548
	}
549
 
550
}