UnicodeDecodeError when using cache mysql

[jeffclay]

Description of Issue/Question

I configured mysql cache. The master was able to contact the mariadb server and create the specified table in the correct db but the salt masters log file is spammed with the error below.

2018-06-27 14:41:34,999 [salt.master      :1783][ERROR   ][38641] Error in function _pillar:
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/salt/master.py", line 1776, in run_func
    ret = getattr(self, func)(load)
  File "/usr/lib/python2.7/site-packages/salt/master.py", line 1487, in _pillar
    'pillar': data})
  File "/usr/lib/python2.7/site-packages/salt/cache/__init__.py", line 156, in store
    return self.modules[fun](bank, key, data, **self._kwargs)
  File "/usr/lib/python2.7/site-packages/salt/cache/mysql_cache.py", line 176, in store
    "'{3}')".format(_table_name, bank, key, data)
UnicodeDecodeError: 'ascii' codec can't decode byte 0x82 in position 0: ordinal not in range(128)

Setup

localectl status
System Locale: LANG=en_US.UTF-8
VC Keymap: us
X11 Layout: us

Versions Report

salt --versions-report
Salt Version:
           Salt: 2018.3.2

Dependency Versions:
           cffi: Not Installed
       cherrypy: Not Installed
       dateutil: Not Installed
      docker-py: Not Installed
          gitdb: 0.6.4
      gitpython: 1.0.1
          ioflo: Not Installed
         Jinja2: 2.7.2
        libgit2: Not Installed
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.5.1
   mysql-python: 1.2.5
      pycparser: Not Installed
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: Not Installed
         Python: 2.7.5 (default, Apr 11 2018, 07:36:10)
   python-gnupg: Not Installed
         PyYAML: 3.11
          PyZMQ: 15.3.0
           RAET: Not Installed
          smmap: 0.9.0
        timelib: Not Installed
        Tornado: 4.2.1
            ZMQ: 4.1.4

System Versions:
           dist: centos 7.5.1804 Core
         locale: UTF-8
        machine: x86_64
        release: 3.10.0-862.3.3.el7.x86_64
         system: Linux
        version: CentOS Linux 7.5.1804 Core

[Ch3LL]

can you share a sanitized version of your mysql cache salt master config to help replicate the issue?

[jeffclay]

user: root
keep_jobs: 0
timeout: 600
minion_data_cache: True
event_return: mysql
ping_on_rotate: True
worker_threads: 50
keysize: 4096
autosign_file: /etc/salt/autosign.conf
autoreject_file: /etc/salt/autoreject.conf
state_output: full
file_roots:
  base:
    - /srv/salt/base
  windows:
    - /srv/salt/base
    - /srv/salt/windows
  linux:
    - /srv/salt/base
    - /srv/salt/linux
top_file_merging_strategy: same
fileserver_backend:
  - roots
winrepo_dir_ng: '/srv/salt/base/win/repo-ng'
# Which returner(s) will be used for minion's result:
return: mysql
master_job_cache: mysql
mysql.host: 'server'
mysql.user: 'user'
mysql.pass: 'password'
mysql.db: 'database'
mysql.port: 3306
#info for cache
mysql.database: 'database'
mysql.password: 'password'
mysql.table_name: 'cache'

[Ch3LL]

im having a hard time replicating this. I am able to run a test.ping for example and it shows up in the database. Can you clarify what command you are running when you are seeing this error?

[jeffclay]

My apologies. I left out a configuration option.

cache: mysql

To answer your question, I'm not running a specific command. As soon as I set the "cache: mysql" setting and restart the master the error begins showing in the log every few seconds without running any command from the masters console.

[Ch3LL]

okay looks like i'm able to replicate this now thanks. we will need to get this fixed up. thanks

[rallytime]

Hi @jeffclay - This should be fixed with #48495. Can you give that a try?

[jeffclay]

I removed the existing mysql_cache.py* files from /usr/lib/python2.7/site-packages/salt/cache then ran 'wget https://raw.githubusercontent.com/garethgreenaway/salt/0029f1903303954bf0ed9d470e4a487d422158a1/salt/cache/mysql_cache.py' to obtain the patched file and I get a similar error.

2018-07-23 16:20:28,111 [salt.master      :1783][ERROR   ][63806] Error in function _pillar:
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/salt/master.py", line 1776, in run_func
    ret = getattr(self, func)(load)
  File "/usr/lib/python2.7/site-packages/salt/master.py", line 1487, in _pillar
    'pillar': data})
  File "/usr/lib/python2.7/site-packages/salt/cache/__init__.py", line 156, in store
    return self.modules[fun](bank, key, data, **self._kwargs)
  File "/usr/lib/python2.7/site-packages/salt/cache/mysql_cache.py", line 181, in store
    cur, cnt = run_query(client, query)
  File "/usr/lib/python2.7/site-packages/salt/cache/mysql_cache.py", line 107, in run_query
    query = query[:150] + "<...>"
UnicodeDecodeError: 'ascii' codec can't decode byte 0x82 in position 83: ordinal not in range(128)

[jeffclay]

@rallytime I also tried DmitryKuzmenko suggestion #48495 and that gave an error about .hex() not existing. I tried modifying to to be hex(data) and got an error that the value couldn't be converted to hex.

[rallytime]

@garethgreenaway Can you follow up when you get a moment on this one?

[jeffclay]

@rallytime @garethgreenaway

I imported binascii to mysql_cache.py and changed store() as shown below

def store(bank, key, data):
    '''
    Store a key value.
    '''
    _init_client()
    data = __context__['serial'].dumps(data)
    query = "REPLACE INTO {0} (bank, etcd_key, data) values('{1}', '{2}', " \
        "X'{3}')".format(_table_name, bank, key, binascii.hexlify(data))
    cur, cnt = run_query(client, query)
    cur.close()
    if cnt not in (1, 2):
        raise SaltCacheError(
            'Error storing {0} {1} returned {2}'.format(bank, key, cnt)
        )

This resolved the error and data is now going into the 'data' column of the database. However, I'm not sure if it's the correct format or if other changes are required to retrieve the data properly.

[jeffclay]

@rallytime @garethgreenaway

Just following up to see if my solution above is the proper fix for this issue or not.

Thanks

[garethgreenaway]

@jeffclay This looks good for me. Would you be able to prepare a pull request with the change above?

[sagetherage]

closing as stale