Zero execution_time_ms reported for non-zero execution time plans even with look-near-best-plan=false settings

[mtakahar]

By default, the framework aborts each query execution once it exceeds the best known plan execution time for the query. This cut-off mechanism helps find the best performing plans efficiently.

This cut-off can be disabled by setting look-near-best-plan=false then the framework is supposed to run each plan to completion. This is very useful for evaluating the cost model quality by allowing collection of more data points.

However, despite the cut-off disabled and extended hard timeout settings, the value of execution_time_ms in the .json report is 0 for some query plans.

test-query-timeout = 9000
look-near-best-plan=false

Examples:

Planning Time: 0.041 ms, Execution Time: 0.657 ms, execution_time_ms: 0

{
    "tag": "",
    "query": "select * from t100 t1 where c2 >= 5",
    "query_hash": "43ea304b4c0146be00cbb949d9b41bd5",
    "tables": null,
    "optimizer_tips": null,
    "explain_hints": "IndexOnlyScan(t100)",
    "execution_plan": {
	"full_str": "Seq Scan on t100 t1  (cost=0.00..10.25 rows=92 width=4108) (actual time=0.437..0.637 rows=91 loops=1)\n  Remote Filter: (c2 >= 5)\nPlanning Time: 0.041 ms\nExecution Time: 0.657 ms\nPeak Memory Usage: 0 kB"
    },
    "execution_time_ms": 0,
    "result_cardinality": 0,
    "result_hash": null,
    "parameters": null,
    "optimizations": null,
    "execution_plan_heatmap": null
},

Planning Time: 0.051 ms, Execution Time: 182.441 ms, execution_time_ms: 0:

{
    "tag": "",
    "query": "select * from t10000w where c2 >= 1",
    "query_hash": "bfe9d27c59e56394679824213333f8ee",
    "tables": null,
    "optimizer_tips": null,
    "explain_hints": "IndexOnlyScan(t10000w)",
    "execution_plan": {
	"full_str": "Index Scan using t10000w_c2_c1 on t10000w  (cost=0.00..1228.88 rows=9999 width=16396) (actual time=6.299..181.759 rows=9997 loops=1)\n  Index Cond: (c2 >= 1)\nPlanning Time: 0.051 ms\nExecution Time: 182.441 ms\nPeak Memory Usage: 8324 kB"
    },
    "execution_time_ms": 0,
    "result_cardinality": 0,
    "result_hash": null,
    "parameters": null,
    "optimizations": null,
    "execution_plan_heatmap": null
}

Test case

• Included in the tarball attached to #2
• .json file produced with "EXPLAIN ANALYZE " from the same model attached here:
  yb_taqo_taqo-issues-2023-05-12-225515.json.gz

[mtakahar]

The look-near-best-plan=false still enforces the query timeout for each query based on the default plan execution time, and those missing time entries were from those that were slower than that.

Specifying extended skip-timeout-delta value, e.g., 120s, or even 600s helps collect more data points when necessary.