| Starting with an upgrade to PuppetDB 6.20 (apt-ugprade), the response times for certain queries went from 2-3s to 12-18s. Here's an explain analyze that shows the problem: Since we are running 9.6.4, the JIT issue reported with other Postgres versions doesn't seem to apply.
puppetdb=> EXPLAIN (ANALYZE,BUFFERS) WITH inactive_nodes AS (SELECT certname FROM certnames WHERE (deactivated IS NOT NULL AND deactivated > '2022-08-18T23:59:00.376Z') OR (expired IS NOT NULL and expired > '2022-08-18T23:59:00.376Z')), not_active_nodes AS (SELECT certname FROM certnames WHERE (deactivated IS NOT NULL OR expired IS NOT NULL)) SELECT certnames.certname AS "certname" FROM certnames LEFT JOIN catalogs ON catalogs.certname = certnames.certname LEFT JOIN factsets fs ON certnames.certname = fs.certname LEFT JOIN reports ON (certnames.certname = reports.certname AND certnames.latest_report_id = reports.id) LEFT JOIN environments catalog_environment ON catalog_environment.id = catalogs.environment_id LEFT JOIN report_statuses ON reports.status_id = report_statuses.id LEFT JOIN environments facts_environment ON facts_environment.id = fs.environment_id LEFT JOIN environments reports_environment ON reports_environment.id = reports.environment_id WHERE ((((certnames.certname) in (SELECT certname FROM ( (SELECT fc.certname AS "certname" FROM (select certname, flattened.* from factsets fs left join lateral ( with recursive flattened_one (parent_path, parent_types, key, value, type) as ( select array[]::text[], '', (jsonb_each(fs.stable||fs.volatile))., 's' union all select parent_path || flattened_one.key, parent_types || flattened_one.type, sub_paths.key, sub_paths.value, sub_paths.type from flattened_one inner join lateral ( select (jsonb_each(value))., 's' as type where jsonb_typeof(value) = 'object' union all select generate_series::text as key, value->generate_series as value, 'i' as type from generate_series(0, jsonb_array_length(value) - 1) where jsonb_typeof(value) = 'array' ) as sub_paths on true ) select environment_id, parent_path || key as path, parent_types || type as types, coalesce(parent_path[1], key) as name, value from flattened_one where not jsonb_typeof(value) = any('{"array", "object"}') ) as flattened on true) fc LEFT JOIN environments env ON fc.environment_id = env.id WHERE ((fc.path = (array['bc_cluster']) and fc.types = 's') AND (jsonb_typeof("value") = 'string' AND (value = '"store-resque-cell-2"')))) ) sub)) AND ((certnames.certname) in (SELECT certname FROM ( (SELECT fc.certname AS "certname" FROM (select certname, flattened.* from factsets fs left join lateral ( with recursive flattened_one (parent_path, parent_types, key, value, type) as ( select array[]::text[], '', (jsonb_each(fs.stable||fs.volatile))., 's' union all select parent_path || flattened_one.key, parent_types || flattened_one.type, sub_paths.key, sub_paths.value, sub_paths.type from flattened_one inner join lateral ( select (jsonb_each(value))., 's' as type where jsonb_typeof(value) = 'object' union all select generate_series::text as key, value->generate_series as value, 'i' as type from generate_series(0, jsonb_array_length(value) - 1) where jsonb_typeof(value) = 'array' ) as sub_paths on true ) select environment_id, parent_path || key as path, parent_types || type as types, coalesce(parent_path[1], key) as name, value from flattened_one where not jsonb_typeof(value) = any('{"array", "object"}') ) as flattened on true) fc LEFT JOIN environments env ON fc.environment_id = env.id WHERE ((fc.path = (array['bc_location']) and fc.types = 's') AND (jsonb_typeof("value") = 'string' AND (value = '"gcp_production"')))) ) sub))) AND NOT ((certnames.certname) in (SELECT certname FROM ( SELECT not_active_nodes.certname AS "certname" FROM not_active_nodes ) sub))); QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ Nested Loop Semi Join (cost=1351052.28..2631226545.73 rows=1151 width=56) (actual time=12834.466..13328.196 rows=2 loops=1) Join Filter: (certnames.certname = fs.certname) Buffers: shared hit=154100 CTE not_active_nodes -> Seq Scan on certnames certnames_1 (cost=0.00..93.02 rows=138 width=56) (actual time=0.015..0.343 rows=138 loops=1) Filter: ((deactivated IS NOT NULL) OR (expired IS NOT NULL)) Rows Removed by Filter: 2164 Buffers: shared hit=70 -> Nested Loop Semi Join (cost=675481.46..1315653469.36 rows=1151 width=112) (actual time=17.068..6053.819 rows=1251 loops=1) Buffers: shared hit=123597 -> Merge Left Join (cost=3.67..79896.90 rows=1151 width=56) (actual time=0.529..197.346 rows=2164 loops=1) Merge Cond: (certnames.certname = catalogs.certname) Buffers: shared hit=71335 -> Nested Loop Left Join (cost=3.39..79042.21 rows=1151 width=56) (actual time=0.522..176.900 rows=2164 loops=1) Buffers: shared hit=68994 -> Index Scan using certnames_transform_certname_key on certnames (cost=3.39..583.66 rows=1151 width=64) (actual time=0.458..11.675 rows=2164 loops=1) Filter: (NOT (hashed SubPlan 2)) Rows Removed by Filter: 138 Buffers: shared hit=2396 SubPlan 2 -> CTE Scan on not_active_nodes (cost=0.00..2.76 rows=138 width=32) (actual time=0.016..0.384 rows=138 loops=1) Buffers: shared hit=70 -> Append (cost=0.00..68.01 rows=16 width=80) (actual time=0.067..0.069 rows=1 loops=2164) Buffers: shared hit=66598 -> Seq Scan on reports (cost=0.00..0.00 rows=1 width=56) (actual time=0.001..0.001 rows=0 loops=2164) Filter: ((certnames.certname = certname) AND (certnames.latest_report_id = id)) -> Index Scan using idx_reports_id_20220819z on reports_20220819z (cost=0.29..4.62 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4296 -> Index Scan using idx_reports_id_20220820z on reports_20220820z (cost=0.29..4.62 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4296 -> Index Scan using idx_reports_id_20220821z on reports_20220821z (cost=0.29..4.62 rows=1 width=80) (actual time=0.002..0.002 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4296 -> Index Scan using idx_reports_id_20220822z on reports_20220822z (cost=0.29..4.62 rows=1 width=80) (actual time=0.002..0.002 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4296 -> Index Scan using idx_reports_id_20220823z on reports_20220823z (cost=0.29..4.53 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4296 -> Index Scan using idx_reports_id_20220824z on reports_20220824z (cost=0.29..4.62 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4297 -> Index Scan using idx_reports_id_20220825z on reports_20220825z (cost=0.29..4.62 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4296 -> Index Scan using idx_reports_id_20220826z on reports_20220826z (cost=0.29..4.60 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4297 -> Index Scan using idx_reports_id_20220827z on reports_20220827z (cost=0.29..4.58 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4296 -> Index Scan using idx_reports_id_20220828z on reports_20220828z (cost=0.29..4.60 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4296 -> Index Scan using idx_reports_id_20220829z on reports_20220829z (cost=0.29..4.55 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4297 -> Index Scan using idx_reports_id_20220830z on reports_20220830z (cost=0.29..4.59 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4297 -> Index Scan using idx_reports_id_20220831z on reports_20220831z (cost=0.29..4.57 rows=1 width=80) (actual time=0.003..0.003 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4300 -> Index Scan using idx_reports_id_20220901z on reports_20220901z (cost=0.29..4.59 rows=1 width=80) (actual time=0.002..0.002 rows=0 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=4304 -> Index Scan using idx_reports_id_20220902z on reports_20220902z (cost=0.29..3.67 rows=1 width=80) (actual time=0.007..0.008 rows=1 loops=2164) Index Cond: (certnames.latest_report_id = id) Filter: (certnames.certname = certname) Buffers: shared hit=6438 -> Index Scan using catalogs_certname_idx on catalogs (cost=0.28..834.61 rows=2293 width=64) (actual time=0.003..7.886 rows=2293 loops=1) Buffers: shared hit=2341 -> Nested Loop (cost=675477.80..1142983.11 rows=1 width=56) (actual time=2.704..2.704 rows=1 loops=2164) Buffers: shared hit=52262 -> Index Scan using factsets_certname_idx on factsets fs_1 (cost=0.28..1.33 rows=1 width=101) (actual time=0.011..0.012 rows=1 loops=2164) Index Cond: (certname = certnames.certname) Buffers: shared hit=6516 -> CTE Scan on flattened_one (cost=675477.52..1142981.77 rows=1 width=136) (actual time=2.664..2.664 rows=1 loops=2164) Filter: ((value = '"gcp_production"'::jsonb) AND (jsonb_typeof(value) <> ALL ('{array,object}'::text[])) AND ((parent_types || type) = 's'::text) AND (jsonb_typeof(value) = 'string'::text) AND ((parent_path || key) = '{bc_location}'::text[])) Rows Removed by Filter: 413 Buffers: shared hit=45746 CTE flattened_one -> Recursive Union (cost=0.00..675477.52 rows=11000100 width=160) (actual time=0.802..2.226 rows=413 loops=2164) Buffers: shared hit=45746 -> Result (cost=0.00..0.52 rows=100 width=160) (actual time=0.779..0.842 rows=120 loops=2164) Buffers: shared hit=45746 -> Nested Loop (cost=0.01..45547.50 rows=1100000 width=160) (actual time=0.017..0.404 rows=99 loops=6379) -> WorkTable Scan on flattened_one flattened_one_3 (cost=0.00..20.00 rows=1000 width=160) (actual time=0.000..0.013 rows=127 loops=6379) -> Append (cost=0.01..29.03 rows=1100 width=96) (actual time=0.002..0.002 rows=1 loops=810605) -> Result (cost=0.01..0.52 rows=100 width=96) (actual time=0.001..0.001 rows=1 loops=810605) One-Time Filter: (jsonb_typeof(flattened_one_3.value) = 'object'::text) -> Result (cost=0.01..17.51 rows=1000 width=96) (actual time=0.000..0.001 rows=0 loops=810605) One-Time Filter: (jsonb_typeof(flattened_one_3.value) = 'array'::text) -> Function Scan on generate_series generate_series_1 (cost=0.01..17.51 rows=1000 width=96) (actual time=0.001..0.002 rows=5 loops=38708) -> Nested Loop (cost=675477.80..1142982.60 rows=1 width=56) (actual time=5.812..5.812 rows=0 loops=1251) Buffers: shared hit=30503 -> Index Scan using factsets_certname_idx on factsets fs (cost=0.28..0.81 rows=1 width=101) (actual time=0.010..0.012 rows=1 loops=1251) Index Cond: (certname = fs_1.certname) Buffers: shared hit=3785 -> CTE Scan on flattened_one flattened_one_1 (cost=675477.52..1142981.77 rows=1 width=136) (actual time=5.701..5.701 rows=0 loops=1251) Filter: ((value = '"store-resque-cell-2"'::jsonb) AND (jsonb_typeof(value) <> ALL ('{array,object}'::text[])) AND ((parent_path || key) = '{bc_cluster}'::text[]) AND ((parent_types || type) = 's'::text) AND (jsonb_typeof(value) = 'string'::text)) Rows Removed by Filter: 1045 Buffers: shared hit=26718 CTE flattened_one -> Recursive Union (cost=0.00..675477.52 rows=11000100 width=160) (actual time=0.802..4.604 rows=1045 loops=1251) Buffers: shared hit=26718 -> Result (cost=0.00..0.52 rows=100 width=160) (actual time=0.800..0.913 rows=212 loops=1251) Buffers: shared hit=26718 -> Nested Loop (cost=0.01..45547.50 rows=1100000 width=160) (actual time=0.017..0.461 rows=118 loops=8804) -> WorkTable Scan on flattened_one flattened_one_2 (cost=0.00..20.00 rows=1000 width=160) (actual time=0.000..0.016 rows=148 loops=8804) -> Append (cost=0.01..29.03 rows=1100 width=96) (actual time=0.002..0.002 rows=1 loops=1306733) -> Result (cost=0.01..0.52 rows=100 width=96) (actual time=0.001..0.001 rows=1 loops=1306733) One-Time Filter: (jsonb_typeof(flattened_one_2.value) = 'object'::text) -> Result (cost=0.01..17.51 rows=1000 width=96) (actual time=0.000..0.001 rows=0 loops=1306733) One-Time Filter: (jsonb_typeof(flattened_one_2.value) = 'array'::text) -> Function Scan on generate_series (cost=0.01..17.51 rows=1000 width=96) (actual time=0.001..0.002 rows=6 loops=59352) Planning time: 4.903 ms Execution time: 13328.706 ms (134 rows)
|