Plumber: Plumber is quite slow in handling large input

[zy79]

I am trying to deploy a function to a web API using plumber. I found that the function is running much slower in plumber than running alone. So I created an empty function like

#* @post /invocations
function(input_body) {

  return(1)
}

I pass a 400KB json file (dumped to a string) to the input and it takes 100 seconds to get the return value. How can I make it faster? e.g. <10 seconds.

[schloerke]

Are this timings done on a local machine? On Mac, Windows, or Linux? (Or have a hosted url?)

Do the timings include the serialization of the JSON? Is it ~100s for just your “hello world” with a 400kb post body?

Can you also post your sessioninfo::session_info()?

Thank you for the report. This magnitude of slowness should not be the norm for a hello world post route.

[zy79]

It is on a local machine running windows 10. The request and time calculation are done through Python:

start_time = time.time()
response = requests.post(
  BASE_URL,
  data = "input_body=" + json.dumps(jsondata)
)
if response.status_code==500:
    print("--- %s seconds ---" % (time.time() - start_time))

and jsondata is something like:

jsondata = [{
   "customer_number": 12345,
   "start_date": "2019-03-10",
   "age": 25,
   ...
 },
...
{
    "customer_number": 23456,
    "start_date": "2019-03-17",
    "age": 37,
    ...
}]

[zy79]

sessioninfo::session_info()

• Session info -------------------------------------------------------------------------------------
  setting value
  version R version 3.5.3 (2019-03-11)
  os Windows >= 8 x64
  system x86_64, mingw32
  ui RStudio
  language (EN)
  collate English_Australia.1252
  ctype English_Australia.1252
  tz Australia/Sydney
  date 2019-03-29

• Packages -----------------------------------------------------------------------------------------
  package * version date lib source
  assertthat 0.2.1 2019-03-21 [1] CRAN (R 3.5.3)
  cli 1.1.0 2019-03-19 [1] CRAN (R 3.5.3)
  crayon 1.3.4 2017-09-16 [1] CRAN (R 3.5.3)
  httpuv 1.5.0 2019-03-15 [1] CRAN (R 3.5.3)
  jsonlite 1.6 2018-12-07 [1] CRAN (R 3.5.3)
  later 0.8.0 2019-02-11 [1] CRAN (R 3.5.3)
  magrittr 1.5 2014-11-22 [1] CRAN (R 3.5.3)
  plumber * 0.4.6 2018-06-05 [1] CRAN (R 3.5.3)
  promises 1.0.1 2018-04-13 [1] CRAN (R 3.5.3)
  R6 2.4.0 2019-02-14 [1] CRAN (R 3.5.3)
  Rcpp 1.0.1 2019-03-17 [1] CRAN (R 3.5.3)
  sessioninfo 1.1.1 2018-11-05 [1] CRAN (R 3.5.3)
  stringi 1.4.3 2019-03-12 [1] CRAN (R 3.5.3)
  withr 2.1.2 2018-03-15 [1] CRAN (R 3.5.3)

[schloerke]

I’ll run some tests tomorrow on my machine (macOS).

If we get different results, we’ll look into hosting options.

[zy79]

I run a simple test:
plumber.R

#* @param input_body 
#* @post /invocations
function(input_body) {
  return("Hello world.")
}

main.R

library(plumber)

serve <- function() {
  pr <- plumb("plumber.R")
  pr$run(port=8080, host="0.0.0.0")
}
# Run at start-up
serve()

and python code to call it

import requests
import json
import time

BASE_URL = 'http://localhost:8080/invocations'
jsondata = [{
   "customer_number": 123456,
   "week1_start_date": "2019-03-10",
   "age": 25,
   "deposit_amount_w1": 123,
   "turnover_w1": 123,
   "revenue_w1": 123,
   "deposit_count_w1": 1,
   "avg_deposit_amt_per_tran_w1": 345,
   "deposit_amount_w2": 456,
   "turnover_w2": 234,
   "revenue_w2": 123,
   "deposit_count_w2": 123,
   "avg_amt_per_tran_w2": 234,
   "deposit_amount_w3": 345,
   "turnover_w3": 456,
   "revenue_w3": 234,
   "deposit_count_w3": 6,
   "avg_amt_per_tran_w3": 123,
   "deposit_amount_w4": 234,
   "turnover_w4": 567,
   "revenue_w4": 123,
   "deposit_count_w4": 3,
   "avg_amt_per_tran_w4": 352,
   "deposit_amount_w5": 123,
   "turnover_w5": 234,
   "revenue_w5": 432,
   "deposit_count_w5": 3,
   "avg_amt_per_tran_w5": 311,
   "deposit_amount_w6": 321,
   "turnover_w6": 234,
   "revenue_w6": 234,
   "deposit_count_w6": 4,
   "avg_amt_per_tran_w6": 123
 }] * 500

