[
https://issues.apache.org/jira/browse/HBASE-30231?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18136817#comment-18136817
]
Andor Molnar commented on HBASE-30231:
--------------------------------------
I checked this against the current branch-2.6 code (2.6.8-SNAPSHOT); the same
code path is still there.
*Root cause (from reading the code, not reproduced)*
The double-checked locking in {{MetricsIO.getInstance()}} is correct, and it is
the only place that creates the {{RegionServer,sub=IO}} source, so this is not
a simple race between the split threads. I think the error in the stack trace
is a follow-up failure, not the original one:
# Hadoop's {{MetricsSystemImpl.register()}} reserves the source name first
({{{}DefaultMetricsSystem.sourceName(...){}}}, MetricsSystemImpl.java:229 in
Hadoop 3.4) and only then starts the source and registers it with JMX.
# Back in {{{}BaseSourceImpl{}}}/{{{}MetricsIOSourceImpl{}}}, more setup
follows the registration ({{{}MetricRegistries.global(){}}}, the metrics
adapter, the histograms).
# If anything throws after step 1, the name stays reserved but
{{MetricsIO.instance}} is never assigned.
# Every later {{getInstance()}} call then registers again and fails with
"Metrics source RegionServer,sub=IO already exists!" for the rest of the JVM's
life. This fits "it succeeded after a retry": the retry was a new JVM.
The original exception is never logged because {{groupOrSplitPhase}} keeps the
split futures in a {{HashSet}} and throws on whichever failed future it reaches
first, in no particular order.
[~Li Zhexi] , if you still have the full client log, could you check for any
other error from the {{LoadIncrementalHFiles-N}} threads around that time? That
would tell us what failed first.
*Impact*
{{HFile.updateReadLatency()}} also goes through
{{{}MetricsIO.getInstance(){}}}, so once this happens, every HFile read and
write in that JVM fails, not just bulk load splits. On a RegionServer that
would be much more serious than a one-off client error.
*On "is this necessary for client work?"*
No, it isn't. Bulk load clients, MR tasks writing HFiles, and tools like
HFilePrettyPrinter all start the Hadoop metrics system and a "RegionServer"
source just to record latency histograms nobody reads. Skipping it outside
server processes is worth a separate follow-up, though.
*Proposed fix*
The attached patch makes {{MetricsIO}} fall back to a no-op {{MetricsIOSource}}
(with one WARN log) if creating the real source throws a {{RuntimeException}}
or {{{}LinkageError{}}}. It never retries, since a retry would hit the reserved
name anyway. A metrics problem can then no longer fail HFile I/O. Unit tests in
{{TestMetricsIO}} cover the fallback.
Co-Authored-By: Claude Opus 5.5 <[email protected]>
> LoadIncrementalHFiles failed for MetricsException: Metrics source
> RegionServer,Sub=IO already exists
> ----------------------------------------------------------------------------------------------------
>
> Key: HBASE-30231
> URL: https://issues.apache.org/jira/browse/HBASE-30231
> Project: HBase
> Issue Type: Bug
> Components: metrics
> Affects Versions: 2.6.1
> Reporter: Li Zhexi
> Assignee: Li Zhexi
> Priority: Major
> Attachments: HBASE-30231.branch-2.6.patch
>
>
> when called
> org.apache.hadoop.hbase.tool.LoadIncrementalHFiles#doBulkLoad(Path hfofDir,
> final Admin admin, Table table, RegionLocator regionLocator) to load HFiles,
> with hadoop jar command.
> Showed the Error message:
> [LoadIncrementalHFiles-19] INFO org.apache.hadoop.io.compress.CodecPool - Got
> brand-new compressor [.snappy]
> [LoadIncrementalHFiles-19] INFO org.apache.hadoop.io.compress.CodecPool - Got
> brand-new compressor [.snappy]
> [LoadIncrementalHFiles-19] INFO org.apache.hadoop.metrics2.impl.MetricsConfig
> - Loaded properties from hadoop-metrics2.properties
> [LoadIncrementalHFiles-19] INFO
> org.apache.hadoop.metrics2.impl.MetricsSystemImpl - Scheduled Metric snapshot
> period at 10 second(s).
> [LoadIncrementalHFiles-19] INFO
> org.apache.hadoop.metrics2.impl.MetricsSystemImpl - HBase metrics system
> started
> [LoadIncrementalHFiles-19] INFO
> org.apache.hadoop.hbase.metrics.MetricRegistries - Loaded MetricRegistries
> class org.apache.hadoop.hbase.metrics.impl.MetricRegistriesImpl
> ERROR tool.LoadIncrementalHFiles: Unexpected execution exception during
> splitting
> java.util.concurrent.ExecutionException:
> org.apache.hadoop.metrics2.MetricsException: Metrics source
> RegionServer,sub=IO already exists!
> at java.util.concurrent.FutureTask.report(FutureTask.java:122)
> at java.util.concurrent.FutureTask.get(FutureTask.java:192)
> at
> org.apache.hadoop.hbase.tool.LoadIncrementalHFiles.groupOrSplitPhase(LoadIncrementalHFiles.java:662)
> at
> org.apache.hadoop.hbase.tool.LoadIncrementalHFiles.performBulkLoad(LoadIncrementalHFiles.java:454)
> at
> org.apache.hadoop.hbase.tool.LoadIncrementalHFiles.doBulkLoad(LoadIncrementalHFiles.java:371)
> at
> org.apache.hadoop.hbase.tool.LoadIncrementalHFiles.doBulkLoad(LoadIncrementalHFiles.java:285)
> at com.xx.xx.XXLoadFile.main(XXLoadFile.java:113)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at org.apache.hadoop.util.RunJar.run(RunJar.java:332)
> at org.apache.hadoop.util.RunJar.main(RunJar.java:247)
> Caused by: org.apache.hadoop.metrics2.MetricsException: Metrics source
> RegionServer,sub-IO already exists!
> at
> org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.newSourceName(DefaultMetricsSystem.java:152)
> at
> org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.sourceName(DefaultMetricsSystem.java:125)
> at
> org.apache.hadoop.metrics2.impl.MetricsSystemImpl.register(MetricsSystemImpl.java:229)
> at
> org.apache.hadoop.hbase.metrics.BaseSourceImpl.<init>(BaseSourceImpl.java:115)
> at
> org.apache.hadoop.hbase.io.MetricsIOSourceImpl.<init>(IOSourceImpl.java:44)
> at
> org.apache.hadoop.hbase.io.MetricsIOSourceImpl.<init>(IOSourceImpl.java:39)
> at
> org.apache.hadoop.hbase.regionserver.MetricsRegionServerSourceFactoryImpl.createIO(MetricsRegionServerSourceFactoryImpl.java:99)
> at org.apache.hadoop.hbase.io.MetricsIO.<init>(MetricsIO.java:36)
> at org.apache.hadoop.hbase.io.MetricsIO.getInstance(MetricsIO.java:52)
> at org.apache.hadoop.hbase.io.hfile.HFile.updateWriteLatency(HFile.java:204)
> at
> org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:1047)
> at
> org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:1032)
> at
> org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:1069)
> at
> org.apache.hadoop.hbase.io.hfile.HFileWriterImpl.close(HFileWriterImpl.java:646)
> at
> org.apache.hadoop.hbase.regionserver.StoreFileWriter$SingleStoreFileWriter.close(StoreFileWriter.java:786)
> at
> org.apache.hadoop.hbase.regionserver.StoreFileWriter$SingleStoreFileWriter.access$1300(StoreFileWriter.java:493)
> at
> org.apache.hadoop.hbase.regionserver.StoreFileWriter.close(StoreFileWriter.java:293)
> at
> org.apache.hadoop.hbase.tools.LoadIncrementalHFiles.copyHFileHalf(LoadIncrementalHFiles.java:1209)
> at
> org.apache.hadoop.hbase.tools.LoadIncrementalHFiles.splitStoreFile(LoadIncrementalHFiles.java:1157)
> at
> org.apache.hadoop.hbase.tools.LoadIncrementalHFiles.splitStoreFile(LoadIncrementalHFiles.java:702)
> at
> org.apache.hadoop.hbase.tools.LoadIncrementalHFiles.groupOrSplit(LoadIncrementalHFiles.java:825)
> at
> org.apache.hadoop.hbase.tools.LoadIncrementalHFiles$2.call(LoadIncrementalHFiles.java:652)
> at
> org.apache.hadoop.hbase.tools.LoadIncrementalHFiles$2.call(LoadIncrementalHFiles.java:648)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:750)
>
> The probability of this issue occurring is very low, it only happened once,
> and it succeeded after a retry. It cannot be reproduced.
> Seems HFile.updateWriteLatency 100% initilize MetricsIO, does it necessary
> for client work？
--
This message was sent by Atlassian Jira
(v10.3.26#10030026)
