SuspiciousOperation should not be answered with HTTP 500

[Daniel Seither]

If a request comes in which does not use one of the allowed host names from the ALLOWED_HOSTS setting, a SuspiciousOperation exception is thrown:

Traceback (most recent call last):

  File "/srv/virtualenv/sesp/lib/python2.7/site-packages/django/core/handlers/base.py", line 89, in get_response
    response = middleware_method(request)

  File "/srv/virtualenv/sesp/lib/python2.7/site-packages/django/middleware/common.py", line 55, in process_request
    host = request.get_host()

  File "/srv/virtualenv/sesp/lib/python2.7/site-packages/django/http/__init__.py", line 223, in get_host
    "Invalid HTTP_HOST header (you may need to set ALLOWED_HOSTS): %s" % host)

SuspiciousOperation: Invalid HTTP_HOST header (you may need to set ALLOWED_HOSTS): spamserver.net.example

This results in an internal server error.

I would expect that an HTTP client error (4xx, maybe 403) is sent instead of an HTTP server error, as the error is caused by the client (here: spoofed host name while trying to mount an attack on the server).

[Preston Holmes]

I'd say that this particular SuspiciousOperation should be handled more like the PermissionDenied in get_response - I'll work up a draft patch

[Carl Meyer]

This was discussed in putting together the patch. IIRC the HTTP spec says that a server should respond to an incorrect Host header with an HTTP 400. I have no doubt that that's more correct; the issue is that in Django's default configuration (and some other common error-reporting tools), site admins only get notified on 500 errors, not 4xx responses. Thus, making this change could increase the number of people who deploy a broken configuration and fail to notice it right away.

I think the right approach is to return a 400 instead, but also log an error (not just a warning, like PermissionDenied) to the 'django.request' logger. This should mean that in the default logging config admins will still get notified (that should be tested).

[Preston Holmes]

I think the logging tests already demonstrate that logger.error notifies admins:

​https://github.com/django/django/blob/master/tests/regressiontests/logging_tests/tests.py#L165

[Preston Holmes]

proposed patch:

​https://github.com/ptone/django/compare/ticket;19866-disallowed-host-403

[Daniel Seither]

Replying to carljm:

I think the right approach is to return a 400 instead, but also log an error (not just a warning, like PermissionDenied) to the 'django.request' logger. This should mean that in the default logging config admins will still get notified (that should be tested).

In less than 24 hours since I upgraded to 1.4.4 and activated the ALLOWED_HOSTS feature, I already got around 10 SuspiciousOperation exceptions for my fairly low traffic site due to spammers spoofing the host header, probably trying to exploit the host header poisoning issue that was fixed in 1.4.4.

So I think it needs to be decided whether it is better to (1) notify people by default because they could have set ALLOWED_HOSTS to be too restricting, while also sending a notification each time a spammer checks out the server, or to (2) only issue and log a warning.

I would strongly opt for (2), as I am not interested in notifications on failed attacks, and you cannot programmatically distinguish between ALLOWED_HOSTS misconfiguration and attackers, so only a fraction of the errors will be caused by misconfiguration.

[Carl Meyer]

Replying to tiwoc:

So I think it needs to be decided whether it is better to (1) notify people by default because they could have set ALLOWED_HOSTS to be too restricting, while also sending a notification each time a spammer checks out the server, or to (2) only issue and log a warning.

I would strongly opt for (2), as I am not interested in notifications on failed attacks, and you cannot programmatically distinguish between ALLOWED_HOSTS misconfiguration and attackers, so only a fraction of the errors will be caused by misconfiguration.

Yeah, this is a good point. Given that we can't tell the difference between misconfiguration and an attack, spamming admins with error notifications is probably not the best response.

I'm a bit concerned that changing it to a warning leaves us overly-prone to not-quickly-detected mis-configuration, but maybe we need to address that via something like #17101 instead.

[Carl Meyer]

After discussion on IRC (with Aymeric, Florian, and Preston), I think that in the long term the right approach here is:

