One note about the backtrace stack. You'll need to detect which trace in the stack to use. Because if someone calls the "priority magic function" ex: $log->info('test'); it will add another trace in the stack from the logger. I've worked around it by detecting the class name, ex:

(A) In this patch, backtraces are made at the instant that the log message is generated, but suppose they're all filtered out later? That could be a big way to lose performance in a high-log environment, with some time-consuming operations (debug_backtrace()) that you can't bypass it with a filter.

(B) On the other side, what if you want to make a filter which filters based on the stack trace or a file whitelist/blacklist?

I think (A) is more likely, myself.

Posted by Ryan Panning (panman) on 2008-08-21T05:56:06.000+0000

I would agree that (A) is more likely and the trace should be more informational than anything. What if the filter is applied at time of event creation? I know it could be changed during runtime but that would be an option.

Posted by Darien Hager (hagerd) on 2008-08-26T02:32:49.000+0000

I'm afraid I don't have access to the code anymore, but I did successfully test a version where the backtracing was done immediately after logger-level filters were applied. (Before writer-level filtering.)

Posted by Benjamin Eberlei (beberlei) on 2008-11-16T04:00:26.000+0000

The idea of using the backtrace is genious i have to say.

What i personally think of this patch, how much performance impact does debug_backtrace() have? its a debug function and many people use the logger on production systems, so its an important question how performance is impacted by say 100-1000 debug_backtrace calls.

So i wrote a little performance checking script, looping 100000 times and doing syslog in the one case and syslog + debug_backtrace in the other case. there was no huge impact in performance, so i guess this should be added in the future.

Posted by Mark Maynereid (mim) on 2008-11-16T11:00:18.000+0000

Performance is surely a potential concern here.

Perhaps the best answer is to have this additional information functionality enabled/disabled by a flag on construction? That way in development one could typically have it on and in live mode off, but could override either as required. And it would be off by default.

Posted by Wil Sinclair (wil) on 2009-01-21T14:06:50.000+0000

This is a great feature that I think many would find useful. We (the ZF team at Zend) also have concerns about performance, but we can also mention features like this that may affect performance in the performance guide.
The one change we suggest is moving this functionality over to Zend_Debug, where not only people can use it for Zend_Log and any other component/applicaiton code, but it also fills out our relatively weak Zend_Debug component with functionality that would be useful in any PHP 5 application.

Posted by Wil Sinclair (wil) on 2009-01-26T09:38:38.000+0000

I'm postponing this since we don't have the resources to implement it in the next few weeks. Any community member can volunteer to implement this (if the code above is used, the author must sign a CLA) and provide appropriate unit tests. If a community member commits to implementing this, I will re-assign the issue to him/her.

Posted by Mark Maynereid (mim) on 2009-01-26T21:28:05.000+0000

I see Benjamin above has done some speed testing suggesting there is no huge impact (apols I missed the post before). That's encouraging :)

I am hopefully still on record as having signed the CLA if anyone wants to push this patch forward. Am still a novice at SVN and unit testing and a community contribution virgin. If I can get time to get up to speed more safely I'll return to this and have a crack at Will's invitation, but anyone more capable is welcome to advance it in the meantime as far as I'm concerned.

I note the mention of backtrace args above. I deliberately thought to exclude them from the patch as it struck me as mission creep and personally that kind of (core dump like stuff) seems more to do with Zend_Debug to me. In fact I wonder if Zend_Debug ought to become a singleton issuing unique IDs in managing PHP var dumps (like 'core dumps' to disk). Perhaps Zend_Log and Zend_Debug could plug into each other in some way but keep their roles nicely separated? eg. log message "Critical error blah bla in file:class:function:line blah blah, var core dump ID: (MD5 hash of file:class:function)". I like that because it seems to me it could facilitate automated bug logging/recurrance counts with vardumps dumped tidily to disk, a third party bugs DB entry made/updated and a lovely message to the user "Sorry but an unrecoverable error has occurred. This error is caused by a (new|known) bug and is logged for attention of the The Support Team. Please accept our apologies for the inconvenience rhubarb rhubarb.."

Well returning to the patch, as a stopgap and if anyone finds it useful, here's my own sub-classing version: