yumpkg.installed broken in salt v2015.8.1 on CentOS 6 minions #28526

clarkperkins · 2015-11-03T16:01:16Z

Hi,

I'm running almost exclusively CentOS 6 minions, and there seems to be a bug whenever you run pkg.installed more than once, but ONLY on 2015.8.1. 2015.8.0 is fine.

Here's the stack trace I get from the command line:

> salt 'my-minions-*' state.sls core.*
....
          ID: install-ntpd
    Function: pkg.installed
      Result: False
     Comment: An exception occurred in this state: Traceback (most recent call last):
                File "/usr/lib/python2.6/site-packages/salt/state.py", line 1591, in call
                  **cdata['kwargs'])
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 943, in installed
                  **kwargs)
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 371, in _find_install_targets
                  problems = _preflight_check(not_installed, **kwargs)
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 547, in _preflight_check
                  *list(desired.keys()), fromrepo=fromrepo, **kwargs
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 760, in check_db
                  set(x.name for x in _repoquery_pkginfo(repoquery_cmd))
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 95, in _repoquery_pkginfo
                  for line in _repoquery(repoquery_args, ignore_stderr=True):
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 149, in _repoquery
                  '{0}'.format(comment)
              CommandExecutionError
     Started: 15:45:08.732476
    Duration: 53774.058 ms
     Changes:
....

And here's the state definition in the sls file:

...

install-ntpd:
  pkg:
    - installed
    - pkgs:
      - ntp
      - ntpdate
      - ntp-doc

...

To clarify, both master and minion are running salt 2015.8.1, but the master is on 14.04.3 LTS, while my minions are on CentOS 6.5.

The text was updated successfully, but these errors were encountered:

jfindlay · 2015-11-03T21:14:04Z

@clarkperkins, thanks for the report. Related to #26129.

cachedout · 2015-11-05T19:53:47Z

@clarkperkins I cannot reproduce this but I am wondering if this might be related: https://github.com/saltstack/salt/pull/27049/files

Can you revert that change on your minion that's exhibiting this behavior and let me know if it makes a difference?

terminalmage · 2015-11-05T19:58:09Z

@clarkperkins Before you do that, please login to the minion and run the following command, and post the output:

salt-call -l debug state.single pkg.installed name=install-ntpd pkgs="[ntp, ntpdate, ntp-doc]"

I'd like to see the command being run which triggers the traceback.

grep4linux · 2015-11-05T21:47:03Z

Recreated the issue on my CentOS 6.5 box deploying redis.

I changed the:

redis:
  pkg.installed:
    - pkgs:
      - redis-server

to

redis:
  pkg.latest:
    - pkgs:
      - redis-server

as a work around.

Here is the output of salt frode-redis state.sls redis test=True -l debug

 ID: redis
    Function: pkg.installed
      Result: False
     Comment: An exception occurred in this state: Traceback (most recent call last):
                File "/usr/lib/python2.6/site-packages/salt/state.py", line 1591, in call
                  **cdata['kwargs'])
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 943, in installed
                  **kwargs)
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 371, in _find_install_targets
                  problems = _preflight_check(not_installed, **kwargs)
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 547, in _preflight_check
                  *list(desired.keys()), fromrepo=fromrepo, **kwargs
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 760, in check_db
                  set(x.name for x in _repoquery_pkginfo(repoquery_cmd))
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 95, in _repoquery_pkginfo
                  for line in _repoquery(repoquery_args, ignore_stderr=True):
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 149, in _repoquery
                  '{0}'.format(comment)
              CommandExecutionError
     Started: 21:35:01.805034
    Duration: 47191.025 ms
     Changes:

Here is the info when running wit salt-call on the minion (salt-call state.sls redis test=True):