1. Catch all SuspiciousOperation (not just this one) in BaseHandler and make them return a 400 HTTP status instead of 500, and log them as warnings to a new "django.security" logger (so they can easily be separated in logging config from "django.request" warnings, which includes e.g. all 404s). This probably requires adding also a handler400 hook, much like the existing handler500, handler404, and handler403.

2. Optionally while doing this refactor BaseHandler.get_response to handle exceptions generically instead of repeating almost-identical except clauses. This could mean using a dictionary to map exception types (e.g. SuspiciousOperation, PermissionDenied, Http404) to HTTP status codes (400, 403, 404), and fallback to 500 for exceptions not found in the dictionary. It could also include making the handlerXXX machinery generic, such that it can work for any 4xx/5xx status code.

Regrettably, I think that even just doing (1) is too much new code to be adding to 1.5 at this point (post RC2, with final coming out next week), or 1.4/1.3. I know we did just add to the potential frequency of SuspiciousOperation with the ALLOWED_HOSTS patch, but really this isn't a new problem; there are other places where a malicious user can already trigger SuspiciousOperation and thus a 500 error. The principle is that malicious users should not be able to trigger 500 errors at will; it doesn't really make sense to fix it only for ALLOWED_HOSTS and not for all SuspiciousOperation at once.

Thus, while I think this is definitely worth fixing for 1.6, I don't think it qualifies as a 1.5 release blocker.

[Carl Meyer]

Editing the title to reflect the modified scope here (we want to deal with all SuspiciousOperation better, not just ALLOWED_HOSTS).

[Daniel Seither]

Sounds good to me!

I want to work around this issue until 1.6 is here. Is defining a logging filter that removes SuspiciousOperation exceptions (along the lines of the example for CallbackFilter from the ​logging docs) the best way to do this?

[Carl Meyer]

Replying to tiwoc:

I want to work around this issue until 1.6 is here. Is defining a logging filter that removes SuspiciousOperation exceptions (along the lines of the example for CallbackFilter from the ​logging docs) the best way to do this?

Yep, that's the right approach.

[Carl Meyer]

This is a release blocker for 1.6. (I think an argument could be made to backport it for 1.5.1).

[Russell Keith-Magee]

#19946 was a duplicate. An informal straw poll on #django-social suggested there would be a bit of support for a quick turnaround 1.5.1 release to correct this problem before there was a lot of legacy code using the 500-returning solution.

[Daniel Seither]

If there's anyone interested in using the logging filter workaround, you can have a look at a ​small example project where SuspiciousOperation exceptions are filtered without modifying the Django source code, and my ​accompanying blog post.

[digimag@…]

Quick idea: the 500 error could still be raised if the allowed hosts list is empty (because it is clearly a misconfiguration). But if the list is not empty, there is no reason why admins should be notified by e-mail. You can throw a more appropriate response (403 or 400 error page) and if you really want it, you can simply log this event.

What do you think about it?

[joejasinski]

The filter from tiwoc seemed to work as a work-around for now. Thank you for the blog post and code example.

[Stavros Korokithakis]

Correct me if I'm wrong, but won't sites just not work with ALLOWED_HOSTS set to the default of []? Not that many people will be unaware that their site produces a 400 error with "Invalid host" all the time.

[Carl Meyer]

Replying to stavros:

Correct me if I'm wrong, but won't sites just not work with ALLOWED_HOSTS set to the default of []? Not that many people will be unaware that their site produces a 400 error with "Invalid host" all the time.

I sympathize with this point of view (that's why it's currently a 500), but on the other hand - are people really launching sites and never once checking the site themselves to see whether it even works? Given the amount of fiddling that's often already necessary to get a site working in production (with static assets and whatnot), this seems pretty dubious to me.

I guess we could do what was suggested above: make it a 500 (ImproperlyConfigured, perhaps) if ALLOWED_HOSTS is empty when DEBUG is False, and a 400 if its non-empty but the request doesn't match.

