Joe McDonnell created IMPALA-13416:
--------------------------------------
Summary: Investigate missing time in tuple cache node's profile
counters
Key: IMPALA-13416
URL: https://issues.apache.org/jira/browse/IMPALA-13416
Project: IMPALA
Issue Type: Improvement
Components: Backend
Affects Versions: Impala 4.5.0
Reporter: Joe McDonnell
When running TPC-H, the first run is storing a tuple cache entry. This takes
significant time, but the time isn't accounted for in the counters:
{noformat}
TUPLE_CACHE_NODE (id=11):(Total: 20s696ms, non-child: 18s134ms, %
non-child: 87.62%)
Combined Key: 34aa5de35a7e7b0f5879bd48e9a44ae3_1543855977
Node Lifecycle Event Timeline: 22s704ms
- Open Started: 61.807ms (61.807ms)
- Open Finished: 276.261ms (214.454ms)
- First Batch Requested: 276.281ms (19.629us)
- First Batch Returned: 363.759ms (87.478ms)
- Last Batch Returned: 22s704ms (22s340ms)
- Closed: 22s704ms (61.922us)
- InactiveTotalTime: 0.000ns
- NumTupleCacheHalted: 0 (0)
- NumTupleCacheHits: 0 (0)
- NumTupleCacheSkipped: 0 (0)
- PeakMemoryUsage: 4.08 MB (4275555)
- RowsReturned: 5.67M (5665668)
- RowsReturnedRate: 273.75 K/sec
- TotalTime: 20s696ms
- TupleCacheSerializeTime: 297.315ms
- TupleCacheWriteTime: 720.171ms{noformat}
This is 18 seconds of non-child time, but it's hard to see where it goes. We
should look into what operations are taking the time and include them in the
profile counters.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
