Bug in Context Lines for Jinja2Error?

Hi all,
My 1st time using Discourse so please let me know of any breaches in protocol!
Also, apologies if this has already been raised previously elsewhere - I’ve done a quick look here, but not looked through GitHub/the old Google group - please ignore if this is already in hand.

I’ve noticed there’s something which looks* like an off-by-one error (or some similar sort of counting error) in the Context lines quoted if there’s a Jinja2 error.
The Context lines quoted seem (sometimes) not to be related to those triggering the actual error - this seems to depend on the order which Jinja2 variables are presented in.
See example cylc tracebacks (right term?) below, generated with the code below.
* NB I’m a cylc/rose noob, so I may well be wrong on this!

From Python, am somewhat used to sometimes having to look at lines surrounding nominal line quoted in traceback, e.g. in the case of (say) mismatched parentheses.

This fuzzy-match approach seems a little trickier here however, as while the Context lines are potentially very useful for debugging (thanks for providing them!), the apparent (off-by-one?) error happening at the Jinja2 level means a completely different part of the suite.rc code (and associated Jinja2 variable) could be being quoted - slightly less helpful, and rather undermining what I suspect was original aim of including Context lines!

Specifically, am raising this here as I’ve just spent a little while attempting to debug a perfectly valid part of a suite.rc, trying to work out the error, before noticing the mismatch between the (correctly-specified) “UndefinedError” target in the traceback (here for a missing JOB_NAME variable) and the (unrelated) Context lines quoted (quoting a different, entirely OK ROSE_ORIG_HOST variable)!
This mismatch between the “UndefinedError” target and the “Context lines” quoted led to me wasting some time trying to debug non-existent issues with the entirely-OK ROSE_ORIG_HOST variable.
I.e. the nominally-helpful “Context lines” were actually unhelpful, because of their “buggy” behaviour.
The root cause of the error (me not understanding that Jinja2 preprocessing of suite.rc isn’t aware whether or not lines are commented) was ~easy to find once I’d spotted the mismatch, and focused on the UndefinedError target, rather than Context lines I was initially focussing on.

I’ve tried to make a ~minimal working example of my original setup demonstrating the issue below.
This includes output I received, a commented recreation of my resulting thought processes, and associated debugging attempts.
Apologies, result is pretty verbose, but hopefully this should make it clear what I think the Context line issue is, and why I think it is “buggy” behaviour, which is potentially confusing for users

Thanks,
Edmund



Version r124999, a ~minimal working example of my original setup.
(not showing some rose-suite.info & empty rose-meta.conf files, which I think are irrelevant)
Root of problem: I’ve not realised that commenting out a line in suite.rc containing an undefined Jinja2 variable doesn’t work…

rose-suite.conf
I’ve commented out a JOB_NAME variable I’ve realised I won’t need, but not got round to removing it

# Set run directory (for cylc-run) to $HOME
root-dir=*=$HOME

[jinja2:suite.rc]
# Put any Jinja settings for suite.rc here

# job name for auditing on CLUSTER
# TODO: remove this, as NOT needed: cylc/rose provides this
# JOB_NAME = project_subproject

suite.rc
Likewise, I’ve tried to comment out the line which was using the JOB_NAME variable.
Turns out this doesn’t work - Jinja2 preprocessing ignores line being commented, and sees a missing JOB_NAME variable (as JOB_NAME was commented out in rose-suite.conf)…

#!Jinja2
[cylc]
    UTC mode = True  # Ignore DST

[scheduling]
    initial cycle point = 2019-05-01T00Z
    [[dependencies]]
        [[[R1]]]
        graph = foo => bar

