[erlang-questions] Sending message at a specific and accurate time

[Joe Armstrong]

I made a new test - here's the result with kernel poll (I've also changed the
units of time to microseconds - so we can see the sub-millisecond effect)

$ erl +K true
Erlang/OTP 18 [erts-7.2.1] [source] [64-bit] [smp:4:4]
[async-threads:10] [hipe] [kernel-poll:true]
Eshell V7.2.1  (abort with ^G)
1> t:test().
[1006032,1006176,1005987,1006065,1000988,1001926,1005561,
 1001584,1000335,1001442]
2> t:test().
[1001963,1005706,1006087,1006171,1005994,1005992,1005985,
 1001037,1005900,1005268]

To test how fast we can send a message and receive it I changed

     erlang:send_after(1000, self(), ping),
to
     self() ! ping

and reran - now I get delays of the order of 2 microseconds
admittedly the process does not now get scheduled in and out

I can only conclude that send_after(Time, Pid, Msg) is deeply broken on the
mac - if inter-processing scheduling and messaging had 6 millisecond
delays Erlang would be unusable.

The time unit in send_after is milliseconds - and it is true that
sending something
6 milliseconds after I wanted it is indeed "after" - but it would also
be true if the message
was sent a year after I asked for it.

I guess I could do a send_after 10ms before I want and then do a busy wait
but this would be crazy.

Here's the slightly modified program.


-module(t).
-compile(export_all).

test() ->
    process_flag(priority, max),
    test(10, []).

test(0, L) ->
    L;
test(K, L) ->
    T1 = microsecond_time(),
    %% erlang:send_after(1000, self(), ping),
    self() ! ping,
    receive
ping ->
   T2 = microsecond_time(),
   test(K-1, [T2-T1|L])
    end.


microsecond_time() ->
    erlang:system_time() div 1000.


/Joe

On Sun, Feb 21, 2016 at 11:29 PM,  <vicbaz@REDACTED> wrote:
> Hello,
>
> Try +K flag.
>
> $ erl
> Erlang/OTP 18 [erts-7.2.1] [source] [64-bit] [smp:2:2] [async-threads:10]
> [hipe] [kernel-poll:false]
>
> Eshell V7.2.1 (abort with ^G)
> 1> c(t).
> {ok,t}
> 2> t:test().
> [5003,5006,5002,5003,5006,5002,5003,5006,5001,5005]
>
> $ erl +K true
> Erlang/OTP 18 [erts-7.2.1] [source] [64-bit] [smp:2:2] [async-threads:10]
> [hipe] [kernel-poll:true]
>
> Eshell V7.2.1 (abort with ^G)
> 1> c(t).
> {ok,t}
> 2> t:test().
> [5001,5001,5001,5001,5001,5001,5001,5001,5001,5001]
>
> $ uname -a
> Linux frontier 4.3.0-0.bpo.1-amd64 #1 SMP Debian 4.3.3-7~bpo8+1 (2016-01-19)
> x86_64 GNU/Linux
>
> $ cat /proc/cpuinfo | grep 'model name'
> model name : Pentium(R) Dual-Core CPU E5300 @ 2.60GHz
> model name : Pentium(R) Dual-Core CPU E5300 @ 2.60GHz
>
>
> On 22/02/16 00:20, Joe Armstrong wrote:
>>
>> I tried a simpler program:
>>
>> test() -> test(10, []).
>>
>> test(0, L) ->
>>      L;
>> test(K, L) ->
>>      T1 = ms_time(),
>>      erlang:send_after(5000, self(), ping),
>>      receive
>>        ping ->
>>           T2 = ms_time(),
>>            test(K-1, [T2-T1|L])
>>      end.
>>
>> ms_time() ->
>>      erlang:system_time() div 1000000.
>>
>> Running this gives the following times
>>
>> [5001,5001,5006,5006,5002,5003,5006,5002,5002,5006]
>>
>> I'd expected 5000 or 5001
>>
>> This is in an unloaded OS with an unloaded erlang. 6ms seems very long -
>> there are very few processes running and the system load is virtually
>> zero.
>>
>> I tried erl -snp disable and setting process_flag(priority, max) but the
>> results
>> are pretty much the same.
>>
>> Waiting for shorter times like 100 ms makes no difference - still
>> events with a 6 ms delay.
>>
>> I want to use this for scheduling music events (controlling synths) and
>> these
>> delays are far more than I expected.
>>
>> /Joe
>>
>>
>>
>> On Sun, Feb 21, 2016 at 8:32 PM, Jesper Louis Andersen
>> <jesper.louis.andersen@REDACTED> wrote:
>>>
>>>
>>> On Sun, Feb 21, 2016 at 7:53 PM, Joe Armstrong <erlang@REDACTED> wrote:
>>>>
>>>>
>>>> I'm getting about a 4 - 9 ms. inaccuracy in the time the messages is
>>>> sent
>>>> and
>>>> the time I want it to be sent - but I'd like it to be much more accurate
>>>> (sub ms if possible)
>>>
>>>
>>>
>>> I would start by making measurements without the network component. When
>>> you
>>> would send the gen_udp message, you take a timestamp, and analyze the
>>> skew
>>> from the suggested skew. This lets you estimate the overhead of the rest
>>> of
>>> the system in isolation from your own code and the Erlang VM.
>>>
>>> Intuitively, 4 to 9 milliseconds is much higher than what I would expect.
>>> But note that if you sleep for, say, 40ms, you will be awoken on the 41ms
>>> flank at the earliest. This is because you are usually "inside" a
>>> millisecond when you make the call so you start by taking the ceiling of
>>> that milli-second before you.
>>>
>>> How much other work is your Erlang VM doing when you make these
>>> measurements? You are saying between 4 to 9 ms, which is variance
>>> suggesting
>>> the VM has lots of work to do at that moment. And of course such stuff
>>> will
>>> affect the running time. You can switch priority of your processes up to
>>> high, but this comes at the expense of other calculations if you can't
>>> finish your work quickly in the process with high priority.
>>>
>>>
>>> --
>>> J.
>>
>> _______________________________________________
>> erlang-questions mailing list
>> erlang-questions@REDACTED
>> http://erlang.org/mailman/listinfo/erlang-questions
>>
>