[BUG] minion returns success but orchestrate runner returns fail

[bipt0]

Description Minion logs return 'success': True, but orchestrate returns failure. Also a related issue where state.apply is successful while state.orch fails.

Minion logs:

[salt.loaded.int.module.cmdmod:414 ][INFO    ][2072] Executing command 'Powershell -NonInteractive -NoProfile "Start-Process -Wait -FilePath \"C:\windows\TEMP\vs_BuildTools.exe\" -ArgumentList \"--passive\""' in directory 'C:\windows\system32\config\systemprofile'
[salt.minion      :1999][DEBUG   ][4240] minion return: {'success': True, 'return': {'pid': 2072, 'fun': 'state.sls', 'arg': ['states.scratch.first', {'__kwarg__': True, 'queue': False, 'concurrent': False}], 'tgt': 'salt-minion-new', 'jid': '20201015223200590679', 'ret': '', 'tgt_type': 'glob', 'user': 'sudo_azureuser'}, 'retcode': 0, 'jid': '20201015223205683741', 'fun': 'saltutil.find_job', 'fun_args': ['20201015223200590679']}
[salt.minion      :1999][DEBUG   ][2072] minion return: {'success': True, 'return': {'module_|-log first_|-log.info_|-run': {'name': 'log.info', 'changes': {'ret': True}, 'comment': 'Module function log.info executed', 'result': True, '__sls__': 'states.scratch.first', '__run_num__': 0, 'start_time': '22:32:13.493369', 'duration': 0.0, '__id__': 'log first'}, 'cmd_|-install vs build tools 1_|-Start-Process -Wait -FilePath "C:\\windows\\TEMP\\vs_BuildTools.exe" -ArgumentList "--passive"_|-run': {'name': 'Start-Process -Wait -FilePath "C:\\windows\\TEMP\\vs_BuildTools.exe" -ArgumentList "--passive"', 'changes': {'pid': 3808, 'retcode': 0, 'stdout': '', 'stderr': ''}, 'result': True, 'comment': 'Command "Start-Process -Wait -FilePath "C:\\windows\\TEMP\\vs_BuildTools.exe" -ArgumentList "--passive"" run', '__sls__': 'states.scratch.first', '__run_num__': 1, 'start_time': '22:32:13.507003', 'duration': 47085.106, '__id__': 'install vs build tools 1'}}, 'retcode': 0, 'jid': '20201015223200590679', 'fun': 'state.sls', 'fun_args': ['states.scratch.first', {'queue': False, 'concurrent': False}]}

Master output:

[DEBUG   ] Sending event: tag = salt/run/20201015223134158159/ret; data = {'fun': 'runner.state.orch', 'jid': '20201015223134158159', 'user': 'sudo_azureuser', 'fun_args': ['orch.scratch', {'orchestration_jid': '20201015223134158159'}], '_stamp': '2020-10-15T22:32:15.862410', 'return': {'data': {'salt-master_master': {'salt_|-Do state_|-Do state_|-state': {'name': 'Do state', 'changes': {'out': 'highstate', 'ret': {'salt-minion-new': False}}, 'comment': 'Run failed on minions: salt-minion-new', 'result': False, '__sls__': 'orch.scratch', '__run_num__': 0, 'start_time': '22:31:35.101771', 'duration': 25431.29, '__id__': 'Do state'}, 'salt_|-Do state again_|-Do state again_|-state': {'name': 'Do state again', 'changes': {'out': 'highstate', 'ret': {'salt-minion-new': False}}, 'comment': 'Run failed on minions: salt-minion-new', 'result': False, '__sls__': 'orch.scratch', '__run_num__': 1, 'start_time': '22:32:00.533627', 'duration': 15325.259, '__id__': 'Do state again'}}}, 'outputter': 'highstate', 'retcode': 1}, 'success': False}
[DEBUG   ] LazyLoaded highstate.output
salt-master_master:
----------
          ID: Do state
    Function: salt.state
      Result: False
     Comment: Run failed on minions: salt-minion-new
     Started: 22:31:35.101771
    Duration: 25431.29 ms
     Changes:
              salt-minion-new:
                  False
