add login failure events to django.security logger

[Preston Holmes]

#18616 added a signal for failed login attempts - a primary use-case for this was monitoring.

With #19866 we have the introduction of a django.security logger, and it would make more sense to log these events there.

I'd be +0 on also deprecating the signal, they are brand new, and probably don't have much traction. There may be non-monitoring uses of said signal though that I'm not thinking of.

[boylea]

Changes user login failure from signalling event to logging the failure

[boylea]

I think the attached patch should work... this is the first time I have worked with the logger (and also my first OS patch!), so let me know if it works. Any feedback on how to do this better appreciated.

[Preston Holmes]

Thanks for the patch!

This patch overall looks good, and needs only a few minor improvements.

deprecation:

We have a procedure we follow anytime we remove a feature, it is documented in a limited way here under "minor releases"

​https://docs.djangoproject.com/en/dev/internals/release-process/

We don't have any real contributor documentation about how to actually write the deprecation - but searching for the "DeprecationWarning" in the code will lead you to some examples of the different levels.

As to whether we should deprecate the signal - that can be a harder call. My instinct is to remove it, as I was never really happy with the cleaning of potentially sensitive info we do given that any code can subscribe to a signal, and do potentially dumb things that might expose something by accident:

​https://github.com/django/django/commit/7cc4068c4470876c526830778cbdac2fdfd6dc26#L0R38

The reasons in favor of keeping the signal are that there could be times you want to take some action, not just monitor (can't think of any ones that are a good idea though) and the signal captures the cleaned credentials providing more info (and we probably don't want to wholesale log those either).

The compromise is to do keep both (signal and log), but strongly suggest using the logging unless you have some strong need to take action based on the credentials.

I know you are just starting out, but what are your thoughts?

If we deprecate the logging signal, the warning would have to come not when the signal is issued, but when something connects to the signal - not sure how messy that gets to do - off the top of my head probably a custom signal subclass that wraps the 'connect' method.

logging levels:

logging levels across different python projects are an ambiguous mess! My esteemed colleague Mr. Gaynor has argued that there are only two levels - oops and OH NO.

In Django we sort of do this in that we have ERROR level set up to email admins, and is more of OH NO, while a failed login should probably just be a 'warning' level, so that would be a minor change.

Docs
You've added a feature!, we need to make sure people know about it. This kind of change would warrant a small mention in the release notes, and also some brief mention of its availability in the logging docs, or perhaps alternatively/additionally in the Auth docs. I can take a look if you need more pointers. If deprecation of the signal happens, that is an additional entry that goes into the deprecation timeline.

Bravo on including a test.

Trac housekeeping:
We have a bunch of meta-data around the tickets here, and so one thing you can do after submitting a patch is mark the ticket as "has patch"

​https://docs.djangoproject.com/en/dev/internals/contributing/triaging-tickets/#has-patch

This helps direct other people who are willing to contribute by reviewing patches.

Thanks again for contributing!

[Simon Charette]

Concerning the logger, you should use a sublogger of 'django.security' such as 'django.security.FailedLogingAttempt'. Plus you should pass the message format and arguments to the logging method instead of the interpolated message.

I'm not convinced we should deprecate the signal since it was added to allow implementation of security features such as throttling in the first place.

[boylea]

Thank you for the wonderful feedback. So it seems that including both logging the failed attempt, and signalling it, is the way to go here. If this feature is to be removed, then that can be another ticket. So I will include that change, and fix the use of the logger as suggested. For the release docs, should I just append a section to the latest (1.6.txt) release doc file, or put it under a bullet under the minor features title (or does this matter much)?

[Preston Holmes]

actually, since the security logger is new, there is already a release note for this, probably don't need to call out this part of it in the existing release note. But the other docs will need some changes. I still think pointing out the logger in the signal docs would be good.

[boylea]

Uses warning level for logging user login failures, provides extra context to logger, includes documentation

[boylea]

So, a couple of things here I am not sure about... if the 'username' key is not in the credentials, I add it as None, and include it in the extra content for the logger. I did this so that format strings could refer to it without getting a key error. I included a test for this situation. Also, I added a bit to the topics/logging documentation, but I am not sure if this is where it should go as this file seemed to be less specific, and not including subloggers.

[Unai Zalakain]

Instead of:

if 'username' not in credentials:
    credentials['username'] = None

You could use:

credentials.setdefault('username', None)

The patch_logger function's docstring need to be updated because of the new formatstr argument.

The versionaddeds should also be updated to 1.7 (1.6 is feature frozen) and the one in django.security.* section should be placed above the update.

If you have the opportunity, create a PR in github (it makes it easier to comment).

[boylea]

Thank you for your review. I made those changes and submitted a pull request.

​https://github.com/django/django/pull/2013

All tests pass using sqlite

[Florian Apolloner]

I am not sure if it's good idea to log the credentials to prevent leakage. Even though you try to clean them, I'd assume that everything passed to this function is sensitive information.

[boylea]

Perhaps it is better to err on the side of caution with sensitive info. Do you think just logging a message like, "User login credentials invalid to all supplied authentication backends" would be sufficient?

[Bouke Haarsma]

The use case for the logger would be to enable some sort of monitoring. Without being passed any information about the request (like credentials or ip addresses), the functionality of the logger would be severely limited.

[anonymous]

That might be, but putting usernames/passwords in plaintext into a logfile is horrible -- depending on your current logging config this would happen with a change like this.

