RESOURCE_ACQUISITIONS
RESOURCE_ACQUISITIONS fields clarification needed:
As it noted in documentation : (acquisition_timestamp-queue_entry_timestamp) AS 'queue wait'
How can I find out what exactly have been waiting?
What it means DURATION_MS - Duration of the resource request in milliseconds.
I am getting a number of scenarious:
1. queue wait + DURATION_MS ~ duration from query_profiles
2. queue wait = 0 and DURATION_MS is about half of duration from query_profiles
Thanks in advance...
As it noted in documentation : (acquisition_timestamp-queue_entry_timestamp) AS 'queue wait'
How can I find out what exactly have been waiting?
What it means DURATION_MS - Duration of the resource request in milliseconds.
I am getting a number of scenarious:
1. queue wait + DURATION_MS ~ duration from query_profiles
2. queue wait = 0 and DURATION_MS is about half of duration from query_profiles
Thanks in advance...
0
Comments
"duration_ms" suggests - duration for which resources were occupied by a specific transaction. You can get the value by calculating difference betweenrelease_timestamp & acquisition_timestamp)
dbadmin=> SELECT pool_name, queue_entry_timestamp, acquisition_timestamp,release_timestamp,
dbadmin-> (acquisition_timestamp-queue_entry_timestamp)/1000 AS 'queue_wait_ms',
dbadmin-> (release_timestamp-acquisition_timestamp)/1000 AS 'Time_resources_occupied_ms',
dbadmin-> duration_ms
dbadmin-> FROM d33497.RESOURCE_ACQUISITIONS WHERE transaction_id=45035996284960481 and statement_id=1
dbadmin-> ;
pool_name | queue_entry_timestamp | acquisition_timestamp | release_timestamp | queue_wait_ms | Time_resources_occupied_ms | duration_ms
------------------+-------------------------------+-------------------------------+-------------------------------+-----------------+----------------------------+-------------
hp_vertica_pool1 | 2015-01-02 14:39:16.097822+00 | 2015-01-02 14:39:17.487125+00 | 2015-01-02 14:39:18.938807+00 | 00:00:00.001389 | 00:00:00.001452 | 1451
hp_vertica_pool1 | 2015-01-02 14:39:16.096126+00 | 2015-01-02 14:39:17.485644+00 | 2015-01-02 14:39:18.937322+00 | 00:00:00.00139 | 00:00:00.001452 | 1452
hp_vertica_pool1 | 2015-01-02 14:39:16.096635+00 | 2015-01-02 14:39:17.486045+00 | 2015-01-02 14:39:18.937766+00 | 00:00:00.001389 | 00:00:00.001452 | 1451
(3 rows)
From above query , queue_wait_ms + Time_resources_occupied_ms ( 1389+1452=2841 ms) should be nearly equivalent to time take by query execution.
As per query_profiles, time taken by query is 2948 ms.
dbadmin=> select * from d33497.query_profiles WHERE transaction_id=45035996284960481 and statement_id=1;
session_id | transaction_id | statement_id | identifier | node_name | query | query_search_path | schema_name | table_name | projections_used | query_duration_us | query_start_epoch | query_start | query_type | error_code | user_name | processed_row_count | reserved_extra_memory | is_executing
-----------------------------------+-------------------+--------------+------------+-----------------+-----------------------------------------------------------------------------+---------------------------------------------------+-------------+------------+------------------------+-------------------+-------------------+-------------------------------+------------+------------+------------+---------------------+-----------------------+--------------
ossvert1.gre.hp.com-51343:0xe7b73 | 45035996284960481 | 1 | | v_ossa_node0010 | profile select count(distinct x), * from foo1 group by x,z order by z desc; | "$user", public, v_catalog, v_monitor, v_internal | | | query projection_usage | 2948829.000000 | 1578056 | 2015-01-02 15:39:15.990521+01 | QUERY | 0 | hp_vertica | 999945 | 0 | f
(1 row)
So time calculated above is inline with actual time of query execution.
Hope it helps to clarify your doubts.
Regards'
Abhishek