Closed
Description
Description of Issue
In Salt 2019.2.1 and 2019.2.2 the pillar top file and all pillar data are re-rendered for every single salt command that is run. Including things like salt \* test.ping
Setup
Install Salt 2019.2.1 or 2019.2.2. Set the master log to debug and tail /var/log/salt/master
Create a /srv/pillar/top.sls and add a pillar sls file so that your minion will be assigned pillar data.
Steps to Reproduce Issue
Run salt \* saltutil.refresh_pillar
Run salt \* pillar.items
Run salt \* test.ping
You'll see that the pillar top file and pillar data are rendered for every command, when pillar data should only be rendered with refresh_pillar, highstate and the other proscribed times.
2019-10-09 22:52:14,844 [salt.config :2185][DEBUG ][2682] Reading configuration from /etc/salt/master
2019-10-09 22:52:14,846 [salt.config :3666][DEBUG ][2682] Using cached minion ID from /etc/salt/minion_id: xxPing
2019-10-09 22:52:14,848 [salt.config :2289][DEBUG ][2682] Missing configuration file: /root/.saltrc
2019-10-09 22:52:14,851 [salt.utils.event :323 ][DEBUG ][2682] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
2019-10-09 22:52:14,851 [salt.utils.event :324 ][DEBUG ][2682] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
2019-10-09 22:52:14,902 [salt.transport.zeromq:138 ][DEBUG ][2682] Initializing new AsyncZeroMQReqChannel for (u'/etc/salt/pki/master', u'xxPing_master', u'tcp://127.0.0.1:4506', u'clear')
2019-10-09 22:52:14,902 [salt.transport.zeromq:209 ][DEBUG ][2682] Connecting the Minion to the Master URI (for the return server): tcp://127.0.0.1:4506
2019-10-09 22:52:14,903 [salt.transport.zeromq:1189][DEBUG ][2682] Trying to connect to: tcp://127.0.0.1:4506
2019-10-09 22:52:14,908 [salt.utils.event :738 ][DEBUG ][1367] Sending event: tag = 20191009225214907427; data = {u'_stamp': '2019-10-09T22:52:14.908008', u'minions': [u'xxPing']}
2019-10-09 22:52:14,908 [salt.utils.event :738 ][DEBUG ][1367] Sending event: tag = salt/job/20191009225214907427/new; data = {u'tgt_type': 'glob', u'jid': u'20191009225214907427', u'user': 'root', u'tgt': '*', u'arg': [], u'fun': 'test.ping', u'missing': [], u'_stamp': '2019-10-09T22:52:14.908485', u'minions': [u'xxPing']}
2019-10-09 22:52:14,909 [salt.loaded.int.returner.local_cache:252 ][DEBUG ][1367] Adding minions for job 20191009225214907427: [u'xxPing']
2019-10-09 22:52:14,909 [salt.master :2346][INFO ][1367] User root Published command test.ping with jid 20191009225214907427
2019-10-09 22:52:14,909 [salt.master :2354][DEBUG ][1367] Published command details {u'tgt_type': 'glob', u'jid': u'20191009225214907427', u'tgt': '*', u'ret': '', u'user': 'root', u'arg': [], u'fun': 'test.ping'}
2019-10-09 22:52:14,910 [salt.transport.zeromq:1023][DEBUG ][1367] Signing data packet
2019-10-09 22:52:14,910 [salt.crypt :200 ][DEBUG ][1367] salt.crypt.get_rsa_key: Loading private key
2019-10-09 22:52:14,910 [salt.crypt :225 ][DEBUG ][1367] salt.crypt.sign_message: Signing message.
2019-10-09 22:52:14,912 [salt.transport.zeromq:1045][DEBUG ][1367] Sending payload to publish daemon. jid=20191009225214907427 size=436
2019-10-09 22:52:14,913 [salt.transport.zeromq:1050][DEBUG ][1367] Sent payload to publish daemon.
2019-10-09 22:52:14,913 [salt.transport.zeromq:906 ][DEBUG ][1351] Publish daemon received payload. size=436
2019-10-09 22:52:14,913 [salt.transport.zeromq:904 ][DEBUG ][1351] Publish daemon getting data from puller ipc:///var/run/salt/master/publish_pull.ipc
2019-10-09 22:52:14,915 [salt.transport.zeromq:233 ][DEBUG ][2682] Closing AsyncZeroMQReqChannel instance
2019-10-09 22:52:14,918 [salt.utils.lazy :104 ][DEBUG ][2682] LazyLoaded local_cache.get_load
2019-10-09 22:52:14,919 [salt.loaded.int.returner.local_cache:323 ][DEBUG ][2682] Reading minion list from /var/cache/salt/master/jobs/b4/e944dfcf53c1e383d37c3ee6d8ec3527e964ddb669dbdc03e22e3026504c0b/.minions.p
2019-10-09 22:52:14,920 [salt.client :1100][DEBUG ][2682] get_iter_returns for jid 20191009225214907427 sent to set(['xxPing']) will timeout at 22:52:19.919999
2019-10-09 22:52:14,927 [salt.pillar :57 ][DEBUG ][1366] Determining pillar cache
2019-10-09 22:52:14,968 [salt.utils.lazy :104 ][DEBUG ][1366] LazyLoaded jinja.render
2019-10-09 22:52:14,969 [salt.utils.lazy :104 ][DEBUG ][1366] LazyLoaded yaml.render
2019-10-09 22:52:14,981 [salt.template :59 ][DEBUG ][1366] compile template: /srv/pillar/top.sls
2019-10-09 22:52:14,981 [salt.utils.jinja :83 ][DEBUG ][1366] Jinja search path: [u'/srv/pillar', u'/srv/spm/pillar']
2019-10-09 22:52:14,982 [salt.template :26 ][PROFILE ][1366] Time (in seconds) to render '/srv/pillar/top.sls' using 'jinja' renderer: 0.00102114677429
2019-10-09 22:52:14,983 [salt.template :120 ][DEBUG ][1366] Rendered data from file: /srv/pillar/top.sls:
base:
'*':
- test
2019-10-09 22:52:14,983 [salt.loaded.int.render.yaml:80 ][DEBUG ][1366] Results of YAML rendering:
OrderedDict([(u'base', OrderedDict([(u'*', [u'test'])]))])
2019-10-09 22:52:14,984 [salt.template :26 ][PROFILE ][1366] Time (in seconds) to render '/srv/pillar/top.sls' using 'yaml' renderer: 0.000813007354736
2019-10-09 22:52:14,985 [salt.utils.lazy :104 ][DEBUG ][1366] LazyLoaded confirm_top.confirm_top
2019-10-09 22:52:14,987 [salt.utils.lazy :104 ][DEBUG ][1366] LazyLoaded compound_match.match
2019-10-09 22:52:14,989 [salt.loaded.int.matchers.compound_match:35 ][DEBUG ][1366] compound_match: xxPing ? *
2019-10-09 22:52:14,989 [salt.utils.lazy :104 ][DEBUG ][1366] LazyLoaded glob_match.match
2019-10-09 22:52:14,990 [salt.loaded.int.matchers.compound_match:108 ][DEBUG ][1366] compound_match xxPing ? "*" => "True"
2019-10-09 22:52:14,990 [salt.template :59 ][DEBUG ][1366] compile template: /srv/pillar/test.sls
2019-10-09 22:52:14,991 [salt.utils.jinja :83 ][DEBUG ][1366] Jinja search path: [u'/srv/pillar', u'/srv/spm/pillar']
2019-10-09 22:52:14,991 [salt.template :26 ][PROFILE ][1366] Time (in seconds) to render '/srv/pillar/test.sls' using 'jinja' renderer: 0.000850915908813
2019-10-09 22:52:14,992 [salt.template :120 ][DEBUG ][1366] Rendered data from file: /srv/pillar/test.sls:
boucha: True
2019-10-09 22:52:14,992 [salt.loaded.int.render.yaml:80 ][DEBUG ][1366] Results of YAML rendering:
OrderedDict([(u'boucha', True)])
2019-10-09 22:52:14,992 [salt.template :26 ][PROFILE ][1366] Time (in seconds) to render '/srv/pillar/test.sls' using 'yaml' renderer: 0.000324964523315
2019-10-09 22:52:14,993 [salt.utils.event :738 ][DEBUG ][1366] Sending event: tag = minion/refresh/xxPing; data = {u'Minion data cache refresh': 'xxPing', u'_stamp': '2019-10-09T22:52:14.993499'}
2019-10-09 22:52:14,994 [salt.crypt :208 ][DEBUG ][1366] salt.crypt.get_rsa_pub_key: Loading public key
2019-10-09 22:52:15,072 [salt.utils.job :68 ][INFO ][1358] Got return from xxPing for job 20191009225214907427
2019-10-09 22:52:15,072 [salt.utils.event :738 ][DEBUG ][1358] Sending event: tag = salt/job/20191009225214907427/ret/xxPing; data = {'fun_args': [], 'jid': '20191009225214907427', 'return': True, 'retcode': 0, 'success': True, 'cmd': '_return', u'_stamp': '2019-10-09T22:52:15.072368', 'fun': 'test.ping', 'id': 'xxPing'}
2019-10-09 22:52:15,073 [salt.client :1129][DEBUG ][2682] jid 20191009225214907427 return from xxPing
2019-10-09 22:52:15,074 [salt.client :1529][DEBUG ][2682] return event: {u'xxPing': {u'jid': u'20191009225214907427', u'retcode': 0, u'ret': True}}
2019-10-09 22:52:15,076 [salt.utils.lazy :104 ][DEBUG ][2682] LazyLoaded nested.output
2019-10-09 22:52:15,178 [salt.client :1135][DEBUG ][2682] jid 20191009225214907427 found all minions set([u'xxPing'])
2019-10-09 22:52:15,179 [salt.transport.ipc:364 ][DEBUG ][2682] Closing IPCMessageSubscriber instance
Versions Report
[root@xxPing ~]# salt \* test.versions_report
xxPing:
Salt Version:
Salt: 2019.2.1
Dependency Versions:
cffi: Not Installed
cherrypy: Not Installed
dateutil: Not Installed
docker-py: Not Installed
gitdb: Not Installed
gitpython: Not Installed
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.4.6
mysql-python: Not Installed
pycparser: Not Installed
pycrypto: 2.6.1
pycryptodome: Not Installed
pygit2: Not Installed
Python: 2.7.5 (default, Aug 7 2019, 00:51:29)
python-gnupg: Not Installed
PyYAML: 3.11
PyZMQ: 15.3.0
RAET: Not Installed
smmap: Not Installed
timelib: Not Installed
Tornado: 4.2.1
ZMQ: 4.1.4
System Versions:
dist: centos 7.7.1908 Core
locale: ascii
machine: x86_64
release: 4.15.0-65-generic
system: Linux
version: CentOS Linux 7.7.1908 Core