[Berker Peksag]

I've opened ​https://github.com/django/django/pull/3433 to revise ​https://github.com/django/django/pull/2013.

Changes:

• Fixed merge conflict
• Addressed https://code.djangoproject.com/ticket/20495#comment:9
• Added a note to the release documents
• Simplified the test

[Tim Graham]

Without any details about the credentials, this seems of limited use. As a site owner, what value would I get out of "User login credentials invalid to all supplied authentication backends." messages in my logs? It seems like it would just be noise. Thoughts? If the warning message could be tied to the request so that you could, for example, detect a large number of failed login attempts from a particular IP, that seems potentially useful. It seems like building a tool for site owner's to implement such a policy would be better though rather than monitoring logs to deduce this information. If there's a use case I'm missing, let's expand the docs a bit.

[Florian Apolloner]

It is of limited use, but the main issue is that we can't log credentials by default, this would have to be something you enable explicitly. Take sentry as an example, logging stuff there is often okay cause the logging (as opposed to errors) don't include sensitive data (hopefully). If we now log usernames and passwords that's a completely different story…

[Tim Graham]

I guess I don't see the advantage of forcing a particular "not-that-useful" implementation on all users. We already have the signal which users could use to implement their own logging if they like. If someone else like this change though, I wouldn't stand in the way. Hopefully Preston can comment on his original thinking and whether or not the current proposal matches what he had in mind.

[Tim Graham]

Closing in absence of follow up to my last question.

[Vaibhav Mallya]

The ticket @jacobian put up here: https://code.djangoproject.com/ticket/26629 has some more rationale on why logging failed attempts by default is a good idea.

The main situation I'm worried about is being aware of targeted brute-forcing of admin user's credentials, esp. with known email addresses, on the admin panel.

Here's the specific case:

1. Someone is attempting to brute-force a known admin's email address via the panel
2. I see Sentry lighting up with multiple security errors
3. I can decide what action to take for that IP address, user account [temporarily downgrade perms for it? ban the IP? etc]

With regards to what to log:

1. Logging the password seems like a bad idea.
2. But logging the username and privilege level of the user seems like a good one. At the very least the PK of the user object under consideration, if not the username - something so I know what to try and protect.
3. Logging the IP address of the host attempting any failed login is definitely a good idea
4. NIST guidelines also describe how VPNs log special properties of the failed login attempt:

​http://csrc.nist.gov/publications/nistpubs/800-92/SP800-92.pdf

VPN systems typically log successful and failed login attempts, as well as the dates and times each user connected and disconnected, and the amount of data sent and received in each user session. VPN systems that support granular access control, such as many Secure Sockets Layer (SSL) VPNs, may log detailed information about the use of resources.

If there's additional metadata about the login attempt that can be helpful, it may make sense to do that as well (cookies? browser version? user-agent? not sure.)

[Tim Graham]

Monitoring logging and manually handling brute force login attempts doesn't seem like a common (or scalable) solution.

As I mentioned in a previous comment, the user_login_failed signal allows a developer to implement whatever logic, logging or otherwise, that they like. For your use case of logging the IP addresss, etc., one problem is that the HttpRequest isn't available in the signal, however, that should be possible to add as discussed in #23155.

If you find consensus on the DevelopersMailingList to add some default logging, we can reopen the ticket.

[Clayton Daley]

I'd like to at least +1 that extensive logging of authentication (etc. etc. etc.) is a requirement in some industries (e.g. healthcare). I suspect the "why" is a combination of SIEM's real time features and breach notification regulations. For example, the severity of the breach (number of impacted records) affects your regulatory obligations so it behooves you to know *exactly* what was touched even if you didn't stop it.

Of course, if you're selling into the healthcare space and your customers demand it, how is far more important than why. For example, the following is what one healthcare client requires:

The Product or Service will provide user activity Audit Log information.

Audit Log entries must be generated for the following general classifications of events: login/logout (success and failure); failed attempts to access system resources (files, directories, databases, services, etc.); system configuration changes; security profile changes (permission changes, security group membership); changes to user privileges; actions that require administrative authority (running privileged commands, running commands as another user, starting or stopping services, etc.); and remote control sessions (session established, login, logout, end session, etc.).

Each Audit Log entry must include the following information about the logged event: date and time of event; type of event; event description; user associated with event; and network identifiers (IP address, MAC Address, etc.) or logical identifiers (system name, port, etc.).

The description is somewhat ambiguous between OS and software-level logging because it's intended to cover both. Many of these (auth, roles, permissions and related administrative actions) have to be captured from Django components.

===

The lesson I draw from #23155 is that logging can't (in fact shouldn't) depend on signals. Signals should be lightweight. It should be enough to say "user _n_ failed to log on". If the receiver needs to know about user _n_, they should load whatever additional data they need (hopefully from cache). That's what a signal is.

Logging should (and generally does) aspire to the opposite. We don't say "that's too trivial... don't log it". We say "log it, but classify it as DEBUG". I think we should have the same mindset for sensitive data. The comment above is correct that logging usernames/passwords to plain text would be inappropriate. What we really need is a "DEBUG flag" for content.

I even have a thought about how this might be done... an improved logger that "white lists" data elements. Send everything and let the consumer decide. Debate the defaults. We agree that username shouldn't be included so it's left out of the defaults, but not hard-coded into Django.