[MCOL-4503] query executime is not consistent Created: 2021-01-18  Updated: 2021-04-19

Status: Closed
Project: MariaDB ColumnStore
Component/s: None
Affects Version/s: 1.2.5
Fix Version/s: Icebox

Type: Task Priority: Major
Reporter: Allen Lee (Inactive) Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None
Environment:

hyperV cluster

  • Cores = 96 per HV host Networking = dual 10g OS = server 2019 Storage = fast. Dual 16g fiber to netapp flashpool accelerated 10k SAS aggregate
  • x2 UMs (cpu,ram,disk) 32 64GB 500GB OS 2TB Storage
  • x5 PMs 16 32GB 500GB OS 10TB DB
  • 2UMs, 5PMs

Issue Links:
Duplicate
duplicates MCOL-4527 Simple query performace is degraded b... Closed

 Description   

The customer reported that they didn't get consistent query executime for the same query.

  • query

SELECT COUNT(*) as total, action from ( select case when ll_cat_id = 4002 then 'allowed' when ll_cat_id = 4003 then 'denied' end as action FROM q_2020_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND log_source_id IN (SELECT log_source_id FROM sys_lookup_log_sources where log_source_identifier IN ('37-001311-033392-02','per4-durh00nc-5512','per5-denv00co-100d-1','per5-denv00co-100D-2','per5-denv00co-100d-3','3144-001311-034725-16','37-001311-034725-13','VPRLDEMO01','37-001311-034725-15','37-001311-034725-08','37-001311-034725-10','per4-durh00nc-100D-W1','37-001311-034725-20','00-000000-000000-01','01-001311-000985-03')) AND q_epoch BETWEEN 1609446898 AND 1610051698 UNION ALL select case when ll_cat_id = 4002 then 'allowed' when ll_cat_id = 4003 then 'denied' end as action FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND log_source_id IN (SELECT log_source_id FROM sys_lookup_log_sources where log_source_identifier IN ('37-001311-033392-02','per4-durh00nc-5512','per5-denv00co-100d-1','per5-denv00co-100D-2','per5-denv00co-100d-3','3144-001311-034725-16','37-001311-034725-13','VPRLDEMO01','37-001311-034725-15','37-001311-034725-08','37-001311-034725-10','per4-durh00nc-100D-W1','37-001311-034725-20','00-000000-000000-01','01-001311-000985-03')) AND q_epoch BETWEEN 1609446898 AND 1610051698 ) as t1 group by action UNION ALL SELECT COUNT(*) as total, action from ( select 1, 'total' as action FROM q_2020_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND log_source_id IN (SELECT log_source_id FROM sys_lookup_log_sources where log_source_identifier IN ('37-001311-033392-02','per4-durh00nc-5512','per5-denv00co-100d-1','per5-denv00co-100D-2','per5-denv00co-100d-3','3144-001311-034725-16','37-001311-034725-13','VPRLDEMO01','37-001311-034725-15','37-001311-034725-08','37-001311-034725-10','per4-durh00nc-100D-W1','37-001311-034725-20','00-000000-000000-01','01-001311-000985-03')) AND q_epoch BETWEEN 1609446898 AND 1610051698 UNION ALL select 1, 'total' as action FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND log_source_id IN (SELECT log_source_id FROM sys_lookup_log_sources where log_source_identifier IN ('37-001311-033392-02','per4-durh00nc-5512','per5-denv00co-100d-1','per5-denv00co-100D-2','per5-denv00co-100d-3','3144-001311-034725-16','37-001311-034725-13','VPRLDEMO01','37-001311-034725-15','37-001311-034725-08','37-001311-034725-10','per4-durh00nc-100D-W1','37-001311-034725-20','00-000000-000000-01','01-001311-000985-03')) AND q_epoch BETWEEN 1609446898 AND 1610051698 ) as t1 group by action

  • executime time

1st
+--------+---------+
| total | action |
+--------+---------+
| 210787 | denied |
| 480355 | allowed |
| 691142 | total |
+--------+---------+
3 rows in set (25.305 sec)
 
2nd
+--------+---------+
| total | action |
+--------+---------+
| 691142 | total |
| 210787 | denied |
| 480355 | allowed |
+--------+---------+
3 rows in set (4.784 sec)
 
3rd
+--------+---------+
| total | action |
+--------+---------+
| 691142 | total |
| 210787 | denied |
| 480355 | allowed |
+--------+---------+
3 rows in set (10.612 sec)

Then, tried to different query with relatively small query.

