Skip to content

Instantly share code, notes, and snippets.

@ochaton
Created July 6, 2021 16:45
Show Gist options
  • Save ochaton/6bc9a7030df7b4e7c63703599a5b2f96 to your computer and use it in GitHub Desktop.
Save ochaton/6bc9a7030df7b4e7c63703599a5b2f96 to your computer and use it in GitHub Desktop.
Monitoring fiber of latency of single ev_once
> tarantool -l fiber -l clock -e 'fiber.create(function() while true do while clock.time() < fiber.time()+0.1 do end fiber.sleep(0.01) end end)' test.lua
entering the event loop
e:100.011µs p:0.017µs t:99.998µs
e:100.042µs p:0.010µs t:100.035µs
e:100.013µs p:0.015µs t:100.004µs
e:100.005µs p:0.006µs t:99.994µs
e:100.007µs p:0.004µs t:99.996µs
e:100.010µs p:0.009µs t:99.993µs
e:100.012µs p:0.016µs t:100.000µs
e:100.009µs p:0.050µs t:99.999µs
e:100.011µs p:0.016µs t:100.002µs
e:100.009µs p:0.009µs t:99.999µs
e:100.009µs p:0.014µs t:99.992µs
e:100.009µs p:0.010µs t:99.962µs
# if fiber is sleeping more than 0 seconds (uses fiber.sleep(0.01) instead of fiber.yield())
# then we see that it utilizes previous loop
> tarantool -l fiber -l clock -e 'fiber.create(function() while true do while clock.time() < fiber.time()+0.1 do end fiber.sleep(0) end end)' test.lua
entering the event loop
e:100.032µs p:100.016µs t:0.004µs
e:100.020µs p:100.028µs t:0.006µs
e:100.015µs p:100.044µs t:0.005µs
e:100.007µs p:100.011µs t:0.003µs
e:100.021µs p:100.024µs t:0.008µs
e:100.027µs p:100.013µs t:0.013µs
e:100.056µs p:100.011µs t:0.009µs
# if fiber uses fiber.yield()/fiber.sleep(0) we see that it takes precedence over our monitoring fiber
local clock = require 'clock'
local fiber = require 'fiber'
local ev_now_64 = function() return 1e3*fiber.time64() end
-- Returns microseconds
local function ev_run_time()
fiber.sleep(0) -- setups watcher to the start of next ev_once
local e0, w0 = ev_now_64(), clock.time64()
fiber.sleep(0) -- rotates single loop
local e1, w1 = ev_now_64(), clock.time64()
-- e0 <= w0 <= e1 <= w1 (if ntp is ok)
local ev_prolog = w1-e1 -- lag from the start of the loop till current fiber (must be as little as possible)
local ev_tail = e1-w0 -- the epilog of previous ev_once
local ev_loop_time = e1-e0
return tonumber(ev_loop_time/1e3), tonumber(ev_prolog/1e3), tonumber(ev_tail/1e3)
end
return ev_run_time
local ev_run_time = require 'evloop'
local fiber = require 'fiber'
local log = require 'log'
local function run_loop(mesure_interval, on_tick_cb)
mesure_interval = tonumber(mesure_interval) or 0.01 -- every 10ms
if not on_tick_cb then
on_tick_cb = function() end
end
local gen
if package.reload then gen = package.reload.count end
local is_run = function()
if gen and gen ~= package.reload.count then
return false
end
fiber.testcancel()
return true
end
while is_run() do
local ev_once_time, ev_prolog_time, ev_epilog_time = ev_run_time() -- microseconds
-- export anywhere you'd like to
local ok, err = pcall(on_tick_cb, ev_once_time, ev_prolog_time, ev_epilog_time)
if not ok then
log.error("[ev_loop_time] on_tick_cb failed: %s", err)
end
fiber.sleep(mesure_interval)
end
end
f = fiber.create(run_loop, nil, function(e, p, t)
log.info("e:%.3fµs p:%.3fµs t:%.3fµs", e/1000, p/1000, t/1000)
end)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment