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 <huangquanl...@gmail.com>