salt-call state.sls redis test=True 
[INFO    ] Loading fresh modules for state activity
[INFO    ] Fetching file from saltenv 'base', ** done ** u'redis/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** done ** u'redis/map.jinja'
[INFO    ] Running state [redis] at time 21:44:31.035483
[INFO    ] Executing state pkg.installed for redis
[INFO    ] Executing command ['rpm', '-qa', '--queryformat', '%{NAME}_|-%{VERSION}_|-%{RELEASE}_|-%{ARCH}_|-(none)\n'] in directory '/root'
[INFO    ] Executing command "repoquery --plugins --queryformat '%{NAME}_|-%{ARCH}'  --pkgnarrow=all --all" in directory '/root'
[INFO    ] Executing command "repoquery --plugins --queryformat '%{NAME}_|-%{VERSION}_|-%{RELEASE}_|-%{ARCH}_|-%{REPOID}'   --all --quiet --whatprovides " in directory '/root'
[ERROR   ] Command "repoquery --plugins --queryformat '%{NAME}_|-%{VERSION}_|-%{RELEASE}_|-%{ARCH}_|-%{REPOID}'   --all --quiet --whatprovides " failed with return code: -9
[ERROR   ] retcode: -9
[ERROR   ] An exception occurred in this state: Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/salt/state.py", line 1591, in call
    **cdata['kwargs'])
  File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 943, in installed
    **kwargs)
  File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 371, in _find_install_targets
    problems = _preflight_check(not_installed, **kwargs)
  File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 547, in _preflight_check
    *list(desired.keys()), fromrepo=fromrepo, **kwargs
  File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 760, in check_db
    set(x.name for x in _repoquery_pkginfo(repoquery_cmd))
  File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 95, in _repoquery_pkginfo
    for line in _repoquery(repoquery_args, ignore_stderr=True):
  File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 149, in _repoquery
    '{0}'.format(comment)
CommandExecutionError

[INFO    ] Completed state [redis] at time 21:45:24.938664
local:
----------
          ID: redis
    Function: pkg.installed
      Result: False
     Comment: An exception occurred in this state: Traceback (most recent call last):
                File "/usr/lib/python2.6/site-packages/salt/state.py", line 1591, in call
                  **cdata['kwargs'])
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 943, in installed
                  **kwargs)
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 371, in _find_install_targets
                  problems = _preflight_check(not_installed, **kwargs)
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 547, in _preflight_check
                  *list(desired.keys()), fromrepo=fromrepo, **kwargs
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 760, in check_db
                  set(x.name for x in _repoquery_pkginfo(repoquery_cmd))
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 95, in _repoquery_pkginfo
                  for line in _repoquery(repoquery_args, ignore_stderr=True):
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 149, in _repoquery
                  '{0}'.format(comment)
              CommandExecutionError
     Started: 21:44:31.035483
    Duration: 53903.181 ms
     Changes:   
----------
          ID: redis_conf
    Function: file.managed
        Name: /etc/redis.conf
      Result: False
     Comment: One or more requisite failed: redis.redis
     Started: 
    Duration: 
     Changes:   
----------
          ID: redis
    Function: service.running
      Result: False
     Comment: One or more requisite failed: redis.redis_conf
     Started: 
    Duration: 
     Changes:   

Summary for local
------------
Succeeded: 0
Failed:    3
------------
Total states run:     3
Total run time:  53.903 s

ankitforcode · 2015-11-06T02:34:07Z

+1

ankitforcode · 2015-11-06T02:34:22Z

I was able to replicate the issue since yesterday.. :-(

ankitforcode · 2015-11-06T02:34:54Z

Function: pkg.installed
  Result: False
 Comment: An exception occurred in this state: Traceback (most recent call last):
            File "/usr/lib/python2.6/site-packages/salt/state.py", line 1591, in call
              **cdata['kwargs'])
            File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 943, in installed
              **kwargs)
            File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 371, in _find_install_targets
              problems = _preflight_check(not_installed, **kwargs)
            File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 547, in _preflight_check
              *list(desired.keys()), fromrepo=fromrepo, **kwargs
            File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 760, in check_db
              set(x.name for x in _repoquery_pkginfo(repoquery_cmd))
            File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 95, in _repoquery_pkginfo
              for line in _repoquery(repoquery_args, ignore_stderr=True):
            File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 149, in _repoquery
              '{0}'.format(comment)
          CommandExecutionError
 Started: 02:31:52.792727