[runtime]
    [[root]]
        script = """
            echo "Hello from ${CYLC_TASK_ID}"
            echo "Task being run on host:$(hostname) by user:$USER"
            echo "Suite being run on host:${CYLC_SUITE_HOST} by user:${CYLC_SUITE_OWNER}"
            """

    [[CLUSTER_JOB]]
    # Family for "real" jobs, submitted to CLUSTER
        [[[job]]]
            batch system = slurm
            execution time limit = PT10M
        [[[directives]]]
            --mem = 1500
            --ntasks = 1
            # --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit

    [[LOCAL_JOB]]
    # Family for testing jobs, submitted to local machine
        [[[remote]]]
            # set current host (where "rose suite-run" cmd was invoked)
            host = {{ ROSE_ORIG_HOST }}
        [[[job]]]
            batch system = background

    [[foo]]
        # inherit = CLUSTER_JOB
        inherit = LOCAL_JOB

    [[bar]]
        inherit = LOCAL_JOB

Output
When trying to validate my suite, I get an error.
What springs to my eyes is the Context lines quoted, which seem to be about ROSE_ORIG_HOST
I miss the fact the UndefinedError line mentions a different variable, JOB_NAME.
So I start chasing down the wrong thing…

me@mycomp:> rose suite-run --validate-suite-only  # r124999
[INFO] export CYLC_VERSION=7.8.3
[INFO] export ROSE_ORIG_HOST=mycomp
[INFO] export ROSE_SITE=
[INFO] export ROSE_VERSION=2019.01.2
[INFO] create: log.20190719T234344Z
[INFO] symlink: log.20190719T234344Z <= log
[INFO] create: log/suite
[INFO] create: log/rose-conf
[INFO] symlink: rose-conf/20190720T004344-validate-suite-only.conf <= log/rose-suite-run.conf
[INFO] symlink: rose-conf/20190720T004344-validate-suite-only.version <= log/rose-suite-run.version
[INFO] install: rose-suite.info
[INFO]     source: /path/to/me/and/my/suite/mi-su173/rose-suite.info
[INFO] create: meta
[INFO] install: meta
[INFO]     source: /path/to/me/and/my/suite/mi-su173/meta
[INFO] install: suite.rc
[FAIL] cylc validate -o /var/tmp/tmpD6SZfU --debug --strict /var/tmp/tmpievkuP/cylc-run/mi-su173 # return-code=1, stderr=
[FAIL] 2019-07-20T00:43:45+01:00 DEBUG - Loading site/user global config files
[FAIL] 2019-07-20T00:43:45+01:00 DEBUG - Reading file /path/to/fcm/cylc-7.8.3/etc/global.rc
[FAIL] 2019-07-20T00:43:45+01:00 DEBUG - Reading file /path/to/me/.cylc/global.rc
[FAIL] 2019-07-20T00:43:45+01:00 DEBUG - Reading file /var/tmp/tmpievkuP/cylc-run/mi-su173/suite.rc
[FAIL] 2019-07-20T00:43:45+01:00 DEBUG - Processing with Jinja2
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 50, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]     # Family for testing jobs, submitted to local machine
[FAIL]         [[[remote]]]
[FAIL]             # set current host (where "rose suite-run" cmd was invoked)
[FAIL]             host = {{ ROSE_ORIG_HOST }}  <-- Jinja2Error
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] parsec.fileparse.FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 50, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]     # Family for testing jobs, submitted to local machine
[FAIL]         [[[remote]]]
[FAIL]             # set current host (where "rose suite-run" cmd was invoked)
[FAIL]             host = {{ ROSE_ORIG_HOST }}  <-- Jinja2Error


r125000, where I’m trying to debug the apparent ROSE_ORIG_HOST error
(for ~brevity, have only put changed files in below)

suite.rc
Fishing for red herrings, trying to debug the valid ROSE_ORIG_HOST variable…

#!Jinja2
[cylc]
    UTC mode = True  # Ignore DST

[scheduling]
    initial cycle point = 2019-05-01T00Z
    [[dependencies]]
        [[[R1]]]
        graph = foo => bar

