Logging variables in Plumber

Viewed 101

I have followed the Rstudio example here for logging for logging requests in Plumber (R API package) and would like to add other variables to the log. However, the registerHooks statement does not recognise global variables (<<-).

# Enable CORS Filtering
#' @filter auth_filter
auth_filter <- function(req, res) {
req_user <<- req$HEADERS['authorization'] %>% as.character()
req_tenant <<- req$HTTP_TENANT
}

pr$registerHooks(
list(
preroute = function() {
# Start timer for log info
tictoc::tic()
},
postroute = function(req, res) {
end <- tictoc::toc(quiet = TRUE)
# Log details about the request and the response
log_info('{convert_empty(req_user)} {convert_empty(req_tenant)} {convert_empty(req$REMOTE_ADDR)} "{convert_empty(req$HTTP_USER_AGENT)}" {convert_empty(req$HTTP_HOST)} {convert_empty(req$REQUEST_METHOD)} {convert_empty(req$PATH_INFO)} {convert_empty(res$status)} {round(end$toc - end$tic, digits = getOption("digits", 5))}')
}))

In the above example, req_user and req_tenant change for every request. The above example gives an error message, stating that req_user and req_tenant do not exist. I have also tried preserialize as an alternative to postroute. How can these variables be logged? The don't need to be global, this was just an additional attempt to solve the problem.

2 Answers

I believe the error is produced because of the convert_empty function not being able to handle null's or na's.

I adjusted this function to handle null's or na's in case they do occur:

convert_empty <- function(string) {
  if (is.null(string) || is.na(string) || string == "") {
    "-"
  } else {
    string
  }
}

Using the sample plumber.R code that's produced in RStudio, this should work:

#Plumber.R file

library(plumber)
library(logger)

# Specify how logs are written
log_dir <- "logs"
if (!fs::dir_exists(log_dir)) fs::dir_create(log_dir)
log_appender(appender_tee(tempfile("plumber_", log_dir, ".log")))

#* Return the sum of two numbers
#* @param a The first number to add
#* @param b The second number to add
#* @post /sum
function(a, b) {
    as.numeric(a) + as.numeric(b)
}

Then we register the hooks as follows:

library(plumber)

pr <- plumb("plumber.R")

convert_empty <- function(string) {
  if (is.null(string) || is.na(string) || string == "") {
    "-"
  } else {
    string
  }
}

pr$registerHooks(
  list(
    preroute = function() {
      # Start timer for log info
      tictoc::tic()
    },
    postroute = function(req, res) {
      end <- tictoc::toc(quiet = TRUE)
      # Log details about the request and the response
      log_info('{convert_empty(as.character(req$HEADERS["authorization"]))} {convert_empty(req$HTTP_TENANT)} {convert_empty(req$REMOTE_ADDR)} {convert_empty(req$HTTP_USER_AGENT)} {convert_empty(req$HTTP_HOST)} {convert_empty(req$REQUEST_METHOD)} {convert_empty(req$PATH_INFO)} {convert_empty(res$status)} {round(end$toc - end$tic, digits = getOption("digits", 5))}')
    }
  )
)

pr

In the console, you can do:

pr$run()

so serve your API locally.

From there, go to the terminal in RStudio and do a curl. Assuming is your port, an example would be:

curl -H "Authorization: Bearer my_token" -H "TENANT: 123" -X POST "http://127.0.0.1:9520/sum?a=1&b=2"

You should see a return of 3 in the terminal, and if you look at the R console, you will see the Authorization and tenant headers logged

So it turns out my specific problem was actually the format of tenant name, e.g. req$HTTP_TENANT = "Company A/S". When this is passed by log_info, it gets split into two columns, which is more than the logging table expects. Maybe the forward slash is escaping something.

For some reason, you have to put it in quotes in log_info, so log_info('"{convert_empty(req$HTTP_TENANT)}"') instead of log_info('{convert_empty(req$HTTP_TENANT)}') as with req$HTTP_USER_AGENT in the original post.

Related