Duration: 13341.813 ms
 Changes:

ankitforcode · 2015-11-06T02:35:58Z

salt --versions-report

Salt Version:
Salt: 2015.8.1

Dependency Versions:
Jinja2: 2.2.1
M2Crypto: 0.20.2
Mako: Not Installed
PyYAML: 3.11
PyZMQ: 14.5.0
Python: 2.6.6 (r266:84292, Jul 23 2015, 15:22:56)
RAET: Not Installed
Tornado: 4.2.1
ZMQ: 4.0.5
cffi: Not Installed
cherrypy: Not Installed
dateutil: Not Installed
gitdb: Not Installed
gitpython: Not Installed
ioflo: Not Installed
libnacl: Not Installed
msgpack-pure: Not Installed
msgpack-python: 0.4.6
mysql-python: Not Installed
pycparser: Not Installed
pycrypto: 2.6.1
pygit2: Not Installed
python-gnupg: Not Installed
smmap: Not Installed
timelib: Not Installed

System Versions:
dist: centos 6.7 Final
machine: x86_64
release: 2.6.32-504.12.2.el6.x86_64
system: CentOS 6.7 Final

RuriRyan · 2015-11-06T13:02:32Z

If you do a salt-call and repoquery returns a -9 look at your messages log. It may be because the linux oom-killer striked and killed your process.
We had a similar issue and discovered repoquery claimed up to 1.5 GB of RAM. Increasing the RAM helped.
(Note: we are using virtual machines)

clarkperkins · 2015-11-06T16:36:24Z

@RuriRyan - when I do the salt-call command, that is exactly what happens actually. It says there's a -9 retcode, and the messages log reports that it killed repoquery. The box I'm running on only has 600 some MB of ram, so that might be a part of it. But that doesn't really explain why this wasn't a problem with salt 2015.8.0, and only occurs in 2015.8.1

terminalmage · 2015-11-06T16:50:34Z

@grep4linux You have removed all the debug logging that I was hoping to see from the salt-call output. Can you please re-attempt and post the full output, not just the state return?

clarkperkins · 2015-11-06T17:50:11Z

Here is the debug logging:

for 2015.8.1:

[DEBUG   ] Reading configuration from /etc/salt/minion
[DEBUG   ] Including configuration from '/etc/salt/minion.d/_schedule.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/_schedule.conf
[DEBUG   ] Configuration file path: /etc/salt/minion
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG   ] Reading configuration from /etc/salt/minion
[DEBUG   ] Including configuration from '/etc/salt/minion.d/_schedule.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/_schedule.conf
[DEBUG   ] Please install 'virt-what' to improve results of the 'virtual' grain.
[DEBUG   ] Initializing new SAuth for ('/etc/salt/pki/minion', 'clark-java-0', 'tcp://10.101.251.131:4506')
[DEBUG   ] Generated random reconnect delay between '1000ms' and '11000ms' (10611)
[DEBUG   ] Setting zmq_reconnect_ivl to '10611ms'
[DEBUG   ] Setting zmq_reconnect_ivl_max to '11000ms'
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'clark-java-0', 'tcp://10.101.251.131:4506', 'aes')
[DEBUG   ] Initializing new SAuth for ('/etc/salt/pki/minion', 'clark-java-0', 'tcp://10.101.251.131:4506')
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'clark-java-0', 'tcp://10.101.251.131:4506', 'clear')
[DEBUG   ] Decrypting the current master AES key
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] LazyLoaded state.single
[DEBUG   ] LazyLoaded saltutil.is_running
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'clark-java-0', 'tcp://10.101.251.131:4506', 'aes')
[DEBUG   ] Initializing new SAuth for ('/etc/salt/pki/minion', 'clark-java-0', 'tcp://10.101.251.131:4506')
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[INFO    ] Loading fresh modules for state activity
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] LazyLoaded pkg.install
[DEBUG   ] LazyLoaded pkg.installed
[DEBUG   ] Error loading module.ipmi: No module named pyghmi.ipmi
[DEBUG   ] LazyLoaded config.get
[DEBUG   ] Error loading module.ifttt: IFTTT Secret Key Unavailable, not loading.
[DEBUG   ] Error loading module.victorops: No VictorOps api key found.
[DEBUG   ] Error loading module.tls: ['PyOpenSSL version 0.10 or later must be installed before this module can be used.']
[DEBUG   ] Error loading module.nacl: libnacl import error, perhaps missing python libnacl package
[DEBUG   ] Error loading module.npm: npm execution module could not be loaded because the npm binary could not be located
[DEBUG   ] SMBIOS: neither dmidecode nor smbios found!
[DEBUG   ] Could not LazyLoad pkg.ex_mod_init
[INFO    ] Running state [install-ntpd] at time 16:29:18.991430
[INFO    ] Executing state pkg.installed for install-ntpd
[INFO    ] Executing command ['rpm', '-qa', '--queryformat', '%{NAME}_|-%{VERSION}_|-%{RELEASE}_|-%{ARCH}_|-(none)\n'] in directory '/root'
[INFO    ] Executing command "repoquery --plugins --queryformat '%{NAME}_|-%{ARCH}'  --pkgnarrow=all --all" in directory '/root'
[INFO    ] Executing command "repoquery --plugins --queryformat '%{NAME}_|-%{VERSION}_|-%{RELEASE}_|-%{ARCH}_|-%{REPOID}'   --all --quiet --whatprovides " in directory '/root'
[ERROR   ] Command "repoquery --plugins --queryformat '%{NAME}_|-%{VERSION}_|-%{RELEASE}_|-%{ARCH}_|-%{REPOID}'   --all --quiet --whatprovides " failed with return code: -9
[ERROR   ] retcode: -9
[ERROR   ] An exception occurred in this state: Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/salt/state.py", line 1591, in call
    **cdata['kwargs'])
  File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 943, in installed
    **kwargs)
  File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 371, in _find_install_targets
    problems = _preflight_check(not_installed, **kwargs)
  File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 547, in _preflight_check
    *list(desired.keys()), fromrepo=fromrepo, **kwargs
  File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 760, in check_db
