Bonesnap;11051721 wrote:It should be noted that the way I handle errors is directly influenced by you in my project thread.
I appreciate your fresh thoughts on the matter.
Bonesnap;11051721 wrote:Because of the advice provided I have become accustomed to using exceptions and the (very easy) ability to create custom exceptions allows for a fine-grained approach to error checking and handling. With that in mind I use it quite a bit. Before I refactored my code I was simply just writing the exception's message to the PHP error log. Once I refactored my code I created a log table in my database much like what you are doing. The fields differ a bit but the overall idea is definitely there:
id
exception_type (basically I use get_class() on the exception so I know what type of exception it was)
timestamp (datetime - way better than a Unix timestamp)
exception_trace (just a string dump of the stack trace)
user_message (the message that was basically included when throwing the exception, AKA, $e->getMessage())
line
* file
I've never really bothered to define a whole bunch of exception types. I'm wondering if you find any specific advantages yet in having multiple Exception types? I'm also curious about what your catch blocks may look like in situations where you are trying to distinguish exception types.
I also agree that datetimes are waaaaay more readable than unix timestamps, but would point out that a DateTime only provides time accuracy down to a whole second. I anticipate that I may encounter situations where two distinct process threads are working at the same time and milliseconds may matter. I've therefore chosen to use the output of [man]microtime(TRUE)[man] as my timestamp. I suppose I could order first by a DateTime and then by some autoincrementing primary key instead, but microtime seemed more precise.
error_type (or event_type is what I'm calling it actually) in my case is going to be some string that pertains to the business at hand (accounting, sales, IT) rather than coding considerations (db, api, email). The whole point of these event types is to help categorize/filter/narrow-down the db_log contents for analysis or viewing.
I've also got a user_friendly_id that is generated when I instantiate my db_log object within a script. This user_friendly_id will be common to all log entries written during the lifetime of the db_log object to make it easy to locate all db_log records that pertain to a given page request or script execution. The reason I call it user_friendly_id (which is, admittedly a poor name) is because it can be shown to a user as a readable token without showing any sensitive information. I still wonder a bit if it's safe to use [man]uniqid[/man] to generate this id but it seems OK. E.g.:
$log = new db_log($this->db); // this operation generates a user_friendly_id
$log->write("Here is a log entry message", "some-event-type", SEVERITY_LOW); // creates a db log entry
$log->write("Here is another message", "some-event-type", SEVERITY_MEDIUM); // creates a db log entry which shares user_friendly_id with the last entry
if ($there_is_a_big_problem) {
$log->write("Here is another message", "some-event-type", SEVERITY_HIGH); // also shares user_friendly_id with the last entry
echo "There was a big problem. Please contact tech support. Your issue id is " . $log->user_friendly_id;
}
Bonesnap;11051721 wrote:Not going to lie, I hadn't thought about severity of the error, but I feel like that could easily change based on context and is difficult to quantify. In my eyes I rather see the list of errors and decide for myself what is "critical" and what is "trivial" (you basically addressed this in your second last paragraph).
As I posted, the idea of severity relates to log verbosity. I've seen this concept in many august and respectable software projects. If it's good enough for Apache, it's good enough for me. To me, it provides two immediately obvious benefits:
I can establish some threshold of importance to limit the volume of messages written to my db_log. This may be very important if the db_log proves to be a bottleneck. Up the threshold, reduce the volume of messages being written to my busy db.
Viewing the log, I can limit the volume of information. If I need more detail, I can drill deeper if I must -- at least up to the point where I reach the log threshold.
Bonesnap;11051721 wrote:Philosophically, if the error didn't affect the user and it didn't affect the application, then it really didn't exist, even if it was logged. At that point I would reevaluate what that error is really for and the condition that causes it, since we're now challenging its existence.
My production code right now is writing so many text logs right now. They almost never get examined. When something goes wrong, though, they are critical. And they don't seem to be hurting performance so there doesn't seem to be any harm. Looking into them, however, is a chore. Login via ssh, run some grep commands, inspect raw text, etc. No queries possible, no dashboards for employees easily constructed, etc. The reason for severity again is such that some trivial, never-noticed message may be written to the db_log but when the time comes that we actually need that log entry, we can dig deeper and it will show itself. On the other hand, I'm concerned about the db being bottleneck. On the other hand blah blah blah. Log files....how much logging do you need? Seems adjustability is important.
Bonesnap;11051721 wrote:Heh I just ran into this last night when I was cleaning up my error_log() messages. What I did in this case was simply output a die() with an error message about connecting to the database and I wrote the info to the PHP error log, because to me that's an actual error - that shouldn't be happening, ever, and since the entire application is dependent on the database, it should be right up front and centre that it failed to connect. An email could work, but as you noted, if the database goes down and you have hundreds of people trying to access the application, then you're going to get hundreds of emails, and we all know people will keep hitting refresh, so yeah, your inbox is going to get really full really fast. At least with an error log you can prune it pretty quickly and easily.
I like your idea of using [man]error_log[/man] for these and I'm adopting that approach. I've made a variation of my $log->write method, $log->write_no_exception, which has a try/catch block to catch any exceptions that might get thrown trying to write the db log. If it catches any exceptions trying to write the db log, it just uses error_log instead. I can use it if I feel that db problems are likely--or any time at all really. Sort of depends on whether I want an exception thrown if I can't write the db log.
As for the php error_log, I don't think it needs pruning under most setups I've deal with. log_rotate is configured to automagically rotate the php/apache logs.
EDIT: but is an unexamined error_log useful? Sort of harks back to my first question.