saltstack / saltstack/salt

Schedule run from utils concurrency issue

Open
#56,312 3 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug severity-medium
Dominant language
Python
Stars
15.7k
Forks
5.6k
Avg merge
2d 44m
Merged PRs (30d)
80

Description

Description of Issue

Given Salt Master's schedule setup with more than one entry and default schedule settings, only one job executes

Setup

Master config:

schedule:
  periodic1:
    function: state.orchestrate
    args:
      - minion._orchestrate.o1
    minutes: 1
  periodic2:
    function: state.orchestrate
    args:
      - minion._orchestrate.o2
    minutes: 1

Example State Tree:

> cat minion/_orchestrate/o1.sls
o1_orch:
  salt.state:
    - tgt: "*"
    - sls:
      - minion.debug1

> cat minion/_orchestrate/o2.sls
o2_orch:
  salt.state:
    - tgt: "*"
    - sls:
      - minion.debug2
> cat minion/debug1.sls
#!py
import datetime

def run():
    return {
        '/tmp/o1': {
            'file.managed': [
                { 'makedirs': True},
                { 'contents': "date: " + str(datetime.datetime.now())}
            ]
        }
    }
> cat minion/debug2.sls
#!py
import datetime

def run():
    return {
        '/tmp/o2': {
            'file.managed': [
                { 'makedirs': True},
                { 'contents': "date: " + str(datetime.datetime.now())}
            ]
        }
    }
Steps to Reproduce Issue

For aforementioned config, start the Salt Master and wait for ~ 1 minute.
Master logs:

2020-03-05 16:00:25,261 [salt.utils.schedule:1591][INFO    ][19] schedule: maxrunning parameter was not specified for job periodic1, defaulting to 1.
2020-03-05 16:00:25,262 [salt.utils.schedule:1605][INFO    ][19] Running scheduled job: periodic1 (runtime missed by 5 seconds)
2020-03-05 16:00:25,272 [salt.utils.schedule:1591][INFO    ][19] schedule: maxrunning parameter was not specified for job periodic2, defaulting to 1.
2020-03-05 16:00:25,273 [salt.utils.schedule:1605][INFO    ][19] Running scheduled job: periodic2 (runtime missed by 5 seconds)
...
2020-03-05 16:00:25,881 [salt.state       :1014][INFO    ][214] Loading fresh modules for state activity
2020-03-05 16:00:25,961 [salt.fileclient  :1238][INFO    ][214] Fetching file from saltenv 'base', ** done ** 'minion/_orchestrate/o2.sls'
2020-03-05 16:00:26,001 [salt.state       :1867][INFO    ][214] Running state [o2_orch] at time 16:00:26.001293
2020-03-05 16:00:26,002 [salt.state       :1900][INFO    ][214] Executing state salt.state for [o2_orch]
2020-03-05 16:00:26,092 [salt.master      :2346][INFO    ][34] User root Published command state.sls with jid 20200305160026083765
2020-03-05 16:00:26,683 [salt.utils.job   :68  ][INFO    ][33] Got return from salt-master-6bb6cff64c-9r5tw for job 20200305160026083765
2020-03-05 16:00:31,146 [salt.master      :2346][INFO    ][34] User root Published command saltutil.find_job with jid 20200305160031143710
...
2020-03-05 16:00:41,302 [salt.state       :2045][INFO    ][214] Completed state [o2_orch] at time 16:00:41.302527 (duration_in_ms=15301.223)

Nothing about o1_orch
On the Minion side only /tmp/o2 exists. After some schedule iterations the o1_orch will execute but never both.

Workaround

Setting in Master's config either:

# multiprocessing: False  # this has global implications, or
run_schedule_jobs_in_background: False  # better to use this one as it disables schedule multiprocessing only

causes both states (referenced by orchestrate runner) to run properly

Based on that workaround I guess there is a problem somewhere in salt.utils.schedule.Schedule._run_job

Versions Report
Salt Version:
           Salt: 3000

Dependency Versions:
           cffi: 1.14.0
       cherrypy: 18.5.0
       dateutil: 2.7.3
      docker-py: 1.10.6
          gitdb: 2.0.5
      gitpython: 2.1.11
         Jinja2: 2.11.1
        libgit2: 0.28.4
       M2Crypto: Not Installed
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.5.6
   mysql-python: Not Installed
      pycparser: 2.19
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: 1.0.3
         Python: 3.7.3 (default, Dec 20 2019, 18:57:59)
   python-gnupg: Not Installed
         PyYAML: 3.13
          PyZMQ: 17.1.2
          smmap: 2.0.5
        timelib: Not Installed
        Tornado: 4.5.3
            ZMQ: 4.3.1

System Versions:
           dist: debian 10.3
         locale: utf-8
        machine: x86_64
        release: 4.15.0-76-generic
         system: Linux
        version: debian 10.3

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start in salt.utils.schedule.Schedule._run_job and examine how run_schedule_jobs_in_background handles multiple scheduled jobs. Reproduce the issue with the two periodic entries from the master configuration, compare the default and workaround settings, and confirm that both orchestrate states execute on each schedule iteration.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
devops, infrastructure
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
38/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.