Mar 18 22:59:43 ip-10-185-3-147 kernel: imklog 5.8.10, log source = /proc/kmsg started.
Mar 18 22:59:43 ip-10-185-3-147 rsyslogd: [origin software="rsyslogd" swVersion="5.8.10" x-pid="704" x-info="http://www.rsyslog.com"] start
Mar 18 22:59:43 ip-10-185-3-147 kernel: Initializing cgroup subsys cpuset
Mar 18 22:59:43 ip-10-185-3-147 kernel: Initializing cgroup subsys cpu
Mar 18 22:59:43 ip-10-185-3-147 kernel: Linux version 2.6.32-431.29.2.el6.x86_64 (mockbuild@c6b9.bsys.dev.centos.org) (gcc version 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC) ) #1 SMP Tue Sep 9 21:36:05 UTC 2014
Mar 18 22:59:43 ip-10-185-3-147 kernel: Command line: ro root=LABEL=_ console=ttyS0,115200 crashkernel=no
Mar 18 22:59:43 ip-10-185-3-147 kernel: KERNEL supported cpus:
Mar 18 22:59:43 ip-10-185-3-147 kernel:  Intel GenuineIntel
Mar 18 22:59:43 ip-10-185-3-147 kernel:  AMD AuthenticAMD
Mar 18 22:59:43 ip-10-185-3-147 kernel:  Centaur CentaurHauls
Mar 18 22:59:43 ip-10-185-3-147 kernel: ACPI in unprivileged domain disabled
Mar 18 22:59:43 ip-10-185-3-147 kernel: released 0 pages of unused memory
Mar 18 22:59:43 ip-10-185-3-147 kernel: BIOS-provided physical RAM map:
Mar 18 22:59:43 ip-10-185-3-147 kernel: Xen: 0000000000000000 - 00000000000a0000 (usable)
Mar 18 22:59:43 ip-10-185-3-147 kernel: Xen: 00000000000a0000 - 0000000000100000 (reserved)
Mar 18 22:59:43 ip-10-185-3-147 kernel: Xen: 0000000000100000 - 0000000026700000 (usable)
Mar 18 22:59:43 ip-10-185-3-147 kernel: DMI not present or invalid.
Mar 18 22:59:43 ip-10-185-3-147 kernel: last_pfn = 0x26700 max_arch_pfn = 0x400000000
Mar 18 22:59:43 ip-10-185-3-147 kernel: x2apic enabled by BIOS, switching to x2apic ops
Mar 18 22:59:43 ip-10-185-3-147 kernel: init_memory_mapping: 0000000000000000-0000000026700000
Mar 18 22:59:43 ip-10-185-3-147 kernel: RAMDISK: 02041000 - 045bf000
Mar 18 22:59:43 ip-10-185-3-147 kernel: No NUMA configuration found
Mar 18 22:59:43 ip-10-185-3-147 kernel: Faking a node at 0000000000000000-0000000026700000
Mar 18 22:59:43 ip-10-185-3-147 kernel: Bootmem setup node 0 0000000000000000-0000000026700000
Mar 18 22:59:43 ip-10-185-3-147 kernel:  NODE_DATA [0000000000008000 - 000000000003bfff]
Mar 18 22:59:43 ip-10-185-3-147 kernel:  bootmap [000000000003c000 -  0000000000040cdf] pages 5
Mar 18 22:59:43 ip-10-185-3-147 kernel: (7 early reservations) ==> bootmem [0000000000 - 0026700000]
Mar 18 22:59:43 ip-10-185-3-147 kernel:  #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
Mar 18 22:59:43 ip-10-185-3-147 kernel:  #1 [00046f6000 - 000471d000]   XEN PAGETABLES ==> [00046f6000 - 000471d000]
Mar 18 22:59:43 ip-10-185-3-147 kernel:  #2 [0000006000 - 0000008000]       TRAMPOLINE ==> [0000006000 - 0000008000]
Mar 18 22:59:43 ip-10-185-3-147 kernel:  #3 [0001000000 - 0002020aa4]    TEXT DATA BSS ==> [0001000000 - 0002020aa4]
Mar 18 22:59:43 ip-10-185-3-147 kernel:  #4 [0002041000 - 00045bf000]          RAMDISK ==> [0002041000 - 00045bf000]
Mar 18 22:59:43 ip-10-185-3-147 kernel:  #5 [00045bf000 - 00046f6000]   XEN START INFO ==> [00045bf000 - 00046f6000]
Mar 18 22:59:43 ip-10-185-3-147 kernel:  #6 [0000100000 - 000020c000]          PGTABLE ==> [0000100000 - 000020c000]
Mar 18 22:59:43 ip-10-185-3-147 kernel: crashkernel: memory value expected
Mar 18 22:59:43 ip-10-185-3-147 kernel: Zone PFN ranges:
Mar 18 22:59:43 ip-10-185-3-147 kernel:  DMA      0x00000001 -> 0x00001000
Mar 18 22:59:43 ip-10-185-3-147 kernel:  DMA32    0x00001000 -> 0x00100000
Mar 18 22:59:43 ip-10-185-3-147 kernel:  Normal   0x00100000 -> 0x00100000
Mar 18 22:59:43 ip-10-185-3-147 kernel: Movable zone start PFN for each node
Mar 18 22:59:43 ip-10-185-3-147 kernel: early_node_map[2] active PFN ranges
Mar 18 22:59:43 ip-10-185-3-147 kernel:    0: 0x00000001 -> 0x000000a0
Mar 18 22:59:43 ip-10-185-3-147 kernel:    0: 0x00000100 -> 0x00026700
Mar 18 22:59:43 ip-10-185-3-147 kernel: SFI: Simple Firmware Interface v0.7 http://simplefirmware.org
Mar 18 22:59:43 ip-10-185-3-147 kernel: SMP: Allowing 1 CPUs, 0 hotplug CPUs
Mar 18 22:59:43 ip-10-185-3-147 kernel: PM: Registered nosave memory: 00000000000a0000 - 0000000000100000
Mar 18 22:59:43 ip-10-185-3-147 kernel: Allocating PCI resources starting at 26700000 (gap: 26700000:d9900000)
Mar 18 22:59:43 ip-10-185-3-147 kernel: Booting paravirtualized kernel on Xen
Mar 18 22:59:43 ip-10-185-3-147 kernel: Xen version: 3.4.3.amazon (preserve-AD)
Mar 18 22:59:43 ip-10-185-3-147 kernel: NR_CPUS:4096 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
Mar 18 22:59:43 ip-10-185-3-147 kernel: PERCPU: Embedded 31 pages/cpu @ffff880004753000 s94872 r8192 d23912 u126976
Mar 18 22:59:43 ip-10-185-3-147 kernel: pcpu-alloc: s94872 r8192 d23912 u126976 alloc=31*4096
Mar 18 22:59:43 ip-10-185-3-147 kernel: pcpu-alloc: [0] 0
Mar 18 22:59:43 ip-10-185-3-147 kernel: Xen: using vcpu_info placement
"messages" 559L, 49510C
    set(x.name for x in _repoquery_pkginfo(repoquery_cmd))
  File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 95, in _repoquery_pkginfo
    for line in _repoquery(repoquery_args, ignore_stderr=True):
  File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 149, in _repoquery
    '{0}'.format(comment)
