Opinions: What kind of API service logging is useful?
-
Our logging and introspection sucks. Hard.
For instance, our website API container (which contains the code to serve the web interface as well as proxy requests to the rest of the infrastructure)'s log contains only lines like
10.0.1.4 - - [14/May/2021:21:07:03 +0000] "POST /interface/interface.ajax.php?callback=jQuery33108221074744306338_1621026422027 HTTP/1.1" 200 389 "https://local-interface.redacted.com/interface/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36"Sure, it says 200 was the response code. But really, the state of the request is really embedded in the response object, which always looks like
{"result": "success|error", "message": "the real body here"}. It doesn't return anything other than 200 unless the container itself is non-functional, which gets picked up elsewhere. In fact, if the PHP has errors, it usually just doesn't return anything at all. Which breaks all sorts of things.Makes tracking down errors really kinda painful. Other projects are so chatty with their logging that trying to pull the logs from a functioning production server crashes the docker manager node. Really.
So what would you want out of an API server log? By environment (production vs development)?
-
@Benjamin-Hall said in Opinions: What kind of API service logging is useful?:
It doesn't return anything other than 200 unless the container itself is non-functional, which gets picked up elsewhere.
504 OK
-
@Benjamin-Hall said in Opinions: What kind of API service logging is useful?:
So what would you want out of an API server log? By environment (production vs development)?
For production: the client identity, date and time, the endpoint, and the response code. Which technically you should already have there except all the tunneling is obfuscating it (internal IP instead of
X-Forwarded-Forand dashes for the authentication strings,interface.ajax.phpinstead of something that hints what the request was for,200regardless of whether stuff succeeded or failed gracefully or blew up). If you need more information, your operations team should be able to collect enough of the non-logging information to let you try to replicate it in development.For development: I'm ridiculously spoiled by things like Visual Studio Remote Debugger, time-traveling debugging, live watches and inspection, Postman, Xdebug, et cetera. So I haven't really put much thought into logging. Pretty much the only conclusion I came to was (after watching my teammates struggle with trying to find anything in their home grown log system) regardless of what I logged, the how should be structured logs to a dedicated repository like Seq.
-
@Benjamin-Hall said in Opinions: What kind of API service logging is useful?:
{"result": "success|error", "message": "the real body here"}. It doesn't return anything other than 200 unless the container itself is non-functional, which gets picked up elsewhere. In fact, if the PHP has errors, it usually just doesn't return anything at all. Which breaks all sorts of things.Makes tracking down errors really kinda painful. Other projects are so chatty with their logging that trying to pull the logs from a functioning production server crashes the docker manager node. Really.
So what would you want out of an API server log? By environment (production vs development)?
It sounds to me like you know at least one thing you want: when the container breaks, you absolutely want that logged. Verbosely. It shouldn't happen in prod at all, but if it does it is a huge issue and you want to hunt it down.
Apart from that, keep the amount of enabled logging in prod to a (likely non-zero) minimum. It slows things down. You want enough to be able to say, when something goes wrong, "oh, they were doing that". Only unexpected exceptions really should get any real verbosity in prod, but even then they should be logged at most once. I recommend logging at the point where they are ultimately handled, probably at the place where they get converted into a "shit happened, the admin has been notified" lie for the user. (Put whatever helps in when not in prod.)
Many logging frameworks include the ability to ask whether a logging level is enabled. That is a very good thing; it let's you avoid doing expensive work preparing stuff for logging when you don't need it.
-
@Benjamin-Hall said in Opinions: What kind of API service logging is useful?:
Our logging and introspection sucks. Hard.
For instance, our website API container (which contains the code to serve the web interface as well as proxy requests to the rest of the infrastructure)'s log contains only lines like
10.0.1.4 - - [14/May/2021:21:07:03 +0000] "POST /interface/interface.ajax.php?callback=jQuery33108221074744306338_1621026422027 HTTP/1.1" 200 389 "https://local-interface.redacted.com/interface/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36"That looks like a webserver's access logs. Those are good for certain things but I wouldn't consider them to be application logs.
As already stated, the first thing you must have in your application logs is any error / exception that happens.
Beyond that, it's difficult to say, since it depends a lot on what you're doing. What questions do you ask when you're trying to solve something?
-
@boomzilla said in Opinions: What kind of API service logging is useful?:
any error / exception that happens
I'd qualify that to unexpected errors only. Expected ones (such as “I didn't find that row in the DB”) don't need exhaustive logging as they're very well understood. (They might get a brief note, of course.) Detailed logs are for when the code goes wonky.
-
@dkf yeah. Although "I didn't find that" should probably be unexpected. Unless it's "Your search didn't return any results" kind of stuff.
-
@boomzilla said in Opinions: What kind of API service logging is useful?:
Although "I didn't find that" should probably be unexpected.
The issue is that you don't really learn anything from the stack trace there. The app asked the DB if it could get the thing with id blah and the DB said “nope”. You might log that the DB lookup failed, but a stack trace is of no actual use; you know where the DB gets called (or should do!) so the path through the application stack is just going to fill your logs without increasing understanding. By contrast, if there's an NPE then you really want the stack trace because it's showing where you done fucked up.
Also, be careful with trimming frameworks out of stack traces. That can be nice… except when you hit a framework bug (they do happen) and end up with a stack trace that confuses you utterly. BTDT also.
-
@dkf said in Opinions: What kind of API service logging is useful?:
@boomzilla said in Opinions: What kind of API service logging is useful?:
Although "I didn't find that" should probably be unexpected.
The issue is that you don't really learn anything from the stack trace there. The app asked the DB if it could get the thing with id blah and the DB said “nope”. You might log that the DB lookup failed, but a stack trace is of no actual use; you know where the DB gets called (or should do!) so the path through the application stack is just going to fill your logs without increasing understanding. By contrast, if there's an NPE then you really want the stack trace because it's showing where you done fucked up.
Strongly disagree. Stuff is looked up all over the place. If I expected there to be some data but it's gone, I need to know...was it looking stuff up incorrectly? Is my data bad (pointing to problems elsewhere)? Missing DB constraint?
-
@boomzilla said in Opinions: What kind of API service logging is useful?:
Strongly disagree. Stuff is looked up all over the place. If I expected there to be some data but it's gone, I need to know...was it looking stuff up incorrectly? Is my data bad (pointing to problems elsewhere)? Missing DB constraint?
Since you should only log at the point where you catch and handle the exception (not if you rethrow it or wrap it) then you can decide on a case-by-case basis.
-
@dkf my assumption is that these are uncaught exceptions.
-
@boomzilla design your apps better and you won't need that crutch so bad
-
@Gribnit Magic me some actual requirements documentation, and maybe I will.
-
Remember that, no matter the logging level, you don't want sensitive data (like passwords, social security numbers, credit card data etc.etc.) accidentally ending up in your logging from indiscriminately logging all database queries or input form data.
-
@Grunnen You only ever want to move that sort of thing into the database via bound parameters; those you don't have to log (and there''s good reason not to in this case). If you're generating SQL with them in, you've got all sorts of other problems as well as sensitive data ending up in logs. Ideally, no SQL will be generated at all. The world isn't ideal, of course, but it's still a really good goal to aim for.
-
I used to have a stack trace object that I passed in with every function call that, at the end, would print a custom stack trace with the real error down at the bottom. But, then, that was an actual C# application and not a pile of JavaSpaghetti sitting on top of Entity, so I actually had a somewhat unbroken chain and insight into what was actually going on.
-
@Zenith what a concept. Do you know you can manage the stack trace through supported mechanisms?
-
@Gribnit Yes but I didn't want a giant wall of red text that doesn't tell me anything useful. I needed literally the call stack, the error at the bottom of it, and basic date/user info.
-
@Zenith you have total control of the stack trace without rolling your own, in Java the relevant methods are overridable
-
@Gribnit I wrote it in C# 15+ years ago.
-
@Zenith said in Opinions: What kind of API service logging is useful?:
@Gribnit I wrote it in C# 15+ years ago.
Burn it with fire
-
@Gribnit And replace it with what, a framework with undocumented dependencies that doesn't behave how I want it to? How 'bout "no," Scott.
-
@Zenith said in Opinions: What kind of API service logging is useful?:
@Gribnit And replace it with what, a framework with undocumented dependencies that doesn't behave how I want it to? How 'bout "no," Scott.
Burn it with intern tears then
