24

An inspection of currently running Celery tasks reveals a weird time_start timestamp:

>> celery.app.control.inspect().active()
{u'celery@worker.hostname': [{u'acknowledged': True,
   u'args': u'(...,)',
   u'delivery_info': {u'exchange': u'celery',
    u'priority': 0,
    u'redelivered': None,
    u'routing_key': u'celery'},
   u'hostname': u'celery@worker.hostname',
   u'id': u'3d92fdfd-524e-4ba1-98cb-cf83af2ad8e9',
   u'kwargs': u'{}',
   u'name': u'task_name',
   u'time_start': 9636801.218162088,
   u'worker_pid': 7931}]}

The time_start attribute dates the task back to 1970 (that's before the creation of Celery, Python, and I don't own a customised DeLorean): 

>> from datetime import datetime
>> datetime.fromtimestamp(9636801.218162088)
datetime.datetime(1970, 4, 22, 13, 53, 21, 218162)

Am I misinterpreting the time_task attribute? Is my Celery app misconfigured?

I am using Celery 3.1.4 on Linux with a Django app and a Redis backend.

Tasks are run by a worker that is executed as follows:

./manage.py celery worker --loglevel=INFO --soft-time-limit=600 --logfile=/tmp/w1.log --pidfile=/tmp/w1.pid -n 'w1.%%h'
Régis B.
  • 10,092
  • 6
  • 54
  • 90
  • Thanks for your interest! I added a couple details. – Régis B. Nov 20 '13 at 09:52
  • next questions: whats your OS? are all tasks with such strange start_times or only some of them? and what is your date value on machine with workers? – alko Nov 20 '13 at 09:59
  • The timestamp is not a UNIX timestamp, it's using `time.monotonic()`, so it may not be useful outside of the process (depending on the implementation of monotonic) – asksol Nov 21 '13 at 14:43

1 Answers1

34

I found the answer to my own question by digging in the Celery and Kombu code: the time_start attribute of a task is computed by the kombu.five.monotonic function. (Ironically, the kombu code also refers to another StackOverflow question for reference) The timestamp returned by that function refers to a "monotonic" time computed by the clock_gettime system call.

As explained in the clock_gettime documentation, this monotonic time represents the time elapsed "since some unspecified starting point". The purpose of this function is to make sure that time increases monotonically, despite changes of other clock values.

Thus, in order to obtain the real datetime at which the task was started, we just need to compare the time_start attribute to the current value of the monotonic clock:

>> from datetime import datetime
>> from time import time
>> import kombu.five
>> datetime.fromtimestamp(time() - (kombu.five.monotonic() - 9636801.218162088))
datetime.datetime(2013, 11, 20, 9, 55, 56, 193768)

EDIT: the time_start attribute reported by inspection is no longer monotonic : https://github.com/celery/celery/pull/3684 And it only took me four years to write a proper pull request 0:-)

Régis B.
  • 10,092
  • 6
  • 54
  • 90
  • Shouldn't have commented before reading your answer :) Note that the monotonic time is only useful on the same machine. We could provide a reference timestamp in the inspect output if you need it (you can open a feature request on the celery github issue tracker) – asksol Nov 21 '13 at 14:46
  • That would be great! I'll do that. – Régis B. Nov 21 '13 at 18:23
  • 4
    This works pretty good until you have more than one machine running celery. When this happens the `monotonic` of the current machine is just not the right one for every task. – Hassek Sep 30 '14 at 22:11
  • Every time I come back to this answer I feel bad about not making that PR... @asksol would that still be relevant? – Régis B. Jul 20 '16 at 09:37
  • @RégisB. Thank you for this. Could you clarify now, after the fix, what `time_start` measures exactly? Would you believe I can not find this in the docs anywhere. Is this now just epoch time as returned by `time.time()`? And can this be compared with `time.time()` to get a time delta (time elapsed since it started)? Is there a convenient way to render `time_start` as a local time? – Bernd Wechner Oct 22 '21 at 00:38