in reply to Re^2: Perl threads loss of performance with system call
in thread Perl threads loss of performance with system call
I think I see the same effect on fedora! But that may be due to terminal's sequential stdout!
Here is a script which can help you debug this further, it prints start and stop time of shell system command and which cpu the shell was at the beginning and at the end (or at least that's what I believe as I am not into the Linux scheduler at all). I think it is better to rely on these numbers rather than on the frequency you see "spawned 10" on the terminal, something very unreliable! You can process these timings and see for yourself if there is delay from creating to sleeping. I don't see it, e.g. the 1st shell-command is run at 1626196220.813910751 which is, time-wise, near spawned 3 at 1626196220.81309 I also observe that spawned 7 at 1626196220.82161 and start(i=1, tid=7/449711) on cpu 0: 1626196220.828573978 are very near as well.
use threads; use strict; use Time::HiRes qw/clock_gettime CLOCK_REALTIME/; # use this to control which CPU you assign this script # (and in my system also the shell system command) #use Sys::CpuAffinity; #my $success = Sys::CpuAffinity::setAffinity($$, [1]); print "starting at ".clock_gettime(CLOCK_REALTIME)."\n"; my @pool; for(1..50){ push @pool, threads->create(\&mysub); } $_->join for (@pool); sub mysub { print "spawned " . threads->tid . " at ".clock_gettime(CLOCK_REALT +IME)."\n"; #for(1..100){ select(undef, undef, undef, 0.001); } #my $x = 0.0001 + rand(0.0015); my $x = 0.001; my $id; for my $i (1..100){ $id = "i=$i, tid=".threads->tid; print ` echo -n "start($id/\$\$) on cpu "\`cat /proc/\$\$/stat | cut - +d' ' -f39\`": "; date +%s.%N sleep $x echo -n " stop($id/\$\$) on cpu "\`cat /proc/\$\$/stat | cut - +d' ' -f39\`": "; date +%s.%N `; } print "ended " . threads->tid . " at ".clock_gettime(CLOCK_REALTIM +E)."\n"; } __END__ starting at 1626196220.80981 spawned 1 at 1626196220.81077 spawned 2 at 1626196220.81192 spawned 3 at 1626196220.81309 spawned 4 at 1626196220.81466 spawned 5 at 1626196220.81614 spawned 6 at 1626196220.818 start(i=1, tid=1/449647) on cpu 3: 1626196220.813910751 stop(i=1, tid=1/449647) on cpu 3: 1626196220.818011634 start(i=1, tid=2/449649) on cpu 1: 1626196220.815133617 stop(i=1, tid=2/449649) on cpu 3: 1626196220.819228058 start(i=1, tid=3/449654) on cpu 4: 1626196220.816404247 stop(i=1, tid=3/449654) on cpu 2: 1626196220.820722313 spawned 7 at 1626196220.82161 spawned 8 at 1626196220.8235 start(i=1, tid=4/449665) on cpu 6: 1626196220.818088441 stop(i=1, tid=4/449665) on cpu 4: 1626196220.825072117 spawned 9 at 1626196220.82603 spawned 10 at 1626196220.82844 start(i=1, tid=5/449675) on cpu 4: 1626196220.820177902 start(i=1, tid=6/449684) on cpu 4: 1626196220.824213073 ...
bw, bliako
|
---|
Replies are listed 'Best First'. | |
---|---|
Re^4: Perl threads loss of performance with system call
by daniel85 (Novice) on Jul 13, 2021 at 20:38 UTC |