3

In my team we are currently building an API gateway, where the client can authenticate themselves with an API key. Naturally the authentication may also fail, which produces a message in the log.

Should this be logged on the 'error' or on 'info'-level?

I have a couple of arguments for both, but am unsure if there is a something I'm missing or a clear convention. Google/DuckDuckGo did not yield any meaningful results.

Arguments for the error-level:

  • The gateway is a centralized place to catch these occurrence

Arguments for the info-level:

  • It is a regular occurrence that doesn't indicate and failure on the gateway part
  • It seems more like a problem for the client than the gateway
5
  • 14
    warning? ..... Oct 7, 2022 at 8:16
  • 1
    @RobertHarvey I was so deep in my own question that I completely forgot that exists too!
    – Puck
    Oct 7, 2022 at 9:30
  • Is something implied by the "info", etc. terms? Java? Log4j? What about "Trace", "Debug", and "Fatal"? Oct 7, 2022 at 17:52
  • As an aside, not an attempt to answer the question, do you also have fatal?
    – Spencer
    Oct 7, 2022 at 19:09
  • @Spencer I use Slf4j, so "Trace", "Debug" and "Fatal" are available. I don't consider them valid options for this usecase though.
    – Puck
    Oct 9, 2022 at 16:42

2 Answers 2

15

This sounds tricky­­--and potentially like a subjective question--but I'd say using info should be enough, if this is really something outside your control (you as in the person/entity operating the process).

For example, if the authentication would fail, because a third party server can't be reached or there's some configuration error, that should be a warning or error, not just info. If it's the user failing to use the correct password, that's not an error in the system.

However, I think the more important approach here would be separately tracking/logging these failed authentication attempts and look for potential bruteforce attacks, like producing at least a warning if someone tries the wrong API key 5 times within a minute or so (in addition to locking them out for a given period of time, obviously).

Personally, I'm not a fan of having stuff outside your control that doesn't directly impact the product overall logged as error. That's just misleading and IMO rather annoying (and worst case it might even "shadow" actual issues).

Take Windows' Event Viewer/logging as an example: There's a whole range of events logged as error, even though they actually aren't critical, maybe temporary, or even something completely expected and outside the user's control. But if you check the overview, you see there's been 1 entry marked as error within the last 24 hours and you'd always have to double-check whether it's harmless or not. If you don't you might miss an actual legitimate error, and that's way more harmful to the system overall IMO.

6
  • 1
    I like the idea of not logging anything outside my control as an error. I think I will log wrong API-key, empty API-Key, etc. with the info-level. Anything that is the responsibility of the gateway (like the connection to any auth-providers) as an error. Thanks for your answer :)
    – Puck
    Oct 7, 2022 at 9:35
  • 1
    +1 for separating wrong key attempts to a separate log. Or, if it's structured logging (as it should be in 2022), tag it so it can be easily filtered.
    – jaskij
    Oct 7, 2022 at 9:40
  • 2
    Good answer. A good thing to consider here is whether you want to take action on something. That is, if you log things that aren't really issues as error then you can't really do something like fire alerts on error. The key to effective logging is to focus on how the logs will be used and then structure choose your logging approach to support that. For example, if you have retries around retrieving something from a server, you probably don't want to log an error until the retries are exhausted.
    – JimmyJames
    Oct 7, 2022 at 16:30
  • 1
    Does fatal exist in this scheme?
    – Spencer
    Oct 7, 2022 at 19:08
  • 1
    @UncleCarl It was more of an aside. Anyway, fatal is more then just a higher severity level -- it means "STOP NOW, don't exit gracefully"
    – Spencer
    Oct 7, 2022 at 22:13
8

Efficient log is important, so I'll go on a bit of a tangent first.

The key insight is that logging within a component is for the benefit of the operators of said components:

  • Diagnosing issues with the component.
  • Taking actions to solve issues with the component.

Log level rule of thumb

Which log level to use:

  • Fatal: The component is stopping due to the error.
  • Critical: The component is crippled by the error, it will continue running in "best effort" mode.
  • Error: The component cannot process the current unit of work further due to the error.
  • Warning: The component's processing of the current unit of work is crippled by the error, it will continue processing in "best effort" mode.
  • Notice: High-level messages about the component, for example to track its status, establishment (and termination) of long-term connections, etc...
  • Information: Relatively fine-grained messages about the component. It should be possible to disable them without impacting the ability to "get a read" on the component, and their only use should be to help diagnosing issues in production.
  • Debug: Low-level fine-grained messages used during testing to follow the processing of the component.

Depending on the framework you use, you may not have access to all these levels (and thus some coalescing will be necessary), or they may have different names.

Some examples to help along:

  • Fatal: the database is down, hence the primary function is unachievable.
  • Critical: the avatars' database is down, hence the experience is degraded but the primary function is still available.
  • Error: attempting to save the user's data in the database failed, even though it's working for other users. Strange.
  • Warning: attempting to retrieve the user's avatar failed, even though it's working for other users. Strange.

Warning/Error implies Action

Any log of a warning, an error, or above, should lead to an action:

  • Maybe an operator needs to check the status of the network, or of another component, ...
  • Maybe a developer needs to diagnose the failure, and fix a bug.
  • ...

Warning/Error implies Actionable

And of course, this means that the logs need to be actionable.

In general, this means including both solid phrasing and relevant pieces of data. As a rule of thumb, a log message without any dynamic data is incomplete.

For example, you don't log "database is down", that's not quite helpful:

  • What type of database were you trying to connect to? MySQL? MariaDB? PostgresSQL? Redis? If you don't tell, one will have to guess, and based on the technology the configuration may be stored in different places.
  • Which database were you trying to connect to? If you don't tell, one will have to guess from the configuration, and maybe they'll misinterpret it.
  • What part of the application needs to connect to that database? If you don't tell, it's not clear whether that's the main database, or the cute avatars' database, and that changes the impact tremendously.

Instead, a better message would be:

Primary MYSQL database ({name}) unreachable at {ip}:{port}.

And ideally, the log should also contain similar NOTICE level entries for when the connection was established/terminated, so that operators get an idea of:

  • Since when it's a problem: helps relating the problem to any infrastructure change that happened around the same time.
  • Whether before the problem a different name/ip/port was used: helps checking whether the configuration changed, somehow.

Now, let's review your usecase against all this:

  1. Does this indicate a problem with your component, or not? It does not seem so.
  2. Is there an action you should take to solve the problem? It does not seem so.

As such, I would argue it's not your problem to solve, however you may still be called to assist whoever is trying to connect to solve it. According to these guidelines and this observation, your situation thus calls for Notice (if infrequent/persistent connections) or Information (if frequent/ephemeral connections).

And to help yourself, be mindful to log the relevant details: IP, keys1, etc... and a clear reason for the rejection.

1 Careful with potential secrets, you may want to "XXX" part of them as is done for credit cards so the logs cannot be used to exfiltrate them.

1
  • I tend to think of emissibility/debug levels and notification as orthogonal to the big four prognoses.
    – Spencer
    Oct 7, 2022 at 19:13

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.