Debug: log4PHP

De Wikijoan
Dreceres ràpides: navegació, cerca

Contingut

Teoria bàsica

Log4php is a logging package for php. log4php és un projecte de la Apache Software Foundation, i és un port a PHP del log4j (per a Java). VTiger uses this logging package,so we need to understand it.

Està explicat a la wiki de vTiger: http://wiki.vtiger.com/index.php/Log4php

Log Levels: here is the complete list, starting with the lowest loglevel, ending with the highest:

Ús de log4php

VTiger's index.php code opens loggers like this:

$log =& LoggerManager::getLogger('index');
$seclog =& LoggerManager::getLogger('SECURITY');

This opens a log for the index.php file itself called "index", and another for security logging called "SECURITY".

To log a line:

$log->debug("This is a DEBUG level message for the "index" log.']); 

In this case, $log->debug() logs a DEBUG level message to the logger referenced by $log. The functions fatal(), error(), warn(), and info() log FATAL, ERROR, WARN, and INFO' level messages.

Configuració

The log configuration file specifies details for each named logger. If there is no entry for a logger by that name, no messages for that logger are logged.

The configuration file is the least documented part of log4php. For VTiger the file is log4php.properties.

Here's an example from our configuration file that we added to get logs from VTiger's main index.php:

log4php.logger.index=DEBUG,A8
log4php.appender.A8=LoggerAppenderRollingFile
log4php.appender.A8.MaxFileSize=3MB
log4php.appender.A8.MaxBackupIndex=10
log4php.appender.A8.layout=LoggerLayoutTTCC
log4php.appender.A8.layout.ContextPrinting="true"
log4php.appender.A8.layout.DateFormat="%c"
log4php.appender.A8.File=logs/index.log 

The name of the log is the identifier following log4php.logger.. In this case the logger is named index. In VTiger you open the index log with:

$log =& LoggerManager::getLogger('index');

On the same line as the log name is the logging level. In this case it's DEBUG. That means that messages at level DEBUG and above are logged. The levels from highest to lowest are FATAL, ERROR, WARN, INFO and DEBUG. When the log entry specifies level DEBUG, messages at all levels will be logged.

Here's an entry for security logging that ships with VTiger:

log4php.logger.SECURITY=FATAL,A2
log4php.appender.A2=LoggerAppenderRollingFile
log4php.appender.A2.MaxFileSize=3MB
log4php.appender.A2.MaxBackupIndex=10
log4php.appender.A2.layout=LoggerLayoutTTCC
log4php.appender.A2.layout.ContextPrinting="true"
log4php.appender.A2.layout.DateFormat="%c"
log4php.appender.A2.File=logs/security.log

Every line in a log configuration entry includes a unique ID for that entry. This ID tells log4php which lines go together. The index log entry ID is A8. The security entry ID is A2.

The name of the security log is SECURITY. In VTiger you open the SECURITY logger like this:

$seclog =& LoggerManager::getLogger('SECURITY');

The File= line of each entry specifies the log filename. For index.php it's logs/index.log. For the security log it's logs/security.log.

The log files are intentionally created write-only. The code comment is Denying read option for log file. Added for Vulnerability fix. You can use a script to copy the logs to somewhere safe and change the permissions of the copies.

How to turn on the DEBUG feature for troubleshooting

Edit log4php.properties file in vtiger folder and change

log4php.rootLogger=FATAL,A1

to

log4php.rootLogger=DEBUG,A1 


La idea del rootLogger és que recull els log de tots els logger:

log4php.rootLogger=DEBUG,A1
log4php.appender.A1=LoggerAppenderRollingFile
log4php.appender.A1.MaxFileSize=3MB
log4php.appender.A1.MaxBackupIndex=10
log4php.appender.A1.layout=LoggerLayoutTTCC
log4php.appender.A1.layout.ContextPrinting="true"
log4php.appender.A1.layout.DateFormat="%c"
log4php.appender.A1.File=logs/projecte.log

Implementació mínima en un projecte

El primer que faig és construir-me un projecte petit a partir del vtiger. És important conservar els permisos dels fitxers. El millor és que el propietari sigui www-data. He de copiar la carpeta els fitxers de vtiger/ a projecte/ conservant els atributs mitjançant l'opció --preserve.

 $ mkdir /home/joan/projecte
 $ cd vtiger
 $ sudo cp -R --preserve log4php ../projecte
 $ sudo cp -R --preserve logs ../projecte
 $ sudo cp --preserve include/logging.php ../projecte/include
 $ sudo cp --preserve log4php.properties ../projecte

o bé crear manualment els fitxers i fer que el propietari sigui www-data

i és que si ens fixem bé, el propietari dels fitxers del projecte és www-data. Mirant vtiger els atributs de index.php són:

-rw-r--r-- 1 www-data root 23021 2009-03-18 10:21 index.php
$ sudo chown www-data:root index.php
o bé, per canviar una carpeta
$ sudo chown -R www-data:root logs

Per buidar els fitxers dins de /logs, podem utilitzar la comanda

$ sudo cp /dev/null fitxer_a_esborrar

fitxer index.php:

<?php
require_once('include/logging.php');
global $seclog;

$log =& LoggerManager::getLogger('INDEX');
$seclog =& LoggerManager::getLogger('SECURITY');

$log->debug("****Starting for new session");
$log->info("estem a index.php");
$seclog->debug('operació permesa');
echo "prova logs";
?>

Com veig, tinc dos loggers: index i SECURITY, i vull registrar els log al fitxer index.log (per al logger index), security.log (per al logger SECURITY) i projecte.log (per als dos loggers). Per tal que això sigui possible, el fitxer log4php.properties queda de la següent manera:

log4php.rootLogger=DEBUG,A1
log4php.appender.A1=LoggerAppenderRollingFile
log4php.appender.A1.MaxFileSize=3MB
log4php.appender.A1.MaxBackupIndex=10
log4php.appender.A1.layout=LoggerLayoutTTCC
log4php.appender.A1.layout.ContextPrinting="true"
log4php.appender.A1.layout.DateFormat="%c"
log4php.appender.A1.File=logs/projecte.log

log4php.logger.INDEX=DEBUG,A4
log4php.appender.A4=LoggerAppenderRollingFile
log4php.appender.A4.MaxFileSize=3MB
log4php.appender.A4.MaxBackupIndex=10
log4php.appender.A4.layout=LoggerLayoutTTCC
log4php.appender.A4.layout.ContextPrinting="true"
log4php.appender.A4.layout.DateFormat="%c"
log4php.appender.A4.File=logs/index.log

log4php.logger.SECURITY=DEBUG,A2
log4php.appender.A2=LoggerAppenderRollingFile
log4php.appender.A2.MaxFileSize=3MB
log4php.appender.A2.MaxBackupIndex=10
log4php.appender.A2.layout=LoggerLayoutTTCC
log4php.appender.A2.layout.ContextPrinting="true"
log4php.appender.A2.layout.DateFormat="%c"
log4php.appender.A2.File=logs/security.log

La lectura del fitxer de configuració és fa en el fitxer include/logging.php:

<?php
define('LOG4PHP_DIR', 'log4php');
define('LOG4PHP_DEFAULT_INIT_OVERRIDE', true);

require_once(LOG4PHP_DIR.'/LoggerManager.php');
require_once(LOG4PHP_DIR.'/LoggerPropertyConfigurator.php');

$config = new LoggerPropertyConfigurator();
$config->configure('log4php.properties');
?>

Aquí et pots descarregar el codi mínim per fer funcionar un projecte PHP que implementa log4php per a debugar i informar d'errors: Fitxer:Projecte log4php.zip

Per veure la última línia d'un fitxer de log:

$ tail -f fitxer.log | grep 'XXX'
$  sudo tail -f index.log | grep 'DEBUG'

on XXX és la cadena a buscar

Guardar objectes en una variable de sessió

Per tal de no haver de crear la variable $log cada vegada, que representa una referència a l'objecte LoggerManager, hem de ser capaços d'emmagatzemar aquest objecte en una variable de sessió. Això és útil quna utilitzem tècniques com AJAX o similar.

L'exemple mínim seria:

us_login.php

<?php
require_once('include/logging.php');
session_start();
if (strpos ($_SERVER["REQUEST_URI"], "us_login.php") == 0 & !isset($_SESSION['login'])) {
//logging
$log =& LoggerManager::getLogger('INDEX');
$log->debug("****Starting for new session");
$_SESSION['log']=serialize($log);
header("Location: us_login.php");
}
?>
...

us_login2.php (on es comprova si les dades de login/password són correctes)

<?php
header ("Content-Type: text/html; charset=iso-8859-1");
require_once('include/logging.php');
session_start();
$log=unserialize($_SESSION['log']);

$vlogin=trim($_POST['vlogin']);
$vpwd=trim($_POST['vpwd']);
$key = '123456789012345678901234567890123456789012345678901234567890';
$vpwd = mcrypt_cbc(MCRYPT_RIJNDAEL_128, substr($key,0,32), $vpwd, MCRYPT_ENCRYPT,substr($key,32,16));
$vpwd=bin2hex($vpwd);

include 'config_db.php';
include 'open_db.php';

$sql = "SELECT * FROM LOGIN WHERE login='" . $vlogin . "'";
$log->debug($sql);
$result = mysql_query($sql);
...

d'aquesta manera es pot debugar si la sentència SQL que executem està ben formada. Fixem-nos que fent-ho d'aquesta manera la sentència

$log =& LoggerManager::getLogger('INDEX');

que és la que inicialitza l'objecte, només s'ha de fer una vegada.

serialize serveix per generar una representació de l'objecte apta per a ser emmagatzemada en una variable de sessió. Al contrari, unserialize fa el contrari: a partir de la cadena emmagatzemada en la variable de sessió, genera la referència de l'objecte al qual volem fer referència.



creat per Joan Quintana Compte, març 2009

Eines de l'usuari
Espais de noms
Variants
Accions
Navegació
IES Jaume Balmes
Màquines recreatives
CNC
Informàtica musical
joanillo.org Planet
Eines