You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hudi.apache.org by "sivabalan narayanan (Jira)" <ji...@apache.org> on 2023/01/24 16:58:00 UTC
[jira] [Updated] (HUDI-5607) Repeated calls to metadata table reads
[ https://issues.apache.org/jira/browse/HUDI-5607?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
sivabalan narayanan updated HUDI-5607:
--------------------------------------
Fix Version/s: 0.13.0
> Repeated calls to metadata table reads
> --------------------------------------
>
> Key: HUDI-5607
> URL: https://issues.apache.org/jira/browse/HUDI-5607
> Project: Apache Hudi
> Issue Type: Bug
> Components: metadata
> Reporter: sivabalan narayanan
> Priority: Blocker
> Fix For: 0.13.0
>
>
> I was trying quick start locally and found duplicated log entries while reading from metadata table. not sure if its just metadata or any log record reader.
>
> {code:java}
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Building file system view for partition (asia/india/chennai)
> 23/01/24 08:51:50 INFO HoodieTableMetadataUtil: Loading latest merged file slices for metadata table partition files
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Took 0 ms to read 0 instants, 0 replaced file groups
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Building file system view for partition (americas/united_states/san_francisco)
> 23/01/24 08:51:50 INFO HoodieTableMetadataUtil: Loading latest merged file slices for metadata table partition files
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Took 0 ms to read 0 instants, 0 replaced file groups
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Building file system view for partition (americas/brazil/sao_paulo)
> 23/01/24 08:51:50 INFO HoodieTableMetadataUtil: Loading latest merged file slices for metadata table partition files
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Took 0 ms to read 0 instants, 0 replaced file groups
> 23/01/24 08:51:50 INFO ClusteringUtils: Found 0 files in pending clustering operations
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Building file system view for partition (files)
> 23/01/24 08:51:50 INFO ClusteringUtils: Found 0 files in pending clustering operations
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Building file system view for partition (files)
> 23/01/24 08:51:50 INFO ClusteringUtils: Found 0 files in pending clustering operations
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: Building file system view for partition (files)
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: addFilesToView: NumFiles=9, NumFileGroups=1, FileGroupsCreationTime=2, StoreTimeTaken=0
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: addFilesToView: NumFiles=9, NumFileGroups=1, FileGroupsCreationTime=1, StoreTimeTaken=0
> 23/01/24 08:51:50 INFO AbstractTableFileSystemView: addFilesToView: NumFiles=9, NumFileGroups=1, FileGroupsCreationTime=1, StoreTimeTaken=0
> 23/01/24 08:51:50 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20230124084917775__rollback__COMPLETED]}
> 23/01/24 08:51:50 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20230124084917775__rollback__COMPLETED]}
> 23/01/24 08:51:50 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20230124084917775__rollback__COMPLETED]}
> 23/01/24 08:51:50 INFO HoodieTableMetaClient: Loading HoodieTableMetaClient from file:/tmp/hudi_mdt_mor/.hoodie/metadata
> 23/01/24 08:51:50 INFO HoodieTableConfig: Loading table properties from file:/tmp/hudi_mdt_mor/.hoodie/metadata/.hoodie/hoodie.properties
> 23/01/24 08:51:50 INFO HoodieTableMetaClient: Loading HoodieTableMetaClient from file:/tmp/hudi_mdt_mor/.hoodie/metadata
> 23/01/24 08:51:50 INFO HoodieTableMetaClient: Loading HoodieTableMetaClient from file:/tmp/hudi_mdt_mor/.hoodie/metadata
> 23/01/24 08:51:50 INFO HoodieTableConfig: Loading table properties from file:/tmp/hudi_mdt_mor/.hoodie/metadata/.hoodie/hoodie.properties
> 23/01/24 08:51:50 INFO HoodieTableMetaClient: Finished Loading Table of type MERGE_ON_READ(version=1, baseFileFormat=HFILE) from file:/tmp/hudi_mdt_mor/.hoodie/metadata
> 23/01/24 08:51:50 INFO HoodieTableConfig: Loading table properties from file:/tmp/hudi_mdt_mor/.hoodie/metadata/.hoodie/hoodie.properties
> 23/01/24 08:51:50 INFO HoodieTableMetaClient: Finished Loading Table of type MERGE_ON_READ(version=1, baseFileFormat=HFILE) from file:/tmp/hudi_mdt_mor/.hoodie/metadata
> 23/01/24 08:51:50 INFO HoodieTableMetaClient: Finished Loading Table of type MERGE_ON_READ(version=1, baseFileFormat=HFILE) from file:/tmp/hudi_mdt_mor/.hoodie/metadata
> 23/01/24 08:51:50 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20230124084917775__deltacommit__COMPLETED]}
> 23/01/24 08:51:50 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20230124084917775__deltacommit__COMPLETED]}
> 23/01/24 08:51:50 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[20230124084917775__deltacommit__COMPLETED]}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-0-0', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-0-0', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-0-0', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a delete block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-0-0
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a delete block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-0-0
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a delete block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-0-0
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8', fileLen=-1}
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8', fileLen=-1}
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8 at instant 00000000000000
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8 at instant 00000000000000
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.1_0-7-8 at instant 00000000000000
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44', fileLen=-1}
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44', fileLen=-1}
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44 at instant 20230124084532515
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44 at instant 20230124084532515
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.2_0-38-44 at instant 20230124084532515
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110 at instant 20230124084646340
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110', fileLen=-1}
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110 at instant 20230124084646340
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.3_0-80-110 at instant 20230124084646340
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127 at instant 20230124084719371
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127', fileLen=-1}
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127 at instant 20230124084719371
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a data block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.4_0-94-127 at instant 20230124084719371
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a command block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Rolling back the last log block read in file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1
> 23/01/24 08:51:50 WARN AbstractHoodieLogRecordReader: TargetInstantTime 20230124084719371 invalid or extra rollback command block in file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Number of applied rollback blocks 1
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1', fileLen=-1}
> 23/01/24 08:51:50 INFO HoodieLogFormatReader: Moving to the next reader for logfile HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Scanning log file HoodieLogFile{pathStr='file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1', fileLen=-1}
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a command block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Reading a command block from file file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1
> 23/01/24 08:51:50 INFO AbstractHoodieLogRecordReader: Rolling back the last log block read in file:/tmp/hudi_mdt_mor/.hoodie/metadata/files/.files-0000_00000000000000.log.5_1-0-1 {code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)