Skip to content

[BUG] salt waiting few more seconds after successfully receiving and displaying the obtained minion result #62599

Description

@onlineque

Description
salt waiting few more seconds after successfully receiving and displaying the obtained minion result

Setup
I am having one master and one minion, both running in a container, salt-master together with salt-minion, it's a Docker container

master config:

{"master_id": "dna-backend-master", "pidfile": "/var/run/salt/salt-master.pid", "sock_dir": "/var/run/salt/master", "order_masters": true, "log_level": "debug", "fileserver_backend": ["roots"], "file_roots": {"base": ["/srv/salt"]}, "auto_accept": true}

minion config:

{"id": "dna-backend-master", "master": "dna-backend-master", "pidfile": "/var/run/salt/salt-minion.pid", "sock_dir": "/var/run/salt/minion", "log_level": "debug", "beacons": {"load": [{"averages": {"1m": [0, 0], "5m": [0, 0], "15m": [0, 0]}}, {"emitatstartup": true}, {"onchangeonly": false}, {"interval": 30}], "memusage": [{"percent": "0%"}, {"emitatstartup": true}, {"onchangeonly": false}, {"interval": 30}], "status": [{"cpustats": ["all"]}, {"interval": 30}]}, "schedule": {"job1": {"function": "saltutil.sync_all", "cron": "*/5 * * * *"}}}

Steps to Reproduce the behavior

