Environment variables are templated?

[bretmartin]

Issue Type:

• Bug Report

Ansible Version:

ansible 2.0.0 (devel 2761df232e) last updated 2015/09/01 15:04:26 (GMT -400)
  lib/ansible/modules/core: (detached HEAD bbcfb1092a) last updated 2015/09/01 15:04:54 (GMT -400)
  lib/ansible/modules/extras: (detached HEAD b8803306d1) last updated 2015/09/01 15:04:37 (GMT -400)
  config file = 
  configured module search path = None

Ansible Configuration:

No config file found; using defaults

Environment:

N/A but running on Mac OS X

Summary:

I get ERROR! template error while templating string: unexpected '|' when trying to use a jinja2 filter.

Steps To Reproduce:

roles/test/tasks/main.yml:

---

- debug: msg='{{ foo | default("baz") }}'

Expected Results:

Successful playbook execution, in this case just printing "baz"

Actual Results:

ansible-playbook --vault-password-file=~/.ansible_vault_password \
        playbook-test.yml --limit=localhost -vvvv
No config file found; using defaults
1 plays in playbook-test.yml
Loaded callback default of type stdout, v2.0

PLAY ***************************************************************************

TASK [setup] *******************************************************************
Module: setup, args: {}
ESTABLISH LOCAL CONNECTION FOR USER: bam
localhost EXEC (umask 22 && mkdir -p "$HOME/.ansible/tmp/ansible-tmp-1441134514.32-237346662021616" && echo "$HOME/.ansible/tmp/ansible-tmp-1441134514.32-237346662021616")
localhost PUT /var/folders/n7/wrg1c7615892m2qgyv8r_yg00000gn/T/tmpYZmtsC TO /Users/bam/.ansible/tmp/ansible-tmp-1441134514.32-237346662021616/setup
localhost EXEC LANG=en_US.UTF-8 LC_MESSAGES=en_US.UTF-8 LC_CTYPE=en_US.UTF-8 /usr/bin/python /Users/bam/.ansible/tmp/ansible-tmp-1441134514.32-237346662021616/setup; rm -rf "/Users/bam/.ansible/tmp/ansible-tmp-1441134514.32-237346662021616/" > /dev/null 2>&1
ok: [localhost]
ERROR! template error while templating string: unexpected '|'
make: *** [test] Error 1

[bretmartin]

After testing further, it appears I get the unexpected '|' on any tasks now, so maybe this has nothing to do with jinja2... let me see if I can narrow this down

[bretmartin]

I git bisected this down to af06a97 -- not sure I get how that change could cause this though

[sivel]

I cannot duplicate this issue.

The only way that I can get that is to have a task with {{|}} in it. What is the output of the ansible command with --list-tasks? That first non-meta task is likely the one causing the issue.

[bretmartin]

Thanks for having a look, @sivel. I currently have this happening with no | in the task and here's what --list-tasks shows me. Still trying to characterize this better -- I realize this must be something obscure since clearly this isn't affecting everyone else, since the commit I narrowed it down to is a week+ old.

% ANSIBLE_INVENTORY=inventory ansible-playbook playbook-test.yml --limit=localhost --list-tasks

playbook: playbook-test.yml

  PLAY: #1
    tasks:
      TASK: meta
      TASK: test : debug msg=blah
      TASK: meta
      TASK: meta

[jimi-c]

This could maybe be caused by some data with a | in it being fed back through the template engine. Is the variable in the above real-world example coming from a local fact on the system?

[bretmartin]

foo is undefined in the example.

[bretmartin]

Should I update the top comment? This turns out to happen for me without | anywhere in the task definition

[bretmartin]

@jimi-c, you pointed me in the right direction. I have some environment variables set that appear to be impacting this -- looks like they're being template-expanded. More info coming

[bretmartin]

Got it. If I unset these three environment variables, the problem goes away:

RPROMPT='[022] %B%w %D{%b} %@%b'
RPS1='[022] %B%w %D{%b} %@%b'
TERMCAP='SC|screen|VT 100/ANSI X3.64 virtual terminal:\
        :DO=\E[%dB:LE=\E[%dD:RI=\E[%dC:UP=\E[%dA:bs:bt=\E[Z:\
        :cd=\E[J:ce=\E[K:cl=\E[H\E[J:cm=\E[%i%d;%dH:ct=\E[3g:\
        :do=^J:nd=\E[C:pt:rc=\E8:rs=\Ec:sc=\E7:st=\EH:up=\EM:\
        :le=^H:bl=^G:cr=^M:it#8:ho=\E[H:nw=\EE:ta=^I:is=\E)0:\
        :li#45:co#80:am:xn:xv:LP:sr=\EM:al=\E[L:AL=\E[%dL:\
        :cs=\E[%i%d;%dr:dl=\E[M:DL=\E[%dM:dc=\E[P:DC=\E[%dP:\
        :im=\E[4h:ei=\E[4l:mi:IC=\E[%d@:ks=\E[?1h\E=:\
        :ke=\E[?1l\E>:vi=\E[?25l:ve=\E[34h\E[?25h:vs=\E[34l:\
        :ti=\E[?1049h:te=\E[?1049l:us=\E[4m:ue=\E[24m:so=\E[3m:\
        :se=\E[23m:mb=\E[5m:md=\E[1m:mr=\E[7m:me=\E[m:ms:\
        :Co#8:pa#64:AF=\E[3%dm:AB=\E[4%dm:op=\E[39;49m:AX:\
        :vb=\Eg:G0:as=\E(0:ae=\E(B:\
        :ac=\140\140aaffggjjkkllmmnnooppqqrrssttuuvvwwxxyyzz{{||}}~~..--++,,hhII00:\
        :po=\E[5i:pf=\E[4i:k0=\E[10~:k1=\EOP:k2=\EOQ:k3=\EOR:\
        :k4=\EOS:k5=\E[15~:k6=\E[17~:k7=\E[18~:k8=\E[19~:\
        :k9=\E[20~:k;=\E[21~:F1=\E[23~:F2=\E[24~:F3=\E[1;2P:\
        :F4=\E[1;2Q:F5=\E[1;2R:F6=\E[1;2S:F7=\E[15;2~:\
        :F8=\E[17;2~:F9=\E[18;2~:FA=\E[19;2~:kb=^H:K2=\EOE:\
        :kB=\E[Z:kF=\E[1;2B:kR=\E[1;2A:*4=\E[3;2~:*7=\E[1;2F:\
        :#2=\E[1;2H:#3=\E[2;2~:#4=\E[1;2D:%c=\E[6;2~:%e=\E[5;2~:\
        :%i=\E[1;2C:kh=\E[1~:@1=\E[1~:kH=\E[4~:@7=\E[4~:\
        :kN=\E[6~:kP=\E[5~:kI=\E[2~:kD=\E[3~:ku=\EOA:kd=\EOB:\
        :kr=\EOC:kl=\EOD:km:'

[jimi-c]

So the question is, how are those ending up in the template engine?

[jimi-c]

This doesn't trigger it for me:

# FOO="{{|}}" ansible-playbook -vv test1.yml 
Using /etc/ansible/ansible.cfg as config file
1 plays in test1.yml
PLAY ***************************************************************************
TASK [debug msg=here i am] *****************************************************
ok: [awxlocal] => {
    "changed": false, 
    "msg": "here i am"
}
PLAY RECAP *********************************************************************
awxlocal                   : ok=1    changed=0    unreachable=0    failed=0   

[bretmartin]

I think it only happens with local -- does awxlocal have ansible_connection=local specified in your test scenario?

[bretmartin]

If you're going to awxlocal over SSH, then the environment variable isn't set at the remote end, I think.

[jimi-c]

Just to update here, discussing in IRC too and using local inventory and/or ANSIBLE_INVENTORY=inventory did not work either.

[bretmartin]

Hmm, I just noticed my output, when I work around this, includes

TASK [setup] *******************************************************************
ok: [localhost]

after the PLAY line and before the first "real" TASK line. But yours doesn't above, @jimi-c. Is this a hint?

[bretmartin]

Is it possible you have gather_facts: False set?

[jimi-c]

@bretmartin I've just pushed up the above feature branch, if you'd like to give it a test. This essentially creates a wrapper class which sets an attribute for the Templar to signify something shouldn't be templated. Anything coming from the FactCache class will be wrapped with this, meaning we no longer need to introspect values coming from facts.

[jimi-c]

Testing:

# cat test1.yml 
- hosts: all
  gather_facts: yes
  vars:
    foo: "{{lookup('env', 'FOO')}}"
  tasks:
  - debug: msg="here i am {{foo}}"
# FOO="{{|}}" ansible-playbook -vv test1.yml -i inventory 
Using /etc/ansible/ansible.cfg as config file
1 plays in test1.yml
PLAY ***************************************************************************
TASK [setup] *******************************************************************
ok: [localhost]
TASK [debug msg=here i am {{foo}}] *********************************************
ok: [localhost] => {
    "changed": false, 
    "msg": "here i am {{|}}"
}
PLAY RECAP *********************************************************************
localhost                  : ok=2    changed=0    unreachable=0    failed=0   

[bretmartin]

@jimi-c I can report that this fixes the issue for me in my local testing. Thanks -- this looks like it was quite a bit of work. Does it at least make sense that af06a97 changed the behavior from working to broken, in the context of the changes you made?

[jimi-c]

I believe this would have happened regardless of that commit, as the problem lies in the slightly different (and really, better) way that we do variables via hostvars. Before, in v1, facts were searched for jinja2 constructs like {%%} and {{}} and turned into comments to avoid this, but that was slow when the output from the module was large.