----------
          ID: Do state again
    Function: salt.state
      Result: False
     Comment: Run failed on minions: salt-minion-new
     Started: 22:32:00.533627
    Duration: 15325.259 ms
     Changes:
              salt-minion-new:
                  False

Summary for salt-master_master
------------
Succeeded: 0 (changed=2)
Failed:    2
------------
Total states run:     2
Total run time:  40.757 s

Setup 3 files: scratch.sls, first.sls, vs_BuildTools.exe Clean VM running Windows 2019

salt://orch/scratch:

Do state:
  salt.state:
    - sls: states.scratch.first
    - tgt: 'salt-minion-new'
Do state again:
  salt.state:
    - sls: states.scratch.first
    - tgt: 'salt-minion-new'

salt://states/scratch/first:

log first:
  module.run:
    - name: log.info
    - message: Starting first
install vs build tools 1:
  cmd.run:
    - name: Start-Process -Wait -FilePath "{{ salt['environ.get']('temp') }}\vs_BuildTools.exe" -ArgumentList "--passive"
    - shell: powershell

vs_BuildTools.exe from here: https://visualstudio.microsoft.com/downloads/#build-tools-for-visual-studio-2019

Steps to Reproduce the behavior This works :heavy_check_mark:: salt -t 60 'salt-minion-new' state.apply states.scratch.first -l debug This fails :x:: salt-run -t 60 state.orch orch.scratch -l debug

Expected behavior salt-run state.orch orch.scratch should succeed

Screenshots

Versions Report

salt --versions-report on master

(Provided by running salt --versions-report. Please also mention any differences in master/minion versions.) ``` Salt Version: Salt: 3001.1 Dependency Versions: cffi: Not Installed cherrypy: Not Installed dateutil: 2.6.1 docker-py: Not Installed gitdb: 2.0.3 gitpython: 2.1.8 Jinja2: 2.10 libgit2: 0.26.0 M2Crypto: Not Installed Mako: Not Installed msgpack-pure: Not Installed msgpack-python: 0.5.6 mysql-python: Not Installed pycparser: Not Installed pycrypto: 2.6.1 pycryptodome: 3.4.7 pygit2: 0.26.2 Python: 3.6.9 (default, Jul 17 2020, 12:50:27) python-gnupg: 0.4.1 PyYAML: 3.12 PyZMQ: 17.1.2 smmap: 2.0.3 timelib: Not Installed Tornado: 4.5.3 ZMQ: 4.2.5 System Versions: dist: ubuntu 18.04 Bionic Beaver locale: UTF-8 machine: x86_64 release: 5.4.0-1031-azure system: Linux version: Ubuntu 18.04 Bionic Beaver ```

Minion: Salt-Minion-3001.1-Py3-AMD64-Setup.exe

[bipt0]

Any update? Do you need more information?

[garethgreenaway]

@bipt0 Apologies for the delay on this one. Is this something you're seeing specifically on Windows or are you seeing this running the orchestration states on other operating systems as well?

[bipt0]

This is specifically on windows because of the vs_BuildTools.exe installer.

[xeacott]

Recently we had something... maybe... related come up where the issue is salt win_patch do.thing args and salt-call do.thing args are treating the arguments differently, i.e. not wrapping a string correctly and it being passed as an int. Wonder if this is related. But thanks for the information! Definitely will be taking a look at this this week.

[yukpun]

Do you have any update on this?

[xeacott]

I do not have any updates on this yet... let me get back before tomorrow (20/07/2021) end of day.

[xeacott]

hey @yukpun so i have the following setup:

salt-master on ub20 (running v3002.2) salt-minion on win10 (running v3003.1)

and here's my orch state:

do thing:
  salt.state:
    - sls: test-file
    - tgt: "win_box"
do thing again:
  salt.state:
    - sls: test-file
    - tgt: "win_box"

and the state file:

log first:
  module.run:
    - name: log.info
    - message: Starting first
install:
  cmd.run:
    - name: Start-Process -Wait -FilePath "C:\test\build_tools.exe" -ArgumentList "--passive"
    - shell: powershell

and executed with : salt-run state.orch orch.test-orch -l debug

and it came back successful:

