trace.py 14 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402
  1. # -*- coding: utf-8 -*-
  2. """
  3. celery.task.trace
  4. ~~~~~~~~~~~~~~~~~~~~
  5. This module defines how the task execution is traced:
  6. errors are recorded, handlers are applied and so on.
  7. """
  8. from __future__ import absolute_import
  9. # ## ---
  10. # This is the heart of the worker, the inner loop so to speak.
  11. # It used to be split up into nice little classes and methods,
  12. # but in the end it only resulted in bad performance and horrible tracebacks,
  13. # so instead we now use one closure per task class.
  14. import os
  15. import socket
  16. import sys
  17. from warnings import warn
  18. from kombu.utils import kwdict
  19. from celery import current_app
  20. from celery import states, signals
  21. from celery._state import _task_stack
  22. from celery.app import set_default_app
  23. from celery.app.task import Task as BaseTask, Context
  24. from celery.datastructures import ExceptionInfo
  25. from celery.exceptions import RetryTaskError
  26. from celery.utils.serialization import get_pickleable_exception
  27. from celery.utils.log import get_logger
  28. _logger = get_logger(__name__)
  29. send_prerun = signals.task_prerun.send
  30. prerun_receivers = signals.task_prerun.receivers
  31. send_postrun = signals.task_postrun.send
  32. postrun_receivers = signals.task_postrun.receivers
  33. send_success = signals.task_success.send
  34. success_receivers = signals.task_success.receivers
  35. STARTED = states.STARTED
  36. SUCCESS = states.SUCCESS
  37. RETRY = states.RETRY
  38. FAILURE = states.FAILURE
  39. EXCEPTION_STATES = states.EXCEPTION_STATES
  40. #: set by :func:`setup_worker_optimizations`
  41. _tasks = None
  42. _patched = {}
  43. def mro_lookup(cls, attr, stop=(), monkey_patched=[]):
  44. """Returns the first node by MRO order that defines an attribute.
  45. :keyword stop: A list of types that if reached will stop the search.
  46. :keyword monkey_patched: Use one of the stop classes if the attr's
  47. module origin is not in this list, this to detect monkey patched
  48. attributes.
  49. :returns None: if the attribute was not found.
  50. """
  51. for node in cls.mro():
  52. if node in stop:
  53. try:
  54. attr = node.__dict__[attr]
  55. module_origin = attr.__module__
  56. except (AttributeError, KeyError):
  57. pass
  58. else:
  59. if module_origin not in monkey_patched:
  60. return node
  61. return
  62. if attr in node.__dict__:
  63. return node
  64. def task_has_custom(task, attr):
  65. """Returns true if the task or one of its bases
  66. defines ``attr`` (excluding the one in BaseTask)."""
  67. return mro_lookup(task.__class__, attr, stop=(BaseTask, object),
  68. monkey_patched=['celery.app.task'])
  69. class TraceInfo(object):
  70. __slots__ = ('state', 'retval')
  71. def __init__(self, state, retval=None):
  72. self.state = state
  73. self.retval = retval
  74. def handle_error_state(self, task, eager=False):
  75. store_errors = not eager
  76. if task.ignore_result:
  77. store_errors = task.store_errors_even_if_ignored
  78. return {
  79. RETRY: self.handle_retry,
  80. FAILURE: self.handle_failure,
  81. }[self.state](task, store_errors=store_errors)
  82. def handle_retry(self, task, store_errors=True):
  83. """Handle retry exception."""
  84. # the exception raised is the RetryTaskError semi-predicate,
  85. # and it's exc' attribute is the original exception raised (if any).
  86. req = task.request
  87. type_, _, tb = sys.exc_info()
  88. try:
  89. pred = self.retval
  90. einfo = ExceptionInfo((type_, pred, tb))
  91. if store_errors:
  92. task.backend.mark_as_retry(req.id, pred.exc, einfo.traceback)
  93. task.on_retry(pred.exc, req.id, req.args, req.kwargs, einfo)
  94. return einfo
  95. finally:
  96. del(tb)
  97. def handle_failure(self, task, store_errors=True):
  98. """Handle exception."""
  99. req = task.request
  100. type_, _, tb = sys.exc_info()
  101. try:
  102. exc = self.retval
  103. einfo = ExceptionInfo((type_, get_pickleable_exception(exc), tb))
  104. if store_errors:
  105. task.backend.mark_as_failure(req.id, exc, einfo.traceback)
  106. task.on_failure(exc, req.id, req.args, req.kwargs, einfo)
  107. signals.task_failure.send(sender=task, task_id=req.id,
  108. exception=exc, args=req.args,
  109. kwargs=req.kwargs,
  110. traceback=einfo.tb,
  111. einfo=einfo)
  112. return einfo
  113. finally:
  114. del(tb)
  115. def build_tracer(name, task, loader=None, hostname=None, store_errors=True,
  116. Info=TraceInfo, eager=False, propagate=False):
  117. """Builts a function that tracing the tasks execution; catches all
  118. exceptions, and saves the state and result of the task execution
  119. to the result backend.
  120. If the call was successful, it saves the result to the task result
  121. backend, and sets the task status to `"SUCCESS"`.
  122. If the call raises :exc:`~celery.exceptions.RetryTaskError`, it extracts
  123. the original exception, uses that as the result and sets the task status
  124. to `"RETRY"`.
  125. If the call results in an exception, it saves the exception as the task
  126. result, and sets the task status to `"FAILURE"`.
  127. Returns a function that takes the following arguments:
  128. :param uuid: The unique id of the task.
  129. :param args: List of positional args to pass on to the function.
  130. :param kwargs: Keyword arguments mapping to pass on to the function.
  131. :keyword request: Request dict.
  132. """
  133. # If the task doesn't define a custom __call__ method
  134. # we optimize it away by simply calling the run method directly,
  135. # saving the extra method call and a line less in the stack trace.
  136. fun = task if task_has_custom(task, '__call__') else task.run
  137. loader = loader or current_app.loader
  138. backend = task.backend
  139. ignore_result = task.ignore_result
  140. track_started = task.track_started
  141. track_started = not eager and (task.track_started and not ignore_result)
  142. publish_result = not eager and not ignore_result
  143. hostname = hostname or socket.gethostname()
  144. loader_task_init = loader.on_task_init
  145. loader_cleanup = loader.on_process_cleanup
  146. task_on_success = None
  147. task_after_return = None
  148. if task_has_custom(task, 'on_success'):
  149. task_on_success = task.on_success
  150. if task_has_custom(task, 'after_return'):
  151. task_after_return = task.after_return
  152. store_result = backend.store_result
  153. backend_cleanup = backend.process_cleanup
  154. pid = os.getpid()
  155. request_stack = task.request_stack
  156. push_request = request_stack.push
  157. pop_request = request_stack.pop
  158. push_task = _task_stack.push
  159. pop_task = _task_stack.pop
  160. on_chord_part_return = backend.on_chord_part_return
  161. from celery import canvas
  162. subtask = canvas.subtask
  163. def trace_task(uuid, args, kwargs, request=None):
  164. R = I = None
  165. kwargs = kwdict(kwargs)
  166. try:
  167. push_task(task)
  168. task_request = Context(request or {}, args=args,
  169. called_directly=False, kwargs=kwargs)
  170. push_request(task_request)
  171. try:
  172. # -*- PRE -*-
  173. if prerun_receivers:
  174. send_prerun(sender=task, task_id=uuid, task=task,
  175. args=args, kwargs=kwargs)
  176. loader_task_init(uuid, task)
  177. if track_started:
  178. store_result(uuid, {'pid': pid,
  179. 'hostname': hostname}, STARTED)
  180. # -*- TRACE -*-
  181. try:
  182. R = retval = fun(*args, **kwargs)
  183. state = SUCCESS
  184. except RetryTaskError, exc:
  185. I = Info(RETRY, exc)
  186. state, retval = I.state, I.retval
  187. R = I.handle_error_state(task, eager=eager)
  188. except Exception, exc:
  189. if propagate:
  190. raise
  191. I = Info(FAILURE, exc)
  192. state, retval = I.state, I.retval
  193. R = I.handle_error_state(task, eager=eager)
  194. [subtask(errback).apply_async((uuid, ))
  195. for errback in task_request.errbacks or []]
  196. except BaseException, exc:
  197. raise
  198. except: # pragma: no cover
  199. # For Python2.5 where raising strings are still allowed
  200. # (but deprecated)
  201. if propagate:
  202. raise
  203. I = Info(FAILURE, None)
  204. state, retval = I.state, I.retval
  205. R = I.handle_error_state(task, eager=eager)
  206. [subtask(errback).apply_async((uuid, ))
  207. for errback in task_request.errbacks or []]
  208. else:
  209. # callback tasks must be applied before the result is
  210. # stored, so that result.children is populated.
  211. [subtask(callback).apply_async((retval, ))
  212. for callback in task_request.callbacks or []]
  213. if publish_result:
  214. store_result(uuid, retval, SUCCESS)
  215. if task_on_success:
  216. task_on_success(retval, uuid, args, kwargs)
  217. if success_receivers:
  218. send_success(sender=task, result=retval)
  219. # -* POST *-
  220. if task_request.chord:
  221. on_chord_part_return(task)
  222. if task_after_return:
  223. task_after_return(state, retval, uuid, args, kwargs, None)
  224. if postrun_receivers:
  225. send_postrun(sender=task, task_id=uuid, task=task,
  226. args=args, kwargs=kwargs,
  227. retval=retval, state=state)
  228. finally:
  229. pop_task()
  230. pop_request()
  231. if not eager:
  232. try:
  233. backend_cleanup()
  234. loader_cleanup()
  235. except (KeyboardInterrupt, SystemExit, MemoryError):
  236. raise
  237. except Exception, exc:
  238. _logger.error('Process cleanup failed: %r', exc,
  239. exc_info=True)
  240. except Exception, exc:
  241. if eager:
  242. raise
  243. R = report_internal_error(task, exc)
  244. return R, I
  245. return trace_task
  246. def trace_task(task, uuid, args, kwargs, request={}, **opts):
  247. try:
  248. if task.__trace__ is None:
  249. task.__trace__ = build_tracer(task.name, task, **opts)
  250. return task.__trace__(uuid, args, kwargs, request)[0]
  251. except Exception, exc:
  252. return report_internal_error(task, exc)
  253. def _trace_task_ret(name, uuid, args, kwargs, request={}, **opts):
  254. return trace_task(current_app.tasks[name],
  255. uuid, args, kwargs, request, **opts)
  256. trace_task_ret = _trace_task_ret
  257. def _fast_trace_task(task, uuid, args, kwargs, request={}):
  258. # setup_worker_optimizations will point trace_task_ret to here,
  259. # so this is the function used in the worker.
  260. return _tasks[task].__trace__(uuid, args, kwargs, request)[0]
  261. def eager_trace_task(task, uuid, args, kwargs, request=None, **opts):
  262. opts.setdefault('eager', True)
  263. return build_tracer(task.name, task, **opts)(
  264. uuid, args, kwargs, request)
  265. def report_internal_error(task, exc):
  266. _type, _value, _tb = sys.exc_info()
  267. try:
  268. _value = task.backend.prepare_exception(exc)
  269. exc_info = ExceptionInfo((_type, _value, _tb), internal=True)
  270. warn(RuntimeWarning(
  271. 'Exception raised outside body: %r:\n%s' % (
  272. exc, exc_info.traceback)))
  273. return exc_info
  274. finally:
  275. del(_tb)
  276. def setup_worker_optimizations(app):
  277. global _tasks
  278. global trace_task_ret
  279. # make sure custom Task.__call__ methods that calls super
  280. # will not mess up the request/task stack.
  281. _install_stack_protection()
  282. # all new threads start without a current app, so if an app is not
  283. # passed on to the thread it will fall back to the "default app",
  284. # which then could be the wrong app. So for the worker
  285. # we set this to always return our app. This is a hack,
  286. # and means that only a single app can be used for workers
  287. # running in the same process.
  288. set_default_app(app)
  289. # evaluate all task classes by finalizing the app.
  290. app.finalize()
  291. # set fast shortcut to task registry
  292. _tasks = app._tasks
  293. trace_task_ret = _fast_trace_task
  294. try:
  295. sys.modules['celery.worker.job'].trace_task_ret = _fast_trace_task
  296. except KeyError:
  297. pass
  298. def reset_worker_optimizations():
  299. global trace_task_ret
  300. trace_task_ret = _trace_task_ret
  301. try:
  302. delattr(BaseTask, '_stackprotected')
  303. except AttributeError:
  304. pass
  305. try:
  306. BaseTask.__call__ = _patched.pop('BaseTask.__call__')
  307. except KeyError:
  308. pass
  309. try:
  310. sys.modules['celery.worker.job'].trace_task_ret = _trace_task_ret
  311. except KeyError:
  312. pass
  313. def _install_stack_protection():
  314. # Patches BaseTask.__call__ in the worker to handle the edge case
  315. # where people override it and also call super.
  316. #
  317. # - The worker optimizes away BaseTask.__call__ and instead
  318. # calls task.run directly.
  319. # - so with the addition of current_task and the request stack
  320. # BaseTask.__call__ now pushes to those stacks so that
  321. # they work when tasks are called directly.
  322. #
  323. # The worker only optimizes away __call__ in the case
  324. # where it has not been overridden, so the request/task stack
  325. # will blow if a custom task class defines __call__ and also
  326. # calls super().
  327. if not getattr(BaseTask, '_stackprotected', False):
  328. _patched['BaseTask.__call__'] = orig = BaseTask.__call__
  329. def __protected_call__(self, *args, **kwargs):
  330. req, stack = self.request, self.request_stack
  331. if not req._protected and len(stack) == 2 and \
  332. not req.called_directly:
  333. req._protected = 1
  334. return self.run(*args, **kwargs)
  335. return orig(self, *args, **kwargs)
  336. BaseTask.__call__ = __protected_call__
  337. BaseTask._stackprotected = True