Wrong line number with multiline opening tags? Wrong filepath when calling warnings.warn from a template?

[pawamoy]

Hello, I'm maintaining mkdocstrings, and I'm currently trying to rename my templates from *.html to *.html.jinja, for proper syntax highlighting (and other tooling support). Since it's a breaking change (I allow users to override templates with custom ones), I want to prepare a deprecation period where overriding templates with a filename ending with .html, or inheriting from a .html base template will emit a deprecation warning. For this I add partials to the environment globals:

class TemplateWarner:
    """A wrapper class to emit warnings from templates."""

    user = partial(warnings.warn, category=UserWarning, stacklevel=0)
    """Emit a warning targetted at end users."""

    deprecation = partial(warnings.warn, category=DeprecationWarning, stacklevel=0)
    """Emit a warning about a deprecation."""

    runtime = partial(warnings.warn, category=RuntimeWarning, stacklevel=0)
    """Emit a warning about a runtime issue."""

    future = partial(warnings.warn, category=FutureWarning, stacklevel=0)
    """Emit a warning about a future issue."""

    pending_deprecation = partial(warnings.warn, category=PendingDeprecationWarning, stacklevel=0)
    """Emit a warning about a pending deprecation."""

# somewhere else
env.globals["warn"] = TemplateWarner

I can then warn like this:

{# in _base/attribute.html #}
{{ warn.deprecation("this template is deprecated blabla") }}

However, running MkDocs, here's the output I get:

INFO    -  DeprecationWarning: this template is deprecated blabla
             File "/media/data/dev/mkdocstrings/.venv/lib/python3.11/site-packages/mkdocstrings_handlers/python/templates/material/_base/children.html", line 97, in root
               {% if members_list is not none or module.is_public(check_name=False) %}
             File "/media/data/dev/mkdocstrings/.venv/lib/python3.11/site-packages/jinja2/runtime.py", line 298, in call
               return __obj(*args, **kwargs)

Note the file path _base/children.html and the line number 97. The actual call to warn is in _base/attribute.html at line 3.

First, I have to let you know that this is not the first time I'm noticing wrong line numbers: when debugging mkdocstrings, everytime I'm in a Jinja frame, I'm on the wrong line. So maybe there's a more general issue here. I don't use particularly fancy templating stuff, apart maybe from multiline opening tags such as:

          {% with modules = obj.modules|filter_objects(
            filters=config.filters,
            members_list=members_list,
            inherited_members=config.inherited_members,
            keep_no_docstrings=config.show_if_no_docstring,
          ) %}

...(and similar ones with filter, set, etc.), as well as empty {% with %} tags (with bodies) for namespacing.

My (rather cheap) intuition is that maybe these multiline opening tags are shifting the line numbers? Therefore line 97 above would actually be 97 + S, where S is the number of continuation lines in multiline opening tags? But that doesn't make sense when I look at my templates: the line that includes the attribute.html template, itself extending the _base/attribute.html template, is line 35. There's another line, 125, which includes the same template, but the condition to reach it isn't set. Weirdly, this line and the calculated offset would match!

• 125 - 97 = 28
• Counting "extra" lines in my templates, i.e. lines from the opening {% (excluded) up to the closing %} (included): 28!

Click to see the children.html template

When running the code, config.group_by_category is true, but somehow the line number reported by Jinja plus the offset computed from continuation lines matches line 125, which would be reached if the condition was false. Weird.

I have added trailing comments on continuation lines to increment a counter 🙂

{{% if obj.members %}
  {{ log.debug("Rendering children of " + obj.path) }}

  <div class="doc doc-children">

    {% if root_members %}
      {% set members_list = config.members %}
    {% else %}
      {% set members_list = none %}
    {% endif %}

    {% if config.group_by_category %}

      {% with %}

        {% if config.show_category_heading %}
          {% set extra_level = 1 %}
        {% else %}
          {% set extra_level = 0 %}
        {% endif %}

        {% with attributes = obj.attributes|filter_objects(
          filters=config.filters,                             {# 1 #}
          members_list=members_list,                          {# 2 #}
          inherited_members=config.inherited_members,         {# 3 #}
          keep_no_docstrings=config.show_if_no_docstring,     {# 4 #}
        ) %}                                                  {# 5 #}
          {% if attributes %}
            {% if config.show_category_heading %}
              {% filter heading(heading_level, id=html_id ~ "-attributes") %}Attributes{% endfilter %}
            {% endif %}
            {% with heading_level = heading_level + extra_level %}
              {% for attribute in attributes|order_members(config.members_order, members_list) %}
                {% if members_list is not none or attribute.is_public(check_name=False) %}
                  {% include attribute|get_template with context %}         {# THIS IS LINE 35! #}
                {% endif %}
              {% endfor %}
            {% endwith %}
          {% endif %}
        {% endwith %}

        {% with classes = obj.classes|filter_objects(
          filters=config.filters,                             {# 6 #}
          members_list=members_list,                          {# 7 #}
          inherited_members=config.inherited_members,         {# 8 #}
          keep_no_docstrings=config.show_if_no_docstring,     {# 9 #}
        ) %}                                                  {# 10 #}
          {% if classes %}
            {% if config.show_category_heading %}
              {% filter heading(heading_level, id=html_id ~ "-classes") %}Classes{% endfilter %}
            {% endif %}
            {% with heading_level = heading_level + extra_level %}
              {% for class in classes|order_members(config.members_order, members_list) %}
                {% if members_list is not none or class.is_public(check_name=False) %}
                  {% include class|get_template with context %}
                {% endif %}
              {% endfor %}
            {% endwith %}
          {% endif %}
        {% endwith %}

        {% with functions = obj.functions|filter_objects(
          filters=config.filters,                             {# 11 #}
          members_list=members_list,                          {# 12 #}
          inherited_members=config.inherited_members,         {# 13 #}
          keep_no_docstrings=config.show_if_no_docstring,     {# 14 #}
        ) %}                                                  {# 15 #}
          {% if functions %}
            {% if config.show_category_heading %}
              {% filter heading(heading_level, id=html_id ~ "-functions") %}Functions{% endfilter %}
            {% endif %}
            {% with heading_level = heading_level + extra_level %}
              {% for function in functions|order_members(config.members_order, members_list) %}
                {% if not (obj.kind.value == "class" and function.name == "__init__" and config.merge_init_into_class) %}
                  {% if members_list is not none or function.is_public(check_name=False) %}
                    {% include function|get_template with context %}
                  {% endif %}
                {% endif %}
              {% endfor %}
            {% endwith %}
          {% endif %}
        {% endwith %}

        {% if config.show_submodules %}
          {% with modules = obj.modules|filter_objects(
            filters=config.filters,                             {# 16 #}
            members_list=members_list,                          {# 17 #}
            inherited_members=config.inherited_members,         {# 18 #}
            keep_no_docstrings=config.show_if_no_docstring,     {# 19 #}
          ) %}                                                  {# 20 #}
            {% if modules %}
              {% if config.show_category_heading %}
                {% filter heading(heading_level, id=html_id ~ "-modules") %}Modules{% endfilter %}
              {% endif %}
              {% with heading_level = heading_level + extra_level %}
                {% for module in modules|order_members(config.members_order.alphabetical, members_list) %}
                  {% if members_list is not none or module.is_public(check_name=False) %}
                    {% include module|get_template with context %}
                  {% endif %}
                {% endfor %}
              {% endwith %}
            {% endif %}
          {% endwith %}
        {% endif %}

      {% endwith %}

    {% else %}

      {% for child in obj.all_members
        |filter_objects(                                      {# 21 #}
          filters=config.filters,                             {# 22 #}
          members_list=members_list,                          {# 23 #}
          inherited_members=config.inherited_members,         {# 24 #}
          keep_no_docstrings=config.show_if_no_docstring,     {# 25 #}
        )                                                     {# 26 #}
        |order_members(config.members_order, members_list)    {# 27 #}
      %}                                                      {# 28 #}

        {% if not (obj.is_class and child.name == "__init__" and config.merge_init_into_class) %}

          {% if members_list is not none or child.is_public(check_name=False) %}
            {% if child.is_attribute %}
              {% with attribute = child %}
                {% include attribute|get_template with context %}         {# THIS IS LINE 125 (97+28)! #}
              {% endwith %}

            {% elif child.is_class %}
              {% with class = child %}
                {% include class|get_template with context %}
              {% endwith %}

            {% elif child.is_function %}
              {% with function = child %}
                {% include function|get_template with context %}
              {% endwith %}

            {% elif child.is_module and config.show_submodules %}
              {% with module = child %}
                {% include module|get_template with context %}
              {% endwith %}

            {% endif %}
          {% endif %}

        {% endif %}

      {% endfor %}

    {% endif %}

  </div>

{% endif %}

If my intuition is right, that's one issue out of three that is elucidated.

1. Wrong line numbers: shifted by continuation lines in opening tags ✔️
2. Line number of wrong branch: is it because both lines 35 and 125 are the same (except for indentation)? And the last one "overrides" the first one in a "line hash / line number" mapping or something? Note that the execution enters the correct branch, it's just the frame info that is wrong 💡
3. Partial warnings.warn reporting frames starting at the frame above: no idea 🤷

To backup my second intuition about line numbers of the wrong conditional branch, here's a screenshot of me debugging execution of mkdocstrings:

I set a breakpoint in the do_get_template function (you can see the call stack in the left sidebar), that is called as a filter within the instruction that includes the attribute.html template (editor panel, middle, though the frame reports line 124 and not 125).

You can see that the frame info reports we're in the else clause of the {$ if config.group_by_category %} condition (editor panel, top), while config.group_by_category is actually true (watched variables panel, bottom right).

---

Sorry, this post is a bit messy. I guess I could summarize my questions as:

• are Jinja frames supposed to report the right line numbers in templates?
• if yes, what do you think about the behavior demonstrated above? are these bugs, or something I just don't understand?

Happy to try and provide more minimal examples if needed 🙂

[pawamoy]

I've tried creating a minimal example, but it looks like Jinja always produces correct tracebacks when there's an error in a template. However during debug sessions the lines do not match. I suppose Jinja doesn't mess too much with the frames and rather corrects tracebacks when an exception is raised? That would explain why tracebacks are correct, while line numbers in debug session frames are not, and frames reported by warnings.warn are not either.

[pawamoy]

Huh, MkDocs catches warnings anyway to re-emit them as info logs... I guess I can just log them as warnings instead then.