You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@impala.apache.org by "Quanlong Huang (Code Review)" <ge...@cloudera.org> on 2023/05/25 11:25:38 UTC

[Impala-ASF-CR] IMPALA-6665: Tag CatalogOp logs with query ids

Quanlong Huang has uploaded a new patch set (#2). ( http://gerrit.cloudera.org:8080/19926 )

Change subject: IMPALA-6665: Tag CatalogOp logs with query ids
......................................................................

IMPALA-6665: Tag CatalogOp logs with query ids

Adds query id in TCatalogServiceRequestHeader. Coordinator uses it to
pass the query id in catalogd RPCs. The query id is then used in
catalogd to be set in the ThreadDebugInfo. It will be prepended to logs
of the thread executing the RPC.

Here is an example of a CTAS command. It actually contains two RPCs,
an execDdl and an updateCatalog request. The query id binds them
together.

I0524 22:16:58.439786 17112 JniUtil.java:166] 5043cba7eaa92133:600815f800000000] execDdl request: CREATE_TABLE_AS_SELECT test_generic_java_udfs_ea877ad4.replace_string_input issued by jenkins
I0524 22:16:58.450062 17112 Table.java:221] 5043cba7eaa92133:600815f800000000] createEventId_ for table: test_generic_java_udfs_ea877ad4.replace_string_input set to: 41893
I0524 22:16:58.450099 17112 Table.java:236] 5043cba7eaa92133:600815f800000000] lastSyncedEventId_ for table: test_generic_java_udfs_ea877ad4.replace_string_input set from -1 to 41893
I0524 22:16:58.450129 17112 CatalogOpExecutor.java:3607] 5043cba7eaa92133:600815f800000000] Created catalog table test_generic_java_udfs_ea877ad4.replace_string_input with create event id 41893
I0524 22:16:58.450171 17112 JniUtil.java:177] 5043cba7eaa92133:600815f800000000] Finished execDdl request: CREATE_TABLE_AS_SELECT test_generic_java_udfs_ea877ad4.replace_string_input issued by jenkins. Time spent: 11ms
I0524 22:16:58.469336  8057 JniUtil.java:166] 5043cba7eaa92133:600815f800000000] updateCatalog request: Update catalog for test_generic_java_udfs_ea877ad4.replace_string_input
I0524 22:16:58.469403  8057 TableLoadingMgr.java:72] 5043cba7eaa92133:600815f800000000] Loading metadata for table: test_generic_java_udfs_ea877ad4.replace_string_input
I0524 22:16:58.469463 12091 TableLoader.java:76] Loading metadata for: test_generic_java_udfs_ea877ad4.replace_string_input (Load for INSERT)
I0524 22:16:58.469496  8057 TableLoadingMgr.java:74] 5043cba7eaa92133:600815f800000000] Remaining items in queue: 0. Loads in progress: 1
I0524 22:16:58.473240 12091 Table.java:221] createEventId_ for table: test_generic_java_udfs_ea877ad4.replace_string_input set to: 41893
I0524 22:16:58.473273 12091 Table.java:236] lastSyncedEventId_ for table: test_generic_java_udfs_ea877ad4.replace_string_input set from -1 to 41893
I0524 22:16:58.473307 12091 HdfsTable.java:1243] Loading metadata for table definition and all partition(s) of test_generic_java_udfs_ea877ad4.replace_string_input (Load for INSERT)
I0524 22:16:58.473488 12091 HdfsTable.java:1863] Loaded 1 columns from HMS. Actual columns: 1
I0524 22:16:58.476650 12091 HdfsTable.java:3028] Load Valid Write Id List Done. Time taken: 1.545us
I0524 22:16:58.476675 12091 HdfsTable.java:1282] Fetching partition metadata from the Metastore: test_generic_java_udfs_ea877ad4.replace_string_input
I0524 22:16:58.477051 12091 MetaStoreUtil.java:190] Fetching 0 partitions for: test_generic_java_udfs_ea877ad4.replace_string_input using partition batch size: 1000
I0524 22:16:58.477066 12091 HdfsTable.java:1289] Fetched partition metadata from the Metastore: test_generic_java_udfs_ea877ad4.replace_string_input
I0524 22:16:58.477887 12091 HdfsTable.java:813] Loaded file and block metadata for test_generic_java_udfs_ea877ad4.replace_string_input partitions: . Time taken: 442.635us
I0524 22:16:58.478031 12091 Table.java:1048] last refreshed event id for table: test_generic_java_udfs_ea877ad4.replace_string_input set to: -1
I0524 22:16:58.478052 12091 TableLoader.java:176] Loaded metadata for: test_generic_java_udfs_ea877ad4.replace_string_input (8ms)
I0524 22:16:58.479095  8057 CatalogOpExecutor.java:6937] 5043cba7eaa92133:600815f800000000] 1 new files detected for table test_generic_java_udfs_ea877ad4.replace_string_input
I0524 22:16:58.479876  8057 MetastoreShim.java:476] 5043cba7eaa92133:600815f800000000] Firing 1 insert event(s) for test_generic_java_udfs_ea877ad4.replace_string_input
I0524 22:16:58.484315  8057 MetastoreShim.java:414] 5043cba7eaa92133:600815f800000000] Time taken to fire insert events on table test_generic_java_udfs_ea877ad4.replace_string_input: 4 msec
I0524 22:16:58.484354  8057 CatalogServiceCatalog.java:1126] 5043cba7eaa92133:600815f800000000] Added eventId 41894 in table's test_generic_java_udfs_ea877ad4.replace_string_input in-flight events
I0524 22:16:58.487223  8057 HdfsTable.java:1243] 5043cba7eaa92133:600815f800000000] Reloading metadata for all partition(s) of test_generic_java_udfs_ea877ad4.replace_string_input (INSERT)
I0524 22:16:58.487262  8057 HdfsTable.java:3028] 5043cba7eaa92133:600815f800000000] Load Valid Write Id List Done. Time taken: 1.506us
I0524 22:16:58.487931  8057 HdfsTable.java:813] 5043cba7eaa92133:600815f800000000] Loaded file and block metadata for test_generic_java_udfs_ea877ad4.replace_string_input partitions: . Time taken: 262.133us
I0524 22:16:58.487958  8057 HdfsTable.java:1280] 5043cba7eaa92133:600815f800000000] Incrementally loaded table metadata for: test_generic_java_udfs_ea877ad4.replace_string_input
I0524 22:16:58.488173  8057 JniUtil.java:177] 5043cba7eaa92133:600815f800000000] Finished updateCatalog request: Update catalog for test_generic_java_udfs_ea877ad4.replace_string_input. Time spent: 19ms

