0

I want to create task to update ranking.

settings.py 

djcelery.setup_loader()

BROKER_URL = "amqp://guest:guest@localhost:5672//"

CELERY_TIMEZONE = 'UTC'

I use django worker python manage.py celery worker --loglevel=info

The task:

@celery.task
def update_ranking(duck_pk, new_position):
    duck = Duck.objects.get(pk=duck_pk)

    print 'duck.rank_number="%s"' % scope.rank_number

    # Not in rank yet
    if duck.rank_number is None:
        pass
    else:
        # Positive trend regards to previous rank
        if duck.rank_number > new_position:
            duck.rank_trend = True
        # Negative trend regards to previous rank
        elif duck.rank_number < new_position:
            duck.rank_trend = False
        # No changes, keep previous
        else:
            pass

    print 'Title: %s, Old pos: %s, New pos: %s, Trend: %s' \
          % (duck.title, duck.rank_number, new_position, duck.rank_trend)

    duck.rank_number = new_position
    duck.save()

The view part:

tasks = []
for new_position, duck in enumerate(Duck.objects.all().order_by('-like_number', 'pk')):
    tasks.append(update_ranking.s(duck.pk, new_position + 1))

group = celery.group(tasks)
group.apply_async()

The field rank_number is updated perfectly but rank_trend not!? This is probably tiny and obvious mistake at some point. But I am sitting 5th hour and nothing. The code works properly when I run it on the view without celery. Please help.

EDIT 19:30 (Task output)

