PHP: Making sense of the 8 log levels
In reality, you‘ll probably use four
Every time I need to create an app, there are parts that I want to log for different reasons: debugging, statistics, potential warnings or flat-out errors.
Most frameworks and packages follow the PSR-3 standard, which describes how a Logging system works. It’s basically an interface you should rely on when pushing logs to a system. From these, Monolog is the most used as it’s very flexible and easy to understand.
Back to the point, the PSR-3 implementation describes eight log levels. You read that right. In order of “severity”: Emergency, Alert, Critical, Error, Warning, Notice, Info and Debug. That’s a lot, if you ask me.
It’s not a problem to understand for which scenarios you should use each log level, but trying to decide which is sometimes confusing. Is an error also an alert? Is a debug message informational too?
Logs fall on many levels
Making sense of the log levels is not difficult if we make an example with an application.
This application captures the activity of many digital keylocks (IoT) from a third party hub, which later can be seen in a dashboard. Each employee has its own card and password for every keylock. These would send events to the hub, which in turn would push the data into the app through a simple HTTP Request.
8. Debug is development
When I finished development, I mounted a staging version for internal use, where we could see how the application behaved transparently. A lot of debug messages with fake but sensible information was written verbatim, with an old keylock we used for testing.
On production, these messages are not written, since the Log Level is 7, meaning, log everything that’s not a debug message.
7. Informational is statistical
The app logs every sign in as info, with a lot of information except sensible data, like the credentials. This is pure statistical information about the activity on the securer compound, which should be useful to make graphs from about who moved where, when.
6. Notice is relevant
When an user cycles its keycode for a door, we log that event as notice. It’s normal to cycle the keycode after a period of time, as its mandatory, but it’s not normal to see employees changing it before this period.
That doesn’t mean they were forced to do it, but sometimes people forgets their keycode and decide to generate a new one.
5. Warning is undesired
When an user fails to sign in, I push a multiple-fails message at warning level, with the ID of the user. This way we can know if someone tried to access by brute-forcing the code.
Most of the time this is not an error, but a significant event that may help when dealing with unauthorized access.
4. Error is unstable
Some old keylock models pushed garbage from time to time. Worn-out keycard would spit wrong IDs. Signal interference is also a thing. When any of these occurred, the hub would report an “error” to the app, which in turn would write an error message in the log.
The message includes which door was not working fine. A technician would be dispatched later to check the keylock.
3. Critical is stateful
Each minute, plus some random seconds, a “ping” would be sent by the hub to each keylock to check their status. I was pretty much sure it worked with WebSockets over BLE, but be my guest.
These rarely failed to respond, but when they do, they’re practically AWOL as the hub probably ensures multiple times it’s not a false positive. Any non-responding keycode event would be logged as critical.
2. Alert is unsecure
If any keycode sent a “blocked” response to the app, like when somebody tries to force their way in, it would be logged as alert. Security (or law enforcement) would be dispatched immediately to secure the room. Rarely this was set by someone accidentally bumping on the door or knocking, so this mechanism was very reliable. My guess is that the keylock has some well-calibrated smart sensors and a gyroscope.
This was also sent if the app received any weird or not expected request (like a “pong”, for sure from the hub. It’s not that the hub can’t be hacked, but nonetheless.
1. Emergency is unusable
Finally, if the hub itself went down for more than 1 minute, an emergency event would be logged, as someone would have probably cut the power for the hub, which would make a blind spot on door activity.
Putting everything into a table
I made this table to check which log level I should need to put the message I want to log. This has helped me a lot cleaning messages once I apply a filter by severity.
It’s normal to take some liberties and push messages in other log levels to make more sense even if these do not follow any property at all. For example, when the storage is half-full, that’s an critical right away, since the provider takes its sweet time to add more storage to the machine.
Just using four
At the beginning of the article I wrote that I mostly use four log levels. This is true for most simple applications, as some other log levels are covered by default by other systems.
- Debug: For anything that shows the inner workings of the app.
- Error: Something that shouldn’t happen, happened.
- Alert: Anything that risks the state of the app on the short term.
- Emergency: Any part of the application has stopped working.
This gives me a bit of peace of mind since I can know easily what happened, and with which severity. I hope it works for you too.
