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)
