json/utf8 problem with pgjsonb, postgres and mysql returners

[AldarisPale]

Setup

/etc/salt/master

[…]
returner.pgjsonb.host: 'localhost'
returner.pgjsonb.user: ‘xxx'
returner.pgjsonb.pass: ‘xxx'
returner.pgjsonb.db: 'salt_master_cache'
returner.pgjsonb.port: 5432

master_job_cache: pgjsonb
event_return: pgjsonb
# lets keep jobs in "active" part of database for 24h and then move them to archive tables
keep_jobs: 24
archive_jobs: True
[…]

Steps to Reproduce Issue

/var/log/salt/master:
2019-11-07 15:21:50,884 [salt.utils.event :1233][ERROR   ][524] Could not store events - returner 'pgjsonb.event_return' raised exception: 'utf8' codec can't decode byte 0xaa in position 2: invalid start byte
2019-11-07 15:21:50,885 [salt.master      :1846][ERROR   ][539] Error in function _return:
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/salt/master.py", line 1839, in run_func
    ret = getattr(self, func)(load)
  File "/usr/lib/python2.7/dist-packages/salt/master.py", line 1638, in _return
    self.opts, load, event=self.event, mminion=self.mminion)
  File "/usr/lib/python2.7/dist-packages/salt/utils/job.py", line 108, in store_job
    mminion.returners[savefstr](load['jid'], load)
  File "/usr/lib/python2.7/dist-packages/salt/returners/pgjsonb.py", line 332, in save_load
    {'jid': jid, 'load': psycopg2.extras.Json(load)})
  File "/usr/lib/python2.7/dist-packages/psycopg2/_json.py", line 96, in getquoted
    s = self.dumps(self.adapted)
  File "/usr/lib/python2.7/dist-packages/psycopg2/_json.py", line 89, in dumps
    return dumps(obj)
  File "/usr/lib/python2.7/json/__init__.py", line 244, in dumps
    return _default_encoder.encode(obj)
  File "/usr/lib/python2.7/json/encoder.py", line 207, in encode
    chunks = self.iterencode(o, _one_shot=True)
  File "/usr/lib/python2.7/json/encoder.py", line 270, in iterencode
    return _iterencode(o, 0)
UnicodeDecodeError: 'utf8' codec can't decode byte 0xaa in position 2: invalid start byte

Postgres:

postgres=# \l
                                       List of databases
       Name        |  Owner   | Encoding |   Collate   |    Ctype    |    Access privileges     
-------------------+----------+----------+-------------+-------------+--------------------------
 postgres          | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 | 
 salt_master_cache | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 | =Tc/postgres            +
                   |          |          |             |             | postgres=CTc/postgres   +
                   |          |          |             |             | xxx=CTc/postgres
 template0         | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 | =c/postgres             +
                   |          |          |             |             | postgres=CTc/postgres
 template1         | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 | =c/postgres             +
                   |          |          |             |             | postgres=CTc/postgres

Versions Report

master:

Salt Version:
           Salt: 2019.2.2
 
Dependency Versions:
           cffi: Not Installed
       cherrypy: Not Installed
       dateutil: 2.5.3
      docker-py: Not Installed
          gitdb: 2.0.0
      gitpython: 2.1.1
          ioflo: Not Installed
         Jinja2: 2.9.4
        libgit2: 0.24.5
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.4.8
   mysql-python: Not Installed
      pycparser: Not Installed
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: 0.24.2
         Python: 2.7.13 (default, Sep 26 2018, 18:42:22)
   python-gnupg: Not Installed
         PyYAML: 3.12
          PyZMQ: 16.0.2
           RAET: Not Installed
          smmap: 2.0.1
        timelib: Not Installed
        Tornado: 4.4.3
            ZMQ: 4.2.1
 
System Versions:
           dist: debian 9.11 
         locale: UTF-8
        machine: x86_64
        release: 4.9.0-11-amd64
         system: Linux
        version: debian 9.11 

