Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Warn if templates are missing variables #4505

Merged
merged 14 commits into from
Sep 12, 2024

Conversation

iaindillingham
Copy link
Member

@iaindillingham iaindillingham commented Jul 31, 2024

Previously, messages about missing context variables were ignored. This was because the django.template logger logged them as DEBUG messages (1), but the django logger (the parent of the django.template logger) sent only INFO messages (or higher) to the console.

Now, the django.template logger sends DEBUG messages (or higher) to the missing_variable_error filter. This filter always returns False, meaning that messages are (still) not sent to the console. However, it also converts messages about missing context variables to warnings.

pytest catches warnings during, and displays them at the end of, test sessions (2). So, if a template is missing a context variable, and the template response associated with the template is tested, then pytest should tell us, shouldn't it? Sadly, it's not that simple. Messages about missing context variables are only generated when a template response is rendered. If a test constructs, but doesn't render, a template response, then pytest won't tell us about missing context variables because it won't know about them either. In these cases, because warning messages are written to sys.stderr, we would most likely find out about missing context variables by inspecting the output of Django's development server.

Notice that the missing_variable_error filter only converts some messages about missing context variables to warnings. Whilst some are beyond our control, others are not cost- effective to fix.

Closes #4462

@iaindillingham
Copy link
Member Author

Thanks for talking this through earlier, @lucyb. Since we spoke, I have made three changes.

First, I have removed a commit that patched AnonymousUser in a test. Instead, I have added all_roles to the set of template variables that we ignore. As you predicted, patching AnonymousUser fixed the test, but would have resulted in warnings being reported to Sentry.

Second, I have tried to track down tests where we modify how we filter warnings (e.g. with pytest.mark.filterwarnings), but can't find any. I'm going to say that the behaviour I noticed yesterday with respect to the error warning filter was a result of my misunderstanding.

Third, I have marked MissingVariableErrorFilter.filter with pragma: no cover. Clearly, this method is being exercised by the tests (see, for example, test_missing_variable_error_filter) but not in a way that's accessible to Coverage.py.

Copy link
Contributor