payload = "input_body=" + json.dumps(jsondata)
start_time = time.time()
response = requests.post(
  BASE_URL,
  data = payload
)

print("status: ", response.status_code, response.reason)
print("--- %s seconds ---" % (time.time() - start_time))

It takes about 150 seconds to finish on my machine. Is there anyway to make it faster?

[schloerke]

Ok. So I think I have it under 0.10 seconds.

Your plumber router was solid, so no necessary changes where needed for the speed improvement.

I have changed the plumber API to the code below to make sure the post body was received and processed. It will return the number of names in the input_body and the head of the input_body.

tmpfile <- tempfile()
cat('
#* @param input_body 
#* @post /invocations
function(input_body) {
 return(paste0(
    "Hello world.\n", 
    "Length of names: ", length(input_body), "\n",
    "Head of `input_body`: \n",
    paste0(collapse = "\n", 
      capture.output({
        head(input_body)
      })
    )
  ))
}
', file = tmpfile)
plumber::plumb(tmpfile)$run(port = 8080)

payload = "input_body=" + json.dumps(jsondata) is invalid JSON code and could not be parsed by plumber.

I believe we need to restructure how the payload is constructed in python. If the payload is constructed to be a JSON object containing the key inside the dumps command, it works as expected. (SO answer)

import requests
import json
import time

BASE_URL = 'http://localhost:8080/invocations'
jsondata = [{
   "customer_number": 123456,
   "week1_start_date": "2019-03-10",
   "age": 25,
   "deposit_amount_w1": 123,
   "turnover_w1": 123,
   "revenue_w1": 123,
 }] * 10000

payload = json.dumps({"input_body": jsondata})
start_time = time.time()
response = requests.post(
  BASE_URL,
  data = payload
)
print("--- %s seconds ---" % (time.time() - start_time))
print("status: ", response.status_code, response.reason)
print("content:\n" + "".join(response.json()))

>>> --- 0.190752029419 seconds ---
>>> ('status: ', 200, 'OK')
>>> content:
Hello world.
Length of names: 6
Head of `input_body`: 
  revenue_w1 age customer_number turnover_w1 deposit_amount_w1 week1_start_date
1        123  25          123456         123               123       2019-03-10
2        123  25          123456         123               123       2019-03-10
3        123  25          123456         123               123       2019-03-10
4        123  25          123456         123               123       2019-03-10
5        123  25          123456         123               123       2019-03-10
6        123  25          123456         123               123       2019-03-10
>>> 

---

Testing with iris data set within R

library(magrittr)
system.time({
  httr::POST(
    "127.0.0.1:8080/invocations",
    encode = "json",
    body = list(input_body = rbind(iris, iris, iris, iris))
  ) %>%
    httr::content() %>%
    extract2(1) %>%
    cat("\n\n")
})

Hello world.
Length of names: 5
Head of `input_body`: 
  Sepal.Length Sepal.Width Petal.Length Petal.Width Species
1          5.1         3.5          1.4         0.2  setosa
2          4.9         3.0          1.4         0.2  setosa
3          4.7         3.2          1.3         0.2  setosa
4          4.6         3.1          1.5         0.2  setosa
5          5.0         3.6          1.4         0.2  setosa
6          5.4         3.9          1.7         0.4  setosa 

   user  system elapsed 
  0.009   0.001   0.024 

---

Try with a reeeally long string.

chars = "qwertyuiopasdfghjklzxcvbnm" * 100000
payload = json.dumps({"input_body": chars})
start_time = time.time()
response = requests.post(
  BASE_URL,
  data = payload
)
print("--- %s seconds ---" % (time.time() - start_time))
print("status: ", response.status_code, response.reason)
print("content:\n" + "".join(response.json()))

>>> --- 0.96817612648 seconds ---
>>> ('status: ', 200, 'OK')
>>> content:
Hello world.
Length of names: 1
Head of `input_body`: 
[1] "qwertyuiopasdfghjklzxcvbnmqwertyuiopasdfghjklzxcvbnmqwertyuiopasdfghjklzxcvbnmqwertyuiopasdfghjklzxc..............(lots of printing manually truncated)

Since it finishes quickly, I believe the original issue was caused by a malformed JSON post body payload.

[zy79]

You are correct! Thanks for your time and effort.