CommandExecutionError

[INFO    ] Completed state [install-ntpd] at time 16:30:14.855629
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'clark-java-0', 'tcp://10.101.251.131:4506', 'aes')
[DEBUG   ] Initializing new SAuth for ('/etc/salt/pki/minion', 'clark-java-0', 'tcp://10.101.251.131:4506')
[DEBUG   ] LazyLoaded highstate.output
local:
----------
          ID: install-ntpd
    Function: pkg.installed
      Result: False
     Comment: An exception occurred in this state: Traceback (most recent call last):
                File "/usr/lib/python2.6/site-packages/salt/state.py", line 1591, in call
                  **cdata['kwargs'])
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 943, in installed
                  **kwargs)
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 371, in _find_install_targets
                  problems = _preflight_check(not_installed, **kwargs)
                File "/usr/lib/python2.6/site-packages/salt/states/pkg.py", line 547, in _preflight_check
                  *list(desired.keys()), fromrepo=fromrepo, **kwargs
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 760, in check_db
                  set(x.name for x in _repoquery_pkginfo(repoquery_cmd))
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 95, in _repoquery_pkginfo
                  for line in _repoquery(repoquery_args, ignore_stderr=True):
                File "/usr/lib/python2.6/site-packages/salt/modules/yumpkg.py", line 149, in _repoquery
                  '{0}'.format(comment)
              CommandExecutionError
     Started: 16:29:18.991430
    Duration: 55864.199 ms
     Changes:

Summary for local
------------
Succeeded: 0
Failed:    1
------------
Total states run:     1
Total run time:  55.864 s

for 2015.8.0:

[DEBUG   ] Reading configuration from /etc/salt/minion
[DEBUG   ] Including configuration from '/etc/salt/minion.d/_schedule.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/_schedule.conf
[DEBUG   ] Configuration file path: /etc/salt/minion
[DEBUG   ] Reading configuration from /etc/salt/minion
[DEBUG   ] Including configuration from '/etc/salt/minion.d/_schedule.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/_schedule.conf
[DEBUG   ] Please install 'virt-what' to improve results of the 'virtual' grain.
[DEBUG   ] Initializing new SAuth for ('/etc/salt/pki/minion', 'clark-scale-test-nn', 'tcp://10.101.251.131:4506')
[DEBUG   ] Generated random reconnect delay between '1000ms' and '11000ms' (9591)
[DEBUG   ] Setting zmq_reconnect_ivl to '9591ms'
[DEBUG   ] Setting zmq_reconnect_ivl_max to '11000ms'
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'clark-scale-test-nn', 'tcp://10.101.251.131:4506', 'aes')
[DEBUG   ] Initializing new SAuth for ('/etc/salt/pki/minion', 'clark-scale-test-nn', 'tcp://10.101.251.131:4506')
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'clark-scale-test-nn', 'tcp://10.101.251.131:4506', 'clear')
[DEBUG   ] Decrypting the current master AES key
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] LazyLoaded state.single
[DEBUG   ] LazyLoaded saltutil.is_running
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'clark-scale-test-nn', 'tcp://10.101.251.131:4506', 'aes')
[DEBUG   ] Initializing new SAuth for ('/etc/salt/pki/minion', 'clark-scale-test-nn', 'tcp://10.101.251.131:4506')
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[INFO    ] Loading fresh modules for state activity
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] LazyLoaded pkg.install
[DEBUG   ] LazyLoaded pkg.installed
[DEBUG   ] Error loading module.ipmi: No module named pyghmi.ipmi
[DEBUG   ] LazyLoaded config.get
[DEBUG   ] Error loading module.ifttt: IFTTT Secret Key Unavailable, not loading.
[DEBUG   ] Error loading module.victorops: No VictorOps api key found.
[DEBUG   ] Error loading module.tls: ['PyOpenSSL version 0.10 or later must be installed before this module can be used.']
[DEBUG   ] Error loading module.nacl: libnacl import error, perhaps missing python libnacl package
[DEBUG   ] Error loading module.npm: npm execution module could not be loaded because the npm binary could not be located
[DEBUG   ] SMBIOS: neither dmidecode nor smbios found!
[DEBUG   ] Could not LazyLoad pkg.ex_mod_init
[INFO    ] Running state [install-ntpd] at time 16:40:24.360436
[INFO    ] Executing state pkg.installed for install-ntpd
[INFO    ] Executing command ['rpm', '-qa', '--queryformat', '%{NAME}_|-%{VERSION}_|-%{RELEASE}_|-%{ARCH}_|-(none)\n'] in directory '/root'
[WARNING ] Unexpected osrelease grain '6.5', please report this
[INFO    ] Executing command "repoquery --plugins --queryformat '%{NAME}_|-%{ARCH}'  --pkgnarrow=all --all" in directory '/root'
[INFO    ] All specified packages are already installed
[INFO    ] Completed state [install-ntpd] at time 16:40:31.642829
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'clark-scale-test-nn', 'tcp://10.101.251.131:4506', 'aes')
[DEBUG   ] Initializing new SAuth for ('/etc/salt/pki/minion', 'clark-scale-test-nn', 'tcp://10.101.251.131:4506')
[DEBUG   ] LazyLoaded highstate.output
local:
----------
          ID: install-ntpd
    Function: pkg.installed
      Result: True
     Comment: All specified packages are already installed
     Started: 16:40:24.360436
    Duration: 7282.393 ms
     Changes:

Summary for local
------------
Succeeded: 1
Failed:    0
------------
Total states run:     1
Total run time:   7.282 s

clarkperkins · 2015-11-06T17:56:57Z

