Symfony: Error Logging Hack

Symfony is an excellent PHP framework used on Colnect. As any piece of software, however, it has its shortcomings. The good thing is that I can hack it to fit my needs when some things are not to my likings. A recent hack I've done (and should have done a long time ago) is about the error logs. Though the guidebook to Symfony describes logging at length I couldn't figure out how to easily add some useful information to any Exception thrown on my production machine.

The following hack can be has been customized for my needs but you can change it to your preferences. It'll change the output Symfony places in the PHP error log file.

What the Hack Does?

A boring Exception such as:

[04-Mar-2009 17:20:25] Action "coins/collect" does not exist.

Will become:

[04-Mar-2009 17:20:25] CODE[0] MESSAGE[Action "coins/collect" does not exist.]
FILE[.\config_core_compile.yml.php] Line[715]
REQUEST[/it/coins/sdlk] REFERER[]
AGENT[Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.0.6) Gecko/2009011913 Firefox/3.0.6] ADDR[127.0.0.1]

How To?

Find sfException class (should be /symfony/lib/exception/sfException.class.php) and add the following method:

public function getMessageFull() {
$exception = is_null($this->wrappedException) ? $this : $this->wrappedException;

try {
$sReq = isset($_SERVER['REQUEST_URI']) ? $_SERVER['REQUEST_URI'] : '';
$sRef = isset($_SERVER['HTTP_REFERER']) ? $_SERVER['HTTP_REFERER'] : '';
$sUserAgent = isset($_SERVER['HTTP_USER_AGENT']) ? $_SERVER['HTTP_USER_AGENT'] : '';
$sRemoteAddr = isset($_SERVER['REMOTE_ADDR']) ? $_SERVER['REMOTE_ADDR'] : '';

$sErrMessage = "CODE[".$exception->getCode().'] MESSAGE['.$exception->getMessage()."]"
."\n\tFILE[".$exception->getFile()."] Line[".$exception->getLine()."]"
."\n\tREQUEST[$sReq] REFERER[$sRef]"
."\n\tAGENT[$sUserAgent] ADDR[$sRemoteAddr]\n"
;
}
catch (Exception $e)
{
$sErrMessage = $exception->getMessage();
}

return $sErrMessage;
}

Customize this method to your needs. Make sure it doesn't raise any exceptions itself.
Now you need 2 more small changes in both sfException.php and sfError404Exception. Change the line:

error_log($this->getMessage());

to:

error_log($this->getMessageFull());

More Enhancements?

It's your call. You can email yourself an alert, include more system-specific pieces of information or use the code as is. It's obviously not the cleanest solution possible but it works for me and hope it helps you.

Upto 80% Speed Increase on Colnect with Symfony

I have managed to cut up to 80% in loading times for Colnect's pages. This is going to be a technical post that would hopefully help others using Symfony framework on their websites. Please mind that for many sites, caching can and should be enabled. On Colnect, however, a lot of pages (especially the heavy ones) cannot be cached since they need be calculated on every request from the same user. If your site is not very dynamic, using APC (if you have a single server) or memcached (when you have many) is the best thing you can do for performance.

Partials are evil

Maybe not that evil but they take their toll on your loading time. The worst is when using them inside a loop as the price increases linearly. Use helpers whenever possible but make sure you load only the necessary helpers on each call and don't try to re-load helpers when inside a loop.

Re-use function results

Symfony encourages you to use methods and functions repeatedly, for example sfContext::getInstance()->getModuleName();. Obviously, the more calculations, the longer things take so whenever you need to re-use results, save the variable content.

A good PHP structure for re-using results is:

function foo_calculate() {
static $result = null;
if (is_null($result)) {
# perform calculations
$result = calculation results...
}
return $result;
}


Escaping PHP and going back to PHP takes its toll

Using
?>xxx
is more costly than
echo 'xxx';
See code on the next paragraph.


Using many echo calls slows things down

It's better to accumulate output in a variable and call a single echo.
The following code performs simple tests so you can get a feeling of the differences in execution times. Run it a few times (when all other applications are closed) since results alter a bit every time.


public function executeCompareOutput(sfWebRequest $request) {
$times = 100000;
echo 'Looping for '.$times.' times - results in msec';
echo '<-div style="display:none">';
$start = microtime(true);
for ($x = 0; $x++ < $times;) {
echo ' '.$x;
}
echo '<-/div><-br/>'.round(1000 * (microtime(true) - $start));

$start = microtime(true);
echo '<-div style="display:none">';
for ($x = 0; $x++ < $times;) {
?> echo $x;
}
echo '<-br/>'.round(1000 * (microtime(true) - $start));

$start = microtime(true);
echo '<-div style="display:none">';
$sBuf = '';
for ($x = 0; $x++ < $times;) {
$sBuf .= ' '.$x;
}
echo $sBuf;
echo '<-br/>'.round(1000 * (microtime(true) - $start));

$start = microtime(true);
echo '<-div style="display:none">';
$sBuf = '';
for ($x = 0; $x++ < $times;) {
$sBuf .= ' ';
$sBuf .= $x;
}
echo $sBuf;
echo '<-br/>'.round(1000 * (microtime(true) - $start));

$start = microtime(true);
echo '<-div style="display:none">';
$GLOBALS['bufbuf'] = '';
for ($x = 0; $x++ < $times;) {
$GLOBALS['bufbuf'] .= ' '.$x;
}
echo $sBuf;
echo '<-br/>'.round(1000 * (microtime(true) - $start));

die('<-br/>bye');
}


Here is a sample output:

Looping for 10000 times - results in msec
3044
5503
10
15
16
bye


On this run using multiple echo calls + PHP escaping took 55 TIMES MORE than buffering the output in a variable. This clearly proves that the style suggested by Symfony templates, using many PHP echo blocks, is HIGHLY inefficient. If you have a few dozens of it in your templates and your content is cached, this is negligible. If your content is very dynamic, as is the case with Colnect, we're talking about something very worth noting.

Doctrine v1.0 is finally out

Colnect V2 (including stamps and more collectibles) is now almost ready to be shown in alpha and that's why it's such good news that Doctrine v1.0 has been released.

Doctrine is a PHP ORM that is nicely integrated with Symfony. It allows defining your database schema easily with YAML files. The database and PHP classes can then be automatically generated to provide you will all the needed functionality of database interaction.

Although IMO some edges have not yet been met in Doctrine (most importantly the i18n support), I hope it'll be able to work properly on the new Colnect. Developing with an ORM is surely much easier to maintain than using raw SQL. I expect Doctrine to keep growing stronger and more stable in the near future as the ideas behind it are very useful and needed.

Following the Doctrine for Colnect Philately

Colnect Philately is now under rapid development and is planned to have a limited release in September. Colnect is written completely from scratch, using bleeding edge tools which provide really cool features but come with a price. Once such tool is Doctrine.
Doctrine is a PHP ORM that is nicely integrated with Symfony. It allows defining your database schema easily with YAML files. The database and PHP classes can then be automatically generated to provide you will all the needed functionality of database interaction.
Doctrine is not yet a completely mature project and that becomes when using it for some time. However, it's going in the right direction and yesterday's announcement that "Doctrine gets its first employee" is an important step for an open source project.
So yes, using bleeding edge tools is a bet but being an entrepreneur is about believing, isn't it?