celery task eta is off, using rabbitmq

Question

I've gotten Celery tasks happening ok, using the default settings in the tutorials and rabbitmq running on ubuntu. All is fine when I schedule a task with no delay, but when I give them an eta, they get scheduled in the future as if my clock is off somewhere.

Here is some python code that is asking for tasks:

for index, to_address in enumerate(email_addresses):
        # schedule one email every two seconds
        delay = index * 2
        log.info("MessageUsersFormView.process_action() scheduling task,"
            "email to %s, countdown = %i" % (to_address, delay) )
        tasks.send_email.apply_async(args=[to_address, subject, body],
            countdown = delay)

So the first one should go out immediately, and then every two seconds. Looking at my celery console, the first one happens immediately, and then the others are scheduled two seconds apart, but starting tomorrow:

[2012-03-09 17:32:40,988: INFO/MainProcess] Got task from broker: stabil.tasks.send_email[24fafc0b-071b-490b-a808-29d47bbee435]
[2012-03-09 17:32:40,989: INFO/MainProcess] Got task from broker: stabil.tasks.send_email[3eb6c3ea-2c84-4368-babe-8a2ac0093836] eta:[2012-03-10 01:32:42.971072-08:00]
[2012-03-09 17:32:40,991: INFO/MainProcess] Got task from broker: stabil.tasks.send_email[a53110d6-b704-4d9c-904a-8d74b99a33af] eta:[2012-03-10 01:32:44.971779-08:00]
[2012-03-09 17:32:40,992: INFO/MainProcess] Got task from broker: stabil.tasks.send_email[2363329b-47e7-4edd-b38e-b09fed232003] eta:[2012-03-10 01:32:46.972422-08:00]

I'm totally new to both Celery and RabbitMQ so any tips on how to fix this or where to look for the cause would be great. This is on a VMWare virtual machine of Ubuntu, but I have the clock set correctly. Thanks!

Answer 1

I think it is actually working as you expect. The time on the left (between the square brackets and before INFO/MainProcess) is presented in local time, but the eta time is shown as UTC time. For instance:

Take the ETA time presented in the second line of your console output:

2012-03-10 01:32:42.971072-08:00

Subtract 8 hours (-08:00 is the timezone offset) and you get:

2012-03-09 17:32:42.971072

Which is just 2 seconds after the sent time:

2012-03-09 17:32:40,989

I hope that makes sense. Dealing with times often gives me a headache.