[runtime]
    [[root]]
        # Debug: both of these ROSE_ORIG_HOST variants *should* work:
        # https://metomi.github.io/rose/doc/html/api/command-reference.html#command-rose-suite-run
        pre-script = """
            echo "Expect to see two lines below for current host"
            echo "{{ ROSE_ORIG_HOST }}"
            echo "${ROSE_ORIG_HOST}"
            """

        script = """
            echo "Hello from ${CYLC_TASK_ID}"
            echo "Task being run on host:$(hostname) by user:$USER"
            echo "Suite being run on host:${CYLC_SUITE_HOST} by user:${CYLC_SUITE_OWNER}"
            """

    [[CLUSTER_JOB]]
    # Family for "real" jobs, submitted to CLUSTER
        [[[job]]]
            batch system = slurm
            execution time limit = PT10M
        [[[directives]]]
            --mem = 1500
            --ntasks = 1
            # --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit

    [[LOCAL_JOB]]
    # Family for testing jobs, submitted to local machine
        [[[remote]]]
            # set current host (where "rose suite-run" cmd was invoked)
            host = {{ ROSE_ORIG_HOST }}
        [[[job]]]
            batch system = background

    [[foo]]
        # inherit = CLUSTER_JOB
        inherit = LOCAL_JOB

    [[bar]]
        inherit = LOCAL_JOB

Output
Despite my pre-script testing ROSE_ORIG_HOST earlier, I notice error quotes the same ROSE_ORIG_HOST Context lines as before?!

me@mycomp:> rose suite-run --validate-suite-only  #r125000
[INFO] export CYLC_VERSION=7.8.3
[INFO] export ROSE_ORIG_HOST=mycomp
[INFO] export ROSE_SITE=
[INFO] export ROSE_VERSION=2019.01.2
[INFO] create: log.20190720T000614Z
[INFO] symlink: log.20190720T000614Z <= log
[INFO] create: log/suite
[INFO] create: log/rose-conf
[INFO] symlink: rose-conf/20190720T010614-validate-suite-only.conf <= log/rose-suite-run.conf
[INFO] symlink: rose-conf/20190720T010614-validate-suite-only.version <= log/rose-suite-run.version
[INFO] install: rose-suite.info
[INFO]     source: /path/to/me/and/my/suite/mi-su173/rose-suite.info
[INFO] create: meta
[INFO] install: meta
[INFO]     source: /path/to/me/and/my/suite/mi-su173/meta
[INFO] install: suite.rc
[FAIL] cylc validate -o /var/tmp/tmpLCfmdM --debug --strict /var/tmp/tmpuHEvDt/cylc-run/mi-su173 # return-code=1, stderr=
[FAIL] 2019-07-20T01:06:14+01:00 DEBUG - Loading site/user global config files
[FAIL] 2019-07-20T01:06:14+01:00 DEBUG - Reading file /path/to/fcm/cylc-7.8.3/etc/global.rc
[FAIL] 2019-07-20T01:06:14+01:00 DEBUG - Reading file /path/to/me/.cylc/global.rc
[FAIL] 2019-07-20T01:06:14+01:00 DEBUG - Reading file /var/tmp/tmpuHEvDt/cylc-run/mi-su173/suite.rc
[FAIL] 2019-07-20T01:06:14+01:00 DEBUG - Processing with Jinja2
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 58, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]     # Family for testing jobs, submitted to local machine
[FAIL]         [[[remote]]]
[FAIL]             # set current host (where "rose suite-run" cmd was invoked)
[FAIL]             host = {{ ROSE_ORIG_HOST }}  <-- Jinja2Error
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] parsec.fileparse.FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 58, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]     # Family for testing jobs, submitted to local machine
[FAIL]         [[[remote]]]
[FAIL]             # set current host (where "rose suite-run" cmd was invoked)
[FAIL]             host = {{ ROSE_ORIG_HOST }}  <-- Jinja2Error


