[erlang-questions] NIF and timing

[Sverker Eriksson]

Fredrik Linder wrote:
> Hello
>
> First, thanks for your help on previous questions :-)
>
> I have a NIF implementation that have a peculiar timing behavior (the NIF 
> code is pretty simple, doing enif_get_tuple, enif_get_atom, 
> enif_get_resource and some O(1) operations).
>
> The median time is 39 us (microseconds)
> 15666/16079 calls take < 100 us
> 16049/16079 calls take < 1000 us
> 16052/16079 calls take < 10000 us
> 16067/16079 calls take < 100000 us
>
> I'm running a list comprehension that gives me the time taken for each call:
>
> [begin A = os:timestamp(), doit(), io:format("~w ", 
> [now:time_diff(os:timestamp(), A)]) end || _ <- lists:seq(1, 16#10000)].
>
> I'm running R16B on a 4 core VM.
>
> Of course some lag due to process switching etc would be expected, but 12 
> of the 16k calls take more than 0.1 seconds to run. That seems way to much 
> to me. (I get the same behavior when not doing the io:format/2 call).
>
> Any clue why?
>
>   
If your NIF builds terms that triggers a garbage collection (fills up 
the heap), that GC will be done before the NIF returns returns to its 
caller.

/Sverker
Erlang/OTP Ericsson