Time::HiRes usleep problems

Posted on 2005-02-24 16:09:29-08 by cstanton

On my box at home (A), usleep will sleep (approximately) the number of microseconds you pass to it. (requested + 0-2000us)

On another box (B), it is all over the place. Some times +10000, sometimes +20000!

I can deal with a 2000us wiggle, but a I can't handle the usleep instability on machine B.
And, I am having a hell of a time trying to figure out its source.

Originally I had Time:HiRes version 1.66 at home on box A and box B had 1.38 (from the RH RPM). I thought that was the problem so I installed 1.66 from CPAN onto box B. But 1.38 and 1.66 have the same behavior on machine B ...

machine A: 1CPU Athlon with Fedora Core 3
machine B: looks like a 2CPU with HyperThreading on running RedHat Enterprise Linux WS

machine C, 2CPU with HyperThreading off running RH EL AS, has the same results as B.

Something related to RedHat Enterprise Linux? I doubt that it would be due to multi CPUs.

help,
Christopher

################################################################################ #------------------------------------------------------------------------------- hires_test.pl #------------------------------------------------------------------------------- #!/usr/bin/perl -w use warnings; use strict; use Time::HiRes qw(gettimeofday sleep usleep time); print "Time::HiRes\n"; print "VERSION:" . Time::HiRes->VERSION . "\n\n"; print `uname -a` . "\n"; my $index = 1000; print "usleep (usec)\n(requested == actual)\n"; while ( $index <= 40_000 ){ print "$index == " . Time::HiRes::usleep($index) . "\n"; $index += 1000; } print "\n\n"; $index = 0.001000; print "sleep (sec)\n(requested == actual)\n"; while ( $index <= 0.0405 ){ print "$index == " . Time::HiRes::sleep($index) . "\n"; $index += 0.001; } exit; #------------------------------------------------------------------------------- machine A #------------------------------------------------------------------------------- Time::HiRes VERSION:1.66 Linux **** 2.6.10-1.741_FC3 #1 Thu Jan 13 16:38:22 EST 2005 i686 athlon i386 GNU/Linux usleep (usec) (requested == actual) 1000 == 2348 2000 == 3944 3000 == 4987 4000 == 5990 5000 == 6992 6000 == 7980 7000 == 8985 8000 == 9963 9000 == 10981 10000 == 11983 11000 == 12984 12000 == 13981 13000 == 14988 14000 == 15990 15000 == 16982 16000 == 17987 17000 == 18989 18000 == 19979 19000 == 20987 20000 == 21983 21000 == 22979 22000 == 23987 23000 == 24981 24000 == 25988 25000 == 27055 26000 == 27904 27000 == 28964 28000 == 29954 29000 == 30979 30000 == 31979 31000 == 32966 32000 == 33977 33000 == 34978 34000 == 35984 35000 == 36978 36000 == 37977 37000 == 38977 38000 == 39977 39000 == 40978 40000 == 41967 sleep (sec) (requested == actual) 0.001 == 0.0029 0.002 == 0.00398 0.003 == 0.004987 0.004 == 0.005988 0.005 == 0.006988 0.006 == 0.00802 0.007 == 0.008951 0.008 == 0.009986 0.009 == 0.010988 0.01 == 0.011987 0.011 == 0.012988 0.012 == 0.01398 0.013 == 0.014987 0.014 == 0.016016 0.015 == 0.016951 0.016 == 0.01798 0.017 == 0.018981 0.018 == 0.01998 0.019 == 0.020985 0.02 == 0.021986 0.021 == 0.022979 0.022 == 0.023986 0.023 == 0.024976 0.024 == 0.025986 0.025 == 0.026977 0.026 == 0.027984 0.027 == 0.028981 0.028 == 0.029961 0.029 == 0.030975 0.03 == 0.031948 0.031 == 0.032976 0.032 == 0.033974 0.033 == 0.034979 0.034 == 0.035964 0.035 == 0.036971 0.036 == 0.037975 0.037 == 0.038975 0.038 == 0.039982 0.039 == 0.040967 0.04 == 0.041976 #------------------------------------------------------------------------------- machine B #------------------------------------------------------------------------------- Time::HiRes VERSION:1.38 Linux **** 2.4.21-27.0.2.ELsmp #1 SMP Wed Jan 12 23:35:44 EST 2005 i686 i686 i386 GNU/Linux usleep (usec) (requested == actual) 1000 == 16799 2000 == 19946 3000 == 20013 4000 == 19946 5000 == 19980 6000 == 20005 7000 == 19982 8000 == 19973 9000 == 19981 10000 == 19962 11000 == 29982 12000 == 29995 13000 == 29958 14000 == 29994 15000 == 29984 16000 == 29982 17000 == 29997 18000 == 29964 19000 == 29980 20000 == 29981 21000 == 40021 22000 == 39907 23000 == 39976 24000 == 40009 25000 == 39913 26000 == 39996 27000 == 39997 28000 == 39872 29000 == 39990 30000 == 39930 31000 == 49968 32000 == 49956 33000 == 49973 34000 == 49993 35000 == 49980 36000 == 49973 37000 == 49952 38000 == 49984 39000 == 49985 40000 == 49973 sleep (sec) (requested == actual) 0.001 == 0.019934 0.002 == 0.019998 0.003 == 0.019987 0.004 == 0.020042 0.005 == 0.019919 0.006 == 0.019972 0.007 == 0.019994 0.008 == 0.01998 0.009 == 0.019969 0.01 == 0.019971 0.011 == 0.030011 0.012 == 0.02996 0.013 == 0.029991 0.014 == 0.029958 0.015 == 0.030004 0.016 == 0.029987 0.017 == 0.029976 0.018 == 0.029925 0.019 == 0.030006 0.02 == 0.029951 0.021 == 0.039992 0.022 == 0.040002 0.023 == 0.039903 0.024 == 0.040005 0.025 == 0.039938 0.026 == 0.039966 0.027 == 0.039988 0.028 == 0.039985 0.029 == 0.039929 0.03 == 0.039984 0.031 == 0.04994 0.032 == 0.049978 0.033 == 0.049945 0.034 == 0.049982 0.035 == 0.049987 0.036 == 0.049972 0.037 == 0.049978 0.038 == 0.049998 0.039 == 0.049942 0.04 == 0.049978 #------------------------------------------------------------------------------- machine B #------------------------------------------------------------------------------- Time::HiRes VERSION:1.66 Linux **** 2.4.21-27.0.2.ELsmp #1 SMP Wed Jan 12 23:35:44 EST 2005 i686 i686 i386 GNU/Linux usleep (usec) (requested == actual) 1000 == 15854 2000 == 19939 3000 == 19971 4000 == 19949 5000 == 19988 6000 == 20001 7000 == 19947 8000 == 19992 9000 == 19970 10000 == 19988 11000 == 29955 12000 == 29984 13000 == 29978 14000 == 29944 15000 == 29988 16000 == 29984 17000 == 29951 18000 == 30014 19000 == 29929 20000 == 29953 21000 == 39999 22000 == 39943 23000 == 40009 24000 == 39936 25000 == 39962 26000 == 39954 27000 == 39994 28000 == 39976 29000 == 39932 30000 == 39967 31000 == 49959 32000 == 49923 33000 == 49968 34000 == 49965 35000 == 49968 36000 == 50005 37000 == 49908 38000 == 49961 39000 == 49950 40000 == 49990 sleep (sec) (requested == actual) 0.001 == 0.019945 0.002 == 0.020002 0.003 == 0.019968 0.004 == 0.019985 0.005 == 0.019993 0.006 == 0.019974 0.007 == 0.019986 0.008 == 0.020003 0.009 == 0.019971 0.01 == 0.019971 0.011 == 0.029993 0.012 == 0.02998 0.013 == 0.029989 0.014 == 0.029984 0.015 == 0.030005 0.016 == 0.029949 0.017 == 0.030052 0.018 == 0.029874 0.019 == 0.029999 0.02 == 0.029974 0.021 == 0.039991 0.022 == 0.039957 0.023 == 0.03998 0.024 == 0.039974 0.025 == 0.039976 0.026 == 0.039951 0.027 == 0.03998 0.028 == 0.039994 0.029 == 0.039952 0.03 == 0.039976 0.031 == 0.049965 0.032 == 0.049999 0.033 == 0.049979 0.034 == 0.049948 0.035 == 0.049969 0.036 == 0.049979 0.037 == 0.049988 0.038 == 0.049942 0.039 == 0.049968 0.04 == 0.049934

Direct Responses: 150 | Write a response

Posted on 2005-02-24 17:49:39-08 by cstanton in response to 149

Re: Time::HiRes usleep problems

It looks like the issue isn't with the Time::HiRes module, but with the glibc libraries which are part of the RH EL distro.

Directly using the usleep call in C on RH EL has the same issue. FC3 does not.

Fedora Core 3: glibc-2.3.4-2.fc3
RedHat EL 3: glibc-2.3.2-95.30

Christopher

Direct Responses: 2222 | 11286 | Write a response

Posted on 2006-05-01 18:33:46-07 by jvg in response to 150

Re: Time::HiRes usleep problems

Did you ever resolve this issue? I just came across the exact same problem with ActiveState PERL running on WindowsXP 2002.

Joe

Direct Responses: Write a response

Posted on 2009-08-12 14:07:02-07 by ianrvaughan in response to 150

Re: Time::HiRes usleep problems

Hi, I am seeing the same problems as you :-

Time::HiRes VERSION:1.86 Linux 2.6.18-128.el5 #1 SMP Wed Dec 17 11:42:39 EST 2008 i686 i686 i386 GNU/Linux usleep (usec) (requested == actual) 1000 == 2243 2000 == 3986 3000 == 5084 4000 == 6079 5000 == 7061 6000 == 8095 7000 == 8065 8000 == 9099 9000 == 11196 10000 == 12173 11000 == 13164 12000 == 13178 13000 == 15244 14000 == 16221 15000 == 16239 16000 == 18301 17000 == 18264 18000 == 19301 19000 == 21409 20000 == 21276 21000 == 23483 22000 == 23463 23000 == 25524 24000 == 25503 25000 == 26544 26000 == 27564 27000 == 28544 28000 == 29604 29000 == 30605 30000 == 31645 31000 == 32686 32000 == 33685 33000 == 34673 34000 == 36747 35000 == 36767 36000 == 37765 37000 == 38767 38000 == 39814 39000 == 40847 40000 == 41845 sleep (sec) (requested == actual) 0.001 == 0.001992 0.002 == 0.003027 0.003 == 0.004057 0.004 == 0.005097 0.005 == 0.007138 0.006 == 0.008178 0.007 == 0.009178 0.008 == 0.009158 0.009 == 0.010199 0.01 == 0.012217 0.011 == 0.013259 0.012 == 0.013238 0.013 == 0.014279 0.014 == 0.016339 0.015 == 0.0163 0.016 == 0.01734 0.017 == 0.019401 0.018 == 0.019366 0.019 == 0.021463 0.02 == 0.0214 0.021 == 0.022482 0.022 == 0.02344 0.023 == 0.024522 0.024 == 0.02548 0.025 == 0.026582 0.026 == 0.02754 0.027 == 0.029605 0.028 == 0.029598 0.029 == 0.030589 0.03 == 0.032663 0.031 == 0.032684 0.032 == 0.033662 0.033 == 0.034703 0.034 == 0.035723 0.035 == 0.036743 0.036 == 0.03774 0.037 == 0.038783 0.038 == 0.039802 0.039 == 0.040824 0.04 == 0.041844 # rpm -qa | grep glibc glibc-2.5-34 glibc-common-2.5-34 glibc-devel-2.5-34 glibc-headers-2.5-34

Anyone subscribed to this thread?

Direct Responses: 11290 | Write a response

Posted on 2009-08-13 05:00:38-07 by ianrvaughan in response to 11286

Re: Time::HiRes usleep problems

Results are slightly better on my wife's laptop! :-

Time::HiRes VERSION:1.9711 Linux 2.6.28-14-generic #47-Ubuntu SMP Sat Jul 25 00:28:35 UTC 2009 i686 GNU/Linux usleep (usec) (requested == actual) 1000 == 1436 2000 == 2226 3000 == 3225 4000 == 4082 5000 == 5226 6000 == 6221 7000 == 9144 8000 == 9127 9000 == 9227 10000 == 11638 11000 == 11227 12000 == 18495 13000 == 13224 14000 == 14069 15000 == 15223 16000 == 16073 17000 == 17225 18000 == 18072 19000 == 19070 20000 == 20226 21000 == 21227 22000 == 22069 23000 == 23222 24000 == 24084 25000 == 25083 26000 == 26223 27000 == 27167 28000 == 28068 29000 == 29224 30000 == 30073 31000 == 31077 32000 == 32074 33000 == 33220 34000 == 34225 35000 == 35085 36000 == 36225 37000 == 37228 38000 == 38228 39000 == 39223 40000 == 40088 sleep (sec) (requested == actual) 0.001 == 0.001225 0.002 == 0.002222 0.003 == 0.003222 0.004 == 0.00408 0.005 == 0.005068 0.006 == 0.006223 0.007 == 0.007223 0.008 == 0.008224 0.009 == 0.009068 0.01 == 0.010072 0.011 == 0.011227 0.012 == 0.012221 0.013 == 0.013085 0.014 == 0.014068 0.015 == 0.015226 0.016 == 0.01607 0.017 == 0.017228 0.018 == 0.018068 0.019 == 0.019071 0.02 == 0.020131 0.021 == 0.021224 0.022 == 0.02207 0.023 == 0.023227 0.024 == 0.024224 0.025 == 0.025222 0.026 == 0.026222 0.027 == 0.027229 0.028 == 0.028222 0.029 == 0.029228 0.03 == 0.030141 0.031 == 0.031086 0.032 == 0.032225 0.033 == 0.033235 0.034 == 0.034084 0.035 == 0.035135 0.036 == 0.036226 0.037 == 0.037088 0.038 == 0.038074 0.039 == 0.039073 0.04 == 0.040068

Direct Responses: Write a response