Cylc-flow: Jinja error in validation shows incorrect context

[trwhitcomb]

When validating a suite using Jinja2 templating commands, the error handling will print out the Jinja exception as well as the context lines. However, they don't match. Take the following suite:

#!jinja2

[scheduling]
    initial cycle point = 20171129T20

    [[dependencies]]
        [[[PT5M]]]
            graph = """
                foo => bar
            """

[runtime]
    [[root]]
        [[[environment]]]
            watch_directory = {{ watch_directory }}

    [[CheckRequests]]
        [[[environment]]]
            processing_suite = {{ processing_suite }}

When validating with no command-line Jinja options, it gives the error:

Jinja2Error:
  File "<template>", line 18, in top-level template code
UndefinedError: 'watch_directory' is undefined
Context lines:

    [[CheckRequests]]
        [[[environment]]]
            processing_suite = {{ processing_suite }}   <-- Jinja2Error

I would have expected the context lines to show the watch_directory line instead of the processing_suite variable line contexts. I've tried to reproduce this in a standalone (non-Cylc) case but so far have been unsuccessful in my quick attempts to get Jinja to throw an error for the undefined variable. I'm also not sure if this is a Cylc-specific problem or if this is passed all the way through from Jinja. If it's Jinja, feel free to close.

[matthewrmshin]

On initial investigation, I think this may be a Jinja2 bug. I'll ask a 2nd pair of eyes to confirm.

[oliver-sanders]

Confirmed, this is a bad Jinja2 bug - https://github.com/pallets/jinja/issues/276.

[trwhitcomb]

Thanks, guys. I suspected it might be so - feel free to close if you'd like.

[matthewrmshin]

@trwhitcomb We have moved this to milestone never, as a known issue related to a non-cylc bug.

[kinow]

I think this and #2708 can be closed once jinja 2.11 is released and we update to this version (checking for backward compatibility, of course).

Python 3.8 changed how they reported multiline errors, but without fixing the issue with exceptions being thrown from this multiline errors. My fix for Jinja was flawed, as it would break other features of Jinja.

But luckily a maintainer of Jinja recently changed the code, which now removes the multiline usage - https://github.com/pallets/jinja/pull/1109. This means we don't have the line number, however, the exception trace should give the correct line with the error.

So for the example suite above, the output for Cylc 8 master when installing the master branch of JInja is:

(venv) kinow@ranma:~/Development/python/workspace$ cylc validate test-jinja
Jinja2Error: 'watch_directory' is undefined
Context lines:
    [[root]]
        [[[environment]]]
            watch_directory = {{ watch_directory }} <-- UndefinedError

So that gives the correct line. We could later perhaps find that line and add the line number ourselves. Looks like the Jinja2Error doesn't bring that information, but on the bright side doesn't report the wrong line number.

[kinow]

(actually looks like the line number never came from the JinjaError, my bad... so it looks like this is working as expected? :grin: )

[hjoliver]

OK, so we can close this once Jinja 2.11.0 is released?

No due date, but 98% done: https://github.com/pallets/jinja/milestones

[kinow]

Yup!!! It will give the correct context. Just the line number is missing from the exception/traceback printed. (Not sure if it is due to some change in Jinja, something we need to update in Cylc, etc). But the issue reported here will be fixed 👍 🎊 🎉

[kinow]

Issue fixed in Jinja2 2.11.1, released January 30th 2020 :tada:

Validation

Created suite 2572 in ~/cylc-suites/2572/suite.rc with the example from this issue.

Then registered it with the code from master using a newly created virtual environment.

$ cylc register 2572 ~/cylc-suites/2572/
REGISTERED 2572 -> /home/kinow/cylc-suites/2572

And tried to validate it, reproducing the issue:

(venv) kinow@kinow-VirtualBox:~/Development/python/workspace/cylc-flow$ cylc validate 2572
Jinja2Error: 'watch_directory' is undefined
Context lines:
    [[CheckRequests]]
        [[[environment]]]
            processing_suite = {{ processing_suite }}   <-- UndefinedError

