salt [BUG] "TypeError: string indices must be integers" when running initial "state.apply" with "--out=profile"

Description Because an initial state.apply took quite a while, I took the liberty to use the tip provided by 1 to list out a profile. That however results in this exception:

`salt 'xt*' state.apply --state-output=changes --out=profile`

root@saltmaster:/home/vagrant# salt 'xt*' state.apply --state-output=changes --out=profile
[ERROR   ] Nested output failed: 
Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 36, in try_printout
    printout = get_printout(out, opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 42, in try_printout
    printout = get_printout("nested", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers
[ERROR   ] An un-handled exception was caught by Salt's global exception handler:
TypeError: string indices must be integers
Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 36, in try_printout
    printout = get_printout(out, opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 42, in try_printout
    printout = get_printout("nested", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/salt", line 11, in <module>
    sys.exit(salt_main())
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 533, in salt_main
    client.run()
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/salt.py", line 198, in run
    self._output_ret(ret_, out, retcode=retcode)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/salt.py", line 399, in _output_ret
    salt.output.display_output(ret, out=out, opts=self.config, _retcode=retcode)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 88, in display_output
    display_data = try_printout(data, out, opts, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 47, in try_printout
    printout = get_printout("raw", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers
Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 36, in try_printout
    printout = get_printout(out, opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 42, in try_printout
    printout = get_printout("nested", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/salt", line 11, in <module>
    sys.exit(salt_main())
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 533, in salt_main
    client.run()
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/salt.py", line 198, in run
    self._output_ret(ret_, out, retcode=retcode)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/salt.py", line 399, in _output_ret
    salt.output.display_output(ret, out=out, opts=self.config, _retcode=retcode)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 88, in display_output
    display_data = try_printout(data, out, opts, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 47, in try_printout
    printout = get_printout("raw", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

When I run my state.apply after this initial failure. All goes well. So both the state.apply runs fine and the profile table is printed.

Setup (Please provide relevant configs and/or SLS files (be sure to remove sensitive info. There is no general set-up of Salt.)

Please be as specific as possible and give set-up details.

[ ] on-prem machine
[x] VM Vagrant using libvirt (i.e. KVM)
[ ] VM running on a cloud service, please be explicit and add details
[ ] container (Kubernetes, Docker, containerd, etc. please specify)
[ ] jails if it is FreeBSD
[ ] classic packaging
[x] onedir packaging
[ ] used bootstrap to install

Steps to Reproduce the behavior Do an initial state.apply that takes quite a while (i.e. >5 minutes).

Expected behavior The state.apply does its things and afterwards a profile table is shown.

Versions Report

`salt --versions-report`

(Provided by running salt --versions-report. Please also mention any differences in master/minion versions.)

salt --versions-report
Salt Version:
          Salt: 3006.1
 
Python Version:
        Python: 3.10.11 (main, May  5 2023, 02:31:54) [GCC 11.2.0]
 
Dependency Versions:
          cffi: 1.14.6
      cherrypy: unknown
      dateutil: 2.8.1
     docker-py: Not Installed
         gitdb: Not Installed
     gitpython: Not Installed
        Jinja2: 3.1.2
       libgit2: Not Installed
  looseversion: 1.0.2
      M2Crypto: Not Installed
          Mako: Not Installed
       msgpack: 1.0.2
  msgpack-pure: Not Installed
  mysql-python: Not Installed
     packaging: 22.0
     pycparser: 2.21
      pycrypto: Not Installed
  pycryptodome: 3.9.8
        pygit2: Not Installed
  python-gnupg: 0.4.8
        PyYAML: 5.4.1
         PyZMQ: 23.2.0
        relenv: 0.12.3
         smmap: Not Installed
       timelib: 0.2.4
       Tornado: 4.5.3
           ZMQ: 4.3.4
 
System Versions:
          dist: ubuntu 20.04.5 focal
        locale: utf-8
       machine: x86_64
       release: 5.4.0-125-generic
        system: Linux
       version: Ubuntu 20.04.5 focal

Additional context As mentioned, running state.apply a second time, does not result in the exception.

Sep 04 '23 07:09 hvt

Hi there! Welcome to the Salt Community! Thank you for making your first contribution. We have a lengthy process for issues and PRs. Someone from the Core Team will follow up as soon as possible. In the meantime, here’s some information that may help as you continue your Salt journey. Please be sure to review our Code of Conduct. Also, check out some of our community resources including:

There are lots of ways to get involved in our community. Every month, there are around a dozen opportunities to meet with other contributors and the Salt Core team and collaborate in real time. The best way to keep track is by subscribing to the Salt Community Events Calendar. If you have additional questions, email us at [email protected]. We’re glad you’ve joined our community and look forward to doing awesome things with you!

Sep 04 '23 07:09 welcome[bot]

weird, I can't replicate. which isn't surprising since you say it happens once then works the next time.

I'm wondering if you can capture the event bus when it happens. see what the events being returned look like.

Sep 05 '23 02:09 whytewolf

I will try again with a fresh VM tomorrow.

Could it be the mixing up of --out=profile & --state-output=changes? Or shouldn't that be a problem?

Sep 05 '23 11:09 hvt

No, I thought it was that at first. but i tried it that way several times and still didn't hit the problem.

Sep 05 '23 15:09 whytewolf

Don't know if I did this correctly. I ran https://github.com/saltstack/salt/blob/master/tests/eventlisten.py on the master, and this was the output once I ran salt 'xt*' state.apply --state-output=changes --out=profile:

root@saltmaster:~# /opt/saltstack/salt/bin/python3 eventlisten.py
/var/run/salt/master/master_event_pub.ipc
Event fired at Wed Sep  6 05:40:18 2023
*************************
Tag: 20230906054018663898
Data:
{'_stamp': '2023-09-06T05:40:18.664087', 'minions': ['xt01.rsv.envdev.test']}
Event fired at Wed Sep  6 05:40:18 2023
*************************
Tag: salt/job/20230906054018663898/new
Data:
{'_stamp': '2023-09-06T05:40:18.665779',
 'arg': [],
 'fun': 'state.apply',
 'jid': '20230906054018663898',
 'minions': ['xt01.rsv.envdev.test'],
 'missing': [],
 'tgt': 'xt*',
 'tgt_type': 'glob',
 'user': 'sudo_vagrant'}
Event fired at Wed Sep  6 05:40:23 2023
*************************
Tag: 20230906054023778531
Data:
{'_stamp': '2023-09-06T05:40:23.779534', 'minions': ['xt01.rsv.envdev.test']}
Event fired at Wed Sep  6 05:40:23 2023
*************************
Tag: salt/job/20230906054023778531/new
Data:
{'_stamp': '2023-09-06T05:40:23.782762',
 'arg': ['20230906054018663898'],
 'fun': 'saltutil.find_job',
 'jid': '20230906054023778531',
 'minions': ['xt01.rsv.envdev.test'],
 'missing': [],
 'tgt': ['xt01.rsv.envdev.test'],
 'tgt_type': 'list',
 'user': 'sudo_vagrant'}

The salt state.apply then fails like before:

root@saltmaster:/home/vagrant# salt 'xt*' state.apply --state-output=changes --out=profile
[ERROR   ] Nested output failed: 
Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 36, in try_printout
    printout = get_printout(out, opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 42, in try_printout
    printout = get_printout("nested", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers
[ERROR   ] An un-handled exception was caught by Salt's global exception handler:
TypeError: string indices must be integers
Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 36, in try_printout
    printout = get_printout(out, opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 42, in try_printout
    printout = get_printout("nested", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/salt", line 11, in <module>
    sys.exit(salt_main())
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 533, in salt_main
    client.run()
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/salt.py", line 198, in run
    self._output_ret(ret_, out, retcode=retcode)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/salt.py", line 399, in _output_ret
    salt.output.display_output(ret, out=out, opts=self.config, _retcode=retcode)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 88, in display_output
    display_data = try_printout(data, out, opts, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 47, in try_printout
    printout = get_printout("raw", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers
Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 36, in try_printout
    printout = get_printout(out, opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 42, in try_printout
    printout = get_printout("nested", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/salt", line 11, in <module>
    sys.exit(salt_main())
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/scripts.py", line 533, in salt_main
    client.run()
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/salt.py", line 198, in run
    self._output_ret(ret_, out, retcode=retcode)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/cli/salt.py", line 399, in _output_ret
    salt.output.display_output(ret, out=out, opts=self.config, _retcode=retcode)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 88, in display_output
    display_data = try_printout(data, out, opts, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/__init__.py", line 47, in try_printout
    printout = get_printout("raw", opts)(data, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 149, in __call__
    return self.loader.run(run_func, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1232, in run
    return self._last_context.run(self._run_as, _func_or_method, *args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/loader/lazy.py", line 1247, in _run_as
    return _func_or_method(*args, **kwargs)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 75, in output
    rows = _find_durations(data)
  File "/opt/saltstack/salt/lib/python3.10/site-packages/salt/output/profile.py", line 47, in _find_durations
    dat = data[host][sid]
TypeError: string indices must be integers

Running the state.apply the second time also fails (same event output).

The third time running state.apply everything goes well and the state is actually applied. The event bus output then includes the output of all the states that have been applied, like this:

Event fired at Wed Sep  6 05:44:35 2023
*************************
Tag: salt/job/20230906054435368744/new
Data:
{'_stamp': '2023-09-06T05:44:35.375187',
 'arg': ['20230906054420154088'],
 'fun': 'saltutil.find_job',
 'jid': '20230906054435368744',
 'minions': ['xt01.rsv.envdev.test'],
 'missing': [],
 'tgt': ['xt01.rsv.envdev.test'],
 'tgt_type': 'list',
 'user': 'sudo_vagrant'}
Event fired at Wed Sep  6 05:44:35 2023
*************************
Tag: salt/job/20230906054435368744/ret/xt01.rsv.envdev.test
Data:
{'_stamp': '2023-09-06T05:44:35.606416',
 'cmd': '_return',
 'fun': 'saltutil.find_job',
 'fun_args': ['20230906054420154088'],
 'id': 'xt01.rsv.envdev.test',
 'jid': '20230906054435368744',
 'retcode': 0,
 'return': {'arg': [],
            'fun': 'state.apply',
            'jid': '20230906054420154088',
            'pid': 31418,
            'ret': '',
            'tgt': 'xt*',
            'tgt_type': 'glob',
            'user': 'sudo_vagrant'},
 'success': True}
Event fired at Wed Sep  6 05:44:35 2023
*************************
Tag: minion/refresh/xt01.rsv.envdev.test
Data:
{'Minion data cache refresh': 'xt01.rsv.envdev.test',
 '_stamp': '2023-09-06T05:44:35.765788'}
Event fired at Wed Sep  6 05:44:36 2023
*************************
Tag: minion/refresh/xt01.rsv.envdev.test
Data:
{'Minion data cache refresh': 'xt01.rsv.envdev.test',
 '_stamp': '2023-09-06T05:44:36.142428'}
Event fired at Wed Sep  6 05:44:36 2023
*************************
Tag: minion/refresh/xt01.rsv.envdev.test
Data:
{'Minion data cache refresh': 'xt01.rsv.envdev.test',
 '_stamp': '2023-09-06T05:44:36.486367'}
Event fired at Wed Sep  6 05:44:37 2023
*************************
Tag: minion/refresh/xt01.rsv.envdev.test
Data:
{'Minion data cache refresh': 'xt01.rsv.envdev.test',
 '_stamp': '2023-09-06T05:44:37.513382'}
Event fired at Wed Sep  6 05:44:37 2023
*************************
Tag: minion/refresh/xt01.rsv.envdev.test
Data:
{'Minion data cache refresh': 'xt01.rsv.envdev.test',
 '_stamp': '2023-09-06T05:44:37.810194'}
Event fired at Wed Sep  6 05:44:38 2023
*************************
Tag: minion/refresh/xt01.rsv.envdev.test
Data:
{'Minion data cache refresh': 'xt01.rsv.envdev.test',
 '_stamp': '2023-09-06T05:44:38.155567'}
Event fired at Wed Sep  6 05:44:39 2023
*************************
Tag: minion/refresh/xt01.rsv.envdev.test
Data:
{'Minion data cache refresh': 'xt01.rsv.envdev.test',
 '_stamp': '2023-09-06T05:44:39.867420'}
Event fired at Wed Sep  6 05:44:40 2023
*************************
Tag: minion/refresh/xt01.rsv.envdev.test
Data:
{'Minion data cache refresh': 'xt01.rsv.envdev.test',
 '_stamp': '2023-09-06T05:44:40.189058'}
Event fired at Wed Sep  6 05:44:45 2023
*************************
Tag: 20230906054445527259
Data:
{'_stamp': '2023-09-06T05:44:45.529808', 'minions': ['xt01.rsv.envdev.test']}
Event fired at Wed Sep  6 05:44:45 2023
*************************
Tag: salt/job/20230906054445527259/new
Data:
{'_stamp': '2023-09-06T05:44:45.538726',
 'arg': ['20230906054420154088'],
 'fun': 'saltutil.find_job',
 'jid': '20230906054445527259',
 'minions': ['xt01.rsv.envdev.test'],
 'missing': [],
 'tgt': ['xt01.rsv.envdev.test'],
 'tgt_type': 'list',
 'user': 'sudo_vagrant'}
Event fired at Wed Sep  6 05:44:45 2023
*************************
Tag: salt/job/20230906054445527259/ret/xt01.rsv.envdev.test
Data:
{'_stamp': '2023-09-06T05:44:45.713764',
 'cmd': '_return',
 'fun': 'saltutil.find_job',
 'fun_args': ['20230906054420154088'],
 'id': 'xt01.rsv.envdev.test',
 'jid': '20230906054445527259',
 'retcode': 0,
 'return': {'arg': [],
            'fun': 'state.apply',
            'jid': '20230906054420154088',
            'pid': 31418,
            'ret': '',
            'tgt': 'xt*',
            'tgt_type': 'glob',
            'user': 'sudo_vagrant'},
 'success': True}
Event fired at Wed Sep  6 05:44:46 2023
*************************
Tag: salt/job/20230906054420154088/ret/xt01.rsv.envdev.test
Data:
{'_stamp': '2023-09-06T05:44:46.099211',
 'cmd': '_return',
 'fun': 'state.apply',
 'fun_args': [],
 'id': 'xt01.rsv.envdev.test',
 'jid': '20230906054420154088',
 'out': 'highstate',
 'retcode': 0,
 'return': {'cmd_|-acme-sh-install-install_|-mkdir -p /usr/local/acme.sh && cd /opt/acme.sh && ./acme.sh --install --home /usr/local/acme.sh --nocron_|-run': {'__id__': 'acme-sh-install-install',
                                                                                                                                                               '__run_num__': 95,
                                                                                                                                                               '__sls__': 'acme-sh.acme-sh-install',
# ... 
# ... 
# ...

Sep 06 '23 05:09 hvt

@hvt this is starting to sound like the highstate is just taking a long time to run and it times out waiting for the results so there are no results to display. try increasing the timeout. by adding -t 300 to the command. that should at least get you past the issue. increase that number if not.

If this does work. do not close this ticket. as this is a valid issue. we shouldn't be throwing a traceback if we don't get a return before timeout.

Sep 06 '23 06:09 whytewolf

Is the vagrant state causing returning something odd that ends up being weird in the profile outputter or is this an issue any state has with the outputter?

Jul 31 '24 16:07 Akm0d

@hvt can you share a sanitized version of the SLS that you ran to get the error?

Jul 31 '24 16:07 Akm0d

At first glance, it looks like data[host] ends up being a string (when the bug is triggered). If for sid in data[host] is iterating over a string, then sid would be a single character string, but data[host][sid] would be trying to use that single character as an index for a string.

So I suspect that some part of the vagrant state is returning a string where it should be a dict.

def _find_durations(data, name_max=60):
    ret = []
    ml = len("duration (ms)")
    for host in data:
        for sid in data[host]:
            dat = data[host][sid]

Jul 31 '24 16:07 Akm0d

Verified the issue. States should return ret["changes"][name] = {"key": "value"} But the vagrant state is returning ret["changes"][name] = "a string". This is why you only see the issue on the first pass, because the formatting error only happens when there are changes.

Jul 31 '24 17:07 Akm0d

Looking at other states, it seems like ret["changes"][name] = "a string" is pretty common. Therefore, I believe this is something that should be fixed in just the profile outputter and not in the vagrant state.

Jul 31 '24 19:07 Akm0d

salt-call --local grains.items --output=profile also produces an error

Jul 31 '24 19:07 Akm0d

Here we go, the bug is most easily reproduced by running this command:

salt-call --local state.sls foo --output=profile

Jul 31 '24 19:07 Akm0d

salt salt copied to clipboard

[BUG] "TypeError: string indices must be integers" when running initial "state.apply" with "--out=profile"

salt
salt copied to clipboard