[2013-07-27 20:49:20,019: WARNING/PoolWorker-1] scope.rank_number="1"
[2013-07-27 20:49:20,020: WARNING/PoolWorker-1] Title: Title 16, Old: 1, New 1, Trend: True
[2013-07-27 20:49:20,020: INFO/MainProcess] Got task from broker: scope.tasks.update_ranking[dc247c1b-f6a9-4644-9834-6fc815c449af]
[2013-07-27 20:49:20,028: WARNING/PoolWorker-4] scope.rank_number="2"
[2013-07-27 20:49:20,028: WARNING/PoolWorker-4] Title: Title 19, Old: 2, New 3, Trend: False
[2013-07-27 20:49:20,030: WARNING/PoolWorker-2] scope.rank_number="3"
[2013-07-27 20:49:20,030: WARNING/PoolWorker-2] Title: Improve physical condition before trip, Old: 3, New 2, Trend: True
[2013-07-27 20:49:20,126: INFO/MainProcess] Task celery.group[1be41b1c-eb67-4ba9-80d6-c236aadb3074] succeeded in 0.122579097748s: <GroupResult:...
[2013-07-27 20:49:20,137: WARNING/PoolWorker-3] scope.rank_number="4"
[2013-07-27 20:49:20,137: WARNING/PoolWorker-3] Title: Title 15, Old: 4, New 4, Trend: False
[2013-07-27 20:49:20,160: INFO/MainProcess] Got task from broker: scope.tasks.update_ranking[85b25c90-465f-4b2a-bc14-a6f7baf52a2f]
[2013-07-27 20:49:20,189: INFO/MainProcess] Task scope.tasks.update_ranking[32fe744a-58df-4499-9cab-c382f42806ae] succeeded in 0.180363893509s: None
[2013-07-27 20:49:20,199: WARNING/PoolWorker-1] scope.rank_number="5"
[2013-07-27 20:49:20,199: WARNING/PoolWorker-1] Title: Buy a car, Old: 5, New 5, Trend: True
[2013-07-27 20:49:20,256: INFO/MainProcess] Task scope.tasks.update_ranking[bd836619-35e6-41b4-8ac8-96ed13383f5b] succeeded in 0.241793870926s: None
[2013-07-27 20:49:20,257: INFO/MainProcess] Task scope.tasks.update_ranking[7c302bc6-5ec8-40a1-b8e7-e71e96de0dd9] succeeded in 0.239971160889s: None
[2013-07-27 20:49:20,266: WARNING/PoolWorker-2] scope.rank_number="6"
[2013-07-27 20:49:20,266: WARNING/PoolWorker-2] Title: Title 1, Old: 6, New 6, Trend: False
[2013-07-27 20:49:20,268: WARNING/PoolWorker-4] scope.rank_number="7"
[2013-07-27 20:49:20,268: WARNING/PoolWorker-4] Title: Title 18, Old: 7, New 7, Trend: False
[2013-07-27 20:49:20,286: INFO/MainProcess] Got task from broker: scope.tasks.update_ranking[c013b17d-b195-4a0e-802f-29d0396c77d9]
[2013-07-27 20:49:20,287: INFO/MainProcess] Got task from broker: scope.tasks.update_ranking[2719a228-9e9e-46e0-817f-b67e30e2b079]
[2013-07-27 20:49:20,287: INFO/MainProcess] Got task from broker: scope.tasks.update_ranking[4b75414c-229c-409b-a79d-ae8648fdead4]
[2013-07-27 20:49:20,301: INFO/MainProcess] Task scope.tasks.update_ranking[3ee7310a-cee8-487e-9b93-ccab84d79305] succeeded in 0.175172805786s: None
[2013-07-27 20:49:20,302: INFO/MainProcess] Got task from broker: scope.tasks.update_ranking[1557ff8d-c336-43e0-b255-1f74def29a5e]
[2013-07-27 20:49:20,310: INFO/MainProcess] Task scope.tasks.update_ranking[3462bff8-d81a-4a19-b439-c466f5fa473b] succeeded in 0.121726989746s: None
[2013-07-27 20:49:20,311: INFO/MainProcess] Got task from broker: scope.tasks.update_ranking[f98d57e8-191e-48ce-baf6-77e35318231b]
[2013-07-27 20:49:20,313: WARNING/PoolWorker-3] scope.rank_number="8"
[2013-07-27 20:49:20,313: WARNING/PoolWorker-3] Title: Title 3, Old: 8, New 8, Trend: False
[2013-07-27 20:49:20,321: WARNING/PoolWorker-1] scope.rank_number="9"
[2013-07-27 20:49:20,321: WARNING/PoolWorker-1] Title: Title 17, Old: 9, New 9, Trend: False
[2013-07-27 20:49:20,323: INFO/MainProcess] Task scope.tasks.update_ranking[e270bea3-2c06-4930-87a0-5b6e2b2d0612] succeeded in 0.0676720142365s: None
[2013-07-27 20:49:20,329: INFO/MainProcess] Task scope.tasks.update_ranking[00e3a20b-8664-4e62-8f29-3d46556dc7aa] succeeded in 0.0739119052887s: None
[2013-07-27 20:49:20,334: WARNING/PoolWorker-2] scope.rank_number="11"
[2013-07-27 20:49:20,334: WARNING/PoolWorker-4] scope.rank_number="10"
[2013-07-27 20:49:20,334: WARNING/PoolWorker-2] Title: Title 4, Old: 11, New 11, Trend: False
[2013-07-27 20:49:20,334: WARNING/PoolWorker-4] Title: Title 2, Old: 10, New 10, Trend: False
[2013-07-27 20:49:20,358: INFO/MainProcess] Task scope.tasks.update_ranking[33c1bf51-2c1e-4d2a-bebc-7d27f5150d25] succeeded in 0.0574328899384s: None
[2013-07-27 20:49:20,368: WARNING/PoolWorker-3] scope.rank_number="12"
[2013-07-27 20:49:20,368: WARNING/PoolWorker-3] Title: Title 5, Old: 12, New 12, Trend: False
[2013-07-27 20:49:20,402: INFO/MainProcess] Task scope.tasks.update_ranking[045b773b-51fc-4f45-858b-07d75e17030b] succeeded in 0.0921649932861s: None
[2013-07-27 20:49:20,413: WARNING/PoolWorker-1] scope.rank_number="13"
[2013-07-27 20:49:20,413: WARNING/PoolWorker-1] Title: Title 7, Old: 13, New 13, Trend: False
[2013-07-27 20:49:20,434: INFO/MainProcess] Task scope.tasks.update_ranking[c11f5bb7-5694-46c0-b915-47aa74ecd652] succeeded in 0.111576795578s: None
[2013-07-27 20:49:20,434: INFO/MainProcess] Task scope.tasks.update_ranking[ae5c15c0-6297-4a3a-9337-a3efe17aaa56] succeeded in 0.112097978592s: None
[2013-07-27 20:49:20,446: WARNING/PoolWorker-4] scope.rank_number="15"
[2013-07-27 20:49:20,446: WARNING/PoolWorker-4] Title: Title 9, Old: 15, New 15, Trend: False
[2013-07-27 20:49:20,447: WARNING/PoolWorker-2] scope.rank_number="14"
[2013-07-27 20:49:20,447: WARNING/PoolWorker-2] Title: Title 8, Old: 14, New 14, Trend: False
[2013-07-27 20:49:20,455: INFO/MainProcess] Task scope.tasks.update_ranking[00ca68f1-75bd-4094-b60a-c10702b7a577] succeeded in 0.0976941585541s: None
[2013-07-27 20:49:20,465: WARNING/PoolWorker-3] scope.rank_number="16"
[2013-07-27 20:49:20,466: WARNING/PoolWorker-3] Title: Title 6, Old: 16, New 16, Trend: False
[2013-07-27 20:49:20,468: INFO/MainProcess] Task scope.tasks.update_ranking[33a6539f-ce14-4d4f-9578-0e84b584d774] succeeded in 0.0659902095795s: None
[2013-07-27 20:49:20,478: WARNING/PoolWorker-1] scope.rank_number="17"
[2013-07-27 20:49:20,478: INFO/MainProcess] Task scope.tasks.update_ranking[05b695d4-be63-4d9b-80e6-188747190739] succeeded in 0.0431280136108s: None
[2013-07-27 20:49:20,478: WARNING/PoolWorker-1] Title: Title 10, Old: 17, New 17, Trend: False
[2013-07-27 20:49:20,490: WARNING/PoolWorker-2] scope.rank_number="18"
[2013-07-27 20:49:20,490: WARNING/PoolWorker-2] Title: Title 11, Old: 18, New 18, Trend: False
[2013-07-27 20:49:20,492: INFO/MainProcess] Task scope.tasks.update_ranking[e1d27126-4e8a-4fe1-8f30-8d2a6746a89c] succeeded in 0.0575590133667s: None
[2013-07-27 20:49:20,504: WARNING/PoolWorker-4] scope.rank_number="19"
[2013-07-27 20:49:20,504: WARNING/PoolWorker-4] Title: Title 12, Old: 19, New 19, Trend: False
[2013-07-27 20:49:20,511: INFO/MainProcess] Task scope.tasks.update_ranking[46127c11-2c52-4497-86c0-772fadc4c16f] succeeded in 0.0559020042419s: None
[2013-07-27 20:49:20,523: INFO/MainProcess] Task scope.tasks.update_ranking[fb3f8f2f-1bd3-4834-bd66-684dfa9d1540] succeeded in 0.0563740730286s: None
[2013-07-27 20:49:20,524: WARNING/PoolWorker-3] scope.rank_number="20"
[2013-07-27 20:49:20,525: WARNING/PoolWorker-3] Title: Title 13, Old: 20, New 20, Trend: False
[2013-07-27 20:49:20,534: INFO/MainProcess] Task scope.tasks.update_ranking[00dd5cfe-336c-4d44-87cb-8168b22a2df6] succeeded in 0.0563879013062s: None
[2013-07-27 20:49:20,545: WARNING/PoolWorker-1] scope.rank_number="21"
[2013-07-27 20:49:20,545: WARNING/PoolWorker-1] Title: Title 14, Old: 21, New 21, Trend: False
[2013-07-27 20:49:20,555: INFO/MainProcess] Task scope.tasks.update_ranking[dc247c1b-f6a9-4644-9834-6fc815c449af] succeeded in 0.0628831386566s: None
[2013-07-27 20:49:20,564: WARNING/PoolWorker-2] scope.rank_number="22"
[2013-07-27 20:49:20,564: WARNING/PoolWorker-2] Title: My New Target, Old: 22, New 22, Trend: False
[2013-07-27 20:49:20,569: WARNING/PoolWorker-4] scope.rank_number="23"
[2013-07-27 20:49:20,569: WARNING/PoolWorker-4] Title: My Dream target, Old: 23, New 23, Trend: False
[2013-07-27 20:49:20,603: INFO/MainProcess] Task scope.tasks.update_ranking[85b25c90-465f-4b2a-bc14-a6f7baf52a2f] succeeded in 0.0919239521027s: None
[2013-07-27 20:49:20,617: WARNING/PoolWorker-3] scope.rank_number="24"
[2013-07-27 20:49:20,617: WARNING/PoolWorker-3] Title: Test target, Old: 24, New 24, Trend: False
[2013-07-27 20:49:20,634: INFO/MainProcess] Task scope.tasks.update_ranking[c013b17d-b195-4a0e-802f-29d0396c77d9] succeeded in 0.109838962555s: None
[2013-07-27 20:49:20,650: WARNING/PoolWorker-1] scope.rank_number="25"
[2013-07-27 20:49:20,650: WARNING/PoolWorker-1] Title: Build a house, Old: 25, New 25, Trend: False
[2013-07-27 20:49:20,656: INFO/MainProcess] Task scope.tasks.update_ranking[2719a228-9e9e-46e0-817f-b67e30e2b079] succeeded in 0.122545003891s: None
[2013-07-27 20:49:20,657: INFO/MainProcess] Task scope.tasks.update_ranking[4b75414c-229c-409b-a79d-ae8648fdead4] succeeded in 0.101506948471s: None
[2013-07-27 20:49:20,667: INFO/MainProcess] Task scope.tasks.update_ranking[1557ff8d-c336-43e0-b255-1f74def29a5e] succeeded in 0.064563035965s: None
[2013-07-27 20:49:20,733: INFO/MainProcess] Task scope.tasks.update_ranking[f98d57e8-191e-48ce-baf6-77e35318231b] succeeded in 0.0984048843384s: None