r125001, where I’ve finally spotted from error stacktrace that the UndefinedError refers to JOB_NAME, not the ROSE_ORIG_HOST in Context lines!
And hence worked out that commenting out lines with Jinja2 variables in suite.rc does not mean these get ignored in Jinja2 preprocessing!
Jinja2 variables still need defining (e.g. in rose-suite.conf), or the commented line in suite.rc needs removing

rose-suite.conf
I’ve uncommented the JOB_NAME variable, so it’s available for Jinja2 preprocessing of suite.rc

# Set run directory (for cylc-run) to $HOME
root-dir=*=$HOME

[jinja2:suite.rc]
# Put any Jinja settings for suite.rc here

# job name for auditing on CLUSTER
# TODO: remove this, as NOT needed: cylc/rose provides this
JOB_NAME = "project_subproject"

Output
Validation passes, now JOB_NAME Jinja2 variable is available, and can be swapped into commented line in suite.rc in preprocessing step

me@mycomp:> rose suite-run --validate-suite-only  #r125001
[INFO] export CYLC_VERSION=7.8.3
[INFO] export ROSE_ORIG_HOST=mycomp
[INFO] export ROSE_SITE=
[INFO] export ROSE_VERSION=2019.01.2
[INFO] create: log.20190720T002059Z
[INFO] symlink: log.20190720T002059Z <= log
[INFO] create: log/suite
[INFO] create: log/rose-conf
[INFO] symlink: rose-conf/20190720T012059-validate-suite-only.conf <= log/rose-suite-run.conf
[INFO] symlink: rose-conf/20190720T012059-validate-suite-only.version <= log/rose-suite-run.version
[INFO] install: rose-suite.info
[INFO]     source: /path/to/me/and/my/suite/mi-su173/rose-suite.info
[INFO] create: meta
[INFO] install: meta
[INFO]     source: /path/to/me/and/my/suite/mi-su173/meta
[INFO] install: suite.rc
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Loading site/user global config files
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Reading file /path/to/fcm/cylc-7.8.3/etc/global.rc
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Reading file /path/to/me/.cylc/global.rc
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Reading file /var/tmp/tmpHEfoln/cylc-run/mi-su173/suite.rc
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Processing with Jinja2
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Processed configuration dumped: /var/tmp/tmp9ETpQh
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Section already encountered: [cylc]
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Expanding [runtime] namespace lists and parameters
[INFO] 2019-07-20T01:21:00+01:00 DEBUG - Parsing the runtime namespace hierarchy
[INFO] 2019-07-20T00:21:00Z DEBUG - Parsing [special tasks]
[INFO] 2019-07-20T00:21:00Z DEBUG - Parsing the dependency graph
[INFO] 2019-07-20T00:21:00Z DEBUG - Configuring internal queues


r125002, for completeness, demonstrating bug has some dependence on where Jinja2 variables occur
Here, where buggy line is the last Jinja2 variable, the Context lines correctly identify the issue

rose-suite.conf
Reimplementing bug, by commenting out JOB_NAME again

# Set run directory (for cylc-run) to $HOME
root-dir=*=$HOME

[jinja2:suite.rc]
# Put any Jinja settings for suite.rc here

# job name for auditing on CLUSTER
# TODO: remove this, as NOT needed: cylc/rose provides this
# JOB_NAME = "project_subproject"

suite.rc
Changing family order, so one with bug in it represents last Jinja2 variable present

#!Jinja2
[cylc]
    UTC mode = True  # Ignore DST

[scheduling]
    initial cycle point = 2019-05-01T00Z
    [[dependencies]]
        [[[R1]]]
        graph = foo => bar

