temboard icon indicating copy to clipboard operation
temboard copied to clipboard

Seeing More Locking in Master temboard UI

Open bsislow opened this issue 2 years ago • 3 comments

we're seeing strings of truncates waiting on other statements and so forth like such:

2022-04-21 11:04:48 CDT [2280]: [1-1] user=temboard,db=temboard,app=temboard,client=[local] LOG:  duration: 12014.963 ms  statement: SELECT * FROM aggregate_data_single('metric_locks', 'metric_locks_record', ' INSERT INTO #agg_table#   SELECT     truncate_time(datetime, ''#interval#'') AS datetime,     instance_id,     dbname,     ROW(       NULL,       AVG((r).access_share),       AVG((r).row_share),       AVG((r).row_exclusive),       AVG((r).share_update_exclusive),       AVG((r).share),       AVG((r).share_row_exclusive),       AVG((r).exclusive),       AVG((r).access_exclusive),       AVG((r).siread),       AVG((r).waiting_access_share),       AVG((r).waiting_row_share),       AVG((r).waiting_row_exclusive),       AVG((r).waiting_share_update_exclusive),       AVG((r).waiting_share),       AVG((r).waiting_share_row_exclusive),       AVG((r).waiting_exclusive),       AVG((r).waiting_access_exclusive)     )::#record_type#,     COUNT(*) AS w   FROM     expand_data_limit(''#name#'', (SELECT tstzrange(MAX(datetime), NOW()) FROM #agg_table#), 100000)     AS (       datetime timestamp with time zone,       instance_id integer,       dbname text,       r #record_type#     )   WHERE     truncate_time(datetime, ''#interval#'') < truncate_time(NOW(), ''#interval#'')   GROUP BY 1,2,3   ORDER BY 1,2,3 ON CONFLICT (datetime, instance_id, dbname) DO UPDATE SET w = EXCLUDED.w, record = EXCLUDED.record WHERE #agg_table#.w < EXCLUDED.w ')
2022-04-21 11:05:19 CDT [3803]: [1-1] user=temboard,db=temboard,app=temboard,client=[local] LOG:  process 3803 still waiting for AccessExclusiveLock on relation 18777 of database 16475 after 1000.088 ms
2022-04-21 11:05:19 CDT [3803]: [2-1] user=temboard,db=temboard,app=temboard,client=[local] DETAIL:  Process holding the lock: 2280. Wait queue: 3803.
2022-04-21 11:05:19 CDT [3803]: [3-1] user=temboard,db=temboard,app=temboard,client=[local] CONTEXT:  SQL statement "TRUNCATE metric_sessions_current"
        PL/pgSQL function archive_current_metrics(text,text,text) line 19 at EXECUTE
2022-04-21 11:05:19 CDT [3803]: [4-1] user=temboard,db=temboard,app=temboard,client=[local] STATEMENT:  SELECT * FROM archive_current_metrics('metric_sessions', 'metric_sessions_record', 'INSERT INTO #history_table# SELECT tstzrange(min(datetime), max(datetime)), instance_id, dbname, array_agg(set_datetime_record(datetime, record)::#record_type#) AS records FROM #current_table# GROUP BY date_trunc(''day'', datetime),2,3 ORDER BY 1,2 ASC;')
2022-04-21 11:05:20 CDT [3803]: [5-1] user=temboard,db=temboard,app=temboard,client=[local] LOG:  process 3803 acquired AccessExclusiveLock on relation 18777 of database 16475 after 2258.914 ms
2022-04-21 11:05:20 CDT [3803]: [6-1] user=temboard,db=temboard,app=temboard,client=[local] CONTEXT:  SQL statement "TRUNCATE metric_sessions_current"
        PL/pgSQL function archive_current_metrics(text,text,text) line 19 at EXECUTE
2022-04-21 11:05:20 CDT [3803]: [7-1] user=temboard,db=temboard,app=temboard,client=[local] STATEMENT:  SELECT * FROM archive_current_metrics('metric_sessions', 'metric_sessions_record', 'INSERT INTO #history_table# SELECT tstzrange(min(datetime), max(datetime)), instance_id, dbname, array_agg(set_datetime_record(datetime, record)::#record_type#) AS records FROM #current_table# GROUP BY date_trunc(''day'', datetime),2,3 ORDER BY 1,2 ASC;')
2022-04-21 11:05:23 CDT [3803]: [8-1] user=temboard,db=temboard,app=temboard,client=[local] LOG:  process 3803 still waiting for AccessExclusiveLock on relation 19113 of database 16475 after 1000.092 ms
2022-04-21 11:05:23 CDT [3803]: [9-1] user=temboard,db=temboard,app=temboard,client=[local] DETAIL:  Process holding the lock: 2280. Wait queue: 3803.
2022-04-21 11:05:23 CDT [3803]: [10-1] user=temboard,db=temboard,app=temboard,client=[local] CONTEXT:  SQL statement "TRUNCATE metric_temp_files_size_delta_current"
        PL/pgSQL function archive_current_metrics(text,text,text) line 19 at EXECUTE

can i email you our postgres logs for review?

bsislow avatar Apr 21 '22 16:04 bsislow

Hi @bsislow ok for the logs. Can you share the version you are running ? Please send a copy to @daamien .

bersace avatar Apr 25 '22 07:04 bersace

@bsislow can you remember me how many agent you have registered ?

bersace avatar Apr 25 '22 07:04 bersace

Emailed you both.

There are 46 agents.

Current version:

$ rpm -qa| grep temboard
temboard-7.10-1.el7.noarch
temboard-agent-7.10-1.el7.noarch

bsislow avatar Apr 26 '22 13:04 bsislow