in reply to Is it OK for Time::HiRes::time() to report the time differently per thread?

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.)

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

    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

      No way. That output did not come from my code. I think you ran your old code by accident.