[salt@dna-backend-master /]$ date;salt -l garbage 'dna-backend-master' test.ping; date
Wed Aug 31 21:19:45 UTC 2022
[TRACE   ] Setting up log file logging: {'log_path': '/var/log/salt/master', 'log_level': 'debug', 'log_format': '%(asctime)s,%(msecs)03d [%(name)-17s:%(lineno)-4d][%(levelname)-8s][%(process)d] %(message)s', 'date_format': '%Y-%m-%d %H:%M:%S', 'max_bytes': 0, 'backup_count': 0, 'user': 'salt'}
[TRACE   ] The required configuration section, 'fluent_handler', was not found the in the configuration. Not loading the fluent logging handlers module.
[TRACE   ] None of the required configuration sections, 'logstash_udp_handler' and 'logstash_zmq_handler', were found in the configuration. Not loading the Logstash logging handlers module.
[TRACE   ] Error loading log_handlers.sentry_mod: Cannot find 'raven' python library, 'sentry_handler' config is empty or not defined
[TRACE   ] Processing <bound method SaltfileMixIn.process_saltfile of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing <bound method ConfigDirMixIn.process_config_dir of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[DEBUG   ] Reading configuration from /etc/salt/master
[DEBUG   ] Including configuration from '/etc/salt/master.d/api.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/api.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/beacons.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/beacons.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/master.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/master.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/user.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/user.conf
[TRACE   ] 'ip' could not be found in the following search path: '['/home/salt/.local/bin', '/home/salt/bin', '/usr/local/sbin', '/usr/local/bin', '/usr/sbin', '/usr/bin', '/sbin', '/bin']'
[TRACE   ] 'ifconfig' could not be found in the following search path: '['/home/salt/.local/bin', '/home/salt/bin', '/usr/local/sbin', '/usr/local/bin', '/usr/sbin', '/usr/bin', '/sbin', '/bin']'
[DEBUG   ] Missing configuration file: /home/salt/.saltrc
[TRACE   ] Processing <bound method ExtendedTargetOptionsMixIn.process_pillar_target of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing <bound method OutputOptionsMixIn.process_output of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing <bound method OutputOptionsMixIn.process_output_file of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing <bound method OutputOptionsMixIn.process_state_verbose of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing <bound method NoParseMixin.process_no_parse of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c739d1f28>, <CustomOption at 0x7f4c66576f98: -H/--hosts>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6bb62400>, <CustomOption at 0x7f4c66576ef0: -E/--pcre>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6659f840>, <CustomOption at 0x7f4c66576f28: -L/--list>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6659f8c8>, <CustomOption at 0x7f4c665a2048: -G/--grain>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6659f950>, <CustomOption at 0x7f4c665a20b8: -P/--grain-pcre>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6659f9d8>, <CustomOption at 0x7f4c665a2128: -N/--nodegroup>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6659fa60>, <CustomOption at 0x7f4c665a2160: -R/--range>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6659fb70>, <CustomOption at 0x7f4c665a2240: -C/--compound>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6659fbf8>, <CustomOption at 0x7f4c665a2358: -J/--pillar-pcre>)
[TRACE   ] Processing functools.partial(<function TargetOptionsMixIn._create_process_functions.<locals>.process at 0x7f4c6659fae8>, <CustomOption at 0x7f4c665a2390: -S/--ipcidr>)
[TRACE   ] Processing functools.partial(<function OutputOptionsMixIn._mixin_setup.<locals>.process at 0x7f4c6659fd08>, <CustomOption at 0x7f4c665a27f0: --out-indent/--output-indent>)
[TRACE   ] Processing functools.partial(<function OutputOptionsMixIn._mixin_setup.<locals>.process at 0x7f4c6659fd90>, <CustomOption at 0x7f4c665a28d0: --out-file-append/--output-file-append>)
[TRACE   ] Processing functools.partial(<function OutputOptionsMixIn._mixin_setup.<locals>.process at 0x7f4c6659fc80>, <CustomOption at 0x7f4c665a2908: --no-color/--no-colour>)
[TRACE   ] Processing functools.partial(<function OutputOptionsMixIn._mixin_setup.<locals>.process at 0x7f4c6659fe18>, <CustomOption at 0x7f4c665a2940: --force-color/--force-colour>)
[TRACE   ] Processing functools.partial(<function OutputOptionsMixIn._mixin_setup.<locals>.process at 0x7f4c6659fea0>, <CustomOption at 0x7f4c665a2978: --state-output/--state_output>)
[TRACE   ] Processing <bound method LogLevelMixIn.process_log_level of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing <bound method LogLevelMixIn.process_log_file of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing <bound method LogLevelMixIn.process_log_level_logfile of <salt.cli.salt.SaltCMD object at 0x7f4c6e1436d8>>
[TRACE   ] Processing <function TargetOptionsMixIn._mixin_after_parsed at 0x7f4c66590f28>
[TRACE   ] Processing <function OutputOptionsMixIn._mixin_after_parsed at 0x7f4c66592620>
[TRACE   ] Processing <function SaltCMDOptionParser._mixin_after_parsed at 0x7f4c6659a0d0>
[TRACE   ] Processing <function LogLevelMixIn.__setup_logging_routines at 0x7f4c665900d0>
[TRACE   ] Processing <function MergeConfigMixIn.__merge_config_with_cli at 0x7f4c6658dae8>
[TRACE   ] Processing <function LogLevelMixIn.__setup_console_logger_config at 0x7f4c66590378>
[TRACE   ] Processing <function LogLevelMixIn.__setup_logfile_logger_config at 0x7f4c66590400>
[TRACE   ] Processing <function LogLevelMixIn.__setup_logging_config at 0x7f4c66590488>
[TRACE   ] Processing <function LogLevelMixIn.__verify_logging at 0x7f4c66590598>
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[TRACE   ] Processing <function LogLevelMixIn.__setup_logging at 0x7f4c66590510>
[TRACE   ] Setting up console logging: {'log_level': 'garbage', 'log_format': '[%(levelname)-8s] %(message)s', 'date_format': '%H:%M:%S'}
[TRACE   ] Setting up log file logging: {'log_path': '/var/log/salt/master', 'log_level': 'debug', 'log_format': '%(asctime)s,%(msecs)03d [%(name)-17s:%(lineno)-4d][%(levelname)-8s][%(process)d] %(message)s', 'date_format': '%Y-%m-%d %H:%M:%S', 'max_bytes': 0, 'backup_count': 0, 'user': 'salt'}
[TRACE   ] The required configuration section, 'fluent_handler', was not found the in the configuration. Not loading the fluent logging handlers module.
[TRACE   ] None of the required configuration sections, 'logstash_udp_handler' and 'logstash_zmq_handler', were found in the configuration. Not loading the Logstash logging handlers module.
[TRACE   ] Error loading log_handlers.sentry_mod: Cannot find 'raven' python library, 'sentry_handler' config is empty or not defined
[DEBUG   ] Configuration file path: /etc/salt/master
[DEBUG   ] Reading configuration from /etc/salt/master
[DEBUG   ] Including configuration from '/etc/salt/master.d/api.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/api.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/beacons.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/beacons.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/master.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/master.conf
[DEBUG   ] Including configuration from '/etc/salt/master.d/user.conf'
[DEBUG   ] Reading configuration from /etc/salt/master.d/user.conf
[TRACE   ] 'ip' could not be found in the following search path: '['/home/salt/.local/bin', '/home/salt/bin', '/usr/local/sbin', '/usr/local/bin', '/usr/sbin', '/usr/bin', '/sbin', '/bin']'
[TRACE   ] 'ifconfig' could not be found in the following search path: '['/home/salt/.local/bin', '/home/salt/bin', '/usr/local/sbin', '/usr/local/bin', '/usr/sbin', '/usr/bin', '/sbin', '/bin']'
[DEBUG   ] Missing configuration file: /home/salt/.saltrc
[DEBUG   ] MasterEvent PUB socket URI: /var/run/salt/master/master_event_pub.ipc
[DEBUG   ] MasterEvent PULL socket URI: /var/run/salt/master/master_event_pull.ipc
[TRACE   ] IPCClient: Connecting to socket: /var/run/salt/master/master_event_pub.ipc
[TRACE   ] ReqChannel send clear load={'cmd': 'publish', 'tgt': 'dna-backend-master', 'fun': 'test.ping', 'arg': [], 'key': 'AuumVLyC7SAlAbLvoDXFtYHE+tUxI5V9K+qCcdIe9b9g1g5gXtvIlZf8lOjcdWS0+Cg9mS+w/Ws=', 'tgt_type': 'glob', 'ret': '', 'jid': '', 'kwargs': {'show_timeout': True, 'show_jid': False, 'delimiter': ':'}, 'user': 'salt', 'to': 5}
[DEBUG   ] Closing AsyncReqChannel instance
[TRACE   ] func get_cli_event_returns()
[DEBUG   ] The functions from module 'local_cache' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded local_cache.get_load
[DEBUG   ] Reading minion list from /var/cache/salt/master/jobs/df/8b308b148a66388ac47a03ab2aaa9222c498e816b7f33294f78cf7125bd17a/.minions.p
[DEBUG   ] get_iter_returns for jid 20220831211946246776 sent to {'dna-backend-master'} will timeout at 21:19:51.262229
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] get_event() received = {'data': {'jid': '20220831211946246776', 'tgt_type': 'glob', 'tgt': 'dna-backend-master', 'user': 'salt', 'fun': 'test.ping', 'arg': [], 'minions': ['dna-backend-master'], 'missing': [], '_stamp': '2022-08-31T21:19:46.248840'}, 'tag': 'salt/job/20220831211946246776/new'}
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] get_event() received = {'data': {'cmd': '_return', 'id': 'dna-backend-master', 'success': True, 'return': True, 'retcode': 0, 'jid': '20220831211946246776', 'fun': 'test.ping', 'fun_args': [], 'master_id': 'dna-backend-master', '_stamp': '2022-08-31T21:19:46.451689'}, 'tag': 'salt/job/20220831211946246776/ret/dna-backend-master'}
[DEBUG   ] jid 20220831211946246776 return from dna-backend-master
[DEBUG   ] return event: {'dna-backend-master': {'ret': True, 'retcode': 0, 'jid': '20220831211946246776'}}
[DEBUG   ] The functions from module 'nested' are being loaded by dir() on the loaded module
[DEBUG   ] LazyLoaded nested.output
[TRACE   ] data = {'dna-backend-master': True}
dna-backend-master:
    True
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[TRACE   ] Get event. tag: (salt/job|syndic/.*)/20220831211946246776
[TRACE   ] _get_event() waited 0 seconds and received nothing
[DEBUG   ] Closing IPCMessageSubscriber instance
Wed Aug 31 21:19:51 UTC 2022