[Preston Holmes]

One of the problematic things about the use of SuspiciousOperation, is that there is no way to get any specificity of event types. If you care about some more than others, it you're stuck with parsing strings.

Since we only raise this exception in relatively few places (I think I count 8), one idea would be to subclass SuspiciousOperation for each case, and have the logger put in e.name at the beginning of the message, so there would at least be that.

If we accept Alex's premise that logging should be bifurcated, into mild or oh-crap, which should SuspiciousOperation be.

My inclination is to log SuspiciousOperation events as info/warning (I'd group those all below Error) and have people configure logging as needed.

This does result in a change in behavior that should be strongly called out in the release notes, as any suspicious operations in <=1.5 would be logged to monitoring tools that watch for 500s (ie sentry) and if we introduce a 400 response path that handles these exceptions, a new shim like the 404 middleware for raven will be needed to deliver these to sentry as well.

[Carl Meyer]

Subclassing SuspiciousOperation for each case where it's used seems fine to me. I don't think we'd need e.__name__ at the beginning of the log message (unless the message is otherwise unclear); I think we should pass on the exception itself as extra data along with the logged message, meaning that logging handlers and filters would have direct access to the exception itself.

[Preston Holmes]

So a near final patch is available here for review:

​https://github.com/ptone/django/compare/ticket/19866-susop

@dstufft's feedback on passing the exc as extra_info was that people are not likely to bother with custom handlers - so the current approach uses a sub-logger with a matching name.

The prior use of SuspiciousOperation varied in terms of how it was handled - in many cases it was handled outside of the base WSGI handler, and in other cases it made it up to the WSGI handler, where it was unhandled, triggering the unhandled exc code path and returning a 500 (the original issue of this ticket)

This patch essentially does two things:

It handles a SuspiciousOperation in the WSGI handler and returns a 400 through a similar process as the 404 and 500 handlers, it was deemed not worthwhile to refactor this resolver branching heavily into something that references a dict or otherwise, as there were enough differences such that there would have been little net gain for increasing the indirection. To fully refactor this would involve URLresolver changes and should be done in a different patch.

Other uses of SuspiciousOperation were being handled before reaching the WSGI handler, but there was no reporting of these to the user - this silent swallowing of potentially security related data is addressed in this patch by logging any SuspiciousOperation to a django.security logger. This is handled inside the init of SuspiciousOperation, because in a number of places SuspiciousOperation was not being handled with any specific behavior, and the "event" worth logging happens at the time the SuspiciousOperation is raised, not when it is handled. The base SuspiciousOperation has been differentiated into subclasses - this was done initially when the filtering was to be done by handlers, but remains as a way of matching the subclass to matched sub-logger (and can still be used in custom handlers).

By default the handler for the security logger is mail-admins. This is to preserve the existing behavior for those places where SuspOp would be caught in the WSGI handler, and because security related stuff should be loud by default - but this also means that situations that raised SuspiciousOperation, which were being silently caught in the past, will also now generate admin-mails. There is a documentation example of how to silence logging associated with specific SuspiciousOperation subclasses.

[Carl Meyer]

@ptone Can you make a pull request for the branch to enable inline commenting?

[Preston Holmes]

@carljm - absolutely:

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

[Claude Paroz]

About the patch_logger functionality, note that I had proposed something similar (capture_logging) in #17958 with a slightly different implementation (using a MemoryHandler instead of a list). At first, I cannot say one is better than the other, but it might be worth considering.

[Preston Holmes <preston@…>]

In d228c1192ed59ab0114d9eba82ac99df611652d2:

Fixed #19866 -- Added security logger and return 400 for SuspiciousOperation.

SuspiciousOperations have been differentiated into subclasses, and
are now logged to a 'django.security.*' logger. SuspiciousOperations
that reach django.core.handlers.base.BaseHandler will now return a 400
instead of a 500.

Thanks to tiwoc for the report, and Carl Meyer and Donald Stufft
for review.