[runtime]
    [[root]]
        # Debug: both of these ROSE_ORIG_HOST variants *should* work:
        # https://metomi.github.io/rose/doc/html/api/command-reference.html#command-rose-suite-run
        pre-script = """
            echo "Expect to see two lines below for current host"
            echo "{{ ROSE_ORIG_HOST }}"
            echo "${ROSE_ORIG_HOST}"
            """

        script = """
            echo "Hello from ${CYLC_TASK_ID}"
            echo "Task being run on host:$(hostname) by user:$USER"
            echo "Suite being run on host:${CYLC_SUITE_HOST} by user:${CYLC_SUITE_OWNER}"
            """

    [[LOCAL_JOB]]
    # Family for testing jobs, submitted to local machine
        [[[remote]]]
            # set current host (where "rose suite-run" cmd was invoked)
            host = {{ ROSE_ORIG_HOST }}
        [[[job]]]
            batch system = background

    [[CLUSTER_JOB]]
    # Family for "real" jobs, submitted to CLUSTER
        [[[job]]]
            batch system = slurm
            execution time limit = PT10M
        [[[directives]]]
            --mem = 1500
            --ntasks = 1
            # --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit

    [[foo]]
        # inherit = CLUSTER_JOB
        inherit = LOCAL_JOB

    [[bar]]
        inherit = LOCAL_JOB

Output
Bug present again, but changing order of Jinja2 variables in suite.rc means Context lines now correctly identify the bug :slight_smile:

me@mycomp:> rose suite-run --validate-suite-only  #r125002
[INFO] export CYLC_VERSION=7.8.3
[INFO] export ROSE_ORIG_HOST=mycomp
[INFO] export ROSE_SITE=
[INFO] export ROSE_VERSION=2019.01.2
[INFO] create: log.20190720T003159Z
[INFO] symlink: log.20190720T003159Z <= log
[INFO] create: log/suite
[INFO] create: log/rose-conf
[INFO] symlink: rose-conf/20190720T013159-validate-suite-only.conf <= log/rose-suite-run.conf
[INFO] symlink: rose-conf/20190720T013159-validate-suite-only.version <= log/rose-suite-run.version
[INFO] install: rose-suite.info
[INFO]     source: /path/to/me/and/my/suite/mi-su173/rose-suite.info
[INFO] create: meta
[INFO] install: meta
[INFO]     source: /path/to/me/and/my/suite/mi-su173/meta
[INFO] install: suite.rc
[FAIL] cylc validate -o /var/tmp/tmpEL2ppY --debug --strict /var/tmp/tmpwVE_gs/cylc-run/mi-su173 # return-code=1, stderr=
[FAIL] 2019-07-20T01:31:59+01:00 DEBUG - Loading site/user global config files
[FAIL] 2019-07-20T01:31:59+01:00 DEBUG - Reading file /path/to/fcm/cylc-7.8.3/etc/global.rc
[FAIL] 2019-07-20T01:31:59+01:00 DEBUG - Reading file /path/to/me/.cylc/global.rc
[FAIL] 2019-07-20T01:31:59+01:00 DEBUG - Reading file /var/tmp/tmpwVE_gs/cylc-run/mi-su173/suite.rc
[FAIL] 2019-07-20T01:31:59+01:00 DEBUG - Processing with Jinja2
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 60, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]         [[[directives]]]
[FAIL]             --mem = 1500
[FAIL]             --ntasks = 1
[FAIL]             # --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit <-- Jinja2Error
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] parsec.fileparse.FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 60, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]         [[[directives]]]
[FAIL]             --mem = 1500
[FAIL]             --ntasks = 1
[FAIL]             # --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit <-- Jinja2Error

Afterthought: oh, and just 2 extra variants to demonstrate that this “bug” is not simply due to the fact that the “buggy” line in suite.rc was commented out.
These variants show the “buggy” behaviour reported above still holds even if the “buggy” line is uncommented
(Possibly obvious, given root source of error was me not realising Jinja2 preprocessing does not take into account whether or not suite.rc lines containing Jinja2 variables are commented)



r125020, a variant on r125000, uncommenting the “buggy” wckey line
The Context lines still quote incorrectly, giving context lines for the wrong Jinja2 variable (ROSE_ORIG_HOST, which is fine), not the Jinja2 variable (JOB_NAME) which is the source of the error reported just above in traceback.

suite.rc
Have simply uncommented the previously-commented line using JOB_NAME, which itself is still commented out in rose-suite.conf

me@mycomp:> fcm diff -r 125000
Index: suite.rc
===================================================================
--- suite.rc    (revision 125000)
+++ suite.rc    (working copy)
@@ -32,7 +32,7 @@
         [[[directives]]]
             --mem = 1500
             --ntasks = 1
-            # --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit
+            --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit

     [[LOCAL_JOB]]
     # Family for testing jobs, submitted to local machine

Output
I still get the same “buggy” behaviour as when the “buggy” line was commented: the Context lines still quote incorrectly.
I.e. whether or not the line is commented seems to be irrelevant to the “bug”

me@mycomp:> rose suite-run --validate-suite-only  #r125020
[INFO] export CYLC_VERSION=7.8.3
[INFO] export ROSE_ORIG_HOST=mycomp
[INFO] export ROSE_SITE=
[INFO] export ROSE_VERSION=2019.01.2
[INFO] create: log.20190721T101652Z
[INFO] symlink: log.20190721T101652Z <= log
[INFO] create: log/suite
[INFO] create: log/rose-conf
[INFO] symlink: rose-conf/20190721T111652-validate-suite-only.conf <= log/rose-suite-run.conf
[INFO] symlink: rose-conf/20190721T111652-validate-suite-only.version <= log/rose-suite-run.version
[INFO] install: rose-suite.info
[INFO]     source: /path/to/me/and/my/suite/mi-su173/rose-suite.info
[INFO] create: meta
[INFO] install: meta
[INFO]     source: /path/to/me/and/my/suite/mi-su173/meta
[INFO] install: suite.rc
[FAIL] cylc validate -o /var/tmp/tmpYOXvIs --debug --strict /var/tmp/tmphSmX5O/cylc-run/mi-su173 # return-code=1, stderr=
[FAIL] 2019-07-21T11:16:53+01:00 DEBUG - Loading site/user global config files
[FAIL] 2019-07-21T11:16:53+01:00 DEBUG - Reading file /path/to/fcm/cylc-7.8.3/etc/global.rc
[FAIL] 2019-07-21T11:16:53+01:00 DEBUG - Reading file /path/to/me/.cylc/global.rc
[FAIL] 2019-07-21T11:16:53+01:00 DEBUG - Reading file /var/tmp/tmphSmX5O/cylc-run/mi-su173/suite.rc
[FAIL] 2019-07-21T11:16:53+01:00 DEBUG - Processing with Jinja2
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 58, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]     # Family for testing jobs, submitted to local machine
[FAIL]         [[[remote]]]
[FAIL]             # set current host (where "rose suite-run" cmd was invoked)
[FAIL]             host = {{ ROSE_ORIG_HOST }}  <-- Jinja2Error
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] parsec.fileparse.FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 58, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]     # Family for testing jobs, submitted to local machine
[FAIL]         [[[remote]]]
[FAIL]             # set current host (where "rose suite-run" cmd was invoked)
[FAIL]             host = {{ ROSE_ORIG_HOST }}  <-- Jinja2Error


r125021, a variant on r125002 (buggy Jinja2 line occurs last), where buggy line is uncommented.
As with r125002, the Context lines now quote correctly, giving context lines for the correct Jinja2 variable (JOB_NAME) which is the source of the error reported just above in traceback.

suite.rc
Again have just uncommented the previously-commented line using JOB_NAME, which itself is still commented out in rose-suite.conf

me@mycomp:> fcm diff -r 125002
Index: suite.rc
===================================================================
--- suite.rc    (revision 125002)
+++ suite.rc    (working copy)
@@ -40,7 +40,7 @@
         [[[directives]]]
             --mem = 1500
             --ntasks = 1
-            # --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit
+            --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit

     [[foo]]
         # inherit = CLUSTER_JOB

Output
As with r125002, the fact that the “buggy” line is the last Jinja2 variable seems to make a difference: the Context lines again now correctly identify the source of the error