Expected behavior
I'd expect salt to finish right after receiving the result completely and not to wait few more seconds and exiting. Not sure if this is a configuration issue on my side or a bug. Please help. Thx !

Versions Report

salt --versions-report

[salt@dna-backend-master master.d]$ salt --versions-report
Salt Version:
Salt: 3005

Dependency Versions:
cffi: 1.11.5
cherrypy: unknown
dateutil: 2.6.1
docker-py: Not Installed
gitdb: Not Installed
gitpython: Not Installed
Jinja2: 2.10.1
libgit2: Not Installed
M2Crypto: 0.35.2
Mako: Not Installed
msgpack: 0.6.2
msgpack-pure: Not Installed
mysql-python: Not Installed
pycparser: 2.14
pycrypto: 3.15.0
pycryptodome: 3.15.0
pygit2: Not Installed
Python: 3.6.8 (default, Apr 12 2022, 06:55:39)
python-gnupg: Not Installed
PyYAML: 3.12
PyZMQ: 20.0.0
smmap: Not Installed
timelib: Not Installed
Tornado: 4.5.3
ZMQ: 4.3.4

System Versions:
dist: rocky 8.6 Green Obsidian
locale: UTF-8
machine: x86_64
release: 4.18.0-348.12.2.el8_5.x86_64
system: Linux
version: Rocky Linux 8.6 Green Obsidian

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions