I'm having a SNAFU moment: timer:sleep/1

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
19 messages Options
Reply | Threaded
Open this post in threaded view
|

I'm having a SNAFU moment: timer:sleep/1

Roberto Ostinelli
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Roberto Ostinelli
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Sergej Jurečko

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

dmkolesnikov
In reply to this post by Roberto Ostinelli
Hello,

timer:sleep() is implemented as receive after T -> ok end. It does not give you microsecond precision so that error is aggregated. 

secondly, lists:foreach(SleepFun, lists:seq(1, Num)) does not look performance friendly for big Num  

try tail recursion it gives better results.

sleep_loop(0, _) ->
        ok;
sleep_loop(N, IntervalMs) ->
        receive after IntervalMs -> ok end,
        sleep_loop(N - 1, IntervalMs).


- Dmitry

On 12 Jan 2015, at 12:40, Roberto Ostinelli <[hidden email]> wrote:

Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.

_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Roberto Ostinelli
In reply to this post by Sergej Jurečko
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Jesper Louis Andersen-2
Hi Roberto,

I'm not sure what you would expect here. timer:sleep/1 has an implementation like this:

sleep(T) ->
    receive
    after T -> ok
    end.

which is what other people told you also. In general, such timing constructs have no guarantee about when they will fire, only that they will fire after the time has elapsed. So what you are seeing is somewhat expected behaviour. The more fine-grained and the more timers you have, the less precise things will get. In a way, this is one of the properties which makes Erlang a soft-realtime system and not a hard-realtime one, although the precise definition of soft/hard realtime are subtly different.

I believe there were some effort being made by the OTP team to address lock contention around the timer wheel, so the code might change behaviour by quite a lot in the future. It might even have to get worse for single-process timers in order to become better for multi-process timers.


On Mon Jan 12 2015 at 12:20:15 PM Roberto Ostinelli <[hidden email]> wrote:
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions

_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Darach Ennis
Hi Roberto,

If you want to avoid clock slewing or you need a timely and periodic event source you
can achieve this somewhat as follows, although the right solution will of course depend
on multiple factors.

-define(INTERVAL, 1000). % One second

main(_) ->
  loop(now_ms(),0).

trigger(Now,Delta,Count) ->
  io:format("At: ~p drift:~p rate:~p/sec~n", [Now, Delta - ?INTERVAL, Count]).

loop(Epoch,Count) -> 
  Now = now_ms(),
  Delta = Now - Epoch,
  case Delta >= ?INTERVAL of
      true -> 
          trigger(Now,Delta,Count),
          loop(Epoch+?INTERVAL,0);
      false ->
          loop(Epoch,Count+1)
  end.

now_ms() ->
  {Mega,Secs,Micros} = os:timestamp(),
  (Mega*1000000 + Secs)*1000 + (Micros div 1000).

This loops at a rate of ~7 million loops/second on my laptop and fires without
slew or significant drift consistently calling the trigger/3 function every second. The rub is I
burn a little more core/process for the privilege than with mechanism that induce slew such
as with timer or erlang:send_after directly. C'est la vie. Accuracy and timeliness aren't free.

In a gen_server you could use a combination of erlang:send_after and a clock based on
os:timestamp and an epoch as above so that you end up with a clock that is 'accurate enough'
for most use cases, and cheap enough for whatever value you ascribe to such tradeoffs given
the specifics of your use case.

Your mileage may vary.

Cheers,

Darach.

On Mon, Jan 12, 2015 at 11:43 AM, Jesper Louis Andersen <[hidden email]> wrote:
Hi Roberto,

I'm not sure what you would expect here. timer:sleep/1 has an implementation like this:

sleep(T) ->
    receive
    after T -> ok
    end.

which is what other people told you also. In general, such timing constructs have no guarantee about when they will fire, only that they will fire after the time has elapsed. So what you are seeing is somewhat expected behaviour. The more fine-grained and the more timers you have, the less precise things will get. In a way, this is one of the properties which makes Erlang a soft-realtime system and not a hard-realtime one, although the precise definition of soft/hard realtime are subtly different.

I believe there were some effort being made by the OTP team to address lock contention around the timer wheel, so the code might change behaviour by quite a lot in the future. It might even have to get worse for single-process timers in order to become better for multi-process timers.


On Mon Jan 12 2015 at 12:20:15 PM Roberto Ostinelli <[hidden email]> wrote:
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions

_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Sergej Jurečko
At least put erlang:yield() at the end of the loop. But to me that is just a gigantic waste of CPU.