(1)
 
MariaDB [qradar]> select calFlushCache();select ll_cat_id,count(*) as ct FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND q_epoch BETWEEN 1609943318 AND 1610548118 group by ll_cat_id; select calGetTrace();
 
+-----------------+
| calFlushCache() |
+-----------------+
| 0 |
+-----------------+
1 row in set (0.005 sec)
 
+-----------+--------+
| ll_cat_id | ct |
+-----------+--------+
| 4003 | 226292 |
| 4002 | 485903 |
+-----------+--------+
2 rows in set, 1 warning (0.832 sec)
 
+--------------------------------------------------------------------------
|calGetTrace() |
+--------------------------------------------------------------------------
Desc Mode Table TableOID ReferencedColumns PIO LIO PBE Elapsed Rows
BPS PM t0 604560 (ll_cat_id,q_epoch) 3016 2202 0 0.128 40
TAS UM - - - - - - 0.112 2
TNS UM - - - - - - 0.000 2
1 row in set (0.001 sec)
 
(2)
 
MariaDB [qradar]> select calFlushCache();select ll_cat_id,count(*) as ct FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND q_epoch BETWEEN 1609943318 AND 1610548118 group by ll_cat_id; select calGetTrace();
 
+-----------------+
| calFlushCache() |
+-----------------+
| 0 |
+-----------------+
1 row in set (0.003 sec)
 
+-----------+--------+
| ll_cat_id | ct |
+-----------+--------+
| 4003 | 226292 |
| 4002 | 485903 |
+-----------+--------+
2 rows in set, 1 warning (1.800 sec)
 
+--------------------------------------------------------------------------
|calGetTrace() |
+--------------------------------------------------------------------------
Desc Mode Table TableOID ReferencedColumns PIO LIO PBE Elapsed Rows
BPS PM t0 604560 (ll_cat_id,q_epoch) 3016 2202 0 0.158 40
TAS UM - - - - - - 0.136 2
TNS UM - - - - - - 0.000 2
1 row in set (0.001 sec)
 
(3)
 
MariaDB [qradar]> select calFlushCache();select ll_cat_id,count(*) as ct FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND q_epoch BETWEEN 1609943318 AND 1610548118 group by ll_cat_id; select calGetTrace();
 
+-----------------+
| calFlushCache() |
+-----------------+
| 0 |
+-----------------+
1 row in set (0.005 sec)
 
+-----------+--------+
| ll_cat_id | ct |
+-----------+--------+
| 4003 | 226292 |
| 4002 | 485903 |
+-----------+--------+
2 rows in set, 1 warning (0.607 sec)
 
+--------------------------------------------------------------------------
|calGetTrace() |
+--------------------------------------------------------------------------
Desc Mode Table TableOID ReferencedColumns PIO LIO PBE Elapsed Rows
BPS PM t0 604560 (ll_cat_id,q_epoch) 3016 2202 0 0.181 40
TAS UM - - - - - - 0.146 2
TNS UM - - - - - - 0.000 2
 
(4)
 
MariaDB [qradar]> select calFlushCache();select ll_cat_id,count(*) as ct FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND q_epoch BETWEEN 1609943318 AND 1610548118 group by ll_cat_id; select calGetTrace();
 
+-----------------+
| calFlushCache() |
+-----------------+
| 0 |
+-----------------+
1 row in set (0.005 sec)
 
+-----------+--------+
| ll_cat_id | ct |
+-----------+--------+
| 4003 | 226292 |
| 4002 | 485903 |
+-----------+--------+
2 rows in set, 1 warning (0.351 sec)
 
+--------------------------------------------------------------------------
|calGetTrace() |
+--------------------------------------------------------------------------
Desc Mode Table TableOID ReferencedColumns PIO LIO PBE Elapsed Rows
BPS PM t0 604560 (ll_cat_id,q_epoch) 3016 2202 0 0.121 40
TAS UM - - - - - - 0.099 2
TNS UM - - - - - - 0.000 2
1 row in set (0.001 sec)
 
(5)
 
MariaDB [qradar]> select calFlushCache();select ll_cat_id,count(*) as ct FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND q_epoch BETWEEN 1609943318 AND 1610548118 group by ll_cat_id; select calGetTrace();
 
+-----------------+
| calFlushCache() |
+-----------------+
| 0 |
+-----------------+
1 row in set (0.003 sec)
 
+-----------+--------+
| ll_cat_id | ct |
+-----------+--------+
| 4003 | 226292 |
| 4002 | 485903 |
+-----------+--------+
2 rows in set, 1 warning (0.440 sec)
 
