Make Yii::log() accept array "messages"

Yii 2.0 General Discussions
1

Hi,

This is a feature request for the logging infrastructure in Yii 2. Perhaps it’s already implemented, but I haven’t seen any examples of it yet.

Currently, in Yii 1, the Yii::log() method only accepts (or rather, only works without errors when you give it) a string as the first argument (the $message parameter). This is fine as long as you only want to log simple string messages, but there are other use cases as well.

Example use case

One such other use case is this: You want to create a custom log route that stores the log messages as structured data in a database, using AR. You want to do for example:




Yii::log(array(

	'user'=>Yii::app()->user->name,

	'previous_state'=>$this->state,

	'message'=>"Power on requested for device {$this->name}.",

), CLogger::LEVEL_INFO, 'audit.power');

This would, using an ActiveLogRoute that saves data using an ActiveRecord model, effectively store the information in that model’s table like: log(id, tstamp, level, category, user, previous_state, message).

In the example above, the log table in question is specifically structured to match the type of logging at hand. There are of course other ways to do the models and tables as well; The common part is that one want to be able to log arrays of data and not just strings.

Usability features of the above use case

The key usability points here are that:

  1. you use the existing log infrastructure, keeps code unified

  2. you use AR models for the various log types you want, makes the code nice and clean

  3. you can for example add validation and filtering to the logging

  4. you can reuse these AR models for other purposes, for example presenting a nice search interface for your logs (CGridView for example)

Tried and proven useful

I already had this and a similar use case, so I have created ActiveLog, ActiveLogRoute and ActiveLogEntry classes to do all this, but it was unfortunate that the Yii::log() did not handle arrays, so I had to do some extra work to fix that.

In summary what I needed to do was supply a custom log() method that wraps array "messages" in a ActiveLogEntry, which provides a __toString() and also its own stack trace generation.

This object (or the untouched string message) is then passed to the regular Yii::log(). The wrapped log message/array survives Yii logging infrastructure because it is now an ActiveLogEntry that can be "read" as a string due to __toString().

Finally the ActiveLogRoute simply saves the stuff using AR in its processLogs() method, supporting scenarios, validation, events and all the nice things we have in AR.

If Yii::log() had not been restricted to strings only, I could have done without one or two of these four classes (the fourth being the AR model). I also made a wrapper Yii class so that one can use Yii::log() instead of ActiveLog::log(), and this wouldn’t have been necessary either :)

Puppy eyes

Ok, this was my attempt at describing a super nice thing to have with a real world use case. I’ve been very happy to be able to log structured data using the basic log infrastructure in Yii and its AR. I’m doing it both to structured/regular tables in a relational database as well as to JSON format.

Is this something we can get for Yii 2.0? :unsure: I’ll be happy to elaborate on the details as needed!

2

This can be done at application layer by writing a new function which converts the input array into a json string.

3

Qiang;

That “works” but it’s not a clean solution. Converting the array message to JSON to make it survive Yii logging infrastructure is kind of a workaround instead of a more flexible design. It adds cruft to the application code. It also (currently) doesn’t look good in the various log routes:




{"user":"rawtaz","previous_state":"teststate","message":"Power on requested

for device TESTDEVICE."}

in

...

If Yii supported what I’m suggesting below we’d see this instead:




array

(

    'user' => 'rawtaz'

    'previous_state' => 'teststate'

    'message' => 'Power on requested for device TESTDEVICE.'

)

in

...

Please read the following before deciding on this:

The entire point of my suggestion is to let us use the logging infrastructure in a more flexible and agnostic way. A (possibly bad) analogy: A cargo truck designed for frozen goods will be happy to transport regular goods too, and does it just as well. Why limit it to frozen goods only? On the same notation, why limit Yii::log() to strings only, when it can do just as well with arrays (and other data types too, read below).

I think the logging entry point (Yii::log()) should not be concerned about what type of data it receives, and it should not modify it either. Yii::log() should only be there as the accommodator you hand your data to, for transport to the final destination (the log route). It should be up to the log route(s) to decide whether the received data is of a valid type (to them) or not (if yes, store it, otherwise throw it away or whatever).

Consider this for a moment:

[list=1]

[*]Yii::log() is currently concatenating a stack trace to the message under some (debug) circumstances. This is making it require a string as the $message parameter.

[*]By moving that small part out of Yii::log() and into CLogger::log(), we easily make Yii::log() agnostic to the data type of $message, since it only passes it along to the logger instance.

[*]In CLogger::log() we can then store the stack trace as a fifth element in the log entry array (the one that it adds to $this->_logs), instead of doing string concatenation. From one perspective this is better separation of “meta data” than adding the trace to the message itself. Either case I think it’s worth it to make Yii logging this much more flexible.

[*]The previous point (#3) also make it so that Yii log transport layer never touches the logged "message". Hence if we want to log object instances of some sort, we can do that too. Seriously, the log routes we build should be the limiting factor on what data we can log, not the transport layer responsible for forwarding the log data to the log routes.

[*]Log routes would naturally have to store/render the stack trace for log entries, if any. This shouldn’t be a biggie though.

[/list]

Here’s what the “new” log entry format would look like:




array(

	[0] => message (mixed)

	[1] => level (string)

	[2] => category (string)

	[3] => timestamp (float, obtained by microtime(true))

	[4] => stack trace (string, if any)

)

I can certainly think of more than one use case for being able to send both arrays and objects to log routes.

Actually, the name of this topic should probably be changed not to be array specific, it should se something like "Make Yii::log() and CLogger message type agnostic". Sorry for the confusion.

4

This would simplify custom log filters. I once gave up on trying to author the filter I needed because the string processing was too complex.

Iiuc, this proposal is like the separation of V and C in MVC, the logger pushes data around and the log route renders it. Good idea.

5

How should a route (including those built-in ones) deal with a message that could be of different types?

6

Assuming I understand your question:

For CFileLogRoute, CWebLogRoute and the other ones that are currently designed for strings:

  • If the message is a string, do what they do now (but with the difference that they concatenate the message with the stack trace, if any, as per my previous list item about separating the stack trace into a fifth element in the log entry array).

  • If the message is an array, wrap it in CVarDumper::dumpAsString() and output that, adding any stack trace (if a custom log route wants to process an array message they can do it any way they want).

  • If another type (I’m thinking some object instance), require/expect that it has a __toString() in it, i.e. treat it like a string. Adding stack trace, if any.

For custom log routes, it’s up to whoever wrote it to handle the log data accordingly. This is what it’s all about :)

If an object instance is handed to Yii::log() it’s naturally up to the programmer to configure the log component such that only relevant log routes will process this log entry.

Qiang, does that answer your question or did I misunderstand it?

7

Ok, I am convinced. Will get this into 2.0. Thanks!

8

That is so nice to hear, thanks a lot! :wub:

Let me know if you encounter any unforeseen issues we haven’t thought about here, I’ll do my best to be of service! :)

9

Oh, this is good news!

In rAWTAZ’s proposal there would be an exception if I delivered an object without a __toString(). You might want to consider using dumpAsString() in this situation.

An exception would often be better in development but if I wrote a fancy filter specifically to debug an uncommon and confusing scenario I’ve only observed in production and haven’t been able to reproduce, I might be grateful for a bit more leniency.