This little c program as an external port does the job very nicely and hardly uses any resources.
int main(int argc, char *argv[])
{

    char c[1];
    c[0] = 'a';
    for (;;)
    {
        usleep(3000);
       
        if (write(1, c, 1) <= 0)
            break;
    }
   
      return 0;
}

On Mon, Jan 12, 2015 at 2:10 PM, Darach Ennis <[hidden email]> wrote:
Hi Roberto,

If you want to avoid clock slewing or you need a timely and periodic event source you
can achieve this somewhat as follows, although the right solution will of course depend
on multiple factors.

-define(INTERVAL, 1000). % One second

main(_) ->
  loop(now_ms(),0).

trigger(Now,Delta,Count) ->
  io:format("At: ~p drift:~p rate:~p/sec~n", [Now, Delta - ?INTERVAL, Count]).

loop(Epoch,Count) -> 
  Now = now_ms(),
  Delta = Now - Epoch,
  case Delta >= ?INTERVAL of
      true -> 
          trigger(Now,Delta,Count),
          loop(Epoch+?INTERVAL,0);
      false ->
          loop(Epoch,Count+1)
  end.

now_ms() ->
  {Mega,Secs,Micros} = os:timestamp(),
  (Mega*1000000 + Secs)*1000 + (Micros div 1000).

This loops at a rate of ~7 million loops/second on my laptop and fires without
slew or significant drift consistently calling the trigger/3 function every second. The rub is I
burn a little more core/process for the privilege than with mechanism that induce slew such
as with timer or erlang:send_after directly. C'est la vie. Accuracy and timeliness aren't free.

In a gen_server you could use a combination of erlang:send_after and a clock based on
os:timestamp and an epoch as above so that you end up with a clock that is 'accurate enough'
for most use cases, and cheap enough for whatever value you ascribe to such tradeoffs given
the specifics of your use case.

Your mileage may vary.

Cheers,

Darach.

On Mon, Jan 12, 2015 at 11:43 AM, Jesper Louis Andersen <[hidden email]> wrote:
Hi Roberto,

I'm not sure what you would expect here. timer:sleep/1 has an implementation like this:

sleep(T) ->
    receive
    after T -> ok
    end.

which is what other people told you also. In general, such timing constructs have no guarantee about when they will fire, only that they will fire after the time has elapsed. So what you are seeing is somewhat expected behaviour. The more fine-grained and the more timers you have, the less precise things will get. In a way, this is one of the properties which makes Erlang a soft-realtime system and not a hard-realtime one, although the precise definition of soft/hard realtime are subtly different.

I believe there were some effort being made by the OTP team to address lock contention around the timer wheel, so the code might change behaviour by quite a lot in the future. It might even have to get worse for single-process timers in order to become better for multi-process timers.


On Mon Jan 12 2015 at 12:20:15 PM Roberto Ostinelli <[hidden email]> wrote:
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions

_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions




_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Darach Ennis
Hi Sergej,

I wasn't suggesting using directly. I was illustrating that erlang can issue periodic
events with reasonable accuracy and timeliness whilst avoiding slew. Not everyone
will want to drop to C to resolve but this is a nice solution for those that do.

Cheers,

Darach.

On Mon, Jan 12, 2015 at 1:18 PM, Sergej Jurečko <[hidden email]> wrote:
At least put erlang:yield() at the end of the loop. But to me that is just a gigantic waste of CPU.

This little c program as an external port does the job very nicely and hardly uses any resources.
int main(int argc, char *argv[])
{

    char c[1];
    c[0] = 'a';
    for (;;)
    {
        usleep(3000);
       
        if (write(1, c, 1) <= 0)
            break;
    }
   
      return 0;
}

On Mon, Jan 12, 2015 at 2:10 PM, Darach Ennis <[hidden email]> wrote:
Hi Roberto,

If you want to avoid clock slewing or you need a timely and periodic event source you
can achieve this somewhat as follows, although the right solution will of course depend
on multiple factors.

-define(INTERVAL, 1000). % One second

main(_) ->
  loop(now_ms(),0).

trigger(Now,Delta,Count) ->
  io:format("At: ~p drift:~p rate:~p/sec~n", [Now, Delta - ?INTERVAL, Count]).

loop(Epoch,Count) -> 
  Now = now_ms(),
  Delta = Now - Epoch,
  case Delta >= ?INTERVAL of
      true -> 
          trigger(Now,Delta,Count),
          loop(Epoch+?INTERVAL,0);
      false ->
          loop(Epoch,Count+1)
  end.

