[HIVE-27773] get_valid_write_ids is being called multiple times for a single query

• Type: Task
• Status: In Progress
• Priority: Major
• Resolution: Unresolved
• Labels: pull-request-available
• Assignee: Ramesh Kumar Thangarajan
• Reporter: Ramesh Kumar Thangarajan
• Created: 05/Oct/23 16:08
• Updated: 28/Mar/24 00:19

Description

Looking at the below logs suggest that the get_valid_write_ids is not cached for a single query for a single table. It is being called multiple times across different phases in the compilation of the query. We should verify if we can safely cache and re use the results. That way we can avoid around 40-50 ms out of 678ms compilation time.

 

2023-09-19T02:55:06,940 INFO [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] ql.Driver: Compiling command(queryId=rameshkumar_20230919025506_b005cc57-1717-4798-b8da-b502aa7ca3d6):
2023-09-19T02:55:06,967 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: <PERFLOG method=get_valid_write_ids from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-09-19T02:55:06,979 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: </PERFLOG method=get_valid_write_ids start=1695117306967 end=1695117306979 duration=12 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler retryCount=0 error=false>
2023-09-19T02:55:06,980 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: <PERFLOG method=get_valid_write_ids from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-09-19T02:55:06,986 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: </PERFLOG method=get_valid_write_ids start=1695117306980 end=1695117306986 duration=6 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler retryCount=0 error=false>
2023-09-19T02:55:06,988 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: <PERFLOG method=get_valid_write_ids from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-09-19T02:55:06,995 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: </PERFLOG method=get_valid_write_ids start=1695117306988 end=1695117306995 duration=7 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler retryCount=0 error=false>
2023-09-19T02:55:06,997 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: <PERFLOG method=get_valid_write_ids from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-09-19T02:55:07,007 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: </PERFLOG method=get_valid_write_ids start=1695117306997 end=1695117307007 duration=10 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler retryCount=0 error=false>
2023-09-19T02:55:07,009 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: <PERFLOG method=get_valid_write_ids from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-09-19T02:55:07,017 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: </PERFLOG method=get_valid_write_ids start=1695117307009 end=1695117307017 duration=8 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler retryCount=0 error=false>
2023-09-19T02:55:07,018 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: <PERFLOG method=get_valid_write_ids from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-09-19T02:55:07,026 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: </PERFLOG method=get_valid_write_ids start=1695117307018 end=1695117307026 duration=8 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler retryCount=0 error=false>
2023-09-19T02:55:07,059 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: <PERFLOG method=get_valid_write_ids from=org.apache.hadoop.hive.metastore.RetryingHMSHandler>
2023-09-19T02:55:07,068 DEBUG [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] metrics.PerfLogger: </PERFLOG method=get_valid_write_ids start=1695117307059 end=1695117307068 duration=9 from=org.apache.hadoop.hive.metastore.RetryingHMSHandler retryCount=0 error=false>
2023-09-19T02:55:07,618 INFO [fa0fa087-7e2c-45b8-bd27-b94fbbe23e49 Listener at 0.0.0.0/50501] ql.Driver: Completed compiling command(queryId=rameshkumar_20230919025506_b005cc57-1717-4798-b8da-b502aa7ca3d6); Time taken: 0.678 seconds

Issue Links

• links to: GitHub Pull Request #4787