1217374 - Improve logging for "Hawk authentication failed" errors on stage/prod

Status: RESOLVED FIXED

(Tree Management :: Treeherder: API, defect, P1)

Description

[Ed Morley [:emorley]]

In bug 1215566 they're seeing '{"detail":"Hawk authentication failed"}' error responses sometimes, but not all of the times when posting to the API.

This only appear as 403s in the stage/prod logs, with no further information, since Django logs 4XX responses as log level WARNING, but we only log ERRORS and above on stage/prod.

However that would only show us the same "Hawk authentication failed" message as they get in the response.

We should also add a handler for 'hawkrest' so we can see the additional info that it logs here:
https://github.com/kumar303/hawkrest/blob/0.0.8/hawkrest/__init__.py#L80

Comment 1

[Ed Morley [:emorley]]

Attachment: Improve Django logging config

This works for now, however in the future I'd like to try and consolidate the logging config in settings.py with that in the Vagrant-specific custom settings file, as well as improve the default logging further (so we can both ditch the local settings file entirely, and also give people the best out of the box experience in Vagrant).

Comment 2

[Treeherder GitHub Bugbot]

Commits pushed to master at https://github.com/mozilla/treeherder

https://github.com/mozilla/treeherder/commit/3ddf626c9cf8f716902f2e7637ab4bba8c569818
Bug 1217374 - Output hawkrest WARNINGs to help debug hawk auth problems

This means rather than just returning this to the client:
'{"detail":"Hawk authentication failed"}'

We'll output more information to the stage/prod/Vagrant console and thus
logs. eg:

WARNING [hawkrest:81] access denied: MacMismatch: MACs do not match;
ours: 8HqvrjA7MO0CmJ3c6Ij2VfEuZxkchEL+pOL6Cw7At2c=; theirs:
CyDv9vnmqP6yGqT+LknMA+FOwJvSLATJwvVgG0OTl8A=

Thanks to the log.warn() here:
https://github.com/kumar303/hawkrest/blob/0.0.8/hawkrest/__init__.py#L80

I've removed the log level set on the console handler, since I think
it's clearer to set them on the loggers themselves, but it's not
entirely clear what Django logging best practices are, since the Django
docs are not very specific.

https://github.com/mozilla/treeherder/commit/82a32b84b042a3e49560998e297b2b43bd8d5107
Bug 1217374 - Log django.request WARNINGs on stage/prod

HTTP errors with a status code of 5XX are logged as ERRORs, and so were
already being output to the log on stage/prod. Status codes of 4XX are
logged as WARNINGs, and so are now logged too. This should make 403s
and 401s clearer when trying to debug issues with people submitting to
our API - particularly given they don't show up in New Relic either, due
to bug 1201086.