Orchestrate runner crashes trying to parse highstate output

[ipmb]

Description of Issue/Question

When running an state.orchestrate, it crashes at the end of the run with this Traceback:

IndexError: list index out of range
Traceback (most recent call last):
  File "/usr/bin/salt-run", line 10, in <module>
    salt_run()
  File "/usr/lib/python2.7/dist-packages/salt/scripts.py", line 403, in salt_run
    client.run()
  File "/usr/lib/python2.7/dist-packages/salt/cli/run.py", line 41, in run
    ret = runner.run()
  File "/usr/lib/python2.7/dist-packages/salt/runner.py", line 266, in run
    daemonize=False)
  File "/usr/lib/python2.7/dist-packages/salt/client/mixins.py", line 467, in _proc_function
    return self.low(fun, low, full_return=False)
  File "/usr/lib/python2.7/dist-packages/salt/client/mixins.py", line 256, in low
    return self._low(fun, low, print_event=print_event, full_return=full_return)
  File "/usr/lib/python2.7/dist-packages/salt/client/mixins.py", line 416, in _low
    namespaced_event.fire_event(data, 'ret')
  File "/usr/lib/python2.7/dist-packages/salt/utils/event.py", line 920, in fire_event
    self.print_func(tag, data)
  File "/usr/lib/python2.7/dist-packages/salt/client/mixins.py", line 545, in print_async_event
    salt.output.display_output(event_data, outputter, self.opts)
  File "/usr/lib/python2.7/dist-packages/salt/output/__init__.py", line 92, in display_output
    display_data = try_printout(data, out, opts, **kwargs)
  File "/usr/lib/python2.7/dist-packages/salt/output/__init__.py", line 39, in try_printout
    printout = get_printout(out, opts)(data, **kwargs)
  File "/usr/lib/python2.7/dist-packages/salt/output/highstate.py", line 145, in output
    for host, hostdata in six.iteritems(data)
  File "/usr/lib/python2.7/dist-packages/salt/output/highstate.py", line 222, in _format_host
    schanged, ctext = _format_changes(ret['changes'], orchestration)
  File "/usr/lib/python2.7/dist-packages/salt/output/highstate.py", line 522, in _format_changes
    s, c = _format_host(host, hostdata)
  File "/usr/lib/python2.7/dist-packages/salt/output/highstate.py", line 313, in _format_host
    if comps[1] != comps[2]:
IndexError: list index out of range

I narrowed the source down to this state:

{{ test_host }}:
  salt.function:
    - name: cloud.profile
    - tgt: {{ master }}
    - kwarg:
        profile: lxc_test
        names:
          - {{ test_host }}
        config_dir: /etc/salt

Its tname in the highstate outputter is just the value of the variable test_host, so comps is just a single item list. Here is the relevant output from that state during a run:

[INFO    ] Running state [cloud.profile] at time 16:57:24.445419
[INFO    ] Executing state salt.function for [cloud.profile]
[DEBUG   ] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
[DEBUG   ] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
[DEBUG   ] Initializing new IPCClient for path: /var/run/salt/master/master_event_pull.ipc
[DEBUG   ] Sending event: tag = salt/run/20180205165438108435/args; data = {'_stamp': '2018-02-05T21:57:24.446851', 'args': {'tgt_type': 'glob', 'ret': '', '_cmd_meta': True, 'kwarg': OrderedDict([('profile', 'lxc_test'), ('names', ['master.test.domain.internal']), ('config_dir', '/etc/salt')]), 'ssh': False, 'timeout': None, 'arg': [], 'expect_minions': False}, 'type': 'function', 'name': 'cloud.profile', 'tgt': 'salt.domain.internal'}
[DEBUG   ] Reading configuration from /etc/salt/master
[DEBUG   ] Including configuration from '/etc/salt/master.d/custom.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/custom.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/reactor.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/reactor.conf
[DEBUG   ] Using cached minion ID from /etc/salt/minion_id: salt.domain.internal
[DEBUG   ] Missing configuration file: /home/pete/.saltrc
[DEBUG   ] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
[DEBUG   ] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/master', 'salt.domain.internal_master', 'tcp://127.0.0.1:4506', 'clear')
[DEBUG   ] Initializing new IPCClient for path: /var/run/salt/master/master_event_pub.ipc
[DEBUG   ] LazyLoaded local_cache.get_load
[DEBUG   ] Reading minion list from /var/cache/salt/master/jobs/8d/8e6dbba4b6732d43c8fe9331978ce5b9c095c5cf88f26ff624999cba984789/.minions.p
[DEBUG   ] get_iter_returns for jid 20180205165724512730 sent to set(['salt.domain.internal']) will timeout at 16:57:34.532774
...
[DEBUG   ] jid 20180205165724512730 return from salt.domain.internal
[DEBUG   ] jid 20180205165724512730 found all minions set(['salt.domain.internal'])
[INFO    ] {'ret': {'salt.domain.internal': {'master.test.domain.internal': {'comment': '', 'runner_return': {'comment': '', 'errors': {'test.domain.internal': {'master.test.domain.internal': []}}, 'test.domain.internal': [{'comment': "Container 'master.test.domain.internal' successfully initialized", 'changes': {'init': [{'create': 'Container created'}, {'config': 'Container configuration updated'}, {'password': 'Password(s) updated'}, {'dns': 'DNS updated'}, {'bootstrap': 'Container successfully bootstrapped'}, {'state': {'new': 'running', 'old': None}}]}, 'result': True, 'name': 'master.test.domain.internal', 'container_name': 'master.test.domain.internal'}], 'ping_status': True, 'done': [{'comment': "Container 'master.test.domain.internal' successfully initialized", 'changes': {'init': [{'create': 'Container created'}, {'config': 'Container configuration updated'}, {'password': 'Password(s) updated'}, {'dns': 'DNS updated'}, {'bootstrap': 'Container successfully bootstrapped'}, {'state': {'new': 'running', 'old': None}}]}, 'result': True, 'name': 'master.test.domain.internal', 'container_name': 'master.test.domain.internal'}], 'result': True}, 'changes': {'created': 'created'}, 'name': 'master.test.domain.internal', 'result': True}}}, 'out': 'highstate'}
[INFO    ] Completed state [cloud.profile] at time 16:59:02.882608 duration_in_ms=98437.188

Versions Report

I see this in both 2016.11 and 2017.7

Salt Version:
           Salt: 2017.7.2

Dependency Versions:
           cffi: Not Installed
       cherrypy: Not Installed
       dateutil: 2.4.0
      docker-py: Not Installed
          gitdb: 2.0.3
      gitpython: 2.1.8
          ioflo: Not Installed
         Jinja2: 2.7.2
        libgit2: Not Installed
        libnacl: Not Installed
       M2Crypto: 0.21.1
           Mako: 0.9.1
   msgpack-pure: Not Installed
 msgpack-python: 0.3.0
   mysql-python: 1.2.3
      pycparser: Not Installed
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: Not Installed
         Python: 2.7.6 (default, Nov 23 2017, 15:49:48)
   python-gnupg: 0.3.6
         PyYAML: 3.10
          PyZMQ: 14.0.1
           RAET: Not Installed
          smmap: 2.0.3
        timelib: Not Installed
        Tornado: 4.2.1
            ZMQ: 4.0.4

System Versions:
           dist: Ubuntu 14.04 trusty
         locale: UTF-8
        machine: x86_64
        release: 3.13.0-123-generic
         system: Linux
        version: Ubuntu 14.04 trusty

[garethgreenaway]

@ipmb Thanks for the report. Definitely looks like a bug and looks like we should be checking that the comps list is at least 2 elements deep before the comparison.

[ipmb]

@gtmanfred

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

If this issue is closed prematurely, please leave a comment and we will gladly reopen the issue.

[ipmb]

not stale

[stale[bot]]

Thank you for updating this issue. It is no longer marked as stale.