@lucyb lucyb left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm noticing some exceptions in the logs when manually checking the site. They aren't being reported as errors though (seems to be info level), which is good because it won't trigger sentry. I think they might be a side effect of some changes you made earlier, so might be worth looking at now (happy for them to be fixed later if they're unrelated):

/home/lucy/datalab/opensafely-core/job-server/.venv/lib/python3.12/site-packages/django/template/base.py:925: UserWarning: Exception while resolving variable 'yes_active_class' in template 'staff/user/list.html'.
  logger.debug(
/home/lucy/datalab/opensafely-core/job-server/.venv/lib/python3.12/site-packages/django/template/base.py:925: UserWarning: Exception while resolving variable 'no_active_class' in template 'staff/user/list.html'.
  logger.debug(
/home/lucy/datalab/opensafely-core/job-server/.venv/lib/python3.12/site-packages/django/template/base.py:925: UserWarning: Exception while resolving variable 'value' in template 'staff/user/list.html'.
  logger.debug(

And

/home/lucy/datalab/opensafely-core/job-server/.venv/lib/python3.12/site-packages/django/template/base.py:925: UserWarning: Exception while resolving variable 'value' in template 'staff/index.html'.
  logger.debug(

And

/home/lucy/datalab/opensafely-core/job-server/.venv/lib/python3.12/site-packages/django/template/base.py:925: UserWarning: Exception while resolving variable 'value' in template 'staff/report/list.html'.
  logger.debug(

tests/unit/services/test_logging.py Show resolved Hide resolved
# And some template variables are just a pain, because of how we use them.
"name", # jobserver.context_processors.nav
"q",
"get_staff_url",
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As far as I can see, get_staff_url is currently only producing a warning from one test:

FAILED tests/integration/test_interactive.py::test_interactive_publishing_report_success - UserWarning: Exception while resolving variable 'get_staff_url' in template 'staff/report/detail.html'.

If that's correct, then it would be worth just editing that template (I think it should be a simple fix).

@lucyb
Copy link
Contributor

lucyb commented Aug 1, 2024

Thanks for talking this through earlier, @lucyb. Since we spoke, I have made three changes.

This all sounds very sensible. Thank you again for walking me through this. It's not easy to make a change like this in a mature application without getting lost in the weeds and I think you've found some good, pragmatic solutions to the inevitable snags that have come up.

@iaindillingham
Copy link
Member Author

Thanks for your comments, @lucyb.

I'm noticing some exceptions in the logs when manually checking the site.

I think you're noticing warnings, rather than exceptions (although the text is confusing!). The warnings are created from log records by MissingVariableErrorFilter.filter:

warnings.warn_explicit(
record.getMessage(), UserWarning, record.pathname, record.lineno
)

I'm afraid I was mistaken when I predicted that we would see warnings in Sentry. We won't, because warnings are not logs, and Sentry handles logs. MissingVariableErrorFilter.filter returns False, meaning it filters out the log records. And even if it didn't, then they're at the wrong level. (I'm confused by your comment about the info level. Do you mean the debug level? As you say, though, Sentry's DjangoIntegration captures at the error level.)

I'm concerned that you (and I) can see warnings when manually checking the site. At first, I thought this was because the templates weren't covered by tests. However, this doesn't seem to be the case. Take the following example:

UserWarning: Exception while resolving variable 'value' in template 'staff/index.html'

This template is associated with staff.views.index.Index, which is tested by tests.unit.staff.views.test_index.test_index_without_search. Why isn't the test failing? Because the test doesn't render the response! 🤦🏻‍♂️

Because we won't see warnings in Sentry and because we can see warnings when manually checking the site, I don't think this PR gives us the confidence we need. I think we should render the responses (and fix the templates), although I imagine we're not doing that now for performance. I think we should also consider not filtering out the log records, and promoting them to errors, such that we see them in Sentry (see "With a logging filter that promotes messages to errors"). Doing both should ensure that we have more confidence in our tests and, should they be deficient, then Sentry will remind us (when a user visits the page).

@lucyb lucyb force-pushed the iaindillingham/django-templates branch from b1b58e8 to 40b3e52 Compare August 6, 2024 13:20
@lucyb
Copy link
Contributor

lucyb commented Aug 6, 2024

FYI I've rebased this commit against main as I incorporated one of your commits into this PR.

@iaindillingham iaindillingham force-pushed the iaindillingham/django-templates branch 2 times, most recently from 1cf9f9a to 07bd99b Compare September 9, 2024 14:53
We're going to make a change that will result in more warnings being
reported. Our default warning filter turns warnings (less serious) into
errors (more serious), and errors cause test sessions to fail. We don't
want test sessions to fail after we make the change, but before we fix
the warnings, so we temporarily disable our default warning filter.
Previously, messages about missing context variables were ignored. This
was because the `django.template` logger logged them as `DEBUG` messages
([1][]), but the `django` logger (the parent of the `django.template`
logger) sent only `INFO` messages (or higher) to the console.

Now, the `django.template` logger sends `DEBUG` messages (or higher) to
the `missing_variable_error` filter. This filter always returns `False`,
meaning that messages are (still) not sent to the console. However, it
also converts messages about missing context variables to warnings.

pytest catches warnings during, and displays them at the end of, test
sessions ([2][]). So, if a template is missing a context variable, and
the template response associated with the template is tested, then
pytest should tell us, shouldn't it? Sadly, it's not that simple.
Messages about missing context variables are only generated when a
template response is rendered. If a test constructs, but doesn't render,
a template response, then pytest won't tell us about missing context
variables because it won't know about them either. In these cases,
because warning messages are written to `sys.stderr`, we would most
likely find out about missing context variables by inspecting the output
of Django's development server.

Notice that the `missing_variable_error` filter only converts *some*
messages about missing context variables to warnings. Whilst some are
beyond our control, others are not cost-effective to fix.

[1]: https://docs.djangoproject.com/en/5.1/ref/logging/#django-template
[2]: https://docs.pytest.org/en/latest/how-to/capture-warnings.html#warnings
At this stage, a project hasn't been created so the `project` template
variable doesn't exist.
In other words, the `value` template variable is no longer missing for
one path.
It isn't possible to create a membership for a user that already has a
membership, so the `checked` attribute of `form_checkbox` will always be
`False`.
We will use the function elsewhere shortly.
`Project.org` is a property, rather than a field, so we need to tell
factory_boy what to do with it when creating a new instance of
`Project`. To do so, `_project_collaboration_factory` needs to handle
the case where `extracted` is a single org, rather than a list of orgs.
Doing so ensures that properties of these orgs are present in templates.
In other words, these template variables are no longer missing for one
path in each template.
Let's not monkey around with the ORM in a template, especially when we
have a perfectly good property that we use elsewhere in the same
template.
We would expect projects to have orgs in production, so we should expect
the same in testing. However, because we're nervous about what might
happen if we change `ProjectFactory`, and because we think the whole
org/orgs thing was a terrible mistake, we only give some projects orgs:
that is, only those projects used in tests that render some aspect of
those orgs.
We would expect this release to have an org in production, but because
of our use of fixtures and factories, it didn't in testing.
@iaindillingham
Copy link
Member Author

@lucyb, I've addressed the get_staff_url issue. I haven't fixed the cases where warnings are displayed on stderr, but the tests for the corresponding views pass (because we don't render the template responses). As you said when we last spoke, this is a step -- but not all the steps -- in the right direction 🙂

@iaindillingham iaindillingham merged commit 6498030 into main Sep 12, 2024
8 checks passed
@iaindillingham iaindillingham deleted the iaindillingham/django-templates branch September 12, 2024 12:57
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Add unit test to fail on warnings in Django Templates
2 participants