[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal usage
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andrew Purtell updated HBASE-17072:
---
Fix Version/s: 1.3.3
> CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal
> usage
>
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 1.2.0, 2.0.0
>Reporter: Eiichi Sato
>Assignee: Eiichi Sato
>Priority: Critical
> Fix For: 1.4.0, 0.98.24, 1.3.3, 2.0.0
>
> Attachments: HBASE-17072-0.98.patch, HBASE-17072.branch-1.001.patch,
> HBASE-17072.master.001.patch, HBASE-17072.master.002.patch,
> HBASE-17072.master.003.patch, HBASE-17072.master.004.patch,
> HBASE-17072.master.005.patch, HBASE-17072.master.005.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal usage
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andrew Purtell updated HBASE-17072:
---
Attachment: HBASE-17072-0.98.patch
When backporting this to 0.98 I found a multithreaded unit test in
TestHFileBlock would fail due to concurrent read/update to the cached header
ByteBuffer's position. In that test there is more than one read in progress
with the same next offset. This is what I've done differently:
{code}
PrefetchedHeader ph = prefetchedHeader.getAndSet(null); // be multithread
safe
ByteBuffer headerBuf = null;
if (ph != null) {
if (ph.offset == offset) {
headerBuf = ph.buf; // our previous read, use the cached buffer
} else {
prefetchedHeader.set(ph); // not our previous read, put back
}
}
{code}
Only the first thread through will get the buffer if the offset matches. If the
offset does not match or if another thread claimed the buffer a concurrently
executing thread will just get {{null}}.
The master patch does only:
{code}
PrefetchedHeader ph = this.prefetchedHeader.get();
return ph != null && ph.offset == offset? ph.buf: null;
{code}
More than one thread can get a reference to the buffer if the offset test
succeeds. Could be fine for master, just pointing this out. Might be relevant
for other backports. 1.1?
> CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal
> usage
>
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
>Assignee: Eiichi Sato
>Priority: Critical
> Fix For: 2.0.0, 1.4.0, 0.98.24
>
> Attachments: HBASE-17072-0.98.patch, HBASE-17072.branch-1.001.patch,
> HBASE-17072.master.001.patch, HBASE-17072.master.002.patch,
> HBASE-17072.master.003.patch, HBASE-17072.master.004.patch,
> HBASE-17072.master.005.patch, HBASE-17072.master.005.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
>
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal usage
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andrew Purtell updated HBASE-17072:
---
Fix Version/s: 0.98.24
> CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal
> usage
>
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
>Assignee: Eiichi Sato
>Priority: Critical
> Fix For: 2.0.0, 1.4.0, 0.98.24
>
> Attachments: HBASE-17072-0.98.patch, HBASE-17072.branch-1.001.patch,
> HBASE-17072.master.001.patch, HBASE-17072.master.002.patch,
> HBASE-17072.master.003.patch, HBASE-17072.master.004.patch,
> HBASE-17072.master.005.patch, HBASE-17072.master.005.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal usage
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Assignee: Eiichi Sato (was: stack)
Priority: Critical (was: Major)
Marking this critical because a long-standing issue that folks have identified
a few times as problematic and have even tried to fix a couple of times in the
past.
Also assigned [~sato_eiichi] the issue because of the amount of work done
finding root cause.
> CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal
> usage
>
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
>Assignee: Eiichi Sato
>Priority: Critical
> Fix For: 2.0.0, 1.4.0
>
> Attachments: HBASE-17072.branch-1.001.patch,
> HBASE-17072.master.001.patch, HBASE-17072.master.002.patch,
> HBASE-17072.master.003.patch, HBASE-17072.master.004.patch,
> HBASE-17072.master.005.patch, HBASE-17072.master.005.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal usage
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Resolution: Fixed
Assignee: stack
Hadoop Flags: Reviewed
Fix Version/s: 1.4.0
2.0.0
Status: Resolved (was: Patch Available)
Pushed to removal of thread local to master and branch-1.
Let me know if you want this one applied [~mantonov] and [~busbey] (might be
late for 1.2 but it is a cleanup of a long-standing trash-making and perf
issue).
> CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal
> usage
>
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
>Assignee: stack
> Fix For: 2.0.0, 1.4.0
>
> Attachments: HBASE-17072.branch-1.001.patch,
> HBASE-17072.master.001.patch, HBASE-17072.master.002.patch,
> HBASE-17072.master.003.patch, HBASE-17072.master.004.patch,
> HBASE-17072.master.005.patch, HBASE-17072.master.005.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal usage
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Attachment: HBASE-17072.branch-1.001.patch
> CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal
> usage
>
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.branch-1.001.patch,
> HBASE-17072.master.001.patch, HBASE-17072.master.002.patch,
> HBASE-17072.master.003.patch, HBASE-17072.master.004.patch,
> HBASE-17072.master.005.patch, HBASE-17072.master.005.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal usage
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Attachment: HBASE-17072.master.005.patch
Seems to pass locally. Retry.
> CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal
> usage
>
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.master.001.patch,
> HBASE-17072.master.002.patch, HBASE-17072.master.003.patch,
> HBASE-17072.master.004.patch, HBASE-17072.master.005.patch,
> HBASE-17072.master.005.patch, disable-block-header-cache.patch,
> mat-threadlocals.png, mat-threads.png, metrics.png, slave1.svg, slave2.svg,
> slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal usage
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Summary: CPU usage starts to climb up to 90-100% when using G1GC; purge
ThreadLocal usage (was: CPU usage starts to climb up to 90-100% when using
G1GC)
> CPU usage starts to climb up to 90-100% when using G1GC; purge ThreadLocal
> usage
>
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.master.001.patch,
> HBASE-17072.master.002.patch, HBASE-17072.master.003.patch,
> HBASE-17072.master.004.patch, HBASE-17072.master.005.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Attachment: HBASE-17072.master.005.patch
> CPU usage starts to climb up to 90-100% when using G1GC
> ---
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.master.001.patch,
> HBASE-17072.master.002.patch, HBASE-17072.master.003.patch,
> HBASE-17072.master.004.patch, HBASE-17072.master.005.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Attachment: HBASE-17072.master.004.patch
> CPU usage starts to climb up to 90-100% when using G1GC
> ---
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.master.001.patch,
> HBASE-17072.master.002.patch, HBASE-17072.master.003.patch,
> HBASE-17072.master.004.patch, disable-block-header-cache.patch,
> mat-threadlocals.png, mat-threads.png, metrics.png, slave1.svg, slave2.svg,
> slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Attachment: HBASE-17072.master.003.patch
> CPU usage starts to climb up to 90-100% when using G1GC
> ---
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.master.001.patch,
> HBASE-17072.master.002.patch, HBASE-17072.master.003.patch,
> HBASE-17072.master.004.patch, disable-block-header-cache.patch,
> mat-threadlocals.png, mat-threads.png, metrics.png, slave1.svg, slave2.svg,
> slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Attachment: HBASE-17072.master.002.patch
> CPU usage starts to climb up to 90-100% when using G1GC
> ---
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 2.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.master.001.patch,
> HBASE-17072.master.002.patch, disable-block-header-cache.patch,
> mat-threadlocals.png, mat-threads.png, metrics.png, slave1.svg, slave2.svg,
> slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Affects Version/s: 2.0.0
Status: Patch Available (was: Open)
> CPU usage starts to climb up to 90-100% when using G1GC
> ---
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.2.0, 1.0.0, 2.0.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.master.001.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
stack updated HBASE-17072:
--
Attachment: HBASE-17072.master.001.patch
> CPU usage starts to climb up to 90-100% when using G1GC
> ---
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: HBASE-17072.master.001.patch,
> disable-block-header-cache.patch, mat-threadlocals.png, mat-threads.png,
> metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Updated] (HBASE-17072) CPU usage starts to climb up to 90-100% when using G1GC
[
https://issues.apache.org/jira/browse/HBASE-17072?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Eiichi Sato updated HBASE-17072:
Attachment: mat-threadlocals.png
metrics.png
disable-block-header-cache.patch
mat-threads.png
slave1.svg
slave2.svg
slave3.svg
slave4.svg
> CPU usage starts to climb up to 90-100% when using G1GC
> ---
>
> Key: HBASE-17072
> URL: https://issues.apache.org/jira/browse/HBASE-17072
> Project: HBase
> Issue Type: Bug
> Components: Performance, regionserver
>Affects Versions: 1.0.0, 1.2.0
>Reporter: Eiichi Sato
> Attachments: disable-block-header-cache.patch, mat-threadlocals.png,
> mat-threads.png, metrics.png, slave1.svg, slave2.svg, slave3.svg, slave4.svg
>
>
> h5. Problem
> CPU usage of a region server in our CDH 5.4.5 cluster, at some point, starts
> to gradually get higher up to nearly 90-100% when using G1GC. We've also run
> into this problem on CDH 5.7.3 and CDH 5.8.2.
> In our production cluster, it normally takes a few weeks for this to happen
> after restarting a RS. We reproduced this on our test cluster and attached
> the results. Please note that, to make it easy to reproduce, we did some
> "anti-tuning" on a table when running tests.
> In metrics.png, soon after we started running some workloads against a test
> cluster (CDH 5.8.2) at about 7 p.m. CPU usage of the two RSs started to rise.
> Flame Graphs (slave1.svg to slave4.svg) are generated from jstack dumps of
> each RS process around 10:30 a.m. the next day.
> After investigating heapdumps from another occurrence on a test cluster
> running CDH 5.7.3, we found that the ThreadLocalMap contain a lot of
> contiguous entries of {{HFileBlock$PrefetchedHeader}} probably due to primary
> clustering. This caused more loops in
> {{ThreadLocalMap#expungeStaleEntries()}}, consuming a certain amount of CPU
> time. What is worse is that the method is called from RPC metrics code,
> which means even a small amount of per-RPC time soon adds up to a huge amount
> of CPU time.
> This is very similar to the issue in HBASE-16616, but we have many
> {{HFileBlock$PrefetchedHeader}} not only {{Counter$IndexHolder}} instances.
> Here are some OQL counts from Eclipse Memory Analyzer (MAT). This shows a
> number of ThreadLocal instances in the ThreadLocalMap of a single handler
> thread.
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name =
> "org.apache.hadoop.hbase.io.hfile.HFileBlock$PrefetchedHeader"
> #=> 10980 instances
> {code}
> {code}
> SELECT *
> FROM OBJECTS (SELECT AS RETAINED SET OBJECTS value
> FROM OBJECTS 0x4ee380430) obj
> WHERE obj.@clazz.@name = "org.apache.hadoop.hbase.util.Counter$IndexHolder"
> #=> 2052 instances
> {code}
> Although as described in HBASE-16616 this somewhat seems to be an issue in
> G1GC side regarding weakly-reachable objects, we should keep ThreadLocal
> usage minimal and avoid creating an indefinite number (in this case, a number
> of HFiles) of ThreadLocal instances.
> HBASE-16146 removes ThreadLocals from the RPC metrics code. That may solve
> the issue (I just saw the patch, never tested it at all), but the
> {{HFileBlock$PrefetchedHeader}} are still there in the ThreadLocalMap, which
> may cause issues in the future again.
> h5. Our Solution
> We simply removed the whole {{HFileBlock$PrefetchedHeader}} caching and
> fortunately we didn't notice any performance degradation for our production
> workloads.
> Because the PrefetchedHeader caching uses ThreadLocal and because RPCs are
> handled randomly in any of the handlers, small Get or small Scan RPCs do not
> benefit from the caching (See HBASE-10676 and HBASE-11402 for the details).
> Probably, we need to see how well reads are saved by the caching for large
> Scan or Get RPCs and especially for compactions if we really remove the
> caching. It's probably better if we can remove ThreadLocals without breaking
> the current caching behavior.
> FWIW, I'm attaching the patch we applied. It's for CDH 5.4.5.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
