Hello Kurt Deschler, Riza Suminto, Impala Public Jenkins,
I'd like you to reexamine a change. Please visit
http://gerrit.cloudera.org:8080/19926
to look at the new patch set (#3).
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.
Note that prepending the query id got from the thread local
ThreadDebugInfo is an existing mechanism already used in coordinator.
All log levels will be affected.
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/3
--
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: 3
Gerrit-Owner: Quanlong Huang <[email protected]>
Gerrit-Reviewer: Impala Public Jenkins <[email protected]>
Gerrit-Reviewer: Kurt Deschler <[email protected]>
Gerrit-Reviewer: Quanlong Huang <[email protected]>
Gerrit-Reviewer: Riza Suminto <[email protected]>