+--------------------------------------------------------------------------
|calGetTrace() |
+--------------------------------------------------------------------------
Desc Mode Table TableOID ReferencedColumns PIO LIO PBE Elapsed Rows
BPS PM t0 604560 (ll_cat_id,q_epoch) 3016 2202 0 0.120 40
TAS UM - - - - - - 0.098 2
TNS UM - - - - - - 0.000 2
1 row in set (0.001 sec)
 
(6)
 
MariaDB [qradar]> select calFlushCache();select ll_cat_id,count(*) as ct FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND q_epoch BETWEEN 1609943318 AND 1610548118 group by ll_cat_id; select calGetTrace();
 
+-----------------+
| calFlushCache() |
+-----------------+
| 0 |
+-----------------+
1 row in set (0.004 sec)
 
+-----------+--------+
| ll_cat_id | ct |
+-----------+--------+
| 4003 | 226292 |
| 4002 | 485903 |
+-----------+--------+
2 rows in set, 1 warning (0.296 sec)
 
+--------------------------------------------------------------------------
|calGetTrace() |
+--------------------------------------------------------------------------
Desc Mode Table TableOID ReferencedColumns PIO LIO PBE Elapsed Rows
BPS PM t0 604560 (ll_cat_id,q_epoch) 3016 2202 0 0.177 40
TAS UM - - - - - - 0.160 2
TNS UM - - - - - - 0.000 2
1 row in set (0.001 sec)
 
(7)
 
MariaDB [qradar]> select calFlushCache();select ll_cat_id,count(*) as ct FROM q_2021_demo AS t0 WHERE t0.ll_cat_id IN (4002, 4003) AND q_epoch BETWEEN 1609943318 AND 1610548118 group by ll_cat_id; select calGetTrace();
 
+-----------------+
| calFlushCache() |
+-----------------+
| 0 |
+-----------------+
1 row in set (0.005 sec)
 
+-----------+--------+
| ll_cat_id | ct |
+-----------+--------+
| 4003 | 226292 |
| 4002 | 485903 |
+-----------+--------+
2 rows in set, 1 warning (9.793 sec)
 
+--------------------------------------------------------------------------
|calGetTrace() |
+--------------------------------------------------------------------------
Desc Mode Table TableOID ReferencedColumns PIO LIO PBE Elapsed Rows
BPS PM t0 604560 (ll_cat_id,q_epoch) 3016 2202 0 0.120 40
TAS UM - - - - - - 0.098 2
TNS UM - - - - - - 0.000 2
1 row in set (0.001 sec)

  • Summary of above results

    (1) 2 rows in set, 1 warning (0.832 sec)
    (2) 2 rows in set, 1 warning (1.800 sec)
    (3) 2 rows in set, 1 warning (0.607 sec)
    (4) 2 rows in set, 1 warning (0.351 sec)
    (5) 2 rows in set, 1 warning (0.440 sec)
    (6) 2 rows in set, 1 warning (0.296 sec)
    (7) 2 rows in set, 1 warning (9.793 sec)
    

  • free -m

    per5-qradar-maria-um1
                  total        used        free      shared  buff/cache   available
    Mem:          31976        2319       27749         162        1908       29130
    Swap:         16127           0       16127
    per5-qradar-maria-um2
                  total        used        free      shared  buff/cache   available
    Mem:          31976        3367       28033          98         576       28177
    Swap:         16127           0       16127
    per5-qradar-maria-pm1
                  total        used        free      shared  buff/cache   available
    Mem:          31976        7627         224         885       24124       23072
    Swap:         16127         569       15558
    per5-qradar-maria-pm2
                  total        used        free      shared  buff/cache   available
    Mem:          31976        8266         224         391       23486       22929
    Swap:         16127         231       15896
    per5-qradar-maria-pm3
                  total        used        free      shared  buff/cache   available
    Mem:          31976        8330         226         400       23419       22854
    Swap:         16127         233       15894
    per5-qradar-maria-pm4
                  total        used        free      shared  buff/cache   available
    Mem:          31976        6112         663         398       25200       25075
    Swap:         16127         217       15910
    per5-qradar-maria-pm5
                  total        used        free      shared  buff/cache   available
    Mem:          31976        7487         219         391       24270       23707
    Swap:         16127         236       15891
    

*Note that that executime time is random without any type of workload during this test. *


Generated at Thu Feb 08 02:50:50 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.