now_ms() ->
  {Mega,Secs,Micros} = os:timestamp(),
  (Mega*1000000 + Secs)*1000 + (Micros div 1000).

This loops at a rate of ~7 million loops/second on my laptop and fires without
slew or significant drift consistently calling the trigger/3 function every second. The rub is I
burn a little more core/process for the privilege than with mechanism that induce slew such
as with timer or erlang:send_after directly. C'est la vie. Accuracy and timeliness aren't free.

In a gen_server you could use a combination of erlang:send_after and a clock based on
os:timestamp and an epoch as above so that you end up with a clock that is 'accurate enough'
for most use cases, and cheap enough for whatever value you ascribe to such tradeoffs given
the specifics of your use case.

Your mileage may vary.

Cheers,

Darach.

On Mon, Jan 12, 2015 at 11:43 AM, Jesper Louis Andersen <[hidden email]> wrote:
Hi Roberto,

I'm not sure what you would expect here. timer:sleep/1 has an implementation like this:

sleep(T) ->
    receive
    after T -> ok
    end.

which is what other people told you also. In general, such timing constructs have no guarantee about when they will fire, only that they will fire after the time has elapsed. So what you are seeing is somewhat expected behaviour. The more fine-grained and the more timers you have, the less precise things will get. In a way, this is one of the properties which makes Erlang a soft-realtime system and not a hard-realtime one, although the precise definition of soft/hard realtime are subtly different.

I believe there were some effort being made by the OTP team to address lock contention around the timer wheel, so the code might change behaviour by quite a lot in the future. It might even have to get worse for single-process timers in order to become better for multi-process timers.


On Mon Jan 12 2015 at 12:20:15 PM Roberto Ostinelli <[hidden email]> wrote:
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions

_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions





_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Roberto Ostinelli
In reply to this post by Darach Ennis
Isn't this using 100% of 1 cpu?

On Mon, Jan 12, 2015 at 2:10 PM, Darach Ennis <[hidden email]> wrote:
Hi Roberto,

If you want to avoid clock slewing or you need a timely and periodic event source you
can achieve this somewhat as follows, although the right solution will of course depend
on multiple factors.

-define(INTERVAL, 1000). % One second

main(_) ->
  loop(now_ms(),0).

trigger(Now,Delta,Count) ->
  io:format("At: ~p drift:~p rate:~p/sec~n", [Now, Delta - ?INTERVAL, Count]).

loop(Epoch,Count) -> 
  Now = now_ms(),
  Delta = Now - Epoch,
  case Delta >= ?INTERVAL of
      true -> 
          trigger(Now,Delta,Count),
          loop(Epoch+?INTERVAL,0);
      false ->
          loop(Epoch,Count+1)
  end.

now_ms() ->
  {Mega,Secs,Micros} = os:timestamp(),
  (Mega*1000000 + Secs)*1000 + (Micros div 1000).

This loops at a rate of ~7 million loops/second on my laptop and fires without
slew or significant drift consistently calling the trigger/3 function every second. The rub is I
burn a little more core/process for the privilege than with mechanism that induce slew such
as with timer or erlang:send_after directly. C'est la vie. Accuracy and timeliness aren't free.

In a gen_server you could use a combination of erlang:send_after and a clock based on
os:timestamp and an epoch as above so that you end up with a clock that is 'accurate enough'
for most use cases, and cheap enough for whatever value you ascribe to such tradeoffs given
the specifics of your use case.

Your mileage may vary.

Cheers,

Darach.

On Mon, Jan 12, 2015 at 11:43 AM, Jesper Louis Andersen <[hidden email]> wrote:
Hi Roberto,

I'm not sure what you would expect here. timer:sleep/1 has an implementation like this:

sleep(T) ->
    receive
    after T -> ok
    end.

which is what other people told you also. In general, such timing constructs have no guarantee about when they will fire, only that they will fire after the time has elapsed. So what you are seeing is somewhat expected behaviour. The more fine-grained and the more timers you have, the less precise things will get. In a way, this is one of the properties which makes Erlang a soft-realtime system and not a hard-realtime one, although the precise definition of soft/hard realtime are subtly different.

I believe there were some effort being made by the OTP team to address lock contention around the timer wheel, so the code might change behaviour by quite a lot in the future. It might even have to get worse for single-process timers in order to become better for multi-process timers.


