Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How to prevent truncation of error messages in R

I am querying a database in R using RJDBC. The queries are built up from data which is read in from a file. These queries can get very long, and can potentially include non existent columns (resulting in an error).

Below is a simplified example, it takes the file as input and the runs 2 queries generated from the file.

table     column
drinks    cost
drinks    sugar
drinks    volume
food      cost
SELECT column, cost, sugar FROM drinks;
SELECT cost FROM food;

Because these queries can get very long, any errors from the database are often truncated before the useful information. One of my current errors reads:

ERROR [2018-05-16 16:53:07] Error processing table data_baseline_biosamples for DAR-2018-00008 original error message: Error in .verify.JDBC.result(r, "Unable to retrieve JDBC result set for ", : Unable to retrieve JDBC result set for SELECT ed.studyid, {very long list of columns} ,ct.nmr_xl_vldl_pl,ct.nmr_xl_

Because the database error includes the entire query before the key information, the truncation removes valuable information for solving the problem.

In this case the error message probably ends with something like this:

(line 1, Table 'data_biosamples' owned by 'littlefeltfangs' does not contain column 'sample_source'.)

How to I record the full error message sent by the database or otherwise extract the final part of that message?

I am capturing the error in a tryCatch and passing the error into a log file using futile.logger. The total error length when truncated is 8219 characters, with 8190 of those appearing to be from the database.

like image 328
littlefeltfangs Avatar asked May 17 '18 09:05

littlefeltfangs


1 Answers

It's not RJDBC that's cutting off the error message.

See ?stop:

Errors will be truncated to getOption("warning.length") characters, default 1000.

So you can set the option:

stop(paste(rep(letters, 50L), collapse = ''))
options(warning.length = 2000L)
stop(paste(rep(letters, 50L), collapse = ''))

You'll notice the truncation in the first message, but no the second.

For my own helper functions catching errors from RDJBC, I use something like:

result = tryCatch(<some DB operation>, error = identity)

Then do regular expressions on result$message to test for various common errors & produce a friendlier error message.


Not mentioned in ?stop is that warning.length can only be in a fairly narrow range of values. To explore this I ran the following code:

old = options('warning.length')
can = vapply(1:16000L, function(ii) {
  !is.error(tryCatch(options(warning.length=ii), error=identity))
}, logical(1L))
options(old)

png('~/Desktop/warning_valid.png')
plot(can, las = 1L, ylab = 'Valid option value?',
     main = 'Valid option values for `warning.length`',
     type = 's', lwd = 3L, log = 'x')
first = which.max(can)
switches = c(first, first + which.min(can[first:length(can)] - 1L))
abline(v = switches, lty = 2L, col = 'red', lwd = 2L)
axis(side = 1L, at = switches, las = 2L, cex = .5)
dev.off()

A plot showing valid values of the 'warning.length' option. the plot starts at 0 (invalid) and rises to 1 (valid) at Index=100, where it stays before dropping back to 0 at around 8172.

I'm not sure about the minimum value of 100, but 8172 is 8192 - 20 (20 is enough characters to include [... truncated]). Here is the place in the R source where these values are hard-coded in, and here is the place where the buffer size of 8192 is defined.

FWIW, in my own error-parsing helper function (built for querying PrestoDB), I have this line:

core_msg = gsub('.*(Query failed.*)\\)\\s*$', '\\1', result$message)

This is catered to the error messages that come out of PrestoDB, so you'll have to customize it yourself, but the idea is to clip out that part of your error message which is just regurgitating the query itself.

Alternatively, of course you can split result$message into two bits which are less than 8172 characters and print them out separately.

like image 88
MichaelChirico Avatar answered Oct 02 '22 09:10

MichaelChirico