Note that table loading is executed asynchronizedly in other Java
threads. They are not tagged with query id yet. We can improve this in
the future.

Tests:
 - Build and run tests locally

Change-Id: I90933433e23a171993de3c1ee355d776a53eda66
---
M be/src/catalog/catalog.cc
M be/src/service/client-request-state.cc
M common/thrift/CatalogService.thrift
M fe/src/main/java/org/apache/impala/analysis/ResetMetadataStmt.java
M fe/src/main/java/org/apache/impala/analysis/StmtMetadataLoader.java
M fe/src/main/java/org/apache/impala/catalog/FeCatalog.java
M fe/src/main/java/org/apache/impala/catalog/ImpaladCatalog.java
M fe/src/main/java/org/apache/impala/catalog/local/LocalCatalog.java
M fe/src/main/java/org/apache/impala/service/FeSupport.java
M fe/src/main/java/org/apache/impala/service/Frontend.java
M fe/src/test/java/org/apache/impala/analysis/StmtMetadataLoaderTest.java
M fe/src/test/java/org/apache/impala/common/FrontendFixture.java
M fe/src/test/java/org/apache/impala/common/FrontendTestBase.java
M fe/src/test/java/org/apache/impala/testutil/ImpaladTestCatalog.java
14 files changed, 56 insertions(+), 19 deletions(-)


  git pull ssh://gerrit.cloudera.org:29418/Impala-ASF refs/changes/26/19926/2
-- 
To view, visit http://gerrit.cloudera.org:8080/19926
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: newpatchset
Gerrit-Change-Id: I90933433e23a171993de3c1ee355d776a53eda66
Gerrit-Change-Number: 19926
Gerrit-PatchSet: 2
Gerrit-Owner: Quanlong Huang <hu...@gmail.com>