On Mon Jan 12 2015 at 12:20:15 PM Roberto Ostinelli <[hidden email]> wrote:
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions

_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions




_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Imants Cekusins
in the original code, if we replaced sleep_loop with
timer:apply_interval/4

, would it give the expected results?
_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Roberto Ostinelli
In reply to this post by Jesper Louis Andersen-2
Hi Jesper,
I was expecting a more precise timer, that is all. :)
Thank you for your input.

So: how can someone execute an action every 1ms?

Best,
r.

On Mon, Jan 12, 2015 at 12:43 PM, Jesper Louis Andersen <[hidden email]> wrote:
Hi Roberto,

I'm not sure what you would expect here. timer:sleep/1 has an implementation like this:

sleep(T) ->
    receive
    after T -> ok
    end.

which is what other people told you also. In general, such timing constructs have no guarantee about when they will fire, only that they will fire after the time has elapsed. So what you are seeing is somewhat expected behaviour. The more fine-grained and the more timers you have, the less precise things will get. In a way, this is one of the properties which makes Erlang a soft-realtime system and not a hard-realtime one, although the precise definition of soft/hard realtime are subtly different.

I believe there were some effort being made by the OTP team to address lock contention around the timer wheel, so the code might change behaviour by quite a lot in the future. It might even have to get worse for single-process timers in order to become better for multi-process timers.


On Mon Jan 12 2015 at 12:20:15 PM Roberto Ostinelli <[hidden email]> wrote:
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Roberto Ostinelli
In reply to this post by Imants Cekusins
Hi Imants,
If everything is based on the same timer implementation I'm assuming that it would still yield the same problem.

Best,
r.

On Mon, Jan 12, 2015 at 2:59 PM, Imants Cekusins <[hidden email]> wrote:
in the original code, if we replaced sleep_loop with
timer:apply_interval/4

, would it give the expected results?


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Sergej Jurečko
In reply to this post by Roberto Ostinelli
There is no other solution other than the two provided. An endless loop without sleep, or an external program (or driver).


Sergej

On 12 Jan 2015, at 17:03, Roberto Ostinelli <[hidden email]> wrote:

Hi Jesper,
I was expecting a more precise timer, that is all. :)
Thank you for your input.

So: how can someone execute an action every 1ms?

Best,
r.

On Mon, Jan 12, 2015 at 12:43 PM, Jesper Louis Andersen <[hidden email]> wrote:
Hi Roberto,

I'm not sure what you would expect here. timer:sleep/1 has an implementation like this:

sleep(T) ->
    receive
    after T -> ok
    end.

which is what other people told you also. In general, such timing constructs have no guarantee about when they will fire, only that they will fire after the time has elapsed. So what you are seeing is somewhat expected behaviour. The more fine-grained and the more timers you have, the less precise things will get. In a way, this is one of the properties which makes Erlang a soft-realtime system and not a hard-realtime one, although the precise definition of soft/hard realtime are subtly different.

I believe there were some effort being made by the OTP team to address lock contention around the timer wheel, so the code might change behaviour by quite a lot in the future. It might even have to get worse for single-process timers in order to become better for multi-process timers.


On Mon Jan 12 2015 at 12:20:15 PM Roberto Ostinelli <[hidden email]> wrote:
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Darach Ennis
Hi guys,

+1.

And if you consider a loop consider erlang:yield as Sergej recommended.

If your use case can tolerate a little slew or skew then using a timer or
erlang:send_after instead might be a pleasant sufficiency.

If your use case is deadline critical or hard real-time oriented then perhaps
you might be interested in work being done by Peer Strizinger in the embedded
space. He has spoken about this at EUC and Codemesh:


Peer has ported Erlang to an RTEMS and this may also be of interest:


Cheers,

Darach.

On Mon, Jan 12, 2015 at 4:13 PM, Sergej Jurecko <[hidden email]> wrote:
There is no other solution other than the two provided. An endless loop without sleep, or an external program (or driver).


Sergej


On 12 Jan 2015, at 17:03, Roberto Ostinelli <[hidden email]> wrote:

Hi Jesper,
I was expecting a more precise timer, that is all. :)
Thank you for your input.

So: how can someone execute an action every 1ms?

Best,
r.

On Mon, Jan 12, 2015 at 12:43 PM, Jesper Louis Andersen <[hidden email]> wrote:
Hi Roberto,

I'm not sure what you would expect here. timer:sleep/1 has an implementation like this:

sleep(T) ->
    receive
    after T -> ok
    end.

