Anonymous Monk has asked for the wisdom of the Perl Monks concerning the following question:

I would expect all "next" times to be higher than "first" times (unless I messed it with semaphores), but on some invocations it is not the case. Why does this happen? This is Strawberry 5.42

use strict; use warnings; no warnings 'void'; use threads; use Thread::Semaphore ; use Time::HiRes 'time'; my $t = time; my @s = map Thread::Semaphore-> new( 0 ), 1 .. 4; my @t = map async { my $id = threads-> tid - 1; $s[ $id ]-> down; sin for 1 .. 1e7; # work per thread printf "first, %d %.3f\n", $id, time - $t; $s[ $id ]-> up( 4 ); $_-> down for @s; printf "next, %d %.3f\n", $id, time - $t; }, 1 .. 4; sin for 1 .. 1e7; # initial work $_-> up for @s; $_-> join for @t; __END__ first, 2 1.824 first, 3 1.824 first, 1 1.824 first, 0 1.832 next, 1 1.826 next, 3 1.828 next, 2 1.832 next, 0 1.832
  • Comment on Is it OK for Time::HiRes::time() to report the time differently per thread?
  • Download Code

Replies are listed 'Best First'.
Re: Is it OK for Time::HiRes::time() to report the time differently per thread?
by Anonymous Monk on Apr 23, 2026 at 13:03 UTC

    Sorry, looks like replacing time() with clock_gettime(CLOCK_MONOTONIC) fixes the issue. Should have googled better first. I forgot to say, there's supposed to be another synchronised section in place of the 2nd "printf", hence my concern.

      That doesn't fix your bug. The race condition is still present even if you didn't see a failure.

Re: Is it OK for Time::HiRes::time() to report the time differently per thread?
by ikegami (Patriarch) on Apr 23, 2026 at 16:15 UTC

    You expect each thread to only proceed to obtaining the "next" time once every threads has reached that point. In other words, you are trying to implement a barrier.

    However, your implementation is flawed. A race condition exists. It's possible to execute reach $_->down for @s; in one thread before reaching $s[ $id ]->down; in another thread.

    This is what you observed happening. In your run, thread 1 reached $_->down for @s; before thread 0 reached $s[ $id ]->down;.

    You need a separate semaphore to wait for the main thread to complete instead of re-using the ones you have.

    Fixed:

    use strict; use warnings; no warnings 'void'; use threads; use Thread::Semaphore qw( ); use Time::HiRes qw( time ); use constant NUM_THREADS => 4; my $t = time; my $start_sem = Thread::Semaphore->new( 0 ); my @barrier = map Thread::Semaphore->new( 0 ), 1 .. NUM_THREADS; my @t = map async { my $id = threads-> tid - 1; # Wait for main thread to complete. $start_sem->down; sin for 1 .. 1e7; printf "first, %d %.3f\n", $id, time - $t; # Wait for all threads to reach here. $barrier[ $id ]->up( NUM_THREADS ); $_->down for @barrier; printf "next, %d %.3f\n", $id, time - $t; }, 1 .. NUM_THREADS; sin for 1 .. 1e7; # Main thread done $start_sem->up( NUM_THREADS ); $_->join for @t;
    first, 0 0.634 first, 2 0.639 first, 3 0.646 first, 1 0.732 next, 0 0.732 next, 1 0.732 next, 3 0.732 next, 2 0.732

    And here's a solution based on Thread::Barrier:

    use strict; use warnings; no warnings 'void'; use threads; use Thread::Barrier qw( ); use Thread::Semaphore qw( ); use Time::HiRes qw( time ); use constant NUM_THREADS => 4; my $t = time; my $start_sem = Thread::Semaphore->new( 0 ); my $barrier = Thread::Barrier->new( NUM_THREADS ); my @t = map async { my $id = threads-> tid - 1; # Wait for main thread to complete. $start_sem->down; sin for 1 .. 1e7; printf "first, %d %.3f\n", $id, time - $t; # Wait for all threads to reach here. $barrier->wait; printf "next, %d %.3f\n", $id, time - $t; }, 1 .. NUM_THREADS; sin for 1 .. 1e7; # Main thread done $start_sem->up( NUM_THREADS ); $_->join for @t;
    first, 1 0.698 first, 2 0.702 first, 0 0.723 first, 3 0.757 next, 3 0.757 next, 1 0.757 next, 0 0.757 next, 2 0.757

    Or just barriers:

    use strict; use warnings; no warnings 'void'; use threads; use Thread::Barrier qw( ); use Time::HiRes qw( time ); use constant NUM_THREADS => 4; my $t = time; my $barrier1 = Thread::Barrier->new( NUM_THREADS + 1 ); my $barrier2 = Thread::Barrier->new( NUM_THREADS ); my @t = map async { my $id = threads-> tid - 1; # Wait for main thread to complete. $barrier1->wait; sin for 1 .. 1e7; printf "first, %d %.3f\n", $id, time - $t; # Wait for all threads to reach here. $barrier2->wait; printf "next, %d %.3f\n", $id, time - $t; }, 1 .. NUM_THREADS; sin for 1 .. 1e7; $barrier1->wait; $_->join for @t;
    first, 0 0.630 first, 1 0.630 first, 2 0.632 first, 3 0.723 next, 3 0.723 next, 0 0.723 next, 1 0.723 next, 2 0.723

    (This last version is slightly different since it doesn't wait for just the main thread to complete, but for all other threads to reach the first barrier.)

      Thank you very much, indeed, for pointing out about flaw in my code; I think I _do_ see what you mean by

      It's possible to execute reach $_->down for @s; in one thread before reaching $s[ $id ]->down; in another thread

      and, thus, the necessity of separate semaphore. Buggy code and flawed logic could cost me in the future. Thanks!!! Still, however, it won't happen in my SSCCE, nor in my real code, because of amount of time required for executing "payload" (and limited number of threads?). Here's result of one (out of about 10?) invocation of _exactly_ your code (the 1st one), it's the same issue:

      first, 0 1.826 first, 2 1.834 first, 1 1.834 first, 3 1.836 next, 1 1.835 next, 0 1.829 next, 2 1.835 next, 3 1.836

      However, using clock_gettime(CLOCK_MONOTONIC) it's looks like it's _always_ OK, and, FWIW, always the _same_ time reported for all of "next"'s.

      first, 3 1.855 first, 1 1.856 first, 0 1.858 first, 2 1.867 next, 0 1.868 next, 1 1.868 next, 3 1.868 next, 2 1.868
Re: Is it OK for Time::HiRes::time() to report the time differently per thread?
by Corion (Patriarch) on Apr 23, 2026 at 13:00 UTC

    I think the output is consistent. For each thread id, the first output is before the next output.

    I don't know how your OS schedules the different threads, but you cannot really rely on all threads getting scheduled in parallel.

    Update: For the different ordering, you are likely falling afoul of output buffering. But as there are more/other locks in play, it's hard to say.

      I think the output is consistent. For each thread id, the first output is before the next output.

      That's not what the OP wants. The OP want to bar the threads from proceeding to obtaining the "next" time only after every thread has reached that point.

      However, the implementation of the barrier is flawed. A race condition exists.

Re: Is it OK for Time::HiRes::time() to report the time differently per thread?
by ikegami (Patriarch) on Apr 23, 2026 at 15:52 UTC

    [Incorrect post deleted]