poolCheckout Causing Authentication Errors on DB2 Server

[michaelbonilla]

I am trying to troubleshoot an issue here that I have isolated to occurring when poolCheckout() is run.

I am using pool to setup a connection to a DB2 server. The connection becomes active and valid. However, during the connection setup (the first time a connection is checked out from the pool), our DB2 server is getting a lot of authentication errors as the connection attempts to hit every table on the host, not just the databases and libraries specified in our DSN.

Things I tried that work without causing any authentication errors:

• Using DBI:dbConnect() instead of dbPool().
• Any dbGetQuery() command after a connection is manually checked out of the pool.
• Returning and checking out the connection any time after the first.

Since pool::dbGetQuery(poolObject,SQLQuery) causes the error on the first time it is run, I tested manually using poolCheckout() then pool::dbGetQuery(). The authentication errors only happened on the poolCheckout() step in that process.

I am not familiar enough with the methods part of packages, so I am having trouble digging any further than isolating the issue to poolCheckout(). I would like to know how poolCheckout() sets up the connection the first time, so I can see if there is a way to prevent it from checking authentication on every single table on the DB2 server.

Thanks in advance for any help!

[jcheng5]

Do the failing queries look like this?

pool/R/DBI-pool.R

Lines 40 to 46 in 00fad2c

	"SELECT 1",
	"SELECT 1 FROM DUAL",
	"SELECT 1 FROM INFORMATION_SCHEMA.SYSTEM_USERS",
	"SELECT * FROM INFORMATION_SCHEMA.TABLES",
	"VALUES 1",
	"SELECT 1 FROM SYSIBM.SYSDUMMY1",
	"select count(*) from systables"

