Why do my threads not function the way I expect?-CodePudding

I want to create a program which executes some task at intervals, say every 4 seconds, but this should be accomplished using multiple threads which take turns, each doing one task before allowing another to perform the next.

If printing every 4 seconds was the task I want to do, the sequence of events might look like this.

Thread 1 printed at 0 seconds
Thread 2 printed at 4 seconds
Thread 3 printed at 8 seconds
Thread 1 printed at 12 seconds
...

I'm approaching this by storing a queue of thread ID's, and treating the first element of the queue as the ID of the next thread which should execute the task. When a thread executes the task, the queue is rotated so another thread will do the task next. The time since the last task was done is calculated every iteration in each thread and is used to determine if the thread should perform a task (along with it being the current thread's turn).

Here's the code

from threading import Thread, Lock
import threading
from collections import deque
from datetime import datetime
import time

mutex = Lock()
print_interval = 4.0
thread_queue = deque([])
running = True

def print_thread():
    last_print_time = datetime.now()
    
    while running:
        mutex.acquire()
        delta_time = (datetime.now() - last_print_time).total_seconds()

        if delta_time >= print_interval and threading.get_ident() == thread_queue[0]:
            last_print_time = datetime.now()
            thread_queue.rotate(1)
            print('Thread {} printing at time {}'.format(threading.get_ident(), datetime.now().time()), flush=True)
        
        mutex.release()
        
threads = []

for i in range(4):
    thread = Thread(target = print_thread)
    thread.start()
    thread_queue.append(thread.ident)
    
time.sleep(10)

running = False
for thread in threads:
    thread.join()

Here's an example of the output.

Thread 29548 printing at time 17:11:50.662538
Thread 34616 printing at time 17:11:50.683628
Thread 35900 printing at time 17:11:50.683628
Thread 27924 printing at time 17:11:50.683628
Thread 29548 printing at time 17:11:54.667393
Thread 34616 printing at time 17:11:54.683969
Thread 35900 printing at time 17:11:54.683969

Instead of the threads waiting for the correct amount of time to pass, for some reason the delta_time calculation is blowing up on context switches and the thread executes the task right away, only pausing when all threads have done the task. Is my logic correct here? I'm not sure what's going wrong.

Thanks.

edit: I'll explain how I think print_thread should run in steps and try to be clear about it. Let's say we have 2 threads with ID's 1 and 2, and the thread queue looks like [1,2] (thread 1 goes first)

Thread 1 acquires the lock
    delta_time is < 4
    conditional fails to execute
Thread 1 releases the lock

Thread 2 acquires the lock
    delta_time is < 4
    conditional fails to execute
Thread 2 releases the lock

This goes on for about 4 seconds...

Thread 1 acquires the lock
    delta_time is 4.1
    conditional is true because delta_time is >= 4 and this thread is at the front of the queue
    last_print_time = current time
    rotate queue (thread 2 will be next)
Thread 1 releases the lock

Thread 2 acquires the lock
    delta_time is 0.01
    conditional fails because not enough time has passed
Thread 2 releases the lock

Sorry if that's very verbose but this is basically the flow I'm expecting and why the threads should execute sequentially, not at once.

CodePudding user response：

As for me main problem is that every thread uses own private last_print_time and it DOESN'T reset last_print_time in other threads.

You would have to use global last_print_time

Full code with global variable.

I set longer sleep() to see result.

from threading import Thread, Lock
import threading
from collections import deque
from datetime import datetime
import time

mutex = Lock()
print_interval = 4.0
thread_queue = deque([])
running = True

last_print_time = datetime.now()

def print_thread():
    global last_print_time
    
    while running:
        mutex.acquire()
        delta_time = (datetime.now() - last_print_time).total_seconds()

        if delta_time >= print_interval and threading.get_ident() == thread_queue[0]:
            last_print_time = datetime.now()
            thread_queue.rotate(1)
            print('Thread {} printing at time {}'.format(threading.get_ident(), datetime.now().time()), flush=True)
        
        mutex.release()
        
threads = []

for i in range(4):
    thread = Thread(target = print_thread)
    thread.start()
    thread_queue.append(thread.ident)
    
time.sleep(30)

running = False
for thread in threads:
    thread.join()

Result:

Thread 140276746778368 printing at time 19:40:20.012389
Thread 140276517566208 printing at time 19:40:24.015615
Thread 140276729992960 printing at time 19:40:28.021712
Thread 140276738385664 printing at time 19:40:32.037404
Thread 140276746778368 printing at time 19:40:36.038693