RESOURCE_ACQUISITIONS

leonidn

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...

Abhishek_Rana

Hi,

"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