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

[hvt]

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 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 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.) ```yaml 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.

[welcome[bot]]

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:

• Community Wiki
• Salt’s Contributor Guide
• Join our Community Slack
• IRC on LiberaChat
• Salt Project YouTube channel
• Salt Project Twitch channel

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 saltproject@vmware.com. We’re glad you’ve joined our community and look forward to doing awesome things with you!

[whytewolf]

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.

[hvt]

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?

[whytewolf]

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

[hvt]

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:

```sh 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 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 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', # ... # ... # ... ```

[whytewolf]

@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.

[Akm0d]

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?

[Akm0d]

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

[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]

[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.

[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.

[Akm0d]

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

[Akm0d]

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

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