Closed ajoga closed 1 year ago
Hi @ajoga ... we're actually working on startup speed and initialization feedback as part of v0.20.0.
Would appreciate your feedback if you can try one of the alpha versions!
Hi @e-gineer, I just tried the same thing this ticket describes with v0.20.0-alpha.4.
end-user behavior is the same: $ steampipe query 'select 1'
does not return.
System behavior and logs are very different though. Way less system activity (cpu/disk), way less logging, maybe it "deadlocks" in the database sense of the term faster now. I'm not even getting the plenty schema creation logs anymore, just one: [WARN] hub: goFdwImportForeignSchema remote 'hub.steampipe.io/plugins/turbot/aws@latest' local 'aws__58'
5 minutes after command invocation, plugin.log is empty and I see no logging activity.
Disclaimer, the credentials are invalid like described in the ticket, but again I believe this would not change the outcome.
Furthermore, it feels like in this context STEAMPIPE_MAX_PARALLEL
is not honoured. To see if parallelism was an issue, I tried:
$ export STEAMPIPE_MAX_PARALLEL=1
$ steampipe query 'select 1'
With # psql -h 127.0.0.1 -p 9193 steampipe
, running SELECT * FROM pg_stat_activity;
i can see
steampipe=# SELECT count(*) FROM pg_stat_activity where query like '%clone_foreign_schema%';
count
-------
26
(1 row)
$ lsof -ni |grep 9193
corroborates that the steampipe client opened 26 sessions
Hey @ajoga
Sorry things are not working for you right now, and thanks for the investigation.
As @e-gineer we are working on improvements in this area.
It is interesting you are seeing references to auto-vacuum. You could try disabling this to see if it makes any difference.
To do this, drop a .conf file (e.g. custom.conf) into the location ~/.steampipe/db/14.2.0/data/postgresql.conf.d with the following content:
autovacuum=off
Once I have further improvements available in an alpha release, I will reach out to you to test it out in your use case, if that is ok?
Hey @kaidaguerre
autovacuum=off
I tried that and in the context of this ticket (fresh install of latest version with lots of connections), it does not change the outcome. (in other setups harder to replicate reliably it feels like it helped)
Once I have further improvements available in an alpha release, I will reach out to you to test it out in your use case, if that is ok?
Sure. We talked on slack few weeks ago, I think if you talk me there I'll get an email notification.
Thank you
Hi @kaidaguerre,
With the new releases since I opened this ticket I'd like to provide an update. The main object of the issue is still valid ("steampipe hangs forever out of the box with too much connexions").
I rm -fr ~/.steampipe
to reset the test environment and did the MRC as exposed in the issue. While the select 1
is not an issue anymore, trying to issue a more realistic query still exhibits a "deadlock-like" situation.
Still with no valid AWS credentials, and with an interactive steampipe query
, I see this:
steampipe query
Welcome to Steampipe v0.20.2
For more information, type .help
> select name from aws__1.aws_s3_bucket
Error: operation error S3: ListBuckets, https response error StatusCode: 403, RequestID: MBQJ2HP4T6KJ7XA6, HostID: 0IF/tJwaDsym1fgR4aXrtu8E8fe8tSdRQCpSIKOtCkcGTrABIcq60J2xpulTF4N/SjdxajVH2XM=, api error AccessDenied: Access Denied (SQLSTATE HV000)
+------+
| name |
+------+
+------+
> select name from aws__5.aws_s3_bucket
⠸ Waiting for connection 'aws__5' to load (Loaded 3 of 199 connections)
This waiting message stays forever. The database.log gets flooded with:
2023-05-23 10:58:56.222 UTC [9057] ERROR: relation "aws__5.aws_s3_bucket" does not exist at character 18
2023-05-23 10:58:56.222 UTC [9057] STATEMENT: select name from aws__5.aws_s3_bucket
My ps
looks like this, notice the multiple postgres
being WAITING:
8853 pts/2 Sl+ 0:02 | \_ steampipe query
8861 pts/2 S 0:00 | \_ /home/ec2-user/.steampipe/db/14.2.0/postgres/bin/postgres -p 9193 -c listen_addresses="localhost" -c application_name=steampipe -c cluster_name=steampipe -c log_directory=/home/ec2-user/.steampipe/logs -c ssl=on -c ssl_cert_file=/home/ec2-user/.steampipe/db/14.2.0/data/server.crt -c ssl_key_file=/home/ec2-user/.steampipe/db/14.2.0/data/server.key -D /home/ec2-user/.steampipe/db/14.2.0/data
8862 ? Ss 0:00 | | \_ postgres: steampipe: logger
8864 ? Ss 0:00 | | \_ postgres: steampipe: checkpointer
8865 ? Ss 0:00 | | \_ postgres: steampipe: background writer
8866 ? Ss 0:00 | | \_ postgres: steampipe: walwriter
8867 ? Ss 0:00 | | \_ postgres: steampipe: autovacuum launcher
8868 ? Ss 0:00 | | \_ postgres: steampipe: stats collector
8869 ? Ss 0:00 | | \_ postgres: steampipe: logical replication launcher
8892 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(59932) SELECT waiting
8912 ? Ss 0:00 | | \_ postgres: steampipe: steampipe steampipe 127.0.0.1(59934) idle
8914 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(59948) SELECT waiting
8915 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(59962) SELECT waiting
8916 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(59964) SELECT waiting
8917 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(59972) SELECT waiting
8918 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(59980) SELECT waiting
8919 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(59992) SELECT waiting
8920 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60006) SELECT waiting
8921 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60018) SELECT waiting
8922 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60028) SELECT waiting
8923 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60032) SELECT waiting
8924 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60034) SELECT waiting
8925 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60036) SELECT waiting
8926 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60050) SELECT waiting
8927 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60062) SELECT waiting
8928 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60070) SELECT waiting
8929 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60076) SELECT waiting
8930 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60084) SELECT waiting
8932 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60098) SELECT waiting
8933 ? Ssl 0:00 | | \_ postgres: steampipe: root steampipe 127.0.0.1(60106) SELECT waiting
9057 ? Ssl 0:00 | | \_ postgres: steampipe: steampipe steampipe 127.0.0.1(60116) idle
8873 pts/2 Sl 0:00 | \_ /usr/local/bin/steampipe plugin-manager --install-dir /home/ec2-user/.steampipe
8899 pts/2 Sl 0:00 | \_ /home/ec2-user/.steampipe/plugins/hub.steampipe.io/plugins/turbot/aws@latest/steampipe-plugin-aws.plugin
Queries seems indeed stuck on some locking:
steampipe=# SELECT * FROM pg_stat_activity;
datid | datname | pid | leader_pid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | xact_start | query_start | state_change | wait_event_type | wait_event | state | backend_xid | backend_xmin | query_id | query | backend_type
-------+-----------+-------+------------+----------+-----------+-------------------+-------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-------------------------------+-----------------+---------------------+--------+-------------+--------------+----------+--------------------------------------------------------------------------------------------------+---------------------
---------
| | 8867 | | | | steampipe | | | | 2023-05-23 10:56:53.02965+00 | | | | Activity | AutoVacuumMain | | | | | | autovacuum launcher
| | 8869 | | 10 | root | steampipe | | | | 2023-05-23 10:56:53.029687+00 | | | | Activity | LogicalLauncherMain | | | | | | logical replication
launcher
16384 | steampipe | 9057 | | 16386 | steampipe | steampipe_b5b0 | 127.0.0.1 | | 60116 | 2023-05-23 10:56:55.403502+00 | | 2023-05-23 11:01:39.230595+00 | 2023-05-23 11:01:39.230886+00 | Client | ClientRead | idle | | | | SELECT name, +| client backend
| | | | | | | | | | | | | | | | | | | | type, +|
| | | | | | | | | | | | | | | | | | | | import_schema, +|
| | | | | | | | | | | | | | | | | | | | state, +|
| | | | | | | | | | | | | | | | | | | | error, +|
| | | | | | | | | | | | | | | | | | | | plugin, +|
| | | | | | | | | | | | | | | | | | | | schema_mode, +|
| | | | | | | | | | | | | | | | | | | | schema_hash, +|
| | | | | | | | | | | | | | | | | | | | comments_set, +|
| | | | | | | | | | | | | | | | | | | | connection_mod_time, +|
| | | | | | | | | | | | | | | | | | | | plugin_mod_time +|
| | | | | | | | | | | | | | | | | | | | FROM steampipe_internal.steampipe_connection_state |
16384 | steampipe | 8912 | | 16386 | steampipe | steampipe_b5b0 | 127.0.0.1 | | 59934 | 2023-05-23 10:56:54.157415+00 | | 2023-05-23 10:56:54.162779+00 | 2023-05-23 10:56:54.162816+00 | Client | ClientRead | idle | | | | listen steampipe_notification | client backend
16384 | steampipe | 10878 | | 10 | root | psql | 127.0.0.1 | | 42592 | 2023-05-23 11:00:40.350384+00 | 2023-05-23 11:01:39.238104+00 | 2023-05-23 11:01:39.238104+00 | 2023-05-23 11:01:39.238106+00 | | | active | | 772 | | SELECT * FROM pg_stat_activity; | client backend
16384 | steampipe | 8892 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 59932 | 2023-05-23 10:56:53.362636+00 | 2023-05-23 10:56:54.479362+00 | 2023-05-23 10:56:54.479425+00 | 2023-05-23 10:56:54.479426+00 | Lock | extend | active | 772 | 772 | | select clone_foreign_schema('aws__1', 'aws__126', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8920 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60006 | 2023-05-23 10:56:54.490072+00 | 2023-05-23 10:56:54.536651+00 | 2023-05-23 10:56:54.537645+00 | 2023-05-23 10:56:54.537646+00 | Lock | extend | active | 774 | 772 | | select clone_foreign_schema('aws__1', 'aws__33', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8919 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 59992 | 2023-05-23 10:56:54.489733+00 | 2023-05-23 10:56:54.536565+00 | 2023-05-23 10:56:54.537116+00 | 2023-05-23 10:56:54.537117+00 | Lock | extend | active | 787 | 772 | | select clone_foreign_schema('aws__1', 'aws__102', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8921 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60018 | 2023-05-23 10:56:54.490366+00 | 2023-05-23 10:56:54.536612+00 | 2023-05-23 10:56:54.537503+00 | 2023-05-23 10:56:54.537504+00 | Lock | extend | active | 775 | 772 | | select clone_foreign_schema('aws__1', 'aws__169', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8922 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60028 | 2023-05-23 10:56:54.490651+00 | 2023-05-23 10:56:54.532081+00 | 2023-05-23 10:56:54.535759+00 | 2023-05-23 10:56:54.535759+00 | Lock | extend | active | 785 | 772 | | select clone_foreign_schema('aws__1', 'aws__176', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8918 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 59980 | 2023-05-23 10:56:54.490931+00 | 2023-05-23 10:56:54.532124+00 | 2023-05-23 10:56:54.536747+00 | 2023-05-23 10:56:54.536748+00 | Lock | extend | active | 773 | 772 | | select clone_foreign_schema('aws__1', 'aws__94', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8924 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60034 | 2023-05-23 10:56:54.500279+00 | 2023-05-23 10:56:59.591797+00 | 2023-05-23 10:56:59.593887+00 | 2023-05-23 10:56:59.593888+00 | Lock | extend | active | 792 | 772 | | select clone_foreign_schema('aws__1', 'aws__26', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8925 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60036 | 2023-05-23 10:56:54.500562+00 | 2023-05-23 10:56:54.53547+00 | 2023-05-23 10:56:54.540245+00 | 2023-05-23 10:56:54.540246+00 | Lock | extend | active | 776 | 772 | | select clone_foreign_schema('aws__1', 'aws__143', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8917 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 59972 | 2023-05-23 10:56:54.491216+00 | 2023-05-23 10:56:54.541729+00 | 2023-05-23 10:56:54.552214+00 | 2023-05-23 10:56:54.552214+00 | Lock | extend | active | 781 | 772 | | select clone_foreign_schema('aws__1', 'aws__3', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8923 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60032 | 2023-05-23 10:56:54.4914+00 | 2023-05-23 10:56:54.536684+00 | 2023-05-23 10:56:54.542894+00 | 2023-05-23 10:56:54.542895+00 | Lock | extend | active | 786 | 772 | | select clone_foreign_schema('aws__1', 'aws__117', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8928 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60070 | 2023-05-23 10:56:54.501306+00 | 2023-05-23 10:56:54.536716+00 | 2023-05-23 10:56:54.543994+00 | 2023-05-23 10:56:54.543995+00 | Lock | extend | active | 782 | 772 | | select clone_foreign_schema('aws__1', 'aws__193', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8916 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 59964 | 2023-05-23 10:56:54.491772+00 | 2023-05-23 10:56:54.569326+00 | 2023-05-23 10:56:54.570835+00 | 2023-05-23 10:56:54.570835+00 | Lock | extend | active | 790 | 772 | | select clone_foreign_schema('aws__1', 'aws__82', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8926 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60050 | 2023-05-23 10:56:54.500819+00 | 2023-05-23 10:56:54.541681+00 | 2023-05-23 10:56:54.548204+00 | 2023-05-23 10:56:54.548205+00 | Lock | extend | active | 780 | 772 | | select clone_foreign_schema('aws__1', 'aws__66', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8927 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60062 | 2023-05-23 10:56:54.501061+00 | 2023-05-23 10:56:54.543163+00 | 2023-05-23 10:56:54.545578+00 | 2023-05-23 10:56:54.545579+00 | Lock | extend | active | 778 | 772 | | select clone_foreign_schema('aws__1', 'aws__51', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8933 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60106 | 2023-05-23 10:56:54.502028+00 | 2023-05-23 10:56:54.5402+00 | 2023-05-23 10:56:54.547067+00 | 2023-05-23 10:56:54.547068+00 | Lock | extend | active | 783 | 772 | | select clone_foreign_schema('aws__1', 'aws__149', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8929 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60076 | 2023-05-23 10:56:54.501548+00 | 2023-05-23 10:56:59.700239+00 | 2023-05-23 10:56:59.702921+00 | 2023-05-23 10:56:59.702921+00 | Lock | extend | active | 793 | 772 | | select clone_foreign_schema('aws__1', 'aws__175', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8932 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60098 | 2023-05-23 10:56:54.501783+00 | 2023-05-23 10:56:54.544878+00 | 2023-05-23 10:56:54.547625+00 | 2023-05-23 10:56:54.547626+00 | Lock | extend | active | 779 | 772 | | select clone_foreign_schema('aws__1', 'aws__100', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8914 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 59948 | 2023-05-23 10:56:54.50551+00 | 2023-05-23 10:56:54.567917+00 | 2023-05-23 10:56:54.569385+00 | 2023-05-23 10:56:54.569386+00 | Lock | extend | active | 789 | 772 | | select clone_foreign_schema('aws__1', 'aws__6', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8915 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 59962 | 2023-05-23 10:56:54.505326+00 | 2023-05-23 10:56:54.569432+00 | 2023-05-23 10:56:54.569508+00 | 2023-05-23 10:56:54.569509+00 | Lock | extend | active | 788 | 772 | | select clone_foreign_schema('aws__1', 'aws__44', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
16384 | steampipe | 8930 | | 10 | root | pm_steampipe_efcb | 127.0.0.1 | | 60084 | 2023-05-23 10:56:54.502279+00 | 2023-05-23 10:56:54.580207+00 | 2023-05-23 10:56:54.580292+00 | 2023-05-23 10:56:54.580293+00 | Lock | extend | active | 791 | 772 | | select clone_foreign_schema('aws__1', 'aws__153', 'hub.steampipe.io/plugins/turbot/aws@latest'); | client backend
| | 8865 | | | | steampipe | | | | 2023-05-23 10:56:53.030102+00 | | | | Activity | BgWriterMain | | | | | | background writer
| | 8864 | | | | steampipe | | | | 2023-05-23 10:56:53.029158+00 | | | | Activity | CheckpointerMain | | | | | | checkpointer
| | 8866 | | | | steampipe | | | | 2023-05-23 10:56:53.029418+00 | | | | Activity | WalWriterMain | | | | | | walwriter
(28 rows)
steampipe=#
Hey @kaidaguerre -- I just tried the newest v0.20.3 and it's not blocking anymore on this test scenario!
@ajoga Seems like this is working for you now, so we are closing this issue. Please let us know if you face this again.
Describe the bug Starting Steampipe with a lot of connexions leads to a deadlock-like situation ; I suspect this can happen when modifying a connexion too when there is a lot of them.
Steampipe version (
steampipe -v
) v0.19.4Plugin version (
steampipe plugin list
) v0.99.0To reproduce Tried on a fresh machine to isolate this issue, a r6a.large ec2 instance (16GB ram). Install steampipe Install aws plugin
$ steampipe query 'select 1'
: works Generate a lot of connections with this script:Note that these roles are non-existent, I don't think it matter at this stage though.
Run again
$ steampipe query 'select 1'
postgres: steampipe: autovacuum worker steampipe waiting
2023-04-14 13:59:31.205 UTC [WARN] hub: goFdwImportForeignSchema remote 'hub.steampipe.io/plugins/turbot/aws@latest' local 'aws__480'
indatabase-2023-04-14.log
plugin-2023-04-14.log
is emptydatabase-2023-04-14.log
shows:It feels like the db didn't finish its initialization because there is a 2 minutes timeout somewhere
Expected behavior
$ steampipe query 'select 1'
returns either successfully or with an error message I can act upon.