which is what other people told you also. In general, such timing constructs have no guarantee about when they will fire, only that they will fire after the time has elapsed. So what you are seeing is somewhat expected behaviour. The more fine-grained and the more timers you have, the less precise things will get. In a way, this is one of the properties which makes Erlang a soft-realtime system and not a hard-realtime one, although the precise definition of soft/hard realtime are subtly different.

I believe there were some effort being made by the OTP team to address lock contention around the timer wheel, so the code might change behaviour by quite a lot in the future. It might even have to get worse for single-process timers in order to become better for multi-process timers.


On Mon Jan 12 2015 at 12:20:15 PM Roberto Ostinelli <[hidden email]> wrote:
Indeed. From very basic try-outs:

1>  test:sleep_periodical(6, 1000). 
Finished in 6022381 microseconds.
ok
2>  test:sleep_periodical(12, 500).
Finished in 6042683 microseconds.
ok
3>  test:sleep_periodical(24, 250).
Finished in 6062096 microseconds.
ok
4>  test:sleep_periodical(48, 125).  
Finished in 6133169 microseconds.
ok
5> test:sleep_periodical(96, 62).    
Finished in 6320419 microseconds.
ok
6> test:sleep_periodical(192, 31).
Finished in 6492321 microseconds.
ok
7> test:sleep_periodical(384, 16).
Finished in 7327693 microseconds.
ok

So it somewhat is ok until we get in the 125ms range.



On Mon, Jan 12, 2015 at 12:12 PM, Sergej Jurečko <[hidden email]> wrote:

timer:sleep is not even remotely as accurate for those low numbers. It can not go lower than 20ms or so from what i remember.

I have had this issue once when I needed low interval for timer. I used an external c app which printed to stdout every 5ms. I dont think there is any way in erlang to get a timer that low.

Sergej

On Jan 12, 2015 11:46 AM, "Roberto Ostinelli" <[hidden email]> wrote:
Additionally:

6> test:sleep_periodical(1000, 1). 
Finished in 1999097 microsecond

So:
  • Looping 1,000 times and sleeping 1 ms each time takes 2.00 seconds (instead of 1).
Looks like it's ms related, not total count.

Best,
r.



On Mon, Jan 12, 2015 at 11:40 AM, Roberto Ostinelli <[hidden email]> wrote:
Dear list,
I've probably missed out something since I'm not understanding what is going here.

I'm basically just trying to send messages periodically, though I found out that I wasn't seeing the behavior that I was expecting. It looks like the timer has some erratic behavior.

I've stripped out the code to the bare minimum and it looks like this:

-module(test).
-export([sleep_periodical/2]).
-export([sleep_loop/2]).

sleep_periodical(Num, IntervalMs) ->
{Time, _Value} = timer:tc(?MODULE, sleep_loop, [Num, IntervalMs]),
io:format("Finished in ~p microseconds.~n", [Time]).

sleep_loop(Num, IntervalMs) ->
SleepFun = fun(_) -> timer:sleep(IntervalMs) end,
lists:foreach(SleepFun, lists:seq(1, Num)).


When I run this code, I see the following:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:sleep_periodical(1000, 10).
Finished in 12257397 microseconds.
ok
3> test:sleep_periodical(2000, 10).
Finished in 24518070 microseconds.
ok
4> test:sleep_periodical(10000, 1).  
Finished in 20000280 microseconds.
ok
5> test:sleep_periodical(20000, 1).
Finished in 40000685 microseconds.
ok

So:
  • Looping 1,000 times and sleeping 10 ms each time takes 12.26 seconds (instead of 10).
  • Looping 2,000 times and sleeping 10 ms each time takes 24.52 seconds (instead of 20).
  • Looping 10,000 times and sleeping 1 ms each time takes 20.00 seconds (instead of 10).
  • Looping 20,000 times and sleeping 1 ms each time takes 40.00 seconds (instead of 20).
Up to 10,000 times it takes 12,16% (1/8) more time, from 10,000 times it takes 100% (double).

Can some kind soul explain what I'm doing wrong here and how to achieve the desired results?

I'm on OSX, Erlang 17.4.

Help! ^^_
r.



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Imants Cekusins
If the task is to spawn (not complete) a function at specified
intervals, timer:apply interval works just fine.

Just did a 3-module demo with a gen_server.

Interval: 1 ms. Run for 3, then 10 seconds.

Result nr of loops =:= expected number.

