Hello Zoltan Borok-Nagy, Zihao Ye, Impala Public Jenkins,
I'd like you to reexamine a change. Please visit
http://gerrit.cloudera.org:8080/20491
to look at the new patch set (#15).
Change subject: IMPALA-12443: Add catalog timeline for all DDL profiles
......................................................................
IMPALA-12443: Add catalog timeline for all DDL profiles
This is a follow-up work of IMPALA-12024 where we add the catalog
timeline for CreateTable statements. Using the same mechanism, this
patch adds catalog timeline for all DDL/DML profiles, including
REFRESH and INSERT.
The goal is to add timeline markers after each step that could be
blocked, e.g. acquiring locks, external RPCs. So we can better debug
slow DDLs with the catalog timeline in profiles.
Tried to add some constant strings for widely used events, e.g. "Fetched
table from Metastore". Didn't do so for events that only occurs once.
Most of the catalog methods now have a new argument for tracking the
execution timeline. To avoid adding null checks everywhere, for code
paths that don't need a catalog profile, e.g. EventProcessor, uses a
static noop EventSequence as the argument. We can replace it in future
works, e.g. expose execution timeline of a slow processing on an HMS
event.
This patch also removes some unused overloads of HdfsTable#load() and
HdfsTable#reloadPartitionsFromNames().
Example timeline for a REFRESH statement on an unloaded table
(IncompleteTable):
Catalog Server Operation: 2s300ms
- Got catalog version read lock: 26.407us (26.407us)
- Start loading table: 314.663us (288.256us)
- Got Metastore client: 629.599us (314.936us)
- Fetched table from Metastore: 7.248ms (6.618ms)
- Loaded table schema: 27.947ms (20.699ms)
- Preloaded permissions cache for 1824 partitions: 1s514ms (1s486ms)
- Got access level: 1s514ms (588.314us)
- Created partition builders: 2s103ms (588.270ms)
- Start loading file metadata: 2s103ms (49.760us)
- Loaded file metadata for 1824 partitions: 2s282ms (179.839ms)
- Async loaded table: 2s289ms (6.931ms)
- Loaded table from scratch: 2s289ms (72.038us)
- Got table read lock: 2s289ms (2.289us)
- Finished resetMetadata request: 2s300ms (10.188ms)
Example timeline for an INSERT statement:
Catalog Server Operation: 178.120ms
- Got catalog version read lock: 4.238us (4.238us)
- Got catalog version write lock and table write lock: 52.768us (48.530us)
- Got Metastore client: 15.768ms (15.715ms)
- Fired Metastore events: 156.650ms (140.882ms)
- Got Metastore client: 163.317ms (6.666ms)
- Fetched table from Metastore: 166.561ms (3.244ms)
- Start refreshing file metadata: 167.961ms (1.399ms)
- Loaded file metadata for 24 partitions: 177.679ms (9.717ms)
- Reloaded table metadata: 178.021ms (342.261us)
- Finished updateCatalog request: 178.120ms (98.929us)
Example timeline for a "COMPUTE STATS tpcds_parquet.store_sales":
Catalog Server Operation: 6s737ms
- Got catalog version read lock: 19.971us (19.971us)
- Got catalog version write lock and table write lock: 50.255us (30.284us)
- Got Metastore client: 171.819us (121.564us)
- Updated column stats: 25.560ms (25.388ms)
- Got Metastore client: 69.298ms (43.738ms)
- Altered 500 partitions in Metastore: 1s894ms (1s825ms)
- Altered 1000 partitions in Metastore: 3s558ms (1s664ms)
- Altered 1500 partitions in Metastore: 5s144ms (1s586ms)
- Altered 1824 partitions in Metastore: 6s205ms (1s060ms)
- Got Metastore client: 6s205ms (329.481us)
- Altered table in Metastore: 6s216ms (11.073ms)
- Got Metastore client: 6s216ms (13.377us)
- Fetched table from Metastore: 6s219ms (2.419ms)
- Loaded table schema: 6s223ms (4.130ms)
- Got current Metastore event id 19017: 6s639ms (415.690ms)
- Start loading file metadata: 6s639ms (9.591us)
- Loaded file metadata for 1824 partitions: 6s729ms (90.196ms)
- Reloaded table metadata: 6s735ms (5.865ms)
- DDL finished: 6s737ms (2.255ms)
Example timeline for a global INVALIDATE METADATA:
Catalog Server Operation: 301.618ms
- Got catalog version write lock: 9.908ms (9.908ms)
- Got Metastore client: 9.922ms (14.013us)
- Got database list: 11.396ms (1.473ms)
- Loaded functions of default: 44.919ms (33.523ms)
- Loaded TableMeta of 82 tables in database default: 47.524ms (2.604ms)
- Loaded functions of functional: 50.846ms (3.321ms)
- Loaded TableMeta of 101 tables in database functional: 52.580ms (1.734ms)
- Loaded functions of functional_avro: 54.861ms (2.281ms)
- Loaded TableMeta of 35 tables in database functional_avro: 55.789ms
(928.120us)
...
- Loaded functions of tpch_text_gzip: 299.503ms (1.710ms)
- Loaded TableMeta of 8 tables in database tpch_text_gzip: 300.288ms
(784.725us)
- Updated catalog cache: 300.366ms (78.045us)
- Finished resetMetadata request: 301.618ms (1.251ms)
Tests:
- Add e2e test to verify the catalog timeline in some DDLs.
- Ran CORE tests
Change-Id: Ifbceefaeb24c66eb1a064c449d6f56077ea347c5
---
M be/src/exec/catalog-op-executor.cc
M be/src/exec/catalog-op-executor.h
M be/src/service/client-request-state.cc
M be/src/service/client-request-state.h
M be/src/service/impala-server.cc
M common/thrift/CatalogService.thrift
M fe/src/main/java/org/apache/impala/catalog/Catalog.java
M fe/src/main/java/org/apache/impala/catalog/CatalogServiceCatalog.java
M fe/src/main/java/org/apache/impala/catalog/CatalogdTableInvalidator.java
M fe/src/main/java/org/apache/impala/catalog/DataSourceTable.java
M fe/src/main/java/org/apache/impala/catalog/HBaseTable.java
M fe/src/main/java/org/apache/impala/catalog/HdfsTable.java
M fe/src/main/java/org/apache/impala/catalog/IcebergTable.java
M fe/src/main/java/org/apache/impala/catalog/IncompleteTable.java
M fe/src/main/java/org/apache/impala/catalog/KuduTable.java
M fe/src/main/java/org/apache/impala/catalog/MaterializedViewHdfsTable.java
M fe/src/main/java/org/apache/impala/catalog/Table.java
M fe/src/main/java/org/apache/impala/catalog/TableLoader.java
M fe/src/main/java/org/apache/impala/catalog/TableLoadingMgr.java
M fe/src/main/java/org/apache/impala/catalog/View.java
M fe/src/main/java/org/apache/impala/catalog/events/MetastoreEvents.java
M
fe/src/main/java/org/apache/impala/catalog/events/MetastoreEventsProcessor.java
M
fe/src/main/java/org/apache/impala/catalog/metastore/CatalogMetastoreServiceHandler.java
M fe/src/main/java/org/apache/impala/service/CatalogOpExecutor.java
M fe/src/main/java/org/apache/impala/service/JniCatalog.java
M fe/src/main/java/org/apache/impala/service/KuduCatalogOpExecutor.java
M fe/src/main/java/org/apache/impala/util/EventSequence.java
M fe/src/main/java/org/apache/impala/util/KuduUtil.java
A fe/src/main/java/org/apache/impala/util/NoOpEventSequence.java
M fe/src/test/java/org/apache/impala/catalog/CatalogTest.java
M fe/src/test/java/org/apache/impala/catalog/CatalogdTableInvalidatorTest.java
M fe/src/test/java/org/apache/impala/catalog/PartialCatalogInfoWriteIdTest.java
M
fe/src/test/java/org/apache/impala/catalog/events/EventsProcessorStressTest.java
M
fe/src/test/java/org/apache/impala/catalog/events/MetastoreEventsProcessorTest.java
M fe/src/test/java/org/apache/impala/common/FrontendFixture.java
M fe/src/test/java/org/apache/impala/testutil/CatalogServiceTestCatalog.java
M fe/src/test/java/org/apache/impala/testutil/ImpaladTestCatalog.java
M tests/query_test/test_observability.py
38 files changed, 1,068 insertions(+), 651 deletions(-)
git pull ssh://gerrit.cloudera.org:29418/Impala-ASF refs/changes/91/20491/15
--
To view, visit http://gerrit.cloudera.org:8080/20491
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: newpatchset
Gerrit-Change-Id: Ifbceefaeb24c66eb1a064c449d6f56077ea347c5
Gerrit-Change-Number: 20491
Gerrit-PatchSet: 15
Gerrit-Owner: Quanlong Huang <huangquanl...@gmail.com>
Gerrit-Reviewer: Impala Public Jenkins <impala-public-jenk...@cloudera.com>
Gerrit-Reviewer: Quanlong Huang <huangquanl...@gmail.com>
Gerrit-Reviewer: Zihao Ye <eyiz...@163.com>
Gerrit-Reviewer: Zoltan Borok-Nagy <borokna...@cloudera.com>
