full scan in utubettl take()

Comienza en utubettl.lua, inspecciona el método take() y la definición del índice status mostrada en el issue. Ejecuta la reproducción proporcionada con un millón de tareas para observar el escaneo completo y, después, verifica que take() omita eficientemente las utubes ya tomadas y siga seleccionando correctamente las tareas disponibles.

The take() method in utubettl does a linear search for a task from an available utube.
In case there are many tasks in the same utube, calling take() will result in a full scan.

This can be improved by adding the 'utube' field to the status index, like this:

- parts = {i_status, str_type(), i_pri, num_type(), i_id, num_type()}
+ parts = {i_status, str_type(), i_pri, num_type(), i_utube, num_type(), i_id, num_type()}

And then using it in the take() method, quickly skipping taken utubes.

Code to demonstrate the full scan:

local queue = require('queue')
box.once('access:v1', function()
	box.schema.user.grant('guest', 'read,write,execute', 'universe')
	queue.create_tube('q1', 'utubettl', {})
	for i=1,10^6 do
		queue.tube.q1:put('task', {utube='u1'})
	end
end)

local log = require 'log'

log.info('insert done, beginning test')

local fiber = require 'fiber'
local clock = require 'clock'
local start_time = clock.time()
local nworkers = 3
local chan = fiber.channel(nworkers)

for i = 1, nworkers do
	fiber.create(function()
		local myid = i
		while true do
			chan:put(1)
			log.info('worker %d calls take...', myid)
			local task = queue.tube.q1:take()
			log.info('worker %d got task', myid)
			queue.tube.q1:ack(task[1])
			log.info('worker %d ack task', myid)
			fiber.yield() -- give other workers a chance to work
		end
	end)
end

for i = 1, 2*nworkers do
	chan:get()
end

log.info('test took %d seconds', clock.time() - start_time)
os.exit(0)

output (utubettl.lua was modified to log the number of iterations in take()):

2019-09-17 20:42:48.838 [12519] main/101/init.lua I> insert done, beginning test
2019-09-17 20:42:48.838 [12519] main/114/lua I> worker 1 calls take...
2019-09-17 20:42:48.838 [12519] main/115/lua I> worker 2 calls take...
2019-09-17 20:42:54.127 [12519] main/115/lua I> (999999 iterations in utubettl take())
2019-09-17 20:42:54.128 [12519] main/116/lua I> worker 3 calls take...
2019-09-17 20:42:59.855 [12519] main/116/lua I> (999999 iterations in utubettl take())
2019-09-17 20:42:59.855 [12519] main/114/lua txn.c:314 W> too long WAL write: 1 rows at LSN 1000022: 11.017 sec
2019-09-17 20:42:59.855 [12519] main/114/lua I> worker 1 got task
2019-09-17 20:42:59.855 [12519] main/114/lua I> worker 1 ack task
2019-09-17 20:42:59.855 [12519] main/114/lua I> worker 1 calls take...
2019-09-17 20:43:05.866 [12519] main/114/lua I> (999998 iterations in utubettl take())
2019-09-17 20:43:05.867 [12519] main/115/lua txn.c:314 W> too long WAL write: 1 rows at LSN 1000024: 6.012 sec
2019-09-17 20:43:05.867 [12519] main/115/lua I> worker 2 got task
2019-09-17 20:43:05.867 [12519] main/115/lua I> worker 2 ack task
2019-09-17 20:43:05.867 [12519] main/115/lua I> worker 2 calls take...
2019-09-17 20:43:11.836 [12519] main/115/lua I> (999997 iterations in utubettl take())
2019-09-17 20:43:11.836 [12519] main/114/lua txn.c:314 W> too long WAL write: 1 rows at LSN 1000026: 5.969 sec
2019-09-17 20:43:11.836 [12519] main/114/lua I> worker 1 got task
2019-09-17 20:43:11.836 [12519] main/114/lua I> worker 1 ack task
2019-09-17 20:43:11.837 [12519] main/114/lua I> worker 1 calls take...
2019-09-17 20:43:17.140 [12519] main/114/lua I> (999996 iterations in utubettl take())
2019-09-17 20:43:17.140 [12519] main/115/lua txn.c:314 W> too long WAL write: 1 rows at LSN 1000028: 5.304 sec
2019-09-17 20:43:17.140 [12519] main/115/lua I> worker 2 got task
2019-09-17 20:43:17.141 [12519] main/115/lua I> worker 2 ack task
2019-09-17 20:43:17.141 [12519] main/115/lua I> worker 2 calls take...
2019-09-17 20:43:22.495 [12519] main/115/lua I> (999995 iterations in utubettl take())
2019-09-17 20:43:22.495 [12519] main/114/lua txn.c:314 W> too long WAL write: 1 rows at LSN 1000030: 5.354 sec
2019-09-17 20:43:22.495 [12519] main/114/lua I> worker 1 got task
2019-09-17 20:43:22.495 [12519] main/114/lua I> worker 1 ack task
2019-09-17 20:43:22.495 [12519] main/114/lua I> worker 1 calls take...
2019-09-17 20:43:28.938 [12519] main/114/lua I> (999994 iterations in utubettl take())
2019-09-17 20:43:28.938 [12519] main/115/lua txn.c:314 W> too long WAL write: 1 rows at LSN 1000032: 6.443 sec
2019-09-17 20:43:28.938 [12519] main/115/lua I> worker 2 got task
2019-09-17 20:43:28.938 [12519] main/115/lua I> worker 2 ack task
2019-09-17 20:43:28.938 [12519] main/115/lua I> worker 2 calls take...
2019-09-17 20:43:34.251 [12519] main/115/lua I> (999993 iterations in utubettl take())
2019-09-17 20:43:34.251 [12519] main/101/init.lua I> test took 45 seconds

cpu usage is 100% during the whole test and it is hard for producers to put new tasks in the queue, because the lua thread is so busy.