Non puoi selezionare più di 25 argomenti Gli argomenti devono iniziare con una lettera o un numero, possono includere trattini ('-') e possono essere lunghi fino a 35 caratteri.
 
 
 
 

992 righe
38 KiB

  1. # -*- coding: utf-8 -*-
  2. from __future__ import (absolute_import, division, print_function,
  3. unicode_literals)
  4. import errno
  5. import logging
  6. import os
  7. import random
  8. import signal
  9. import socket
  10. import sys
  11. import time
  12. import traceback
  13. import warnings
  14. from datetime import timedelta
  15. from uuid import uuid4
  16. try:
  17. from signal import SIGKILL
  18. except ImportError:
  19. from signal import SIGTERM as SIGKILL
  20. from redis import WatchError
  21. from . import worker_registration
  22. from .compat import PY2, as_text, string_types, text_type
  23. from .connections import get_current_connection, push_connection, pop_connection
  24. from .defaults import (DEFAULT_RESULT_TTL,
  25. DEFAULT_WORKER_TTL, DEFAULT_JOB_MONITORING_INTERVAL,
  26. DEFAULT_LOGGING_FORMAT, DEFAULT_LOGGING_DATE_FORMAT)
  27. from .exceptions import DequeueTimeout, ShutDownImminentException
  28. from .job import Job, JobStatus
  29. from .logutils import setup_loghandlers
  30. from .queue import Queue
  31. from .registry import (FailedJobRegistry, FinishedJobRegistry,
  32. StartedJobRegistry, clean_registries)
  33. from .suspension import is_suspended
  34. from .timeouts import JobTimeoutException, HorseMonitorTimeoutException, UnixSignalDeathPenalty
  35. from .utils import (backend_class, ensure_list, enum,
  36. make_colorizer, utcformat, utcnow, utcparse)
  37. from .version import VERSION
  38. from .worker_registration import clean_worker_registry, get_keys
  39. try:
  40. from setproctitle import setproctitle as setprocname
  41. except ImportError:
  42. def setprocname(*args, **kwargs): # noqa
  43. pass
  44. green = make_colorizer('darkgreen')
  45. yellow = make_colorizer('darkyellow')
  46. blue = make_colorizer('darkblue')
  47. logger = logging.getLogger(__name__)
  48. class StopRequested(Exception):
  49. pass
  50. def compact(l):
  51. return [x for x in l if x is not None]
  52. _signames = dict((getattr(signal, signame), signame)
  53. for signame in dir(signal)
  54. if signame.startswith('SIG') and '_' not in signame)
  55. def signal_name(signum):
  56. try:
  57. if sys.version_info[:2] >= (3, 5):
  58. return signal.Signals(signum).name
  59. else:
  60. return _signames[signum]
  61. except KeyError:
  62. return 'SIG_UNKNOWN'
  63. except ValueError:
  64. return 'SIG_UNKNOWN'
  65. WorkerStatus = enum(
  66. 'WorkerStatus',
  67. STARTED='started',
  68. SUSPENDED='suspended',
  69. BUSY='busy',
  70. IDLE='idle'
  71. )
  72. class Worker(object):
  73. redis_worker_namespace_prefix = 'rq:worker:'
  74. redis_workers_keys = worker_registration.REDIS_WORKER_KEYS
  75. death_penalty_class = UnixSignalDeathPenalty
  76. queue_class = Queue
  77. job_class = Job
  78. # `log_result_lifespan` controls whether "Result is kept for XXX seconds"
  79. # messages are logged after every job, by default they are.
  80. log_result_lifespan = True
  81. # `log_job_description` is used to toggle logging an entire jobs description.
  82. log_job_description = True
  83. @classmethod
  84. def all(cls, connection=None, job_class=None, queue_class=None, queue=None):
  85. """Returns an iterable of all Workers.
  86. """
  87. if queue:
  88. connection = queue.connection
  89. elif connection is None:
  90. connection = get_current_connection()
  91. worker_keys = get_keys(queue=queue, connection=connection)
  92. workers = [cls.find_by_key(as_text(key),
  93. connection=connection,
  94. job_class=job_class,
  95. queue_class=queue_class)
  96. for key in worker_keys]
  97. return compact(workers)
  98. @classmethod
  99. def all_keys(cls, connection=None, queue=None):
  100. return [as_text(key)
  101. for key in get_keys(queue=queue, connection=connection)]
  102. @classmethod
  103. def count(cls, connection=None, queue=None):
  104. """Returns the number of workers by queue or connection"""
  105. return len(get_keys(queue=queue, connection=connection))
  106. @classmethod
  107. def find_by_key(cls, worker_key, connection=None, job_class=None,
  108. queue_class=None):
  109. """Returns a Worker instance, based on the naming conventions for
  110. naming the internal Redis keys. Can be used to reverse-lookup Workers
  111. by their Redis keys.
  112. """
  113. prefix = cls.redis_worker_namespace_prefix
  114. if not worker_key.startswith(prefix):
  115. raise ValueError('Not a valid RQ worker key: %s' % worker_key)
  116. if connection is None:
  117. connection = get_current_connection()
  118. if not connection.exists(worker_key):
  119. connection.srem(cls.redis_workers_keys, worker_key)
  120. return None
  121. name = worker_key[len(prefix):]
  122. worker = cls([], name, connection=connection, job_class=job_class,
  123. queue_class=queue_class, prepare_for_work=False)
  124. worker.refresh()
  125. return worker
  126. def __init__(self, queues, name=None, default_result_ttl=DEFAULT_RESULT_TTL,
  127. connection=None, exc_handler=None, exception_handlers=None,
  128. default_worker_ttl=DEFAULT_WORKER_TTL, job_class=None,
  129. queue_class=None, log_job_description=True,
  130. job_monitoring_interval=DEFAULT_JOB_MONITORING_INTERVAL,
  131. disable_default_exception_handler=False,
  132. prepare_for_work=True): # noqa
  133. if connection is None:
  134. connection = get_current_connection()
  135. self.connection = connection
  136. if prepare_for_work:
  137. self.hostname = socket.gethostname()
  138. self.pid = os.getpid()
  139. else:
  140. self.hostname = None
  141. self.pid = None
  142. self.job_class = backend_class(self, 'job_class', override=job_class)
  143. self.queue_class = backend_class(self, 'queue_class', override=queue_class)
  144. queues = [self.queue_class(name=q,
  145. connection=connection,
  146. job_class=self.job_class)
  147. if isinstance(q, string_types) else q
  148. for q in ensure_list(queues)]
  149. self.name = name or uuid4().hex
  150. self.queues = queues
  151. self.validate_queues()
  152. self._exc_handlers = []
  153. self.default_result_ttl = default_result_ttl
  154. self.default_worker_ttl = default_worker_ttl
  155. self.job_monitoring_interval = job_monitoring_interval
  156. self._state = 'starting'
  157. self._is_horse = False
  158. self._horse_pid = 0
  159. self._stop_requested = False
  160. self.log = logger
  161. self.log_job_description = log_job_description
  162. self.last_cleaned_at = None
  163. self.successful_job_count = 0
  164. self.failed_job_count = 0
  165. self.total_working_time = 0
  166. self.birth_date = None
  167. self.disable_default_exception_handler = disable_default_exception_handler
  168. if isinstance(exception_handlers, list):
  169. for handler in exception_handlers:
  170. self.push_exc_handler(handler)
  171. elif exception_handlers is not None:
  172. self.push_exc_handler(exception_handlers)
  173. def validate_queues(self):
  174. """Sanity check for the given queues."""
  175. for queue in self.queues:
  176. if not isinstance(queue, self.queue_class):
  177. raise TypeError('{0} is not of type {1} or string types'.format(queue, self.queue_class))
  178. def queue_names(self):
  179. """Returns the queue names of this worker's queues."""
  180. return list(map(lambda q: q.name, self.queues))
  181. def queue_keys(self):
  182. """Returns the Redis keys representing this worker's queues."""
  183. return list(map(lambda q: q.key, self.queues))
  184. @property
  185. def key(self):
  186. """Returns the worker's Redis hash key."""
  187. return self.redis_worker_namespace_prefix + self.name
  188. @property
  189. def horse_pid(self):
  190. """The horse's process ID. Only available in the worker. Will return
  191. 0 in the horse part of the fork.
  192. """
  193. return self._horse_pid
  194. @property
  195. def is_horse(self):
  196. """Returns whether or not this is the worker or the work horse."""
  197. return self._is_horse
  198. def procline(self, message):
  199. """Changes the current procname for the process.
  200. This can be used to make `ps -ef` output more readable.
  201. """
  202. setprocname('rq: {0}'.format(message))
  203. def register_birth(self):
  204. """Registers its own birth."""
  205. self.log.debug('Registering birth of worker %s', self.name)
  206. if self.connection.exists(self.key) and \
  207. not self.connection.hexists(self.key, 'death'):
  208. msg = 'There exists an active worker named {0!r} already'
  209. raise ValueError(msg.format(self.name))
  210. key = self.key
  211. queues = ','.join(self.queue_names())
  212. with self.connection.pipeline() as p:
  213. p.delete(key)
  214. now = utcnow()
  215. now_in_string = utcformat(now)
  216. self.birth_date = now
  217. p.hset(key, 'birth', now_in_string)
  218. p.hset(key, 'last_heartbeat', now_in_string)
  219. p.hset(key, 'queues', queues)
  220. p.hset(key, 'pid', self.pid)
  221. p.hset(key, 'hostname', self.hostname)
  222. worker_registration.register(self, p)
  223. p.expire(key, self.default_worker_ttl)
  224. p.execute()
  225. def register_death(self):
  226. """Registers its own death."""
  227. self.log.debug('Registering death')
  228. with self.connection.pipeline() as p:
  229. # We cannot use self.state = 'dead' here, because that would
  230. # rollback the pipeline
  231. worker_registration.unregister(self, p)
  232. p.hset(self.key, 'death', utcformat(utcnow()))
  233. p.expire(self.key, 60)
  234. p.execute()
  235. def set_shutdown_requested_date(self):
  236. """Sets the date on which the worker received a (warm) shutdown request"""
  237. self.connection.hset(self.key, 'shutdown_requested_date', utcformat(utcnow()))
  238. # @property
  239. # def birth_date(self):
  240. # """Fetches birth date from Redis."""
  241. # birth_timestamp = self.connection.hget(self.key, 'birth')
  242. # if birth_timestamp is not None:
  243. # return utcparse(as_text(birth_timestamp))
  244. @property
  245. def shutdown_requested_date(self):
  246. """Fetches shutdown_requested_date from Redis."""
  247. shutdown_requested_timestamp = self.connection.hget(self.key, 'shutdown_requested_date')
  248. if shutdown_requested_timestamp is not None:
  249. return utcparse(as_text(shutdown_requested_timestamp))
  250. @property
  251. def death_date(self):
  252. """Fetches death date from Redis."""
  253. death_timestamp = self.connection.hget(self.key, 'death')
  254. if death_timestamp is not None:
  255. return utcparse(as_text(death_timestamp))
  256. def set_state(self, state, pipeline=None):
  257. self._state = state
  258. connection = pipeline if pipeline is not None else self.connection
  259. connection.hset(self.key, 'state', state)
  260. def _set_state(self, state):
  261. """Raise a DeprecationWarning if ``worker.state = X`` is used"""
  262. warnings.warn(
  263. "worker.state is deprecated, use worker.set_state() instead.",
  264. DeprecationWarning
  265. )
  266. self.set_state(state)
  267. def get_state(self):
  268. return self._state
  269. def _get_state(self):
  270. """Raise a DeprecationWarning if ``worker.state == X`` is used"""
  271. warnings.warn(
  272. "worker.state is deprecated, use worker.get_state() instead.",
  273. DeprecationWarning
  274. )
  275. return self.get_state()
  276. state = property(_get_state, _set_state)
  277. def set_current_job_id(self, job_id, pipeline=None):
  278. connection = pipeline if pipeline is not None else self.connection
  279. if job_id is None:
  280. connection.hdel(self.key, 'current_job')
  281. else:
  282. connection.hset(self.key, 'current_job', job_id)
  283. def get_current_job_id(self, pipeline=None):
  284. connection = pipeline if pipeline is not None else self.connection
  285. return as_text(connection.hget(self.key, 'current_job'))
  286. def get_current_job(self):
  287. """Returns the job id of the currently executing job."""
  288. job_id = self.get_current_job_id()
  289. if job_id is None:
  290. return None
  291. return self.job_class.fetch(job_id, self.connection)
  292. def _install_signal_handlers(self):
  293. """Installs signal handlers for handling SIGINT and SIGTERM
  294. gracefully.
  295. """
  296. signal.signal(signal.SIGINT, self.request_stop)
  297. signal.signal(signal.SIGTERM, self.request_stop)
  298. def kill_horse(self, sig=SIGKILL):
  299. """
  300. Kill the horse but catch "No such process" error has the horse could already be dead.
  301. """
  302. try:
  303. os.kill(self.horse_pid, sig)
  304. except OSError as e:
  305. if e.errno == errno.ESRCH:
  306. # "No such process" is fine with us
  307. self.log.debug('Horse already dead')
  308. else:
  309. raise
  310. def request_force_stop(self, signum, frame):
  311. """Terminates the application (cold shutdown).
  312. """
  313. self.log.warning('Cold shut down')
  314. # Take down the horse with the worker
  315. if self.horse_pid:
  316. self.log.debug('Taking down horse %s with me', self.horse_pid)
  317. self.kill_horse()
  318. raise SystemExit()
  319. def request_stop(self, signum, frame):
  320. """Stops the current worker loop but waits for child processes to
  321. end gracefully (warm shutdown).
  322. """
  323. self.log.debug('Got signal %s', signal_name(signum))
  324. signal.signal(signal.SIGINT, self.request_force_stop)
  325. signal.signal(signal.SIGTERM, self.request_force_stop)
  326. self.handle_warm_shutdown_request()
  327. # If shutdown is requested in the middle of a job, wait until
  328. # finish before shutting down and save the request in redis
  329. if self.get_state() == WorkerStatus.BUSY:
  330. self._stop_requested = True
  331. self.set_shutdown_requested_date()
  332. self.log.debug('Stopping after current horse is finished. '
  333. 'Press Ctrl+C again for a cold shutdown.')
  334. else:
  335. raise StopRequested()
  336. def handle_warm_shutdown_request(self):
  337. self.log.info('Warm shut down requested')
  338. def check_for_suspension(self, burst):
  339. """Check to see if workers have been suspended by `rq suspend`"""
  340. before_state = None
  341. notified = False
  342. while not self._stop_requested and is_suspended(self.connection, self):
  343. if burst:
  344. self.log.info('Suspended in burst mode, exiting')
  345. self.log.info('Note: There could still be unfinished jobs on the queue')
  346. raise StopRequested
  347. if not notified:
  348. self.log.info('Worker suspended, run `rq resume` to resume')
  349. before_state = self.get_state()
  350. self.set_state(WorkerStatus.SUSPENDED)
  351. notified = True
  352. time.sleep(1)
  353. if before_state:
  354. self.set_state(before_state)
  355. def work(self, burst=False, logging_level="INFO", date_format=DEFAULT_LOGGING_DATE_FORMAT,
  356. log_format=DEFAULT_LOGGING_FORMAT, max_jobs=None):
  357. """Starts the work loop.
  358. Pops and performs all jobs on the current list of queues. When all
  359. queues are empty, block and wait for new jobs to arrive on any of the
  360. queues, unless `burst` mode is enabled.
  361. The return value indicates whether any jobs were processed.
  362. """
  363. setup_loghandlers(logging_level, date_format, log_format)
  364. self._install_signal_handlers()
  365. completed_jobs = 0
  366. self.register_birth()
  367. self.log.info("Worker %s: started, version %s", self.key, VERSION)
  368. self.set_state(WorkerStatus.STARTED)
  369. qnames = self.queue_names()
  370. self.log.info('*** Listening on %s...', green(', '.join(qnames)))
  371. try:
  372. while True:
  373. try:
  374. self.check_for_suspension(burst)
  375. if self.should_run_maintenance_tasks:
  376. self.clean_registries()
  377. if self._stop_requested:
  378. self.log.info('Worker %s: stopping on request', self.key)
  379. break
  380. timeout = None if burst else max(1, self.default_worker_ttl - 15)
  381. result = self.dequeue_job_and_maintain_ttl(timeout)
  382. if result is None:
  383. if burst:
  384. self.log.info("Worker %s: done, quitting", self.key)
  385. break
  386. job, queue = result
  387. self.execute_job(job, queue)
  388. self.heartbeat()
  389. completed_jobs += 1
  390. if max_jobs is not None:
  391. if completed_jobs >= max_jobs:
  392. self.log.info(
  393. "Worker %s: finished executing %d jobs, quitting",
  394. self.key, completed_jobs
  395. )
  396. break
  397. except StopRequested:
  398. break
  399. except SystemExit:
  400. # Cold shutdown detected
  401. raise
  402. except: # noqa
  403. self.log.error(
  404. 'Worker %s: found an unhandled exception, quitting...',
  405. self.key, exc_info=True
  406. )
  407. break
  408. finally:
  409. if not self.is_horse:
  410. self.register_death()
  411. return bool(completed_jobs)
  412. def dequeue_job_and_maintain_ttl(self, timeout):
  413. result = None
  414. qnames = ','.join(self.queue_names())
  415. self.set_state(WorkerStatus.IDLE)
  416. self.procline('Listening on ' + qnames)
  417. self.log.debug('*** Listening on %s...', green(qnames))
  418. while True:
  419. self.heartbeat()
  420. try:
  421. result = self.queue_class.dequeue_any(self.queues, timeout,
  422. connection=self.connection,
  423. job_class=self.job_class)
  424. if result is not None:
  425. job, queue = result
  426. if self.log_job_description:
  427. self.log.info(
  428. '%s: %s (%s)', green(queue.name),
  429. blue(job.description), job.id)
  430. else:
  431. self.log.info('%s: %s', green(queue.name), job.id)
  432. break
  433. except DequeueTimeout:
  434. pass
  435. self.heartbeat()
  436. return result
  437. def heartbeat(self, timeout=None, pipeline=None):
  438. """Specifies a new worker timeout, typically by extending the
  439. expiration time of the worker, effectively making this a "heartbeat"
  440. to not expire the worker until the timeout passes.
  441. The next heartbeat should come before this time, or the worker will
  442. die (at least from the monitoring dashboards).
  443. If no timeout is given, the default_worker_ttl will be used to update
  444. the expiration time of the worker.
  445. """
  446. timeout = timeout or self.default_worker_ttl
  447. connection = pipeline if pipeline is not None else self.connection
  448. connection.expire(self.key, timeout)
  449. connection.hset(self.key, 'last_heartbeat', utcformat(utcnow()))
  450. self.log.debug('Sent heartbeat to prevent worker timeout. '
  451. 'Next one should arrive within %s seconds.', timeout)
  452. def refresh(self):
  453. data = self.connection.hmget(
  454. self.key, 'queues', 'state', 'current_job', 'last_heartbeat',
  455. 'birth', 'failed_job_count', 'successful_job_count',
  456. 'total_working_time', 'hostname', 'pid'
  457. )
  458. (queues, state, job_id, last_heartbeat, birth, failed_job_count,
  459. successful_job_count, total_working_time, hostname, pid) = data
  460. queues = as_text(queues)
  461. self.hostname = hostname
  462. self.pid = int(pid) if pid else None
  463. self._state = as_text(state or '?')
  464. self._job_id = job_id or None
  465. if last_heartbeat:
  466. self.last_heartbeat = utcparse(as_text(last_heartbeat))
  467. else:
  468. self.last_heartbeat = None
  469. if birth:
  470. self.birth_date = utcparse(as_text(birth))
  471. else:
  472. self.birth_date = None
  473. if failed_job_count:
  474. self.failed_job_count = int(as_text(failed_job_count))
  475. if successful_job_count:
  476. self.successful_job_count = int(as_text(successful_job_count))
  477. if total_working_time:
  478. self.total_working_time = float(as_text(total_working_time))
  479. if queues:
  480. self.queues = [self.queue_class(queue,
  481. connection=self.connection,
  482. job_class=self.job_class)
  483. for queue in queues.split(',')]
  484. def increment_failed_job_count(self, pipeline=None):
  485. connection = pipeline if pipeline is not None else self.connection
  486. connection.hincrby(self.key, 'failed_job_count', 1)
  487. def increment_successful_job_count(self, pipeline=None):
  488. connection = pipeline if pipeline is not None else self.connection
  489. connection.hincrby(self.key, 'successful_job_count', 1)
  490. def increment_total_working_time(self, job_execution_time, pipeline):
  491. pipeline.hincrbyfloat(self.key, 'total_working_time',
  492. job_execution_time.total_seconds())
  493. def fork_work_horse(self, job, queue):
  494. """Spawns a work horse to perform the actual work and passes it a job.
  495. """
  496. child_pid = os.fork()
  497. os.environ['RQ_WORKER_ID'] = self.name
  498. os.environ['RQ_JOB_ID'] = job.id
  499. if child_pid == 0:
  500. self.main_work_horse(job, queue)
  501. else:
  502. self._horse_pid = child_pid
  503. self.procline('Forked {0} at {1}'.format(child_pid, time.time()))
  504. def monitor_work_horse(self, job):
  505. """The worker will monitor the work horse and make sure that it
  506. either executes successfully or the status of the job is set to
  507. failed
  508. """
  509. while True:
  510. try:
  511. with UnixSignalDeathPenalty(self.job_monitoring_interval, HorseMonitorTimeoutException):
  512. retpid, ret_val = os.waitpid(self._horse_pid, 0)
  513. break
  514. except HorseMonitorTimeoutException:
  515. # Horse has not exited yet and is still running.
  516. # Send a heartbeat to keep the worker alive.
  517. self.heartbeat(self.job_monitoring_interval + 5)
  518. except OSError as e:
  519. # In case we encountered an OSError due to EINTR (which is
  520. # caused by a SIGINT or SIGTERM signal during
  521. # os.waitpid()), we simply ignore it and enter the next
  522. # iteration of the loop, waiting for the child to end. In
  523. # any other case, this is some other unexpected OS error,
  524. # which we don't want to catch, so we re-raise those ones.
  525. if e.errno != errno.EINTR:
  526. raise
  527. # Send a heartbeat to keep the worker alive.
  528. self.heartbeat()
  529. if ret_val == os.EX_OK: # The process exited normally.
  530. return
  531. job_status = job.get_status()
  532. if job_status is None: # Job completed and its ttl has expired
  533. return
  534. if job_status not in [JobStatus.FINISHED, JobStatus.FAILED]:
  535. if not job.ended_at:
  536. job.ended_at = utcnow()
  537. # Unhandled failure: move the job to the failed queue
  538. self.log.warning((
  539. 'Moving job to FailedJobRegistry '
  540. '(work-horse terminated unexpectedly; waitpid returned {})'
  541. ).format(ret_val))
  542. self.handle_job_failure(
  543. job,
  544. exc_string="Work-horse process was terminated unexpectedly "
  545. "(waitpid returned %s)" % ret_val
  546. )
  547. def execute_job(self, job, queue):
  548. """Spawns a work horse to perform the actual work and passes it a job.
  549. The worker will wait for the work horse and make sure it executes
  550. within the given timeout bounds, or will end the work horse with
  551. SIGALRM.
  552. """
  553. self.set_state(WorkerStatus.BUSY)
  554. self.fork_work_horse(job, queue)
  555. self.monitor_work_horse(job)
  556. self.set_state(WorkerStatus.IDLE)
  557. def main_work_horse(self, job, queue):
  558. """This is the entry point of the newly spawned work horse."""
  559. # After fork()'ing, always assure we are generating random sequences
  560. # that are different from the worker.
  561. random.seed()
  562. try:
  563. self.setup_work_horse_signals()
  564. self._is_horse = True
  565. self.log = logger
  566. self.perform_job(job, queue)
  567. except Exception as e: # noqa
  568. # Horse does not terminate properly
  569. raise e
  570. os._exit(1)
  571. # os._exit() is the way to exit from childs after a fork(), in
  572. # constrast to the regular sys.exit()
  573. os._exit(0)
  574. def setup_work_horse_signals(self):
  575. """Setup signal handing for the newly spawned work horse."""
  576. # Always ignore Ctrl+C in the work horse, as it might abort the
  577. # currently running job.
  578. # The main worker catches the Ctrl+C and requests graceful shutdown
  579. # after the current work is done. When cold shutdown is requested, it
  580. # kills the current job anyway.
  581. signal.signal(signal.SIGINT, signal.SIG_IGN)
  582. signal.signal(signal.SIGTERM, signal.SIG_DFL)
  583. def prepare_job_execution(self, job, heartbeat_ttl=None):
  584. """Performs misc bookkeeping like updating states prior to
  585. job execution.
  586. """
  587. if job.timeout == -1:
  588. timeout = -1
  589. else:
  590. timeout = job.timeout or 180
  591. if heartbeat_ttl is None:
  592. heartbeat_ttl = self.job_monitoring_interval + 5
  593. with self.connection.pipeline() as pipeline:
  594. self.set_state(WorkerStatus.BUSY, pipeline=pipeline)
  595. self.set_current_job_id(job.id, pipeline=pipeline)
  596. self.heartbeat(heartbeat_ttl, pipeline=pipeline)
  597. registry = StartedJobRegistry(job.origin, self.connection,
  598. job_class=self.job_class)
  599. registry.add(job, timeout, pipeline=pipeline)
  600. job.set_status(JobStatus.STARTED, pipeline=pipeline)
  601. pipeline.hset(job.key, 'started_at', utcformat(utcnow()))
  602. pipeline.execute()
  603. msg = 'Processing {0} from {1} since {2}'
  604. self.procline(msg.format(job.func_name, job.origin, time.time()))
  605. def handle_job_failure(self, job, started_job_registry=None,
  606. exc_string=''):
  607. """Handles the failure or an executing job by:
  608. 1. Setting the job status to failed
  609. 2. Removing the job from StartedJobRegistry
  610. 3. Setting the workers current job to None
  611. 4. Add the job to FailedJobRegistry
  612. """
  613. self.log.debug('Handling failed execution of job %s', job.id)
  614. with self.connection.pipeline() as pipeline:
  615. if started_job_registry is None:
  616. started_job_registry = StartedJobRegistry(
  617. job.origin,
  618. self.connection,
  619. job_class=self.job_class
  620. )
  621. job.set_status(JobStatus.FAILED, pipeline=pipeline)
  622. started_job_registry.remove(job, pipeline=pipeline)
  623. if not self.disable_default_exception_handler:
  624. failed_job_registry = FailedJobRegistry(job.origin, job.connection,
  625. job_class=self.job_class)
  626. failed_job_registry.add(job, ttl=job.failure_ttl,
  627. exc_string=exc_string, pipeline=pipeline)
  628. self.set_current_job_id(None, pipeline=pipeline)
  629. self.increment_failed_job_count(pipeline)
  630. if job.started_at and job.ended_at:
  631. self.increment_total_working_time(
  632. job.ended_at - job.started_at,
  633. pipeline
  634. )
  635. try:
  636. pipeline.execute()
  637. except Exception:
  638. # Ensure that custom exception handlers are called
  639. # even if Redis is down
  640. pass
  641. def handle_job_success(self, job, queue, started_job_registry):
  642. self.log.debug('Handling successful execution of job %s', job.id)
  643. with self.connection.pipeline() as pipeline:
  644. while True:
  645. try:
  646. # if dependencies are inserted after enqueue_dependents
  647. # a WatchError is thrown by execute()
  648. pipeline.watch(job.dependents_key)
  649. # enqueue_dependents calls multi() on the pipeline!
  650. queue.enqueue_dependents(job, pipeline=pipeline)
  651. self.set_current_job_id(None, pipeline=pipeline)
  652. self.increment_successful_job_count(pipeline=pipeline)
  653. self.increment_total_working_time(
  654. job.ended_at - job.started_at, pipeline
  655. )
  656. result_ttl = job.get_result_ttl(self.default_result_ttl)
  657. if result_ttl != 0:
  658. job.set_status(JobStatus.FINISHED, pipeline=pipeline)
  659. # Don't clobber the user's meta dictionary!
  660. job.save(pipeline=pipeline, include_meta=False)
  661. finished_job_registry = FinishedJobRegistry(job.origin,
  662. self.connection,
  663. job_class=self.job_class)
  664. finished_job_registry.add(job, result_ttl, pipeline)
  665. job.cleanup(result_ttl, pipeline=pipeline,
  666. remove_from_queue=False)
  667. started_job_registry.remove(job, pipeline=pipeline)
  668. pipeline.execute()
  669. break
  670. except WatchError:
  671. continue
  672. def perform_job(self, job, queue, heartbeat_ttl=None):
  673. """Performs the actual work of a job. Will/should only be called
  674. inside the work horse's process.
  675. """
  676. self.prepare_job_execution(job, heartbeat_ttl)
  677. push_connection(self.connection)
  678. started_job_registry = StartedJobRegistry(job.origin,
  679. self.connection,
  680. job_class=self.job_class)
  681. try:
  682. job.started_at = utcnow()
  683. timeout = job.timeout or self.queue_class.DEFAULT_TIMEOUT
  684. with self.death_penalty_class(timeout, JobTimeoutException, job_id=job.id):
  685. rv = job.perform()
  686. job.ended_at = utcnow()
  687. # Pickle the result in the same try-except block since we need
  688. # to use the same exc handling when pickling fails
  689. job._result = rv
  690. self.handle_job_success(job=job,
  691. queue=queue,
  692. started_job_registry=started_job_registry)
  693. except:
  694. job.ended_at = utcnow()
  695. exc_info = sys.exc_info()
  696. exc_string = self._get_safe_exception_string(
  697. traceback.format_exception(*exc_info)
  698. )
  699. self.handle_job_failure(job=job, exc_string=exc_string,
  700. started_job_registry=started_job_registry)
  701. self.handle_exception(job, *exc_info)
  702. return False
  703. finally:
  704. pop_connection()
  705. self.log.info('%s: %s (%s)', green(job.origin), blue('Job OK'), job.id)
  706. if rv is not None:
  707. log_result = "{0!r}".format(as_text(text_type(rv)))
  708. self.log.debug('Result: %s', yellow(log_result))
  709. if self.log_result_lifespan:
  710. result_ttl = job.get_result_ttl(self.default_result_ttl)
  711. if result_ttl == 0:
  712. self.log.info('Result discarded immediately')
  713. elif result_ttl > 0:
  714. self.log.info('Result is kept for %s seconds', result_ttl)
  715. else:
  716. self.log.info('Result will never expire, clean up result key manually')
  717. return True
  718. def handle_exception(self, job, *exc_info):
  719. """Walks the exception handler stack to delegate exception handling."""
  720. exc_string = Worker._get_safe_exception_string(
  721. traceback.format_exception_only(*exc_info[:2]) + traceback.format_exception(*exc_info)
  722. )
  723. self.log.error(exc_string, exc_info=True, extra={
  724. 'func': job.func_name,
  725. 'arguments': job.args,
  726. 'kwargs': job.kwargs,
  727. 'queue': job.origin,
  728. })
  729. for handler in self._exc_handlers:
  730. self.log.debug('Invoking exception handler %s', handler)
  731. fallthrough = handler(job, *exc_info)
  732. # Only handlers with explicit return values should disable further
  733. # exc handling, so interpret a None return value as True.
  734. if fallthrough is None:
  735. fallthrough = True
  736. if not fallthrough:
  737. break
  738. @staticmethod
  739. def _get_safe_exception_string(exc_strings):
  740. """Ensure list of exception strings is decoded on Python 2 and joined as one string safely."""
  741. if sys.version_info[0] < 3:
  742. try:
  743. exc_strings = [exc.decode("utf-8") for exc in exc_strings]
  744. except ValueError:
  745. exc_strings = [exc.decode("latin-1") for exc in exc_strings]
  746. return ''.join(exc_strings)
  747. def push_exc_handler(self, handler_func):
  748. """Pushes an exception handler onto the exc handler stack."""
  749. self._exc_handlers.append(handler_func)
  750. def pop_exc_handler(self):
  751. """Pops the latest exception handler off of the exc handler stack."""
  752. return self._exc_handlers.pop()
  753. def __eq__(self, other):
  754. """Equality does not take the database/connection into account"""
  755. if not isinstance(other, self.__class__):
  756. raise TypeError('Cannot compare workers to other types (of workers)')
  757. return self.name == other.name
  758. def __hash__(self):
  759. """The hash does not take the database/connection into account"""
  760. return hash(self.name)
  761. def clean_registries(self):
  762. """Runs maintenance jobs on each Queue's registries."""
  763. for queue in self.queues:
  764. # If there are multiple workers running, we only want 1 worker
  765. # to run clean_registries().
  766. if queue.acquire_cleaning_lock():
  767. self.log.info('Cleaning registries for queue: %s', queue.name)
  768. clean_registries(queue)
  769. clean_worker_registry(queue)
  770. self.last_cleaned_at = utcnow()
  771. @property
  772. def should_run_maintenance_tasks(self):
  773. """Maintenance tasks should run on first startup or 15 minutes."""
  774. if self.last_cleaned_at is None:
  775. return True
  776. if (utcnow() - self.last_cleaned_at) > timedelta(minutes=15):
  777. return True
  778. return False
  779. class SimpleWorker(Worker):
  780. def main_work_horse(self, *args, **kwargs):
  781. raise NotImplementedError("Test worker does not implement this method")
  782. def execute_job(self, job, queue):
  783. """Execute job in same thread/process, do not fork()"""
  784. timeout = (job.timeout or DEFAULT_WORKER_TTL) + 5
  785. return self.perform_job(job, queue, heartbeat_ttl=timeout)
  786. class HerokuWorker(Worker):
  787. """
  788. Modified version of rq worker which:
  789. * stops work horses getting killed with SIGTERM
  790. * sends SIGRTMIN to work horses on SIGTERM to the main process which in turn
  791. causes the horse to crash `imminent_shutdown_delay` seconds later
  792. """
  793. imminent_shutdown_delay = 6
  794. frame_properties = ['f_code', 'f_lasti', 'f_lineno', 'f_locals', 'f_trace']
  795. if PY2:
  796. frame_properties.extend(
  797. ['f_exc_traceback', 'f_exc_type', 'f_exc_value', 'f_restricted']
  798. )
  799. def setup_work_horse_signals(self):
  800. """Modified to ignore SIGINT and SIGTERM and only handle SIGRTMIN"""
  801. signal.signal(signal.SIGRTMIN, self.request_stop_sigrtmin)
  802. signal.signal(signal.SIGINT, signal.SIG_IGN)
  803. signal.signal(signal.SIGTERM, signal.SIG_IGN)
  804. def handle_warm_shutdown_request(self):
  805. """If horse is alive send it SIGRTMIN"""
  806. if self.horse_pid != 0:
  807. self.log.info(
  808. 'Worker %s: warm shut down requested, sending horse SIGRTMIN signal',
  809. self.key
  810. )
  811. self.kill_horse(sig=signal.SIGRTMIN)
  812. else:
  813. self.log.warning('Warm shut down requested, no horse found')
  814. def request_stop_sigrtmin(self, signum, frame):
  815. if self.imminent_shutdown_delay == 0:
  816. self.log.warning('Imminent shutdown, raising ShutDownImminentException immediately')
  817. self.request_force_stop_sigrtmin(signum, frame)
  818. else:
  819. self.log.warning('Imminent shutdown, raising ShutDownImminentException in %d seconds',
  820. self.imminent_shutdown_delay)
  821. signal.signal(signal.SIGRTMIN, self.request_force_stop_sigrtmin)
  822. signal.signal(signal.SIGALRM, self.request_force_stop_sigrtmin)
  823. signal.alarm(self.imminent_shutdown_delay)
  824. def request_force_stop_sigrtmin(self, signum, frame):
  825. info = dict((attr, getattr(frame, attr)) for attr in self.frame_properties)
  826. self.log.warning('raising ShutDownImminentException to cancel job...')
  827. raise ShutDownImminentException('shut down imminent (signal: %s)' % signal_name(signum), info)