If so, you can fix this by giving dbPool an explicit query it can run (that is fast and doesn't return much data) to validate that the connection is good. This can be provided as a validateQuery string parameter to the dbPool function.

[michaelbonilla]

We are not seeing a specific query that failed. It simply logs the IP address of the Workbench or Connect server, the username, and the database/tables attempting to be accessed.

However, I was using "VALUES 1", then switched to "SELECT 1 FROM SYSIBM.SYSDUMMY1". I had the same issue with both. I just changed the validateQuery to select a column from a table that the account for sure has access to, but we still got authentication errors when I ran poolCheckout().

[michaelbonilla]

If I'm understanding this right, poolCheckout calls pool$fetch() to pull a connection from the pool. Running that directly results in the same errors.

Given that the issue only happens when you start the initial connection and not on subsequent queries, I'm thinking that it occurs when private$createObject is called. Is it possible to return the private function createObject from within the pool environment? I am not well versed enough in environments to figure that part out at this point. With a little direction, I am happy to keep digging further.

[jcheng5]

Just to be clear, you're not seeing any errors on the R side? Only in the logs for the database server?

[michaelbonilla]

Correct. R is not returning any errors about authentication issues. The db2 server is showing the authentication attempts on everything, regardless of the user's access rights to those databases/tables.

[hadley]

Random thought: are you using RStudio? Is it the connection pane that's causing the problem by attempting to get information about all accessible tables?

[michaelbonilla]

Yes, we are using Workbench. If the connection pane is attempting to get information about all tables repeatedly, that could be it. I don't see the issue when I run a connection without pool in the R script itself. I suppose when I do that, it does not actually create the connection in the connection pane. However, when I do that using the pool package, maybe it also opens it up in the connection pane automatically?

If that is the case and this is an RStudio/Workbench issue, is there something that would need to be adjusted to prevent the connection pane from trying to get information about tables that my login should not have access to? Would that be on the RStudio side or potentially something that my DBA would need to look at?

[hadley]

Can you see the db2 connection in the connections pane? If you can't, it's probably something else. (And I don't see that pool does anything special to register connections so this might be a red herring).

Otherwise, I can't see any pool code that lists tables or otherwise queries the database, so unless you can somehow give us a reprex that we can run, unfortunately I don't think there's much chance we can figure out the root cause.

[michaelbonilla]

When I run the dbPool command, it does not open the connection in the connection pane. Furthermore, I tried a normal connection in the connection pane using DBI::dbConnect() which did not cause the same authentication failures we were seeing before, so it can't be the connection pane itself.

I'm still not sure the difference between the connection that dbPool then poolCheckout creates versus the one that dbConnect creates, but we only have issues with the former, and not the latter. I'm not sure how to give a reprex in this instance, unfortunately, but do know that the issue has only been seen when using the pool package for connections.

[hadley]

There is no difference in the connection; dbPool() is a fairly thin wrapper around dbConnect().

So unfortunately because this bug so hard for us to reproduce, we don't have the development resources to fix at this time. It's our policy to close such issues to help stay focussed on the biggest problems, but the issue is still indexed by google, so if other people hit it, they'll be able to find it, and we can consider reopen it if it turns out to be a common problem. Thanks for reporting and I'm sorry we couldn't help more 😞.

[michaelbonilla]

@hadley I'm sorry for bringing this issue back up so quickly after last week's discussion, but I have more info at this point. We have been following up internally and with IBM. As part of the troubleshooting, we started an ODBC trace.

When I run
dbPool( odbc::odbc(), DSN = DSN, UID = UID, PWD = PWD, validateQuery = "SELECT 1 FROM SYSIBM.SYSDUMMY1" )

That doesn't actually tell poolCheckout to only use the validateQuery statement. I am seeing in the trace that the function is still looping through these statements:

pool/R/DBI-pool.R

Lines 39 to 49 in cfe18af

	options <- c(
	"SELECT 1",
	"SELECT 1 FROM DUAL",
	"SELECT 1 FROM INFORMATION_SCHEMA.SYSTEM_USERS",
	"SELECT * FROM INFORMATION_SCHEMA.TABLES",
	"VALUES 1",
	"SELECT 1 FROM SYSIBM.SYSDUMMY1",
	"select count(*) from systables",
	"select count(*) from SYS_TABLES",
	"select count(*) from SYS.TABLES"
	)

It times out on "Select * from INFORMATION_SCHEMA.TABLES", which I confirmed is the specific statement causing the authentication failures.

It appears to me that this part of the code is failing, since it is not seeing the validateQuery = "SELECT 1 FROM SYSIBM.SYSDUMMY1" parameter.

pool/R/DBI-pool.R

Lines 28 to 35 in cfe18af

	query <- pool$state$validateQuery
	if (!is.null(query)) {
	error <- try({
	dbGetQuery(object, query)
	return()
	}, silent = TRUE)
	} else {

I'm hoping that this provides enough additional clarity around the issue that we can re-open the case and figure out a fix.

[hadley]

Hmmm yeah, pool::dbPool(RSQLite::SQLite(), validateQuery = "SYNTAX ERROR") should fail, but it doesn't.

[hadley]

@michaelbonilla can you please restart R and then try remotes::install_github("rstudio/pool#153") to see if that fixes your problem? Thanks!

[michaelbonilla]

That appears to have worked. I tested two things:

1. It appears that specifying the validation query with validateQuery now works as intended.
2. When you standardized the validation queries in f3dd7fe, changing "SELECT * FROM INFORMATION_SCHEMA.TABLES" to "SELECT 1 FROM INFORMATION_SCHEMA.TABLES" may have also prevented the authentication errors I was seeing when I don't specify a validateQuery. I will have to follow up with the DBA for that system tomorrow, but it seems from my end that may have also solved the issue since it was not returning all the contents of that table.

At least for those running DB2, it may be beneficial to switch the order of the validation queries to place "SELECT 1 FROM SYSIBM.SYSDUMMY1" before "SELECT 1 FROM INFORMATION_SCHEMA.TABLES" and "VALUES 1". While all three queries work, the first option returns a result extremely quickly, while the other two take noticeably longer. In my case, "SELECT 1 FROM INFORMATION_SCHEMA.TABLES" returns a single column of 1's that is over 30,000 records long. "VALUES 1" also seemed to take a few seconds to run the first time before it got cached. Of course, DB2 may not be popular enough to make that switch, but "SELECT 1 FROM SYSIBM.SYSDUMMY1" should fail almost instantly and add no noticeable overhead when not on DB2. Just a thought there.

[hadley]

Does SELECT 1 FROM INFORMATION_SCHEMA.TABLES WHERE 0=1 work? I'm pretty sure that adding WHERE 0=1 shouldn't affect which databases it works on, and should substantially improve the performance of the query.

[michaelbonilla]

Yes, that works much better.

I talked to the system admin and we were still seeing the authentication errors before, but adding the WHERE 0=1 prevents the full table from loading and therefore solves that problem as well. With that change, I should be able to run dbPool with validateQuery left to its default setting.

Thank you so much for your help solving this issue! I'll look forward to the updated package being available on CRAN.

[hadley]

Thanks for persisting so we could get to the source of the problem! The fix should also generally improve performance for folks using pool 😄