Ah I think I see the problem. From that PR that was mentioned earlier by @cachedout (https://github.com/saltstack/salt/pull/27049/files) it looks like it's blindly running that second repoquery command, even if names is an empty list. And that's what's causing the command to eat up RAM and get killed. This also explains why it doesn't happen the first time you run the pkg.installed function.

#28526 fixed yumpkg module issue with pkg.installed

jfindlay · 2015-11-11T15:33:01Z

@clarkperkins, thanks for fixing this. @grep4linux, @ankitforcode, can you confirm that this fixes the issue for you?

ngrennan-inflection · 2015-11-13T22:30:32Z

I was experiencing this bug on CentOS 7. The patch fixes it for me.

How is there not test coverage on this?

ankitforcode · 2018-05-20T16:39:43Z

@jfindlay Please close this as has been resolved.

terminalmage · 2018-05-21T14:20:37Z

The code that runs the whatprovides has been gone for years, so yes, this should be closed.

jfindlay added this to the Approved milestone Nov 3, 2015

ssgward added the severity-critical top severity, seen by most users, serious issues label Nov 5, 2015

clarkperkins pushed a commit to clarkperkins/salt that referenced this issue Nov 6, 2015

saltstack#28526 fixed yumpkg module

e11f87b

clarkperkins mentioned this issue Nov 6, 2015

#28526 fixed yumpkg module issue with pkg.installed #28656

Merged

clarkperkins pushed a commit to clarkperkins/salt that referenced this issue Nov 6, 2015

saltstack#28526 fixed yumpkg module

21ff6e2

terminalmage pushed a commit that referenced this issue Nov 9, 2015

Merge pull request #28656 from clarkperkins/bugfix/fix-yumpkg-module

61ba00b

#28526 fixed yumpkg module issue with pkg.installed

vitaliyf mentioned this issue Nov 14, 2015

salt yumpkg implementation painfully slow in some circumstances #26129

Closed

RuriRyan mentioned this issue Nov 18, 2015

"pkg.installed: -pkgs" may takes a very long time to run "repoquery --all" #28996

Closed

rallytime pushed a commit to rallytime/salt that referenced this issue Dec 4, 2015

saltstack#28526 fixed yumpkg module

2f11bb0

meggiebot removed the severity-critical top severity, seen by most users, serious issues label Sep 19, 2016

rallytime closed this as completed May 21, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

yumpkg.installed broken in salt v2015.8.1 on CentOS 6 minions #28526

yumpkg.installed broken in salt v2015.8.1 on CentOS 6 minions #28526

clarkperkins commented Nov 3, 2015

jfindlay commented Nov 3, 2015

cachedout commented Nov 5, 2015

terminalmage commented Nov 5, 2015

grep4linux commented Nov 5, 2015

ankitforcode commented Nov 6, 2015

ankitforcode commented Nov 6, 2015

ankitforcode commented Nov 6, 2015

ankitforcode commented Nov 6, 2015

RuriRyan commented Nov 6, 2015

clarkperkins commented Nov 6, 2015

terminalmage commented Nov 6, 2015

clarkperkins commented Nov 6, 2015

clarkperkins commented Nov 6, 2015

jfindlay commented Nov 11, 2015

ngrennan-inflection commented Nov 13, 2015

ankitforcode commented May 20, 2018

terminalmage commented May 21, 2018

yumpkg.installed broken in salt v2015.8.1 on CentOS 6 minions #28526

yumpkg.installed broken in salt v2015.8.1 on CentOS 6 minions #28526

Comments

clarkperkins commented Nov 3, 2015

jfindlay commented Nov 3, 2015

cachedout commented Nov 5, 2015

terminalmage commented Nov 5, 2015

grep4linux commented Nov 5, 2015

ankitforcode commented Nov 6, 2015

ankitforcode commented Nov 6, 2015

ankitforcode commented Nov 6, 2015

ankitforcode commented Nov 6, 2015

salt --versions-report

RuriRyan commented Nov 6, 2015

clarkperkins commented Nov 6, 2015

terminalmage commented Nov 6, 2015

clarkperkins commented Nov 6, 2015

clarkperkins commented Nov 6, 2015

jfindlay commented Nov 11, 2015

ngrennan-inflection commented Nov 13, 2015

ankitforcode commented May 20, 2018

terminalmage commented May 21, 2018