minion:

    Salt Version:
               Salt: 2019.2.2
     
    Dependency Versions:
               cffi: 1.12.2
           cherrypy: 17.4.1
           dateutil: 2.8.0
          docker-py: Not Installed
              gitdb: 2.0.6
          gitpython: Not Installed
              ioflo: Not Installed
             Jinja2: 2.10.1
            libgit2: Not Installed
            libnacl: 1.6.1
           M2Crypto: Not Installed
               Mako: 1.0.7
       msgpack-pure: Not Installed
     msgpack-python: 0.5.6
       mysql-python: Not Installed
          pycparser: 2.19
           pycrypto: Not Installed
       pycryptodome: 3.8.1
             pygit2: Not Installed
             Python: 3.5.4 (v3.5.4:3f56838, Aug  8 2017, 02:17:05) [MSC v.1900 64 bit (AMD64)]
       python-gnupg: 0.4.4
             PyYAML: 3.13
              PyZMQ: 18.0.1
               RAET: Not Installed
              smmap: 2.0.5
            timelib: 0.2.4
            Tornado: 4.5.3
                ZMQ: 4.3.1
     
    System Versions:
               dist:   
             locale: cp1252
            machine: AMD64
            release: 10
             system: Windows
            version: 10 10.0.18362 SP0 Multiprocessor Free

[Ch3LL]

would you mind adding this log:

diff --git a/salt/returners/pgjsonb.py b/salt/returners/pgjsonb.py
index 04f2af58c0..3e9f275440 100644
--- a/salt/returners/pgjsonb.py
+++ b/salt/returners/pgjsonb.py
@@ -328,6 +328,7 @@ def save_load(jid, load, minions=None):
     '''
     with _get_serv(commit=True) as cur:
         try:
+            log.critical('load is {0}'.format(load))
             cur.execute(PG_SAVE_LOAD_SQL,
                         {'jid': jid, 'load': psycopg2.extras.Json(load)})
         except psycopg2.IntegrityError:

and pasting a sanitized version of load here. I can probably write up a unit test to help replicate this problem and possibly a fix if i know what load looks like.

[AldarisPale]

2019-11-07 22:21:56,242 [salt.loaded.int.returner.pgjsonb:331 ][CRITICAL][1281] load is {'fun_args': [], 'jid': '20191107222150911552', 'return': True, 'retcode': 0, 'success': True, 'cmd': '_return', u'_stamp': '2019-11-07T20:21:56.232522', u'sig': 'g\x06=\'\x10s\xb7(UY\xe7\x02Uc\xd00r\xda|\xa7\x81\xd4?\x99"\xad\xfddHiY\xda\xb0\xa9R\xd0q\xfd\xfe\x86\xcd\x89]}\xc3qMJ\x1a\xb5\x1f\xd2\'\x1f\xdd\xc3\xa8Q\x02k\x99\xa6Qk\xe4\x13S\xa1\xc2\\\xc2\x11\xde\xff\x1a\xd3[f \r\x0f\x90\r\xcb\xa5\xc5\x81\xd1\\\x1a\x8a\x15\x82W\x9d\x8cb H\xc6D\xd2SQ\xc1=x\xbea\xab6\x9b\xd8\xd2DOZ\x9a\x08iN(\xc7\xf1^\x0e\xd2\xf4\xf7,\x89[\xc6\xce\x9e7`\xe8M\xdfi\x1e\xd4\xec\x0eW\x8d\x9a825/\xdeQ\x8eS2[\x1f\xbdD\x82\x9eFIe\xf8\x11\x07\x1b\xb7E\x97\xff\xe1\x17\xc1\x81y\xd6\xfa\xd0\xcc\xba\x98\x9a\x1a\x10f)\xf9\xd5\xe0\x15\xac\x9f\xd3\xd1\xcb\xb7\xe6J\x15\x83\xe5\xb0\xf3b\x8c%\x02dy\x1d\xc0q\x8e\x98@\xe0\x17\xac\xa1b\xd9\xe2y\xb1CU^i\x19\'K\x01\xb8\x12Qg\x9dN\xf1\xe7\xfe5\xcd\xd6\xf3N%|\xd0\xfa\x1a\xba\x87\xc5(8\x8f*y1cD\\\x17}\xc1\xdf\xcc\xa6\xe7U\x13M\xc5\xc15\xb4\x12IsE`\x06\x93\r\xbdt\xf7\xc8:\xc528\xba\x9bK\x1e<%\x1c\xca\xb5&0\xbe\rJ\xe5\xf0\x96)\xcch\xf2\xd83\x9d\x85,QR"\x82%e\xd9y\x0b\x85\xb1I?\x18\x0e\x9d\xad\x0f\x91\x19\xe2a\x0c1\x06P\\\xd2\x05\x9a\x99\xe2\'\xf9\xf2nB}>\xe0\xec\xc6p\xeep\xb2\\\xe2\xd0\xec\x08\x80a\x03\xc19\x92\xe5\x1bj\xe1\xeeFv\xf5B\x94\x91\xe7\xf1\xedu\xdb\xac\xd8\xc4V\xcfP^7H\r\x1b4\xf3\x116\x02\xda\x11\xa4)K\x91R+\xde\xa5u\xc7\xf1\\\nz~-\x9d\x93\xd8\xe6\x18|H=\xf0\xed\x9fHg\xe5h\xc9u\xfb\xa1\x92x\x83\x1c\xf6\xe9\xab\xb3\xe2_$\xa4H\x1a_y\x17T\xd4\x82\xfd\x13\xd1\xeb\xfa\x0c\x03\xb7\x07\xc0\xea\xdc\xf1\xaf\x89\xd9f9q\xbc\xce\x14G*\x84Z\xc6\xb9\xad\x1cg\xd6E\xa8\xcc6\xd5\xf6]\xcd\xc5\xb0\xf5', 'fun': 'test.ping', 'id': 'DESKTOP-FE2HAEQ'}
2019-11-07 22:21:56,243 [salt.master      :1846][ERROR   ][1281] Error in function _return:
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/salt/master.py", line 1839, in run_func
    ret = getattr(self, func)(load)
  File "/usr/lib/python2.7/dist-packages/salt/master.py", line 1638, in _return
    self.opts, load, event=self.event, mminion=self.mminion)
  File "/usr/lib/python2.7/dist-packages/salt/utils/job.py", line 108, in store_job
    mminion.returners[savefstr](load['jid'], load)
  File "/usr/lib/python2.7/dist-packages/salt/returners/pgjsonb.py", line 333, in save_load
    {'jid': jid, 'load': psycopg2.extras.Json(load)})
  File "/usr/lib/python2.7/dist-packages/psycopg2/_json.py", line 96, in getquoted
    s = self.dumps(self.adapted)
  File "/usr/lib/python2.7/dist-packages/psycopg2/_json.py", line 89, in dumps
    return dumps(obj)
  File "/usr/lib/python2.7/json/__init__.py", line 244, in dumps
    return _default_encoder.encode(obj)
  File "/usr/lib/python2.7/json/encoder.py", line 207, in encode
    chunks = self.iterencode(o, _one_shot=True)
  File "/usr/lib/python2.7/json/encoder.py", line 270, in iterencode
    return _iterencode(o, 0)
UnicodeDecodeError: 'utf8' codec can't decode byte 0xb7 in position 6: invalid start byte

[AldarisPale]

Screenshot just in case:

[AldarisPale]

The similar problem occurs with postgres module as well:

2019-11-12 10:10:48,696 [salt.master      :1625][INFO    ][5477] Failed to verify event signature from minion DESKTOP-FE2HAEQ.
2019-11-12 10:10:48,697 [salt.master      :1633][INFO    ][5477] But 'drop_message_signature_fail' is disabled, so message is still accepted.
2019-11-12 10:10:48,706 [salt.utils.job   :68  ][INFO    ][5477] Got return from DESKTOP-FE2HAEQ for job 20191112101038418144
2019-11-12 10:10:48,728 [salt.utils.event :1233][ERROR   ][5468] Could not store events - returner 'postgres.event_return' raised exception: invalid byte sequence for encoding "UTF8": 0x8b

2019-11-12 10:10:48,734 [salt.loaded.int.returner.postgres:272 ][CRITICAL][5477] load is {'fun_args': ['cd'], 'jid': '20191112101038418144', 'return': 'C:\\Windows\\system32\\config\\systemprofile', 'retcode': 0, 'success': True, 'cmd': '_return', u'_stamp': '2019-11-12T08:10:48.709240', u'sig': '\x8br\x140_\xce\nd\xcfHz\xfa\x98\x01\xbbVx\x94\xd3c\xffX\xfc"\xb4\xae\x84~\xf1\\\xd3\xaf9\xfc\x0b4\xfe\x9cE\x18\xb5s\x8e\x9f\xa3\x19\xb6\xc7\xff\x91g6\x91\xa8\xb9\x8b\x93\x16\xe6\x85.:\x0bD:\xa4\x1e9K\xad\xca\xf4\xf1\'}\xdd_\xc7A.\x9e\x17$\xea\x83N\x01\xb3\x84",\x1c)\xe9n[\x82\xa4\xb3\xf9~W\xba\x04\x1ck.I\x9c\x05\x15\x8d\x19\xf1\xaf\xfd\xbc\x18\xe4\x9c\xd5D\xe31\xd8DmHof\xc1\xdd\x1d\xae\xf3\r\xd5\xc0ys\xca\xf5\xc1\xc0$\t\'\xd1\x13\xf0\x81\xc5\xc9\x99\xa9\to\xb6L8\x01\xc1\xa5OPL=L\x8f\x08\x0cwn\x98\xc6n\xd4\x0e\xb7\xa6\x16\xce\xffj\xa0\x84!\xa8hG\xb5N\xc58P\x9fj\xa1\xab\xde7u7\xbc\xcd\xdc\xf3\x84\x8677\x1f\xac,2\x0b\x02\x07\xd3\xbas\xa3\xce\x1c"8<\xbb\x9e\x06\xbc\xcf\xd8\xc0\n\xd6\xd60X|\x9e\x87\x8a\xc1\xf4\ta;6\xb4s\xb04=\xffy\xa3\x01\x92>\x96\x89\xf4\x94\x90gj\xa4hF2h\xea\xe9\xd3\xba\xcc8he\xca\x9e\xbe\xc0 2\xf6\xd8\x1ew\x12\x1b\xb2x\x139{]5\xe3`\x8eX\xe6\xa9\xa3\x1d\x89\x8f\x8fD\xc4\xbd=\x17\xb8`\xe7{\xe4\x06i\x84\xee\x12\xaci\xf4\xbd\xe6!\x8d\'\xf7\xbeJO\x0bJ&\\.?\x05\\\x0e\xa5\xb2\xab\xf9\x0c\xcf\xb9\xaeA\tj\x16\xfb\xf9Dx\x1f$\xec\xbd/{\xe6\xa7f\xe1k\x8c\xc2&\xa2\xbc\xabf\xcf\xfd\xb7\x00\x9cY\x8b\x15\x140*\xfa\x8e(d\x84\xf1\x85\x05\xfa\xb9&_\xa7\x9a,fH\xdc1I\xea\xd9\xc5X:v\\\xa2[\xed\x95\xe9\xaf\xf6\xfc]N\x07A\xe1\xbd\x9f\xcc\xdfT\x01~G\xfaWu\x02\xfe0J:0\xe0\x03\xd6s\xa2\xa56\x1eY-)\x18\x1f\xcc!\xe4\x16.\xe1\ni\x055\\\x0b\xf5\xbd6\xa5\x8b\x17m\xfa\xcaN?\x8d\xe3|\xa78\xbby\xac\xd1\xec\x1d\xe8\xea\xefmx\xb9\xb3\xea\xc5\x95\x8a7K0s\xc7\xed', 'fun': 'cmd.run', 'id': 'DESKTOP-FE2HAEQ'}
2019-11-12 10:10:48,736 [salt.master      :1846][ERROR   ][5477] Error in function _return:
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/salt/master.py", line 1839, in run_func
    ret = getattr(self, func)(load)
  File "/usr/lib/python2.7/dist-packages/salt/master.py", line 1638, in _return
    self.opts, load, event=self.event, mminion=self.mminion)
  File "/usr/lib/python2.7/dist-packages/salt/utils/job.py", line 108, in store_job
    mminion.returners[savefstr](load['jid'], load)
  File "/usr/lib/python2.7/dist-packages/salt/returners/postgres.py", line 276, in save_load
    salt.utils.json.dumps(load)))
DataError: invalid byte sequence for encoding "UTF8": 0x8b

[AldarisPale]

Signature check also fails and if I understand correctly, it should no matter that it fails.

2019-11-12 21:09:55,403 [salt.master      :2347][INFO    ][24948] User root Published command test.ping with jid 20191112210955378618
2019-11-12 21:09:55,441 [salt.transport.mixins.auth:184 ][INFO    ][24948] Authentication request from DESKTOP-FE2HAEQ
2019-11-12 21:09:55,441 [salt.transport.mixins.auth:407 ][INFO    ][24948] Authentication accepted from DESKTOP-FE2HAEQ
2019-11-12 21:10:02,765 [salt.transport.mixins.auth:184 ][INFO    ][24947] Authentication request from DESKTOP-FE2HAEQ
2019-11-12 21:10:02,766 [salt.transport.mixins.auth:407 ][INFO    ][24947] Authentication accepted from DESKTOP-FE2HAEQ
2019-11-12 21:10:02,852 [salt.master      :1626][INFO    ][24944] Failed to verify event signature from minion DESKTOP-FE2HAEQ.
2019-11-12 21:10:02,852 [salt.master      :1634][INFO    ][24944] But 'drop_message_signature_fail' is disabled, so message is still accepted.
2019-11-12 21:10:02,862 [salt.utils.job   :68  ][INFO    ][24944] Got return from DESKTOP-FE2HAEQ for job 20191112210955378618
2019-11-12 21:10:02,883 [salt.utils.event :1233][ERROR   ][24932] Could not store events - returner 'postgres.event_return' raised exception: invalid byte sequence for encoding "UTF8":....

[AldarisPale]

I think it is something not related to postgres at all. Configured mariadb as a job cache. Seems to work until:

root@maaster:~# salt 'DESKTOP-FE2HAEQ' test.ping
[INFO    ] Using default for mysql ssl_key
[INFO    ] Using default for mysql ssl_cert
[INFO    ] Using default for mysql ssl_ca
DESKTOP-FE2HAEQ:
    True
root@maaster:~# salt-run jobs.list_jobs search_target='DESKTOP-FE2HAEQ'
[INFO    ] Using default for mysql ssl_key
[INFO    ] Using default for mysql ssl_cert
[INFO    ] Using default for mysql ssl_ca
[INFO    ] Using default for mysql ssl_key
[INFO    ] Using default for mysql ssl_cert
[INFO    ] Using default for mysql ssl_ca
[INFO    ] Using default for mysql ssl_key
[INFO    ] Using default for mysql ssl_cert
[INFO    ] Using default for mysql ssl_ca
20191114213314696112:
    ----------
    Arguments:
    Function:
        test.ping
    StartTime:
        2019, Nov 14 21:33:14.696112
    Target:
        DESKTOP-FE2HAEQ
    Target-type:
        glob
    User:
        root
20191114214809643619:
    ----------
    Arguments:
    Function:
        test.ping
    StartTime:
        2019, Nov 14 21:48:09.643619
    Target:
        DESKTOP-FE2HAEQ
    Target-type:
        glob
    User:
        root
[INFO    ] Runner completed: 20191114214826084194
root@maaster:~# salt-run jobs.print_job 20191114214809643619
[INFO    ] Using default for mysql ssl_key
[INFO    ] Using default for mysql ssl_cert
[INFO    ] Using default for mysql ssl_ca
[INFO    ] Using default for mysql ssl_key
[INFO    ] Using default for mysql ssl_cert
[INFO    ] Using default for mysql ssl_ca
[INFO    ] Using default for mysql ssl_key
[INFO    ] Using default for mysql ssl_cert
[INFO    ] Using default for mysql ssl_ca
[INFO    ] Using default for mysql ssl_key
[INFO    ] Using default for mysql ssl_cert
[INFO    ] Using default for mysql ssl_ca
Exception occurred in runner jobs.print_job: Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/salt/client/mixins.py", line 377, in low
    data['return'] = func(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/salt/runners/jobs.py", line 449, in print_job
    ret[jid]['Result'] = mminion.returners['{0}.get_jid'.format(returner)](jid)
  File "/usr/lib/python2.7/dist-packages/salt/returners/mysql.py", line 382, in get_jid
    ret[minion] = salt.utils.json.loads(full_ret)
  File "/usr/lib/python2.7/dist-packages/salt/utils/json.py", line 92, in loads
    return json_module.loads(s, **kwargs)
  File "/usr/lib/python2.7/json/__init__.py", line 339, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python2.7/json/decoder.py", line 364, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/lib/python2.7/json/decoder.py", line 380, in raw_decode
    obj, end = self.scan_once(s, idx)
UnicodeDecodeError: 'utf8' codec can't decode byte 0xd3 in position 1: invalid continuation byte
[INFO    ] Runner completed: 20191114214846616313

root@maaster:~# cat /etc/os-release 
PRETTY_NAME="Debian GNU/Linux 9 (stretch)"
NAME="Debian GNU/Linux"
VERSION_ID="9"
VERSION="9 (stretch)"
VERSION_CODENAME=stretch
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"

[AldarisPale]

I tried to switch to python3-based salt as well. In that case all three returners complained that the signature is not JSON serializable. To me it looks like something fundamental is broken here.

How can we move forward with this issue, @Ch3LL? It's blocking salt rollout for us.

[AldarisPale]

Tagging some more people because things have stayed quite quiet here and it seems like a major issue.
@UtahDave, @whiteinge

[Ch3LL]

can you try this fix:

diff --git a/salt/returners/pgjsonb.py b/salt/returners/pgjsonb.py
index 04f2af58c0..4eba15512a 100644
--- a/salt/returners/pgjsonb.py
+++ b/salt/returners/pgjsonb.py
@@ -329,7 +329,8 @@ def save_load(jid, load, minions=None):
     with _get_serv(commit=True) as cur:
         try:
             cur.execute(PG_SAVE_LOAD_SQL,
-                        {'jid': jid, 'load': psycopg2.extras.Json(load)})
+                        {'jid': jid, 'load':
+                         psycopg2.extras.Json(salt.utils.data.decode(load))})
         except psycopg2.IntegrityError:
             # https://github.com/saltstack/salt/issues/22171
             # Without this try/except we get tons of duplicate entry errors

If so i can write up a PR with some tests. If it doesn't i'll dive into it more.

[AldarisPale]

Thanks for your reply, @Ch3LL.
Still does not work and the error message has changed:

2019-12-29 16:36:27,546 [salt.utils.event :1233][ERROR   ][1193] Could not store events - returner 'pgjsonb.event_return' raised exception: 'utf8' codec can't decode byte 0xa6 in position 0: invalid start byte
2019-12-29 16:36:27,623 [salt.utils.event :1233][ERROR   ][1193] Could not store events - returner 'pgjsonb.event_return' raised exception: 'utf8' codec can't decode byte 0xc7 in position 0: invalid continuation byte

[AldarisPale]

Here is the result when both patches are applied:

2019-12-29 17:23:43,177 [salt.loaded.int.returner.pgjsonb:331 ][CRITICAL][2452] load is {'tgt_type': 'glob', 'jid': u'20191229172343159240', 'cmd': 'publish', 'tgt': '*', 'kwargs': {'delimiter': ':', 'show_timeout': True, 'show_jid': False}, 'ret': '', 'user': 'sudo_user', 'arg': [], 'fun': 'test.ping'}
2019-12-29 17:23:43,182 [salt.master      :2346][INFO    ][2452] User sudo_user Published command test.ping with jid 20191229172343159240
2019-12-29 17:23:48,572 [salt.transport.mixins.auth:184 ][INFO    ][2448] Authentication request from DESKTOP-RP36H42
2019-12-29 17:23:48,573 [salt.transport.mixins.auth:407 ][INFO    ][2448] Authentication accepted from DESKTOP-RP36H42
2019-12-29 17:23:48,706 [salt.master      :1625][INFO    ][2454] Failed to verify event signature from minion DESKTOP-RP36H42.
2019-12-29 17:23:48,707 [salt.master      :1633][INFO    ][2454] But 'drop_message_signature_fail' is disabled, so message is still accepted.
2019-12-29 17:23:48,716 [salt.utils.job   :68  ][INFO    ][2454] Got return from DESKTOP-RP36H42 for job 20191229172343159240
2019-12-29 17:23:48,732 [salt.utils.event :1233][ERROR   ][2439] Could not store events - returner 'pgjsonb.event_return' raised exception: 'utf8' codec can't decode byte 0x86 in position 1: invalid start byte
2019-12-29 17:23:48,737 [salt.loaded.int.returner.pgjsonb:331 ][CRITICAL][2454] load is {'fun_args': [], 'jid': '20191229172343159240', 'return': True, 'retcode': 0, 'success': True, 'cmd': '_return', u'_stamp': '2019-12-29T15:23:48.717633', u'sig': '$\x86W\x98\xfd;\\{\x90<\x93\x1a\xc9\x7f\xae7Y\x10\'\xeaY\x9d\x0b4(\xf7\x83\xae\xfc\x9d\xb9[\x00Mw\xeax\xda\x19\xdae\xd5\xec\xdc \xacy:F\xd6\x82\x05I/\xc4]\xa1\xda\xef;\xa2\xe5\x94\xbew\xfc\xfa\x06\n\xefg\xed-\xb3v\xfa\xf5\x11\xd1\'\xbaSO\xe1\x96\x14\x1d\x03\xe3(w\xf0\x17j\x08\xcf\xc3\x19\xe3\xd2V:\x84w\xaeD\xe0\xe1A\xaec\xb7\xcaI\xc2U\xa1.\x8f\x87x\x10a\xcf\xe4x\xc7=\x8fI;eq\xf3\xc6V\xe9N;-0\x89?P\xe2+Y\xeb9(h\x94\x0fi\xe6N\xaaYn\t\x97\xda(\x8bD\x05\xbc\x84|V\xc8\x9a\xad$\x11\xa6V\x19\x0b\xc8\x9d:\xbf\x1aQ\x85P\xbdY\x1b"w6V\xe7B?\x14\xa2\xe9r\xd5\x91:V\xe5nY?\xef[\x99\xac\xfd\xf3+\x14\xc2\xe8G\x93{k\x95\x8c\xe5\x84[T.@F\x92\xc6\xdd\x82Y\x18\x96f\x8b~&~u\x88\xc1]Y;cHs\xc1\x896\xca\x98\x88\xe7\xf3\xcb\xb6\xf8\xfd&f%\x1f\xccP\x91E8\x83\x97\x10Y\xe3\xce\xed\xc3J\xbeP\x99X*9\xae\xfc\x8b\xb1\xfa\xa7\x90\xdb\xba\x93l#c\xd1\x08L3\xf6x\xa0\xf1>\n\xe4\x7f\xb2=l\xd9=\x19V\xf1&J\x1d&\x8a|\x9d\xd6\xdaQ\r\x1cL\xf2\x9fh\xe1;eh\x15p%db3[w\x13\xc5)Uz\xbaN\x93tV\xa0\xa2\xa8{\xe2\xc1\xaf10h\xf8\x83I\r\xcb\x8b5.\xf8\xfcX\xaa\xc1{\xd430\xb3\xf9\x9dd\x0cCQ\x9b\xc0\xed`\xbfLe\r\x13s\x05\x15Q\x12\xa3\x90\n\xfc\xe7\xd3\xb8\xc0rd=\xb6M[\xf3\xbc\x9d\xd6YDy\xfd\xf9\x97\xe1IW\x8d=\x03\xc0\xa8\xf5U\xc9|U\xca\xc7\xa9\x14Z\xccs0\xee\x1a=\xf8\xab2\x13!\xd2G\xed\xdd\xf1\xdf0jG\xf2\x12I\x03\xe9\xe3\xa9\xd7\xea\x0c+Vr\x07=\x95\x81\x18\xcf_O\xe4].(>5~\x073\xe0\xd8\x0c\xf3\xd5e\x95\xd7\x8cjD3', 'fun': 'test.ping', 'id': 'DESKTOP-RP36H42'}
2019-12-29 17:23:48,738 [salt.master      :1846][ERROR   ][2454] Error in function _return:
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/salt/master.py", line 1839, in run_func
    ret = getattr(self, func)(load)
  File "/usr/lib/python2.7/dist-packages/salt/master.py", line 1638, in _return
    self.opts, load, event=self.event, mminion=self.mminion)
  File "/usr/lib/python2.7/dist-packages/salt/utils/job.py", line 108, in store_job
    mminion.returners[savefstr](load['jid'], load)
  File "/usr/lib/python2.7/dist-packages/salt/returners/pgjsonb.py", line 333, in save_load
    {'jid': jid, 'load': psycopg2.extras.Json(salt.utils.data.decode(load))})
  File "/usr/lib/python2.7/dist-packages/salt/utils/data.py", line 191, in decode
    preserve_dict_class, preserve_tuples, to_str)
  File "/usr/lib/python2.7/dist-packages/salt/utils/data.py", line 260, in decode_dict
    value = _decode_func(value, encoding, errors, normalize)
  File "/usr/lib/python2.7/dist-packages/salt/utils/stringutils.py", line 160, in to_unicode
    raise exc  # pylint: disable=raising-bad-type
UnicodeDecodeError: 'utf8' codec can't decode byte 0x86 in position 1: invalid start byte

Function looks like this:

def save_load(jid, load, minions=None):
    '''
    Save the load to the specified jid id
    '''
    with _get_serv(commit=True) as cur:
        try:
            log.critical('load is {0}'.format(load))
            cur.execute(PG_SAVE_LOAD_SQL,
                        {'jid': jid, 'load': psycopg2.extras.Json(salt.utils.data.decode(load))})
        except psycopg2.IntegrityError:
            # https://github.com/saltstack/salt/issues/22171
            # Without this try/except we get tons of duplicate entry errors
            # which result in job returns not being stored properly
            pass

[Ch3LL]

thanks for trying that. That fix did work for me when i threw the load you pasted into it so I will need to dig into this a bit further and setup an instance of postgress or mysql. i've added this to my backlog thanks

[wegenerbenjamin]

Is there any update? We ran into the same problem

[ITJamie]

same issue happening

[ITJamie]

Another quick way to trigger this bug via cli on a salt-master (assuming you have event_return and master_job_cache set to postgres)

/etc/salt/master.d/event_db.conf

event_return: [postgres]
master_job_cache: postgres
returner.postgres.host: 'localhost'
returner.postgres.user: 'db_user'
returner.postgres.passwd: 'db_password'
returner.postgres.db: 'db_name'
returner.postgres.port: 5432

salt-run nacl.enc_file name=./some_binary_file

[ITJamie]

Ive put together a fix in #62150 for the postgress returner.
Ive only tested it with salt-run nacl.enc_file for now

If anyone else has an example of how to trigger it ill happy test that it worked for that too

[ITJamie]

I have updated #62150 with a patch for mysql and pgjsonb also