cmd.run state doesn't print stdout's last character when stateful=True.

[mamalos]

Description of Issue

When executing the state cmd.run on a minion with stateful set to True and the command returns key/value pairs (not JSON), then the last character printed in the Changes: section is omitted.

Setup

Ran on debian10 with 2019.2.3+ds-1 salt package, but I've verified it in various previous salt versions (eg. 2018.3.1 and 2018.3.2) on various systems (eg. debian9 and SmartOS 18.4, 19.4, 17.2).

Steps to Reproduce Issue

Create the following sls file in your file-roots (let's call it testit.sls):

test output1:
  cmd.run:
    - name: echo changed=True lala=lolo lili=lele

test output2:
  cmd.run:
    - name: echo changed=True lala=lolo lili=lele
    - stateful: True

and then run it. The output you'll get will be something like:

# salt 'testmachine' state.apply testit
testmachine:
----------
          ID: test output1
    Function: cmd.run
        Name: echo changed=True lala=lolo lili=lele
      Result: True
     Comment: Command "echo changed=True lala=lolo lili=lele" run
     Started: 13:37:29.594337
    Duration: 83.475 ms
     Changes:   
              ----------
              pid:
                  20544
              retcode:
                  0
              stderr:
              stdout:
                  changed=True lala=lolo lili=lele
----------
          ID: test output2
    Function: cmd.run
        Name: echo changed=True lala=lolo lili=lele
      Result: True
     Comment: 
     Started: 13:37:29.678552
    Duration: 77.335 ms
     Changes:   
              ----------
              changed:
                  True
              lala:
                  lolo
              lili:
                  lele
              pid:
                  20545
              retcode:
                  0
              stderr:
              stdout:
                  changed=True lala=lolo lili=lel

Summary for testmachine
------------
Succeeded: 2 (changed=2)
Failed:    0
------------
Total states run:     2
Total run time: 160.810 ms

where one can see that the final e is missing from the output2 (where stateful is set to True).

Versions Report

           Salt: 2019.2.3
 
Dependency Versions:
           cffi: Not Installed
       cherrypy: unknown
       dateutil: 2.7.3
      docker-py: Not Installed
          gitdb: 2.0.5
      gitpython: 2.1.11
          ioflo: Not Installed
         Jinja2: 2.10
        libgit2: Not Installed
        libnacl: Not Installed
       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: Not Installed
         pygit2: Not Installed
         Python: 3.7.3 (default, Apr  3 2019, 05:39:12)
   python-gnupg: Not Installed
         PyYAML: 3.13
          PyZMQ: 17.1.2
           RAET: Not Installed
          smmap: 2.0.5
        timelib: Not Installed
        Tornado: 4.5.3
            ZMQ: 4.3.1
 
System Versions:
           dist: debian 10.2 
         locale: UTF-8
        machine: x86_64
        release: 4.19.0-6-cloud-amd64
         system: Linux
        version: debian 10.2 

[xeacott]

Thanks for the report! Interesting issue too, by the way. I'm wondering if there is a regex expression or some kind of .strip() that is causing this. I can confirm that this is happening too.

[xeacott]

So the root of the issue is happening in /states/cmd.py around line 300 shown below:

    if changed:
        for key in ret:
            data.setdefault(key, ret[key])

        # if stdout is the state output in JSON, don't show it.
        # otherwise it contains the one line name=value pairs, strip it.
        data['stdout'] = '' if is_json else data.get('stdout', '')[:idx]
        state['changes'] = data

Here's the output from before and after this block of code:

[ERROR   ] data
[ERROR   ] {'changed': 'True', 'lala': 'lolo', 'lili': 'lele', 'pid': 10848, 'retcode': 0, 'stdout': 'changed=True lala=lolo lili=lele', 'stderr': ''}
[ERROR   ] new data
[ERROR   ] {'changed': 'True', 'lala': 'lolo', 'lili': 'lele', 'pid': 10848, 'retcode': 0, 'stdout': 'changed=True lala=lolo lili=lel', 'stderr': ''}
[ERROR   ] An exception occurred in this state: Traceback (most recent call last):

[mamalos]

Yeah, I'm not sure what this idx serves, and I'm not sure if it's correct, since the way it's calculated is a bit strange:

        idx = out.rstrip().rfind('\n')
        if idx != -1:
            out = out[idx + 1:]
        data = {}

where it seems that idx is not -1 only if there's a \n character before the end of out, where in that case it considers that the output is the whole string until the rightmost \n that's not at the end of out...which I'm not sure what it is supposed to serve...you can test the strangeness of this idx if the command in cmd.run is something like this: echo "lala\nchanged=True lili=lili", where the stdout: lala, even though changed has been evaluated as if it was part of stdout. I think it's a bit messy.

So, regardless of my above mentioned comment, if let's say the above code somehow makes sense and we don't want to break it, what I'd suggest we could do in order for it to work correctly, would be to do something like the following:

        idx = out.rstrip().rfind('\n')
        if idx != -1:
            out = out[idx + 1:]
        else:
          idx = None
        data = {}

where in that case, when idx is later used in the code you mentioned, if idx was not -1 in the first place, then it'll work as it worked till now (which to me is still very strange :-)), otherwise it'll be set to None and [:idx] will just print the whole string, without omitting the last character.