In 7th line in logs above there is Trend: True. But in admin panel and on the views is False. This is very weird but I don't know Celery.

EDIT 20:00

Sometimes one in ten tries it does work. I was keeping trying 50 times but have no idea why? I couldn't find any logical explanation. I think something with settings may be wrong.

EDIT 21:51
Updated Task output. Added rank_number log at beginning of the task.

EDIT 21:56 In act of desperation I added: 

for i in range(10000):
    for j in range(10000):
        1000 * 1000

right after the task call on the view. And now is working. Pinch me somebody! Or explain.

EDIT 22:07

MIDDLEWARE_CLASSES = [
    'django.middleware.common.CommonMiddleware',
    'django.contrib.sessions.middleware.SessionMiddleware',
    'django.middleware.csrf.CsrfViewMiddleware',
    'django.contrib.auth.middleware.AuthenticationMiddleware',
    'django.contrib.messages.middleware.MessageMiddleware',
    'django.middleware.clickjacking.XFrameOptionsMiddleware',
]

EDIT 22:17 (When you read everything what is Scope == Duck) sorry for inconsistency on the post.

class ScopeInternalView(BaseView):
    template_name = 'view_internal_scope.html'

    def __init__(self, **kwargs):
        super(ScopeInternalView, self).__init__(**kwargs)
        self.add_action_form = AddActionForm(initial={'form_type': AddActionForm.MY_FORM_ID})
        self.add_support_form = AddSupportForm(initial={'form_type': AddSupportForm.MY_FORM_ID})
        self.edit_entry_form_set = {}
        self.remove_entry_form_set = {}

    def post(self, request, **kwargs):

        if self.add_action_form.MY_FORM_ID == request.POST.get('form_type', ''):
            diary = Diary.get(scope__uuid=kwargs['scope_uuid'])
            if diary.profile.user != request.user:
                raise Exception('Cannot add action which does not belong to logged '
                                'profile.')
            return self.post_add_action(request, diary, **kwargs)
        elif EditEntryForm.MY_FORM_ID == request.POST.get('form_type', ''):
            diary = Diary.get(scope__uuid=kwargs['scope_uuid'])
            if diary.profile.user != request.user:
                raise Exception('Cannot edit entry which does not belong to logged '
                                'profile.')
            return self.post_edit_entry(request, **kwargs)
        elif RemoveEntryForm.MY_FORM_ID == request.POST.get('form_type', ''):
            diary = Diary.get(scope__uuid=kwargs['scope_uuid'])
            if diary.profile.user != request.user:
                raise Exception('Cannot remove entry which does not belong to logged '
                                'profile.')
            return self.post_remove_entry(request, **kwargs)
        elif AddSupportForm.MY_FORM_ID == request.POST.get('form_type', ''):
            diary = Diary.get(scope__uuid=kwargs['scope_uuid'])
            return self.post_add_support(request, diary, **kwargs)
        else:
            raise Exception('Wrong `form_type` on `ScopeInternalView`.')

    def get(self, request, **kwargs):
        diary = Diary.get(scope__uuid=kwargs['scope_uuid'])
        kwargs['is_owner'] = True if diary.profile.user == request.user else False
        # Attach termination to Target
        diary.scope.termination = diary.scope.get_termination()
        entries = self.paginate(request, Entry.filter(diary=diary).order_by('-created'), 6)
        # Build list of forms per page
        for entry in entries:
            entry_uuid = unicode(entry.uuid)
            if not entry_uuid in self.edit_entry_form_set:
                self.edit_entry_form_set[entry_uuid] = \
                    EditEntryForm(initial={'form_type': EditEntryForm.MY_FORM_ID,
                                           'identification': entry_uuid},
                                  instance=entry)
            entry.edit_form = self.edit_entry_form_set[entry_uuid]
            if not entry_uuid in self.remove_entry_form_set:
                self.remove_entry_form_set[entry_uuid] = \
                    RemoveEntryForm(initial={'form_type': RemoveEntryForm.MY_FORM_ID,
                                             'identification': entry_uuid},
                                    instance=entry)
            entry.remove_form = self.remove_entry_form_set[entry_uuid]


        data = {'tags': Tag.filter(scope=diary.scope),
                'diary': diary,
                'scope': diary.scope,
                'motivation_level': diary.scope.asses_motivation(entries=entries),
                'entries_number': len(Entry.filter(diary=diary)),
                'entries': entries,
                'actions': Action.filter(scope=diary.scope).order_by('-created'),
                'add_action_form': self.add_action_form,
                'add_support_form': self.add_support_form}

        parameters = dict(chain(kwargs.iteritems(), data.iteritems()))

        return super(ScopeInternalView, self).get(request, **parameters)

    def post_add_action(self, request, diary, **kwargs):
        form = AddActionForm(request.POST)
        if form.is_valid():
            if not Action.is_limited(kwargs['scope_uuid']):
                self.message = 'Action has been successfully added.'
                action = Action.create(description=form.cleaned_data.get('description'),
                                       hours=form.cleaned_data.get('hours'),
                                       scope=diary.scope)
                action.save()
            else:
                self.error = 'Cannot add more actions then 100 per day.'
            return self.get(request, **kwargs)
        else:
            self.add_action_form = form
            self.show_modal_id = 'addAction'
            return self.get(request, **kwargs)

    def post_add_support(self, request, diary, **kwargs):
        form = AddSupportForm(request.POST)
        if form.is_valid():
            support = Support.create(profile=Profile.get(user=request.user),
                                     scope=diary.scope)
            support.save()
            diray.scope.support_number += 1
            diary.scope.save()

            import celery

            tasks = []
            for index, scope in enumerate(Scope.all().order_by('-support_number', 'pk')):
                tasks.append(update_ranking.s(scope.pk, index))

            group = celery.group(tasks)
            group.apply_async()

            for i in range(10000):
                for j in range(10000):
                    1000 * 1000

            return self.get(request, **kwargs)
        else:
            self.add_support_form = form
            return self.get(request, **kwargs)

