Hi Niphlod, sorry for the late answer, I hadn't access to the involved server. I added the two logs lines you proposed, below the logs: 2013-04-02 09:38:14,561 - web2py.scheduler.mapserver#4162 - DEBUG - ........recording heartbeat (ACTIVE) 2013-04-02 09:38:14,562 - web2py.scheduler.mapserver#4162 - DEBUG - send_heartbeat(), do_assign_tasks=False 2013-04-02 09:38:14,562 - web2py.scheduler.mapserver#4162 - DEBUG - freeing workers that have not sent heartbeat 2013-04-02 09:38:14,564 - web2py.scheduler.mapserver#4162 - INFO - TICKER: I'm a ticker 2013-04-02 09:38:14,644 - web2py.scheduler.mapserver#4162 - DEBUG - looping... 2013-04-02 09:38:14,652 - web2py.scheduler.mapserver#4162 - INFO - pop task True False 2013-04-02 09:38:14,723 - web2py.scheduler.mapserver#4162 - DEBUG - is_a_ticker := True, worker_status[0] := ACTIVE 2013-04-02 09:38:14,732 - web2py.scheduler.mapserver#4162 - INFO - nothing to do 2013-04-02 09:38:14,732 - web2py.scheduler.mapserver#4162 - DEBUG - sleeping... 2013-04-02 09:38:17,727 - web2py.scheduler.mapserver#4162 - DEBUG - ........recording heartbeat (ACTIVE) 2013-04-02 09:38:17,728 - web2py.scheduler.mapserver#4162 - DEBUG - send_heartbeat(), do_assign_tasks=True 2013-04-02 09:38:17,735 - web2py.scheduler.mapserver#4162 - DEBUG - looping... 2013-04-02 09:38:17,736 - web2py.scheduler.mapserver#4162 - INFO - pop task True False 2013-04-02 09:38:17,916 - web2py.scheduler.mapserver#4162 - INFO - nothing to do 2013-04-02 09:38:17,916 - web2py.scheduler.mapserver#4162 - DEBUG - sleeping... 2013-04-02 09:38:20,871 - web2py.scheduler.mapserver#4162 - DEBUG - ........recording heartbeat (ACTIVE) 2013-04-02 09:38:20,872 - web2py.scheduler.mapserver#4162 - DEBUG - send_heartbeat(), do_assign_tasks=False 2013-04-02 09:38:20,919 - web2py.scheduler.mapserver#4162 - DEBUG - looping... 2013-04-02 09:38:20,920 - web2py.scheduler.mapserver#4162 - INFO - pop task True False 2013-04-02 09:38:21,050 - web2py.scheduler.mapserver#4162 - INFO - nothing to do 2013-04-02 09:38:21,050 - web2py.scheduler.mapserver#4162 - DEBUG - sleeping... 2013-04-02 09:38:24,045 - web2py.scheduler.mapserver#4162 - DEBUG - ........recording heartbeat (ACTIVE) 2013-04-02 09:38:24,046 - web2py.scheduler.mapserver#4162 - DEBUG - send_heartbeat(), do_assign_tasks=False 2013-04-02 09:38:24,054 - web2py.scheduler.mapserver#4162 - DEBUG - looping... 2013-04-02 09:38:24,054 - web2py.scheduler.mapserver#4162 - INFO - pop task True False 2013-04-02 09:38:24,234 - web2py.scheduler.mapserver#4162 - INFO - nothing to do 2013-04-02 09:38:24,234 - web2py.scheduler.mapserver#4162 - DEBUG - sleeping... 2013-04-02 09:38:27,193 - web2py.scheduler.mapserver#4162 - DEBUG - ........recording heartbeat (ACTIVE) 2013-04-02 09:38:27,193 - web2py.scheduler.mapserver#4162 - DEBUG - send_heartbeat(), do_assign_tasks=False 2013-04-02 09:38:27,238 - web2py.scheduler.mapserver#4162 - DEBUG - looping... 2013-04-02 09:38:27,238 - web2py.scheduler.mapserver#4162 - INFO - pop task True False 2013-04-02 09:38:27,368 - web2py.scheduler.mapserver#4162 - INFO - nothing to do 2013-04-02 09:38:27,368 - web2py.scheduler.mapserver#4162 - DEBUG - sleeping... 2013-04-02 09:38:30,360 - web2py.scheduler.mapserver#4162 - DEBUG - ........recording heartbeat (ACTIVE) 2013-04-02 09:38:30,361 - web2py.scheduler.mapserver#4162 - DEBUG - send_heartbeat(), do_assign_tasks=False 2013-04-02 09:38:30,361 - web2py.scheduler.mapserver#4162 - DEBUG - freeing workers that have not sent heartbeat 2013-04-02 09:38:30,363 - web2py.scheduler.mapserver#4162 - INFO - TICKER: I'm a ticker
Paolo 2013/3/27 Niphlod <[email protected]> > it was just a trial. > Explaining it further, let's see if someone spots the **supposed** > implementation error.... > > In order to separate transactions and avoid "task contention" among > several workers, we need the **master** steps to both assign tasks and > process tasks. > > The **thread** steps inserts a virtual "assign the task" job setting the > do_assign_task flag to True when necessary. > When that is found to be true, **worker** assigns tasks and sleeps for 3 > seconds, giving the change to the send_heartbeat() to reset the > do_assign_task to False, so you don't have consecutive "assign_tasks" over > and over. > > Skipping over the actual steps taken, a **master** does a loop and sleeps. > > In that loop, if do_assign_task is True, it assign tasks, returns "None" > --> goes to sleep for 3 seconds > > A **thread** does some cleanup, sleeps for 3 seconds and sets the > do_assign_task every 5 cycles. > > Ok, to be fair it's not guaranteed that a loop in either of those > completes in 3 seconds, but the **steps** for both (when the **worker** > doesn't anything) take a few ms (i.e. scheduler doesn't take into account > how many ms passed between the start of either loop before setting the > sleep of 3 seconds...) > > So, self.sleep() in normal condition gets called: > - at every loop of the **thread** (at the end of the send_heartbeat()) > - at every loop of the **master** when it has no tasks or when it assign > tasks (at the end of the loop() function) > > What you are experiencing is that, even if the **thread** sets correctly > do_assign_tasks = True, when the **worker** tries to pop something for some > reason do_assign_task is False. > I can imagine that such a thing happens because do_assign_task is reset to > False, but that reset happens only after (at least) 3 seconds, at the next > send_heartbeat() call. > What I can't reproduce is this behaviour exactly.... how is it possible > that in your logs the "I'm a ticker" message comes 40 ms before pop_task, > and do_assign_task is yet False ? > Can you add a logging line just between these two lines > self.do_assign_tasks = False > if counter % 5 == 0 or mybackedstatus == PICK: > and between > > if self.worker_status[0] == ACTIVE: > self.do_assign_tasks = True > > so we can monitor exactly when the flag is switched ? > > -- > > --- > You received this message because you are subscribed to a topic in the > Google Groups "web2py-users" group. > To unsubscribe from this topic, visit > https://groups.google.com/d/topic/web2py/u_PgzKLuQmw/unsubscribe?hl=en. > To unsubscribe from this group and all its topics, send an email to > [email protected]. > For more options, visit https://groups.google.com/groups/opt_out. > > > -- --- You received this message because you are subscribed to the Google Groups "web2py-users" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. For more options, visit https://groups.google.com/groups/opt_out.
