#982 General Logging update: Profiling, Flushing, Category/Control Filter Exclusion, Route::Enabled, TSysLogRoute, unit tests

[belisoful]

• Adds Profiling with TLogger::PROFILE (for BEGIN and END) and TLogger::PROFILE_BEGIN and TLogger::PROFILE_END
• adds FlushCount to flush the log when reaching the max for long running processes.
• Categories can be Excluded in routes by designating '!' or '~' before the category name, eg. "~Prado\Web\UI" will exclude logs with that path.
• MergeLogs to merge child logs
• TLogRoute::enabled
• Log Message Prefix
• TBrowserLogRoute colorizes the delta Times for easier visualization. Adds the TSysLogRoute
• Better PHP Doc
• Logging finally has unit tests for primary classes

[belisoful]

I'd like to move the logging into its own folder for the 4.3 bump. move the TUtfConverter into the Helpers folder too

[belisoful]

The unit test for the TFileLogRoute is recording so it may be some interaction with when things are logged...

[belisoful]

BTW, if you haven't seen the color coding of times in the TBrowserLogRoute, I suggest you check it out.

Lowest numbers are black and light in font weight. Then blue, cyan, green, yellow, orange, and red. The red are bolded. This basic visualization makes it easy to identify slow parts of the code.

[ctrlaltca]

BTW, if you haven't seen the color coding of times in the TBrowserLogRoute, I suggest you check it out.

Lowest numbers are black and light in font weight. Then blue, cyan, green, yellow, orange, and red. The red are bolded. This basic visualization makes it easy to identify slow parts of the code.

Ouch

$meta['maxdelta'] is a float with value 0.0, and the check should not be strict $meta['maxdelta'] == 0

[belisoful]

float vs int! division by zero

[ctrlaltca]

The unit test for the TFileLogRoute is recording so it may be some interaction with when things are logged...

Yep, give me some time to debug, maybe it's a mess caused by my own application's code

[belisoful]

I fixed the copied comment, divide by zero bug, and the TFirebugLogRoute printing the prefix when it shouldn't.

[ctrlaltca]

TLogRouter is acting weird. When I put TFileLogRoute second it gets added but then doesn't show up during processing. When first, it just doesn't get called.

In TLogger.php:415 the call to $this->deleteLogs(); gets executed even if the logs are not flushed because $final=falseand $count < $this->_processInterval Routes that are instanceof IOutputLogRoute doesn't show this behavior because they always force $final = true in TLogroute::collectLogs()

[belisoful]

TLogRoute stores its logs until $final even when TLogger deletes the application log. Flushing the TFileLogRoute will flush all its retained logs when $final is true on the last pass in the register_shutdown_function. This is why I'm thinking it may be this final call that is 1) not happening or 2) getting corrupted.

[belisoful]

TLogger has a list of unflushed logs, and TLogRoute retains flushed logs until final or count is high enough.

[belisoful]

I see what is going on. There are no logs and so the final flush is not being sent.

    public function onFlushLogs(mixed $sender = null, mixed $final = null)
    {
        if ($this->_flushing || !count($this->_logs)) {
            return;
        }

[ctrlaltca]

TLogger has a list of unflushed logs, and TLogRoute retains flushed logs until final or count is high enough.

Yep, but TLogger::onFlushLogs() will return early if !count($this->_logs), even if the route still has logs to flush

[belisoful]

I'm fixing this now....

[belisoful]

OK. The TFileLogRoute wasn't working for me before and now it is. It was not putting a return at the end of each log line so that's added too. TEmailLogRoute should have the trailing return on each log line as well.

formatLogMessage isn't returning with a trailing return any more so the log routes that use/need it should have it manually put in place. this also stops the trailing return where its not wanted like in the TDbLogRoute.

[belisoful]

The TBrowserLogRoute was working for me without the float 0.0 check (but as an int). it should work for you now too.

The Category and Control filter function has some awesome exclusion code. You can include a specific namespace and then exclude another. by adding '!' or '~' as a prefix to the category/control it will be excluded rather than included. Interestingly, if nothing is explicitly included all are included so the exclusion can be used even when nothing has been explicitly included.

[belisoful]

All this because I needed a "mergeLog" function for children logs.