Skip to content

Test ConnectUsingTrustAuth fails for rake unittest:backend_db

The issue was found by @slawek during 1.11 sanity checks.

The ConnectUsingTrustAuth test fails if the rake unittest:backend_db command is used to run the tests.

It is caused because the connection is improperly recognized as local. The database host in our configuration is set to 127.0.0.1, but in practice, the operation system redirects the connection to the Docker container.

It caused the Stork treats the database as local, but the container sees the connection as remote (the Docker IP gateway address) and requires the password.

IMO interesting case, but it shouldn't affect end users. Postgres in Docker is usually (and by default) configured to use a non-trust authentication method. The trust method is explicitly discouraged by the Docker image documentation.

Conditions to occur the problem:

  • Not providing a password
  • Postgres in Docker container configured to use the trust authentication method
  • Stork configured to connect the database using the localhost address
  • Stork must be running on the same machine where the containers are hosted

Possible solutions:

  • Provide a password
  • Re-configure Docker to use a different authentication method
  • Use a non-localhost address to connect to Postgres (e.g.: Docker gateway or Docker hostname)

Logs

PASS | isc.org/stork/server/configreview coverage: 94.7% of statements
     | time="2023-06-06T11:14:06+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:06+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:06+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:06+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:06+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:06+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:06+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:06+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:06+02:00" level=info msg="Found compatible pg_hba.conf rule: &{tableName:{} LineNumber:86 Type:host Database:[all] UserName:[all] Address:127.0.0.1 Netmask:255.255.255.255 AuthMethod:trust Options:[] Error:}" authMethod=trust type=host userName=stork_trust
     | time="2023-06-06T11:14:06+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:06+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 1/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:08+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 2/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:10+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 3/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:12+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 4/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:14+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 5/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:16+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 6/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:18+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 7/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:20+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 8/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:22+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 9/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
     | time="2023-06-06T11:14:24+02:00" level=warning msg="Problem connecting to db, trying again in 2 seconds, 10/10" error="unable to connect to the database using provided settings: FATAL #28P01 password authentication failed for user \"stork_trust\""
FAIL | ConnectUsingTrustAuth (20.77s)
     |     auth_test.go:213: 
     |         	Error Trace:	/home/deep/Downloads/artifacts (36) (1)/stork-1.11.0/backend/server/database/auth_test.go:213
     |         	Error:      	Received unexpected error:
     |         	            	FATAL #28P01 password authentication failed for user "stork_trust"
     |         	            	unable to connect to the database using provided settings
     |         	            	isc.org/stork/server/database.NewPgDBConn
     |         	            		/home/deep/Downloads/artifacts (36) (1)/stork-1.11.0/backend/server/database/connection.go:99
     |         	            	isc.org/stork/server/database_test.checkDatabaseConnections
     |         	            		/home/deep/Downloads/artifacts (36) (1)/stork-1.11.0/backend/server/database/auth_test.go:129
     |         	            	isc.org/stork/server/database_test.TestConnectUsingTrustAuth
     |         	            		/home/deep/Downloads/artifacts (36) (1)/stork-1.11.0/backend/server/database/auth_test.go:210
     |         	            	testing.tRunner
     |         	            		/home/deep/Downloads/artifacts (36) (1)/stork-1.11.0/tools/golang/go/src/testing/testing.go:1446
     |         	            	runtime.goexit
     |         	            		/home/deep/Downloads/artifacts (36) (1)/stork-1.11.0/tools/golang/go/src/runtime/asm_amd64.s:1594
     |         	            	cannot open database connection using go-pg
     |         	Test:       	TestConnectUsingTrustAuth
     | time="2023-06-06T11:14:26+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:26+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:27+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:28+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:29+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:29+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:29+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:29+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:29+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:29+02:00" level=info msg="Connected to database localhost:5678"
     | WARN: pg: 2023/06/06 11:14:30 SystemUserToGroup.UserID has unknown tag option: "not_null"
     | WARN: pg: 2023/06/06 11:14:30 SystemUserToGroup.GroupID has unknown tag option: "not_null"
     | DEPRECATED: pg: 2023/06/06 11:14:30 add pg:"rel:has-one" to SystemUserToGroup.User field tag
     | DEPRECATED: pg: 2023/06/06 11:14:30 add pg:"rel:has-one" to SystemUserToGroup.Group field tag
     | time="2023-06-06T11:14:30+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:30+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:31+02:00" level=info msg="Successfully migrated database schema" new-version=53 old-version=0
     | time="2023-06-06T11:14:31+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:31+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:31+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:31+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:31+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:31+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:31+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:31+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:32+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:32+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:32+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:32+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:33+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:33+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:33+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:33+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:35+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:35+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:35+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:35+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:37+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:37+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:37+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:37+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:38+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:38+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:38+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:38+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:38+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:38+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:39+02:00" level=info msg="Database 'storktest983817017438083418' already exists"
     | time="2023-06-06T11:14:39+02:00" level=info msg="User 'storktest983817017438083418' already exists"
     | time="2023-06-06T11:14:39+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:39+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:39+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:39+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:39+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:39+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:40+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:40+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:40+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:40+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:40+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:40+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:40+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:40+02:00" level=info msg="Connected to database localhost:5678"
     | time="2023-06-06T11:14:41+02:00" level=info msg="Checking connection to database"
     | time="2023-06-06T11:14:41+02:00" level=info msg="Connected to database localhost:5678"
COVER| 80.6% [########__]
FAIL | 	isc.org/stork/server/database	35.979s