Email me for the code.
_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Imants Cekusins
btw CPU looked ok: was spread across cores and did not max out.
_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Roberto Ostinelli
Thank you Imants.
Indeed, timer:apply_interval/4 actually works perfectly, no timer weirdness. I guess the implementation is not depending on the normal receive..after..end loop.

For others interested, here's a working code example:

-module(test).
-export([call_periodical/2]).
-export([periodical_fun/1]).

call_periodical(Num, IntervalMs) ->
Start = epoch_time_ms(),
{ok, TRef} = timer:apply_interval(IntervalMs, ?MODULE, periodical_fun, [self()]),
wait(Num),
io:format("Finished in ~p microseconds.~n", [epoch_time_ms() - Start]),
timer:cancel(TRef).

wait(0) -> ok;
wait(Num) ->
receive
ok -> wait(Num - 1);
_ -> ok
end.

periodical_fun(Pid) ->
Pid ! ok.

epoch_time_ms() ->
    {Mega, Sec, Micro} = os:timestamp(),
    (Mega * 1000000 + Sec) * 1000 + round(Micro / 1000).


Running it:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:call_periodical(1000, 10).
Finished in 10004 microseconds.
{ok,cancel}
3> test:call_periodical(2000, 10).
Finished in 20002 microseconds.
{ok,cancel}
4> test:call_periodical(10000, 1). 
Finished in 10002 microseconds.
{ok,cancel}
5> test:call_periodical(20000, 1).
Finished in 20000 microseconds.
{ok,cancel}
6> test:call_periodical(1000, 1). 
Finished in 1002 microseconds.
{ok,cancel}

Where everything works as expected.

Thank you everyone!

Best,
r.


On Mon, Jan 12, 2015 at 6:14 PM, Imants Cekusins <[hidden email]> wrote:
btw CPU looked ok: was spread across cores and did not max out.


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions
Reply | Threaded
Open this post in threaded view
|

Re: I'm having a SNAFU moment: timer:sleep/1

Bob Ippolito
The implementation of the timer module does rely on the same sleeping machinery as receive (gen_server timeout) but it doesn't suffer drift by using the technique that Darach suggested. It keeps track of timers in terms of absolute time, and when it wakes up it samples the clock to see which timers need to fire. Nothing special about the timer module, it just uses a better algorithm... although it is a single gen_server process per node, so having a lot of timers can be a bottleneck.


On Tue, Jan 13, 2015 at 8:28 PM, Roberto Ostinelli <[hidden email]> wrote:
Thank you Imants.
Indeed, timer:apply_interval/4 actually works perfectly, no timer weirdness. I guess the implementation is not depending on the normal receive..after..end loop.

For others interested, here's a working code example:

-module(test).
-export([call_periodical/2]).
-export([periodical_fun/1]).

call_periodical(Num, IntervalMs) ->
Start = epoch_time_ms(),
{ok, TRef} = timer:apply_interval(IntervalMs, ?MODULE, periodical_fun, [self()]),
wait(Num),
io:format("Finished in ~p microseconds.~n", [epoch_time_ms() - Start]),
timer:cancel(TRef).

wait(0) -> ok;
wait(Num) ->
receive
ok -> wait(Num - 1);
_ -> ok
end.

periodical_fun(Pid) ->
Pid ! ok.

epoch_time_ms() ->
    {Mega, Sec, Micro} = os:timestamp(),
    (Mega * 1000000 + Sec) * 1000 + round(Micro / 1000).


Running it:

Erlang/OTP 17 [erts-6.3] [source] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Eshell V6.3  (abort with ^G)
1> c(test).
{ok,test}
2> test:call_periodical(1000, 10).
Finished in 10004 microseconds.
{ok,cancel}
3> test:call_periodical(2000, 10).
Finished in 20002 microseconds.
{ok,cancel}
4> test:call_periodical(10000, 1). 
Finished in 10002 microseconds.
{ok,cancel}
5> test:call_periodical(20000, 1).
Finished in 20000 microseconds.
{ok,cancel}
6> test:call_periodical(1000, 1). 
Finished in 1002 microseconds.
{ok,cancel}

Where everything works as expected.

Thank you everyone!

Best,
r.


On Mon, Jan 12, 2015 at 6:14 PM, Imants Cekusins <[hidden email]> wrote:
btw CPU looked ok: was spread across cores and did not max out.


_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions



_______________________________________________
erlang-questions mailing list
[hidden email]
http://erlang.org/mailman/listinfo/erlang-questions