Slow queuing over remote Redis connections

[richfitz]

To simulate, try with toxiproxy

1. Install toxiproxy from here and run the server
2. Install toxiproxyr with devtools::install_github("richfitz/toxiproxyr")
3. In rrqueue/tests/testthat run:

## Attempts at running rrqueue via toxiproxy:
library(toxiproxyr)
devtools::load_all("../../")
source("helper-rrqueue.R")

con <- toxiproxy()
try(con$delete("rrqueue_redis"), silent=TRUE)
tox <- con$create("rrqueue_redis", 6379)

## Cleans up any left over queues
test_cleanup()

obj <- queue("tmpjobs", sources="myfuns.R",
             redis_port=as.integer(tox$listen_port))

## Simulation of Australia:
dat <- toxic_set(upstream=list(latency(100), bandwidth(10)),
                 downstream=list(latency(100), bandwidth(50)))

## check that the toxic connection is slowish:
tox$with(dat, obj$con$PING())

## Here's the benchmark:
system.time(obj$enqueue(sin(1)))
system.time(tox$with(dat, obj$enqueue(sin(1))))

[richfitz]

See #7 for why this matters.

[richfitz]

OK, so the benchmark time with the above proxy is 2.2s; I can get that down to 0.78s using Lua scripting. The set of commands doing that are:

1442418968.324859 [0 127.0.0.1:58041] "INCR" "tmpjobs:tasks:counter"
1442418968.528795 [0 127.0.0.1:58041] "TIME"
1442418968.786687 [0 127.0.0.1:58041] "EVALSHA" "1c6c385f068a3488d3035155985563f63faa105d" "6" "tmpjobs:tasks:id" "tmpjobs:tasks:expr" "tmpjobs:tasks:envir" "tmpjobs:tasks:complete" "tmpjobs:tasks:status" "tmpjobs:tasks:time:sub" "2" "A\n2\n197121\n131840\n531\n2\n6\n1\n262153\n3\nsin\n2\n14\n1\n1\n254\n254\n1026\n1\n262153\n5\nnames\n16\n2\n262153\n4\nexpr\n262153\n12\nobject_names\n254\n" "cc7c061a3c3270d53eacf56b9a083db4" "tmpjobs:tasks:2:complete" "PENDING" "1442418968.528810"
1442418968.787055 [0 lua] "HSET" "tmpjobs:tasks:expr" "2" "A\n2\n197121\n131840\n531\n2\n6\n1\n262153\n3\nsin\n2\n14\n1\n1\n254\n254\n1026\n1\n262153\n5\nnames\n16\n2\n262153\n4\nexpr\n262153\n12\nobject_names\n254\n"
1442418968.787175 [0 lua] "HSET" "tmpjobs:tasks:envir" "2" "cc7c061a3c3270d53eacf56b9a083db4"
1442418968.787220 [0 lua] "HSET" "tmpjobs:tasks:complete" "2" "tmpjobs:tasks:2:complete"
1442418968.787253 [0 lua] "HSET" "tmpjobs:tasks:status" "2" "PENDING"
1442418968.787275 [0 lua] "HSET" "tmpjobs:tasks:time:sub" "2" "1442418968.528810"
1442418968.787314 [0 lua] "RPUSH" "tmpjobs:tasks:id" "2"

which is pretty much the minimum here; INCR and TIME are "random" commands so we can't write after using them.

This is 3 round trips at the moment (there are more savings to be made in the object caching but that's not used here).

It might actually be possible to increment and take time at the same time, returning a list. That would give two round trips.

[richfitz]

Now 0.57s, so a 4x improvement.

1442419683.326714 [0 127.0.0.1:58092] "EVALSHA" "c08d17eabb55a84cf53d22db61bd0cd142d3bf35" "1" "tmpjobs:tasks:counter"
1442419683.326790 [0 lua] "INCR" "KEYS[1]"
1442419683.326807 [0 lua] "TIME"
1442419683.579949 [0 127.0.0.1:58092] "EVALSHA" "1c6c385f068a3488d3035155985563f63faa105d" "6" "tmpjobs:tasks:id" "tmpjobs:tasks:expr" "tmpjobs:tasks:envir" "tmpjobs:tasks:complete" "tmpjobs:tasks:status" "tmpjobs:tasks:time:sub" "5" "A\n2\n197121\n131840\n531\n2\n6\n1\n262153\n3\nsin\n2\n14\n1\n1\n254\n254\n1026\n1\n262153\n5\nnames\n16\n2\n262153\n4\nexpr\n262153\n12\nobject_names\n254\n" "cc7c061a3c3270d53eacf56b9a083db4" "tmpjobs:tasks:5:complete" "PENDING" "1442419683.326812"
1442419683.580041 [0 lua] "HSET" "tmpjobs:tasks:expr" "5" "A\n2\n197121\n131840\n531\n2\n6\n1\n262153\n3\nsin\n2\n14\n1\n1\n254\n254\n1026\n1\n262153\n5\nnames\n16\n2\n262153\n4\nexpr\n262153\n12\nobject_names\n254\n"
1442419683.580067 [0 lua] "HSET" "tmpjobs:tasks:envir" "5" "cc7c061a3c3270d53eacf56b9a083db4"
1442419683.580080 [0 lua] "HSET" "tmpjobs:tasks:complete" "5" "tmpjobs:tasks:5:complete"
1442419683.580091 [0 lua] "HSET" "tmpjobs:tasks:status" "5" "PENDING"
1442419683.580098 [0 lua] "HSET" "tmpjobs:tasks:time:sub" "5" "1442419683.326812"
1442419683.580109 [0 lua] "RPUSH" "tmpjobs:tasks:id" "5"