[
https://issues.apache.org/jira/browse/IMPALA-12870?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18032384#comment-18032384
]
ASF subversion and git services commented on IMPALA-12870:
----------------------------------------------------------
Commit ff8bb33b91cd689bfaf2a51a19d0f615edd33d54 in impala's branch
refs/heads/master from stiga-huang
[ https://gitbox.apache.org/repos/asf?p=impala.git;h=ff8bb33b9 ]
IMPALA-12870: Tag query id for Java pool threads
Logs from Java threads running in ExecutorService are missing the query
id which is stored in the C++ thread-local ThreadDebugInfo variable.
This patch adds JNI calls for Java threads to manage the ThreadDebugInfo
variable. Currently two thread pools are changed:
- MissingTable loading pool in StmtMetadataLoader.parallelTableLoad().
- Table loading pool in TableLoadingMgr.
MissingTable loading pool only lives within the parallelTableLoad()
method. So we initialize ThreadDebugInfo with the queryId at the
beginning of the thread and delete it at the end of the thread. Note
that a thread might be reused to load different tables, but they all
belong to the same query.
Table loading pool is a long running pool in catalogd that never
shut down. Threads in it is used to load tables triggered by different
queries. We initialize ThreadDebugInfo as the above but update it when
the thread starts loading table for a different query id, and reset it
when the loading is done. The query id is passed down from the catalogd
RPC request headers.
Tests:
- Added e2e test to verify the logs.
- Ran existing CORE tests.
Change-Id: I83cca55edc72de35f5e8c5422efc104e6aa894c1
Reviewed-on: http://gerrit.cloudera.org:8080/23558
Reviewed-by: Impala Public Jenkins <[email protected]>
Tested-by: Impala Public Jenkins <[email protected]>
> Tag TableLoader logs with query ids
> -----------------------------------
>
> Key: IMPALA-12870
> URL: https://issues.apache.org/jira/browse/IMPALA-12870
> Project: IMPALA
> Issue Type: Improvement
> Components: Catalog
> Reporter: Quanlong Huang
> Assignee: Quanlong Huang
> Priority: Critical
>
> In local-catalog mode, the reason of table metadata loading is logged as
> "needed by coordinator". It'd be helpful to tag the logs with the query ids.
> So we can confirm which query actually triggers metadata loading on the table.
> Here are the catalogd logs for a REFRESH statement in local-catalog mode. The
> first part is loading the metadata of the table triggered by the planning
> phase in the coordinator. No query ids are tagged in this part. The second
> part starts with the resetMetadata request. Logs are tagged with query ids.
> That's what we want.
> {noformat}
> I0305 09:05:32.802394 11245 TableLoadingMgr.java:72] Loading metadata for
> table: functional.alltypestiny
> I0305 09:05:32.802747 11336 TableLoader.java:76] Loading metadata for:
> functional.alltypestiny (needed by coordinator)
> I0305 09:05:32.803429 11245 TableLoadingMgr.java:74] Remaining items in
> queue: 0. Loads in progress: 1
> I0305 09:05:32.831334 11336 Table.java:244] createEventId_ for table:
> functional.alltypestiny set to: -1
> I0305 09:05:32.831614 11336 HdfsTable.java:1251] Loading metadata for table
> definition and all partition(s) of functional.alltypestiny (needed by
> coordinator)
> I0305 09:05:32.846228 11336 HdfsTable.java:1886] Loaded 13 columns from HMS.
> Actual columns: 13
> I0305 09:05:32.867285 11336 HdfsTable.java:3065] Load Valid Write Id List
> Done. Time taken: 8.479us
> I0305 09:05:32.867355 11336 HdfsTable.java:1291] Fetching partition metadata
> from the Metastore: functional.alltypestiny
> I0305 09:05:32.870157 11336 MetaStoreUtil.java:190] Fetching 4 partitions
> for: functional.alltypestiny using partition batch size: 1000
> I0305 09:05:32.887723 11336 MetaStoreUtil.java:208] Fetched 4/4 partitions
> for table functional.alltypestiny
> I0305 09:05:32.887784 11336 HdfsTable.java:1298] Fetched partition metadata
> from the Metastore: functional.alltypestiny
> I0305 09:05:32.893668 11336 ParallelFileMetadataLoader.java:224] Loading file
> and block metadata for 4 paths for table functional.alltypestiny using a
> thread pool of size 4
> I0305 09:05:32.898553 11336 HdfsTable.java:821] Loaded file and block
> metadata for functional.alltypestiny partitions: year=2009/month=1,
> year=2009/month=2, year=2009/month=3, and 1 others. Time taken: 5.429ms
> I0305 09:05:32.899248 11336 Table.java:1104] last refreshed event id for
> table: functional.alltypestiny set to: -1
> I0305 09:05:32.899305 11336 TableLoader.java:176] Loaded metadata for:
> functional.alltypestiny (96ms)
> I0305 09:05:32.930579 11245 JniUtil.java:166]
> c740fb0d001885d9:6a12143000000000] resetMetadata request: REFRESH TABLE
> functional.alltypestiny issued by quanlong
> I0305 09:05:32.955250 11245 CatalogServiceCatalog.java:2642]
> c740fb0d001885d9:6a12143000000000] Refreshing table metadata:
> functional.alltypestiny
> I0305 09:05:32.963577 11245 HdfsTable.java:1251]
> c740fb0d001885d9:6a12143000000000] Reloading metadata for table definition
> and all partition(s) of functional.alltypestiny (REFRESH TABLE
> functional.alltypestiny issued by quanlong)
> I0305 09:05:32.966183 11245 HdfsTable.java:1886]
> c740fb0d001885d9:6a12143000000000] Loaded 13 columns from HMS. Actual
> columns: 13
> I0305 09:05:32.975786 11245 HdfsTable.java:3065]
> c740fb0d001885d9:6a12143000000000] Load Valid Write Id List Done. Time taken:
> 7.288us
> I0305 09:05:32.981313 11245 ParallelFileMetadataLoader.java:224]
> c740fb0d001885d9:6a12143000000000] Refreshing file and block metadata for 4
> paths for table functional.alltypestiny using a thread pool of size 4
> I0305 09:05:32.985464 11245 HdfsTable.java:821]
> c740fb0d001885d9:6a12143000000000] Loaded file and block metadata for
> functional.alltypestiny partitions: year=2009/month=1, year=2009/month=2,
> year=2009/month=3, and 1 others. Time taken: 5.839ms
> I0305 09:05:32.985622 11245 HdfsTable.java:1289]
> c740fb0d001885d9:6a12143000000000] Incrementally loaded table metadata for:
> functional.alltypestiny
> I0305 09:05:32.985924 11245 CatalogServiceCatalog.java:2703]
> c740fb0d001885d9:6a12143000000000] Refreshed table metadata:
> functional.alltypestiny
> I0305 09:05:32.985971 11245 Table.java:1104]
> c740fb0d001885d9:6a12143000000000] last refreshed event id for table:
> functional.alltypestiny set to: -1
> I0305 09:05:32.988221 11245 JniUtil.java:177]
> c740fb0d001885d9:6a12143000000000] Finished resetMetadata request: REFRESH
> TABLE functional.alltypestiny issued by quanlong. Time spent: 58ms{noformat}
> CC [~fangyurao]
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