joe-VirtualBox_master:
----------
          ID: do thing
    Function: salt.state
      Result: True
     Comment: States ran successfully. Updating win_box.
     Started: 13:50:34.716472
    Duration: 6899.572 ms
     Changes:
              win_box:
              ----------
                        ID: install
                  Function: cmd.run
                      Name: Start-Process -Wait -FilePath "C:\test\build_tools.exe" -ArgumentList "--passive"
                    Result: True
                   Comment: Command "Start-Process -Wait -FilePath "C:\test\build_tools.exe" -ArgumentList "--passive"" run
                   Started: 13:50:36.909079
                  Duration: 4444.906 ms
                   Changes:
                            ----------
                            pid:
                                23448
                            retcode:
                                0
                            stderr:
                            stdout:

              Summary for win_box
              ------------
              Succeeded: 1 (changed=1)
              Failed:    0
              ------------
              Total states run:     1
              Total run time:   4.445 s

Summary for joe-VirtualBox_master
------------
Succeeded: 1 (changed=1)
Failed:    0
------------
Total states run:     1
Total run time:   6.900 s
[INFO    ] Runner completed: 20210721195034022717
[DEBUG   ] Closing IPCMessageClient instance

could you let me know the differences here? im also using a very similar .exe and the installer launches on my minion

[yukpun]

Hi @xeacott

Here is .sls file

install_cortex:
  pkg.installed:
    - name: cortex

And here is winrepo .sls file

# both 32-bit (x86) AND a 64-bit (AMD64) installer available
{% set version = '73120981' %}
{% set source_path = 'http://internal-server/winrepo/pan-traps' %}

cortex:
  '{{version}}':
    {% if grains['cpuarch'] == 'AMD64' %}
    installer: '{{source_path}}/WindowsAgent{{version|replace(".", "_")}}_x64.msi'
    uninstaller: '{{source_path}}/WindowsAgent{{version|replace(".", "_")}}_x64.msi'
    arch: x64
    {% else %}
    installer: '{{source_path}}/WindowsAgent{{version|replace(".", "_")}}_x86.msi'
    uninstaller: '{{source_path}}/WindowsAgent{{version|replace(".", "_")}}_x86.msi'
    arch: x86
    {% endif %}
    full_name: 'Cortex {{version}}'
    install_flags: '/qn /norestart'
    uninstall_flags: '/qn /norestart'
    msiexec: True
    locale: en_US
    reboot: False

Case 1 salt node-id state.sls cortex When run this command, salt returns error, hovewer package installs. You can check error log here

Case 2 salt node-id pkg.install cortex When run this command, everything installs fine.

[marianomd]

I'm experiencing exactly the same issue as @yukpun.

Salt Version: Salt: 3005.1

Using state.apply I get:

TAS-MD:
----------
          ID: install-openlogic-openjdk-jre
    Function: pkg.installed
        Name: openlogic-openjdk-jre
      Result: False
     Comment: The following packages failed to install/update: openlogic-openjdk-jre
     Started: 00:09:33.955229
    Duration: 2159.221 ms
     Changes:
              ----------
              openlogic-openjdk-jre:
                  ----------
                  install status:
                      success

Summary for TAS-MD
------------
Succeeded: 0 (changed=1)
Failed:    1
------------
Total states run:     1
Total run time:   2.159 s

Using pkg.install:

[DEBUG   ] return event: {'TAS-MD': {'ret': {'openlogic-openjdk-jre': {'install status': 'success'}}, 'retcode': 0, 'jid': '20221027031718249050'}}
[DEBUG   ] The functions from module 'nested' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded nested.output
TAS-MD:
    ----------
    openlogic-openjdk-jre:
        ----------
        install status:
            success

/srv/salt/win/repo-ng/openlogic-openjdk-jre.sls:

openlogic-openjdk-jre:
  '8u292-b10-windows-x32':
    full_name: 'OpenLogic OpenJDK JRE 8u292 (32 bit)'
    installer: salt://win/repo-ng/openlogic-openjdk-jre-8u292-b10-windows-x32.msi
    install_flags: 'ADDLOCAL="FeatureEnvironment,FeatureMain,FeatureJarFileRunWith,FeatureJavaHome" /qn /norestart'
    uninstall_flags: '/qn /norestart'
    msiexec: True
    locale: en_US
    reboot: False