Update of "log"
Many hyperlinks are disabled.
Use anonymous login
to enable hyperlinks.
Artifact ID: | 8da678fa1cbd424d2473b0774bdce9a6676a9272 |
---|---|
Page Name: | log |
Date: | 2015-01-06 13:40:24 |
Original User: | mario |
Mimetype: | text/x-markdown |
Parent: | e5d95d497fd7e0ad9b0f6675fcfb8afc90a549b2 (diff) |
Next | 3a890c1e485e4c70f11167b8872a9f2a29a1a184 |
Structured and hierarchical logging with :token-parametric API
- State: experimental
- Category: logging
- Features: journaling, structured, hierarchical
- Backend: SQLite,
JSON,fluentd - Signature: hybrid, parametric
logStruck ł
implements a logging API and SQLite/JSON storage backend.
- It's purpose is storing structured log data, and it tries to retain log event hierarchies.
- Implements a hybrid and terse function interface.
- And accepts plain string messages, Ruby-style
:token
categorizers and placeholders, and expects array structures. - Implicitly captures and maps PHP errors, unhandled exceptions, and most importantly
assert()
ions.
Unlike other PHP logging frameworks it's not a primarily text/line-oriented message store.
Quick example
Basic invocations are along the lines of:
ł(':warn', ':wikiauth', "User doesn't have permission", $pageObj, ':vars', $_SESSION);
All the fun is in the :token
literals, and passing arrays or objects.
Database scheme, primary fields
All columns in the database scheme are primary fields. Any extra data/values go into the context
array.
<style> table.dbstruct { width: 85%; margin-left: 5%; } table.dbstruct tr:nth-child(2n) { background: #efefef; } </style>
i | PRIM | Where i is the primary index, g the event group, and p the parent reference. |
g | INT | |
p | INT | |
timestamp | REAL | Timestamp with microseconds. |
timestr | TEXT | ISO DateTime string. In GMT/UTC of course. |
host | TEXT | Hostname. |
pri | INT | Priority number (0…7). |
prio | TEXT | Priority string (emerg…info) |
source | TEXT | log|sys|lang|excpt|assert |
errno | INT | 0…32767 |
app | TEXT | AppName.php |
section | TEXT | Application structure / module / part / section. |
file | TEXT | path/file.php |
line | INT | 125 |
version | TEXT | Meta data from source code. |
message | TEXT | Primary log event message string. |
doc | TEXT | Extra documentation / long message / href. |
backtrace | JSON | Array of :backtrace |
code | TEXT | Extracted code context (3 lines). |
vars | JSON | Main $vars[] array. |
context | JSON | Additional / user-defined fields. |
Flexible parametric API
The chief invocation method is ł(). On the outset it's a procedural function, thus available globally. Behind the scenes it keeps a primary logger group. Alternatively it can be invoked via ł::option_tokens().
For plain old log messages it's as simple to use as:
ł("A thing happened.");
Usually you also want to convey a priority however:
ł("Warnful warning", ':warn');
The :token attributes are the most important concept in logStruck. They simulate Ruby-style symbols. In PHP they need to be enquoted as strings however.
Besides priority levels, an important use is classifying an application section. Anything that isn't a reserved keyword :token will simply be assumed to refer an application module:
ł(':auth', "Authorization error", ':notice');
Make up memorable designators to categorize your log messages to your application structure.
An obvious benefit of the :token syntax is that it allows freely ordered logging parameter lists.
These are all equivalent:
ł(':warn', ':db', "Database error");
ł(':db', ':warn', "Database error");
ł(':warn', "Database error", ':db');
You'd probably want to settle on one of these. But it occasionally helps readability to be flexible, in particular when passing functional :tokens or arrays/lists.
Array data
As mentioned, this logger API isn't meant for just string data. You often want to convey context data, and additional attributes. It's often as simple as just attaching an array to the parameter list:
ł(':debug', "Front controller state", $RequestVars);
Now those would end up in the context
database field. To retain them in the vars
column, you have two options:
ł(':debug', "Front controller state", ['vars' => $RequestVars]);
Or the more fancy :vars array designator:
ł(':debug', "Front controller state", ':vars', ⃕$RequestVars);
You might also use this for other fields like :message
or :code
or :doc
, as long as the following parameter is an array.
Data mapping with "field: value"
Plain strings usually end up in the message
field. But the structured logging database has more fields, each with specific purposes. You can easily populate them with the key:value syntax.
ł("File reading error", "errno: EACCESS");
Here errno
is also an integer field, which will be converted afterwards.
A more interesting field to take care of is the doc
column.
ł("Cache directory locked", "doc: ?wiki=SetCachePerm");
Nowadays logs are often consumed by machines rather than humans. For some projects you may wish to augment the often coarse and technical messsage summary with a human-readable description for non-coders. (This is usually an afterthought, if at all implemented or manageable in log processors/viewers).
While you could use the doc:
field for a long prosaic documentation, this would of course stuff the database too much. Instead prefer hyperlinks, or references. A "?tktid=12345"
or "See setup.txt on chmod cache"
are helpful minimums too.
All of primary fields can alternatively and also be set using the key:value scheme:
ł('section: auth', "Auth warning");
ł('source: sys', "Exec failure", "errno: $retval", [$cmd]);
ł("message: Log message");
ł("Regex failed", "code: $rx", ':error', ':iniparser');
And fields that aren't primary log event columns/fields, will end up in the context
database array.
ł("Special needs logging", "var1: $var1", "method: $callback");
This is basically equivalent to using a ["key"=>"value", ...]
list. Again, prefer what's more readable in whatever context.
Injectors
Now if there wasn't enough flexibility already, :tokens can also refer to data source functions.
You can augment log events with a :backtrace most of the time:
ł(':warn', "How did we get here?", ':backtrace');
The placeholder token will be substituted by an array, before being pushed to the log store.
Likewise you can interpolate some common vars:
ł(':debug', "Front Controller startup", ':server');
Or extract pretty much all available meta data:
ł(':debug', "Debug by logging", ':backtrace', ':file', ':code', ':version');
The built-in error / exception / assert handlers do this automatically for example, to different degrees.
Hybrid ł::option_tokens()
The :token scheme is pretty neat, but certainly not to everyones liking, and sometimes less readable than plain boring method calls. Therefore the ł
function and ł
class go hand in hand. Instead of listing tokens as arguments, you can just compact them into a virutal method name:
ł::debug_auth("Authorization failed", $UserObject);
You can even freely mix in injector callbacks and one array designator there:
ł::warn_db_backtrace_file_vars("DB error", $stmt);
Again, you're the programmer. Make sound choices on a case-by-case basis. Don't be clingy with same-old same-old.
All the :tokens!
You're free to choose any :section
name for grouping log events. Well, as long as they're not matching one of the reserved token keywords:
Priority levels | ||
---|---|---|
:debug | 7 | Low-level debug events. |
:info | 6 | Process flow infos etc. |
:notice, :note | 5 | Lowest priority language notices. |
:warning, :warn | 4 | Warnings. |
:error, :err | 3 | PHP or system error. |
:critical, :crit | 2 | This can't be good. |
:alert, :alrt | 1 | Turn on the bat light. |
:emergency, :emerg | 0 | Someone call the president. |
Source / generator | ||
:log | Application origin, normal/manual log calls. | |
:sys | System-level events and errno codes. | |
:lang | Language errors, warnings, notices, etc. | |
:exception | Langauge/runtime exceptions. | |
:assert | Assert() warnings. | |
Field names | ||
Any database column / primary field name can be represented as :token . It's pretty much only useful to use :vars however to map the following array parameter. | ||
Injector calls | ||
:backtrace | Populates backtrace. | |
:server | Inserts $_SERVER array into context . | |
:file | Uncovers file and line from backtrace. | |
:version | Reads out meta data (file/scm version, and section) from script comments. | |
:code | Inserts 3 lines of code context. | |
:p | Tries to deduce log event hierarchy from prior calls, sections, and backtraces. (Not yet implemented.) |
Notes / Rationale
- So, this is either genius, or completely bonkers.
- The function name ł isn't completely settled on. (Maybe a bit too much novelty strive.)
- Extensibility of the database scheme is not planned for. (But easily done.)