me@mycomp:> rose suite-run --validate-suite-only  #r125021
[INFO] export CYLC_VERSION=7.8.3
[INFO] export ROSE_ORIG_HOST=mycomp
[INFO] export ROSE_SITE=
[INFO] export ROSE_VERSION=2019.01.2
[INFO] create: log.20190721T104330Z
[INFO] symlink: log.20190721T104330Z <= log
[INFO] create: log/suite
[INFO] create: log/rose-conf
[INFO] symlink: rose-conf/20190721T114330-validate-suite-only.conf <= log/rose-suite-run.conf
[INFO] symlink: rose-conf/20190721T114330-validate-suite-only.version <= log/rose-suite-run.version
[INFO] install: rose-suite.info
[INFO]     source: /path/to/me/and/my/suite/mi-su173/rose-suite.info
[INFO] create: meta
[INFO] install: meta
[INFO]     source: /path/to/me/and/my/suite/mi-su173/meta
[INFO] install: suite.rc
[FAIL] cylc validate -o /var/tmp/tmp4ULgL0 --debug --strict /var/tmp/tmpjmUDf1/cylc-run/mi-su173 # return-code=1, stderr=
[FAIL] 2019-07-21T11:43:31+01:00 DEBUG - Loading site/user global config files
[FAIL] 2019-07-21T11:43:31+01:00 DEBUG - Reading file /path/to/fcm/cylc-7.8.3/etc/global.rc
[FAIL] 2019-07-21T11:43:31+01:00 DEBUG - Reading file /path/to/me/.cylc/global.rc
[FAIL] 2019-07-21T11:43:31+01:00 DEBUG - Reading file /var/tmp/tmpjmUDf1/cylc-run/mi-su173/suite.rc
[FAIL] 2019-07-21T11:43:31+01:00 DEBUG - Processing with Jinja2
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 60, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]         [[[directives]]]
[FAIL]             --mem = 1500
[FAIL]             --ntasks = 1
[FAIL]             --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit   <-- Jinja2Error
[FAIL] Traceback (most recent call last):
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 153, in <module>
[FAIL]     main()
[FAIL]   File "/path/to/fcm/cylc-7.8.3/bin/cylc-validate", line 90, in main
[FAIL]     output_fname=options.output, mem_log_func=profiler.log_memory)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/config.py", line 198, in __init__
[FAIL]     self.pcfg = RawSuiteConfig(fpath, output_fname, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/cylc/cfgspec/suite.py", line 395, in __init__
[FAIL]     self.loadcfg(fpath, "suite definition")
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/config.py", line 73, in loadcfg
[FAIL]     sparse = parse(rcfile, self.output_fname, self.tvars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 336, in parse
[FAIL]     flines = read_and_proc(fpath, template_vars)
[FAIL]   File "/path/to/fcm/cylc-7.8.3/lib/parsec/fileparse.py", line 322, in read_and_proc
[FAIL]     msg, lines=lines, error_name="Jinja2Error")
[FAIL] parsec.fileparse.FileParseError: Jinja2Error:
[FAIL]   File "<template>", line 60, in top-level template code
[FAIL] UndefinedError: 'JOB_NAME' is undefined
[FAIL] Context lines:
[FAIL]         [[[directives]]]
[FAIL]             --mem = 1500
[FAIL]             --ntasks = 1
[FAIL]             --wckey = {{ JOB_NAME }}  # CLUSTER workload key for audit   <-- Jinja2Error

Hi,

I wonder if this could be an occurrence of https://github.com/cylc/cylc-flow/issues/2572, where Jinja2 gets confused when there is an undefined variable mixed with other variables?

Cheers
Bruno

1 Like

Good spotting @kinow - this does indeed look like the same issue.

In which case @edmundh - your problem is due to a Jinja2 bug (reported back in Nov 2013!), not a Cylc bug. But I see @kinow has just proposed a fix on the Jinja2 repository - so watch this space!

1 Like