steampipe
steampipe copied to clipboard
Failed to start a fresh install of Steampipe
Describe the bug
First time installing steampipe on my laptop. I tried to run the query command and it fails.
Steampipe version (steampipe -v
)
v0.16.4
To reproduce
- Fresh Install
- Run
steampipe query
Expected behavior 🤔 Startup the Pg server so I can use the cli.
Additional context
Fresh First Run (no steampipe path)
STEAMPIPE_LOG=trace steampipe query
2022-10-12 22:23:09.977 UTC [TRACE] steampipe: Sending HTTP Request &{POST https://hub.steampipe.io/api/cli/version/latest HTTP/1.1 1 1 map[Content-Type:[application/json] User-Agent:[Turbot Steampipe/0.16.4 (+https://steampipe.io)]] {{"arch":"amd64","os_platform":"darwin","signature":"e72c4c15-5f6e-4eeb-90f2-4e22f64eafec","version":"0.16.4"}} 0x15014a0 109 [] false hub.steampipe.io map[] map[] <nil> map[] <nil> <nil> <nil> 0xc000192000}
2022-10-12 22:23:10.506 UTC [TRACE] steampipe: No memory limit set
2022-10-12 22:23:10.506 UTC [TRACE] steampipe: modfile exists in workspace folder - creating pseudo-resources and loading files recursively
2022-10-12 22:23:10.544 UTC [TRACE] steampipe: parse complete after 1 decode passes
2022-10-12 22:23:10.570 UTC [TRACE] steampipe: parse complete after 1 decode passes
2022-10-12 22:23:10.570 UTC [TRACE] steampipe: telemetry.Init service 'steampipe', tracingEnabled: false, metricsEnabled: false
2022-10-12 22:23:10.570 UTC [TRACE] steampipe: metrics and tracing disabled' - returning
Welcome to Steampipe v0.16.4
2022-10-12 22:23:10.570 UTC [TRACE] steampipe: GetRunStatus - loadRunningInstanceInfo returned nil
For more information, type .help
2022-10-12 22:23:10.570 UTC [TRACE] steampipe: calling removeRunningInstanceInfo
⠋ Prepare database install location...2022-10-12 22:23:10.570 UTC [TRACE] steampipe: ociDownloader.Download: downloading us-docker.pkg.dev/steampipe/steampipe/db:14.2.0
2022-10-12 22:23:10.570 UTC [TRACE] steampipe: ociDownloader.Pull: pulling us-docker.pkg.dev/steampipe/steampipe/db:14.2.0
⠏ Download & install embedded PostgreSQL database...2022-10-12 22:23:13.566 UTC [TRACE] steampipe: looking for application/vnd.turbot.steampipe.db.darwin-amd64.layer.v1+tar
2022-10-12 22:23:13.566 UTC [TRACE] steampipe: looking for application/vnd.turbot.steampipe.db.doc.layer.v1+text
2022-10-12 22:23:13.566 UTC [TRACE] steampipe: looking for application/vnd.turbot.steampipe.db.license.layer.v1+text
⠋ Download & install embedded PostgreSQL database...2022-10-12 22:23:13.655 UTC [TRACE] steampipe: GetRunStatus - loadRunningInstanceInfo returned nil
2022-10-12 22:23:13.658 UTC [TRACE] steampipe: ociDownloader.Download: downloading us-docker.pkg.dev/steampipe/steampipe/fdw:1.4.2
2022-10-12 22:23:13.658 UTC [TRACE] steampipe: ociDownloader.Pull: pulling us-docker.pkg.dev/steampipe/steampipe/fdw:1.4.2
⠋ Download & install steampipe-postgres-fdw...2022-10-12 22:23:14.626 UTC [TRACE] steampipe: looking for application/vnd.turbot.steampipe.fdw.darwin-amd64.layer.v1+gzip
2022-10-12 22:23:14.626 UTC [TRACE] steampipe: looking for application/vnd.turbot.steampipe.fdw.control.layer.v1+text
2022-10-12 22:23:14.626 UTC [TRACE] steampipe: looking for application/vnd.turbot.steampipe.fdw.sql.layer.v1+text
2022-10-12 22:23:14.626 UTC [TRACE] steampipe: looking for application/vnd.turbot.steampipe.fdw.doc.layer.v1+text
2022-10-12 22:23:14.626 UTC [TRACE] steampipe: looking for application/vnd.turbot.steampipe.fdw.license.layer.v1+text
2022-10-12 22:23:14.826 UTC [TRACE] steampipe: initdb start: /Users/nhalstead/.steampipe/db/14.2.0/postgres/bin/initdb --auth=trust --username=root --pgdata=/Users/nhalstead/.steampipe/db/14.2.0/data --encoding=UTF-8 --wal-segsize=1 --debug
⠋ Initializing database...2022-10-12 22:23:18.638 UTC [TRACE] steampipe: Connection string: host=localhost port=63227 user=root dbname=postgres sslmode=disable
2022-10-12 22:23:18.655 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.655 EDT [91338] LOG: starting PostgreSQL 14.2 on x86_64-apple-darwin20.6.0, compiled by Apple clang version 12.0.0 (clang-1200.0.32.29), 64-bit
2022-10-12 22:23:18.656 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.656 EDT [91338] LOG: listening on IPv6 address "::1", port 63227
2022-10-12 22:23:18.656 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.656 EDT [91338] LOG: listening on IPv4 address "127.0.0.1", port 63227
2022-10-12 22:23:18.657 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.657 EDT [91338] LOG: listening on Unix socket "/tmp/.s.PGSQL.63227"
2022-10-12 22:23:18.660 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.660 EDT [91338] LOG: hostssl record cannot match because SSL is disabled
2022-10-12 22:23:18.660 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.660 EDT [91338] HINT: Set ssl = on in postgresql.conf.
2022-10-12 22:23:18.660 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.660 EDT [91338] CONTEXT: line 2 of configuration file "/Users/nhalstead/.steampipe/db/14.2.0/data/pg_hba.conf"
2022-10-12 22:23:18.661 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.661 EDT [91340] LOG: database system was shut down at 2022-10-12 18:23:18 EDT
2022-10-12 22:23:18.664 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:18.664 EDT [91338] LOG: database system is ready to accept connections
⠙ Connection to database...2022-10-12 22:23:18.724 UTC [TRACE] steampipe: valid database name: steampipe
2022-10-12 22:23:18.724 UTC [TRACE] steampipe: installing database with name steampipe
⠹ Configuring database...2022-10-12 22:23:18.860 UTC [TRACE] steampipe: Install Foreign Server: drop extension if exists "steampipe_postgres_fdw" cascade
2022-10-12 22:23:18.860 UTC [TRACE] steampipe: Install Foreign Server: create extension if not exists "steampipe_postgres_fdw"
⠴ Configuring Steampipe...2022-10-12 22:23:19.206 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.206 UTC [INFO] hub: .
2022-10-12 22:23:19.206 UTC [TRACE] steampipe: SERVICE: ******************************************************
2022-10-12 22:23:19.206 UTC [TRACE] steampipe: SERVICE: steampipe postgres fdw init
2022-10-12 22:23:19.206 UTC [TRACE] steampipe: SERVICE: ******************************************************
2022-10-12 22:23:19.206 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.206 UTC [INFO] hub: Version: v1.4.2
2022-10-12 22:23:19.206 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.206 UTC [INFO] hub: Log level: trace
2022-10-12 22:23:19.207 UTC [TRACE] steampipe: Install Foreign Server: create server "steampipe" foreign data wrapper "steampipe_postgres_fdw"
2022-10-12 22:23:19.208 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.208 UTC [INFO] hub: .
2022-10-12 22:23:19.208 UTC [TRACE] steampipe: SERVICE: ******************************************************
2022-10-12 22:23:19.208 UTC [TRACE] steampipe: SERVICE: steampipe postgres fdw shutdown
2022-10-12 22:23:19.208 UTC [TRACE] steampipe: SERVICE: ******************************************************
2022-10-12 22:23:19.208 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:19.208 EDT [91338] LOG: received smart shutdown request
2022-10-12 22:23:19.208 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.208 UTC [TRACE] hub: init telemetry
2022-10-12 22:23:19.209 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.208 UTC [TRACE] hub: telemetry.Init service 'steampipe-postgres-fdw', tracingEnabled: false, metricsEnabled: false
2022-10-12 22:23:19.209 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.209 UTC [TRACE] hub: metrics and tracing disabled' - returning
2022-10-12 22:23:19.209 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.209 UTC [TRACE] hub: hub: close
2022-10-12 22:23:19.209 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.209 UTC [TRACE] hub: shutdown telemetry
2022-10-12 22:23:19.212 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:19.212 EDT [91338] LOG: background worker "logical replication launcher" (PID 91346) exited with exit code 1
2022-10-12 22:23:19.212 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:19.212 EDT [91341] LOG: shutting down
⠦ Completing configuration2022-10-12 22:23:19.221 UTC [TRACE] steampipe: SERVICE: 2022-10-12 18:23:19.221 EDT [91338] LOG: database system is shut down
2022-10-12 22:23:19.313 UTC [TRACE] steampipe: GetRunStatus - loadRunningInstanceInfo returned nil
2022-10-12 22:23:19.313 UTC [TRACE] steampipe: StartDB invoker query
2022-10-12 22:23:19.313 UTC [TRACE] steampipe: StartDB started plugin manager
2022-10-12 22:23:19.313 UTC [TRACE] steampipe: loadRootPrivateKey - failed to load key from /Users/nhalstead/.steampipe/db/14.2.0/data/root.key: open /Users/nhalstead/.steampipe/db/14.2.0/data/root.key: no such file or directory
2022-10-12 22:23:19.611 UTC [TRACE] steampipe: Connection string: host=localhost port=9193 user=root dbname=postgres sslmode=disable
2022-10-12 22:23:19.656 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.656 UTC [91489] LOG: redirecting log output to logging collector process
2022-10-12 22:23:19.656 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:19.656 UTC [91489] HINT: Future log output will appear in directory "/Users/nhalstead/.steampipe/logs".
2022-10-12 22:23:19.776 UTC [TRACE] steampipe: status: {"pid":91489,"port":9193,"listen":["localhost","127.0.0.1"],"listen_type":"local","invoker":"query","password":"XXXX-XXXX-XXXX","user":"steampipe","database":"steampipe","struct_version":20220411}
2022-10-12 22:23:19.776 UTC [TRACE] steampipe: Connection string: host=localhost port=9193 user=root dbname=postgres sslmode=require
Error: failed to connect to `host=localhost user=root database=postgres`: failed to write startup message (x509: certificate signed by unknown authority)
Followup steampipe query
STEAMPIPE_LOG=trace steampipe query
2022-10-12 22:23:48.025 UTC [TRACE] steampipe: No memory limit set
2022-10-12 22:23:48.025 UTC [TRACE] steampipe: modfile exists in workspace folder - creating pseudo-resources and loading files recursively
2022-10-12 22:23:48.054 UTC [TRACE] steampipe: parse complete after 1 decode passes
2022-10-12 22:23:48.080 UTC [TRACE] steampipe: parse complete after 1 decode passes
2022-10-12 22:23:48.081 UTC [TRACE] steampipe: telemetry.Init service 'steampipe', tracingEnabled: false, metricsEnabled: false
2022-10-12 22:23:48.081 UTC [TRACE] steampipe: metrics and tracing disabled' - returning
Welcome to Steampipe v0.16.4
For more information, type .help
2022-10-12 22:23:48.081 UTC [TRACE] steampipe: GetRunStatus - loadRunningInstanceInfo returned nil
> 2022-10-12 22:23:48.129 UTC [TRACE] steampipe: StartDB invoker query
2022-10-12 22:23:48.129 UTC [TRACE] steampipe: StartDB started plugin manager
2022-10-12 22:23:48.132 UTC [TRACE] steampipe: Connection string: host=localhost port=9193 user=root dbname=postgres sslmode=disable
2022-10-12 22:23:48.172 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:48.172 UTC [92724] LOG: redirecting log output to logging collector process
2022-10-12 22:23:48.172 UTC [TRACE] steampipe: SERVICE: 2022-10-12 22:23:48.172 UTC [92724] HINT: Future log output will appear in directory "/Users/nhalstead/.steampipe/logs".
2022-10-12 22:23:48.248 UTC [TRACE] steampipe: status: {"pid":92724,"port":9193,"listen":["localhost","127.0.0.1"],"listen_type":"local","invoker":"query","password":"XXXX-XXXX-XXXX","user":"steampipe","database":"steampipe","struct_version":20220411}
2022-10-12 22:23:48.248 UTC [TRACE] steampipe: Connection string: host=localhost port=9193 user=root dbname=postgres sslmode=require
Error: failed to connect to `host=localhost user=root database=postgres`: failed to write startup message (x509: certificate signed by unknown authority)
Logs
2022-10-12 22:23:19.656 UTC [91489] LOG: starting PostgreSQL 14.2 on x86_64-apple-darwin20.6.0, compiled by Apple clang version 12.0.0 (clang-1200.0.32.29), 64-bit
2022-10-12 22:23:19.657 UTC [91489] LOG: listening on IPv6 address "::1", port 9193
2022-10-12 22:23:19.657 UTC [91489] LOG: listening on IPv4 address "127.0.0.1", port 9193
2022-10-12 22:23:19.658 UTC [91489] LOG: listening on Unix socket "/tmp/.s.PGSQL.9193"
2022-10-12 22:23:19.662 UTC [91493] LOG: database system was shut down at 2022-10-12 22:23:19 UTC
2022-10-12 22:23:19.663 UTC [91494] LOG: connection received: host=127.0.0.1 port=63230
2022-10-12 22:23:19.663 UTC [91494] FATAL: the database system is starting up
2022-10-12 22:23:19.665 UTC [91495] LOG: connection received: host=::1 port=63231
2022-10-12 22:23:19.665 UTC [91495] FATAL: the database system is starting up
2022-10-12 22:23:19.666 UTC [91489] LOG: database system is ready to accept connections
2022-10-12 22:23:19.712 UTC [91514] LOG: connection received: host=127.0.0.1 port=63232
2022-10-12 22:23:19.713 UTC [91514] LOG: connection authorized: user=root database=postgres
2022-10-12 22:23:19.721 UTC [91514] LOG: disconnection: session time: 0:00:00.008 user=root database=postgres host=127.0.0.1 port=63232
2022-10-12 22:23:19.831 UTC [91535] LOG: connection received: host=127.0.0.1 port=63233
2022-10-12 22:23:19.838 UTC [91535] LOG: could not accept SSL connection: sslv3 alert bad certificate
2022-10-12 22:23:19.840 UTC [91536] LOG: connection received: host=::1 port=63234
2022-10-12 22:23:19.843 UTC [91536] LOG: could not accept SSL connection: sslv3 alert bad certificate
2022-10-12 22:23:19.879 UTC [91538] LOG: connection received: host=127.0.0.1 port=63235
...
...
...
2022-10-12 22:23:24.786 UTC [91894] LOG: could not accept SSL connection: sslv3 alert bad certificate
2022-10-12 22:23:48.172 UTC [92724] LOG: starting PostgreSQL 14.2 on x86_64-apple-darwin20.6.0, compiled by Apple clang version 12.0.0 (clang-1200.0.32.29), 64-bit
2022-10-12 22:23:48.173 UTC [92724] LOG: listening on IPv6 address "::1", port 9193
2022-10-12 22:23:48.173 UTC [92724] LOG: listening on IPv4 address "127.0.0.1", port 9193
2022-10-12 22:23:48.173 UTC [92724] LOG: listening on Unix socket "/tmp/.s.PGSQL.9193"
2022-10-12 22:23:48.176 UTC [92726] LOG: database system was interrupted; last known up at 2022-10-12 22:23:19 UTC
2022-10-12 22:23:48.177 UTC [92726] LOG: database system was not properly shut down; automatic recovery in progress
2022-10-12 22:23:48.179 UTC [92726] LOG: redo starts at 0/835B08
2022-10-12 22:23:48.179 UTC [92726] LOG: invalid record length at 0/835B40: wanted 24, got 0
2022-10-12 22:23:48.179 UTC [92726] LOG: redo done at 0/835B08 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
2022-10-12 22:23:48.185 UTC [92724] LOG: database system is ready to accept connections
2022-10-12 22:23:48.186 UTC [92733] LOG: connection received: host=127.0.0.1 port=63436
2022-10-12 22:23:48.187 UTC [92733] LOG: connection authorized: user=root database=postgres
2022-10-12 22:23:48.194 UTC [92733] LOG: disconnection: session time: 0:00:00.007 user=root database=postgres host=127.0.0.1 port=63436
2022-10-12 22:23:48.301 UTC [92737] LOG: connection received: host=127.0.0.1 port=63437
2022-10-12 22:23:48.306 UTC [92737] LOG: could not accept SSL connection: sslv3 alert bad certificate
2022-10-12 22:23:48.307 UTC [92738] LOG: connection received: host=::1 port=63440
Out of curiosity, I did try adding the root to Keychain with no change.
The directories seem to be fine and Postgres is happily running but seems like a config issue.
Again this was the OOBE install, no configs were put in yet.
Sorry you've hit this bump @nhalstead ... thanks for letting us know and for the comprehensive logs!
It appears that something has gone wrong with the self-signed certificate we automatically install with postgres.
In troubleshoot, I have some questions:
- What's in the file
/Users/nhalstead/.steampipe/db/14.2.0/data/root.key
? Are you able to open that file? We seem to fail to load it, and / or get a bad certificate error. - Do you have postgres already installed on this machine? I'm wondering if they might be interacting somehow...
- What OS are you installing on?
As a suggested workaround / fix, can you please try:
# ensure steampipe is not running
steampipe service stop --force
ps aux | grep steampipe
# delete the DB install
rm -rf ~/.steampipe/db
# start steampipe again, which should reinstall the database
steampipe query
Hi @e-gineer,
- It's a valid Private RSA Key file and the corresponding certificate was able to be read by Keychain.
- Yes I have Postgres already installed on the host. I noticed that steampipe runs on a semi-random port so I have doubts it's connecting to the wrong port (plus logs indicate it's trying to connect to the server and the server is seeing it)
- MacOS 12.6
I have run through the steps and got the same results.
Had also read up on alike issues to no avail. (#1417, #2465, #2377)
I'm wondering if you may be hitting this issue https://github.com/turbot/steampipe/issues/1417
Do you have a ~/.postgresql/root.crt
file on your machine? Why did you rule out #1417?
So moving to rename the root certificate to root.crt.bak
allowed it to work.
Is it possible for steampipe to use the existing root certificate (in the ~/.postgresql/root.crt
) to sign the Postgres server certificate? This would allow it to coincide or override the server to explicitly use the path to the existing certificate (~/.steampipe/db/14.2.0/data/root.key
).
https://github.com/turbot/steampipe/blob/main/pkg/db/db_local/ssl.go
'This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 30 days.'
'This issue was closed because it has been stalled for 90 days with no activity.'