Then installed 2.11.1, and tried to validate it again.

Jinja2Error: 'watch_directory' is undefined
Context lines:
    [[root]]
        [[[environment]]]
            watch_directory = {{ watch_directory }} <-- UndefinedError

[hjoliver]

(Is Jinja 2.11.1 Python 3 only? If so, this is fixed for Cylc 8, but not Cylc 7...)

[kinow]

Not yet, they still support the 2.7 series, at least from looking at their setup.py from the 2.11.1 tag:

And they have the unreleased version 3.0.0 (not sure if they will re-name jinja2 to jinja3?) which mentions the drop of 2.7:

ps: looking at the changelog, looks like it was fixed in 2.11.0 (also weird that they have 2.11.1 unreleased, even though it's in PYPI, maybe they still need to update it...)

[hjoliver]

OK I guess we should put this against the 7.8.5 milestone and update the bundled version for that release. (And update dependencies for 8.0a2)

[kinow]

I'm already going through other dependencies in Cylc 8. Just finished testing everything with latest versions, except pyzmq (still looking for the changelog to see what changed from 18.0 to 18.1).

My tests are basically cylc run --no-detach five (no surprise here), then run families2, validate, get-site-config, poll, and finally run the functional tests for ./tests/cyclers/ and ./tests/cylc-trigger and ./tests/graphql. Then will push to my remote branch and wait for Travis CI to run.

If everything works for 8.0a2, I'll prepare one for Cylc 7.

[hjoliver]

(might pay to check that those workflows use Jinja2 - if you haven't already!)

[kinow]

Ah, that was just a quick smoke check. Travis is now going through all the functional tests to confirm that everything is working. Tests under ./tests/jinja2/ passed locally too... so 🤞 now hoping that Travis will get a green build too.

[oliver-sanders]

OK I guess we should put this against the 7.8.5 milestone and update the bundled version for that release. (And update dependencies for 8.0a2)

We will need to do a quick check that this upgrade is a non-breaking change (as some previous updates have been) else provide guidance, etc.

[kinow]

Will finish testing Cylc 7.8.5 later, but will need others :eyes: and some testing to confirm it indeed doesn't break any thing.

[kinow]

Had a bit of spare time just now, so quickly:

1. downloaded Jinja2 2.11.1 from PYPI
2. checked its md5sum
3. copied all files from its ./src into Cylc Flow from branch 7.8.x
4. pushed to a new branch on my fork
5. waited for Travis CI

First it failed due to the asyncio files included. So removed these two.

Then now every test passed, but 1: validate/43-jinja2-template-error-main.t

It just runs cylc validate suite.rc (didn't know I could validate a file directly, I was always registering suites first :man_facepalming:).

Here's the output of cylc validate suite.rc for the suite in that test with Cylc 8 latest:

(venv) kinow@ranma:~/cylc-suites/validate/43-jinja2-template-error-main$ cylc validate suite.rc 
Jinja2Error: You can only sort by either "key" or "value"
Context lines:
[scheduling]
    [[dependencies]]
        graph = {{ foo|dictsort(by='by') }} <-- FilterArgumentError

And here's the output from this branch:

kinow@ranma:~/cylc-suites/validate/43-jinja2-template-error-main$ cylc validate suite.rc 
Jinja2Error:
  File "/home/kinow/Development/python/workspace/cylc-old/lib/jinja2/filters.py", line 288, in do_dictsort
    raise FilterArgumentError('You can only sort by either "key" or "value"')
FilterArgumentError: You can only sort by either "key" or "value"

That test passed with Cylc 8, so I assume we are good. It looks like it's printing the place on the file where the error occurred, instead of raising the error and printing the error context... will have a look tomorrow :+1:

[oliver-sanders]

Closed by https://github.com/cylc/cylc-flow/pull/3502