1318021 - Make the logging configuration more sensible

Status: RESOLVED FIXED

(Tree Management :: Treeherder, defect, P3)

Description

[Ed Morley [:emorley]]

There are several issues at present:
* The Vagrant environment uses a mixture of log files vs console, when it should just use the console to simplify development, and be consistent with Heroku
* The bin/run_* script logging levels are different from those in Procfile and from those obtained when using ./manage.py runserver.
* The Vagrant environment logging config comes from the git ignored settings_local.py, which isn't kept automatically up to date with changes in settings_local.example.py (since it's only copied over if it didn't exist already)

Resolving this blocks:
1) Switching from the bin/run* scripts to something that uses the Procfile (bug 1318020)
2) Removing settings_local.py (bug 1318011)

Comment 1

[Ed Morley [:emorley]]

Some links for reference...

https://docs.djangoproject.com/en/1.8/topics/logging/
https://docs.python.org/2.7/library/logging.html
http://docs.gunicorn.org/en/latest/settings.html#logging
http://docs.celeryproject.org/en/3.1/configuration.html#logging
http://rhodesmill.org/brandon/2012/logging_tree/ (for showing current logging config)

Places where we define logging:
https://github.com/mozilla/treeherder/blob/8b94f6a0ff4322c35c71dd403f65a6fa931d673c/treeherder/config/settings.py#L157-L190
https://github.com/mozilla/treeherder/blob/8b94f6a0ff4322c35c71dd403f65a6fa931d673c/treeherder/config/settings_local.example.py#L7-L46
https://github.com/mozilla/treeherder/blob/8b94f6a0ff4322c35c71dd403f65a6fa931d673c/Procfile
https://github.com/mozilla/treeherder/blob/8b94f6a0ff4322c35c71dd403f65a6fa931d673c/bin/run_gunicorn#L27-L33
(plus the rest of the bin/run_* scripts)

Default logging inherited from packages:
https://github.com/benoitc/gunicorn/blob/master/gunicorn/glogging.py
https://github.com/celery/celery/blob/v3.1.24/celery/app/log.py#L90-L150
https://github.com/django/django/blob/1.8.16/django/utils/log.py#L23-L67

Comment 2

[GitHub Autolander Bot]

Attachment: [treeherder] mozilla:stop-logging-to-file > mozilla:master

Comment 3

[Ed Morley [:emorley]]

Comment on attachment 8813624 [details] [review]
[treeherder] mozilla:stop-logging-to-file > mozilla:master

This is only the first part of this bug, but the later parts are turning out to be fiddly, so splitting this off rather than hoarding yet more partly-finished branches locally :-)

Comment 4

[William Lachance (:wlach)]

Comment on attachment 8813624 [details] [review]
[treeherder] mozilla:stop-logging-to-file > mozilla:master

Makes sense to me.

Comment 5

[Treeherder GitHub Bugbot]

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

https://github.com/mozilla/treeherder/commit/4df19bddd25e5e2edd38408157b53f9f34b5665e
Bug 1318021 - Vagrant: Stop using log files for gunicorn/celery output

Outputting to the console rather than a log file:
* is more user-friendly during development
* is more consistent with Heroku
* means the Vagrant-specific Django LOGGING config is now closer to the
one in settings.py, and so more easily combined with it

Both gunicorn and celery default to outputting to stdout/stderr, so the
`logfile` options can be omitted entirely.

Comment 6

[Treeherder GitHub Bugbot]

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

https://github.com/mozilla/treeherder/commit/5dfb9782a23e3538b9ea1f5214125b874dbef376
Bug 1318021 - Vagrant: Remove support for settings_local.py

Since it is footgun-prone, discourages upstreaming of useful development
tricks & is unnecessary in an environment variable centric world.

The one remaining `BZ_API_URL` setting isn't actively used, and if this
changes in the future, it should be set via an environment variable
instead.

Comment 7

[Ed Morley [:emorley]]

Bah, comment 6 should have been in bug 1318011.

Comment 8

[Ed Morley [:emorley]]

<jmaher> rwood: odd, no output, we should get some kind of print statement
<jmaher> rwood: I would expect to see this line: https://github.com/mozilla/treeherder/pull/2126/files#diff-8eaf98d45f731c643759d48de624bbf5R31
<rwood> jmaher: yep analyze_failures runs, but there's no output
...
<emorley> ah it's a .warn()?
<emorley> checking the log level [for prod] it's set to error and above (which doesn't seem sensible personally)
<emorley> https://github.com/mozilla/treeherder/blob/897bb5649b1b03c97e5f5b1da8c9600980f2f181/treeherder/config/settings.py#L182
<rwood> ahhh
<emorley> we should change that filter from error to warning
<emorley> prior to moving to Heroku it was such a pain to look at our logs that we didn't use them as much, so I guess this got missed
<emorley> sorry for the churn
<rwood> emorley: np! shall I make a quick bug and PR for that?
<emorley> yeah ty
<rwood> ok
<emorley> I think longer term we need to figure out what the log levels should really represent, and in what environments we have them set to what
<emorley> eg prod: warn and above, or info and above?
<emorley> but vagrant perhaps debug and above
<emorley> with an environment variable for overriding where needed temporarily
<emorley> And part of that, we'll need to adjust our logging calls so that there isn't too much noise at the wrong log level
<emorley> for example iirc the log parser outputs loads of lines at info() which would make that a bit too noisy as the prod default currently
<rwood> right, makes sense
<emorley> I can do this as part of bug 1318021

Comment 10

[GitHub Bugzilla PR Linker]

Attachment: Link to GitHub pull-request: https://github.com/mozilla/treeherder/pull/3361

Comment 11

[Cameron Dawson [:camd]]

Left a message in the review before r+'ing this.

Comment 12

[Cameron Dawson [:camd]]

Comment on attachment 8960956 [details] [review]
Link to GitHub pull-request: https://github.com/mozilla/treeherder/pull/3361

Clearing the review for now while waiting for the response to my question in the PR.  :)

Comment 13

[Treeherder GitHub Bugbot]

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

https://github.com/mozilla/treeherder/commit/466b053eba7e55e604fd4cbef47f71e730cf4769
Bug 1318021 - Merge debug logging config into main LOGGING setting