[
https://issues.apache.org/jira/browse/HUDI-5607?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
sivabalan narayanan closed HUDI-5607.
-------------------------------------
Resolution: Invalid
> 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
> Assignee: Alexey Kudinkin
> 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)
