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] [Created] (HUDI-5607) Repeated calls to metadata table reads

sivabalan narayanan created HUDI-5607:
-----------------------------------------

             Summary: 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


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)