The celery task is called on post_add_support()

Bartosz Dabrowski
  • 1,850
  • 2
  • 15
  • 21
  • Are you sure duck.rank_number isn't None at the beginning of the task? Its assigned at the end, so if it was None at the beginning, the else clause would never execute. Likewise, can you change the +1 to a +2 (or something even more incorrect) to make sure there's actually changes, to rule out hitting the inner else clause? – AdamKG Jul 27 '13 at 17:51
  • I am pretty sure. Updated answer. When I not use Celery it does work. – Bartosz Dabrowski Jul 27 '13 at 18:43
  • Are you using transactions? The changes may not have been committed when the task is running. – Maciej Gol Jul 27 '13 at 20:24
  • No, I am not using transactions. – Bartosz Dabrowski Jul 27 '13 at 20:27
  • Could you do `print duck.rank_number` before the if just to make sure it's not `None` ? – Hieu Nguyen Jul 27 '13 at 20:32
  • What is the expected output? It seems that the task works correctly for `Title 19`, and it is not possible to say if it works correctly in other cases as the field value is kept and it's previous value is unknown for us. – Maciej Gol Jul 27 '13 at 20:33
  • Have you got TransactionMiddleware in your middleware settings? – Maciej Gol Jul 27 '13 at 21:04
  • @your edit 22:07, have you got any Duck-modifying code in your view after sending the tasks? – Maciej Gol Jul 27 '13 at 21:09
  • 1
    @BartoszDabrowski, with the pseudo-wait loop everything is working fine because you give your tasks time to finish before calling `Diary.objects.get(...)`. Without the loop, sometimes your tasks execute before the `self.get`, sometimes not. Whilst refreshing the page for result, you are probably resending the tasks resulting in odd behaviour. Is this bug happening after the tasks are done and no other views visited? – Maciej Gol Jul 27 '13 at 21:24
  • 1
    The issue is most likely connected with `save()` method that is saving all fields into the database, unless explicitly told which fields to update (in newer django versions). This would cause odd behaviour with race conditions in your code, i.e. tasks are done and saved changes to the database, but a view is holding an old version of the `Scope` element and does `save()` which results in a loss of what the celery task has done. – Maciej Gol Jul 27 '13 at 21:37
  • @kroolik great thanks for help. You saved me a lot of time. I have to admit its 100% my fault. I found the old function triggered from template which updated rank_number on the get. – Bartosz Dabrowski Jul 28 '13 at 09:44
  • does anyone want to make an answer? :D – Hieu Nguyen Jul 28 '13 at 20:02

1 Answers1

0

The problem was the old method of model which was getting triggered on the get. The method didn't only get value but also updated it "before celery did". I completely forgot about it.

def get_rank(self):
        """\
        Return position of target in ranking.
        """

        scopes = Scope.all().order_by('-support_number', 'pk')

        for index, item in enumerate(scopes):
            if item.id == self.id:
                self.rank_number = index + 1
                break

        self.save()

        return self.rank_number

I didn't found it because it was on the template.
{{ scope.get_rank }}

Bartosz Dabrowski
  • 1,850
  • 2
  • 15
  • 21