You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@phoenix.apache.org by "sunfl@certusnet.com.cn" <su...@certusnet.com.cn> on 2015/01/26 09:19:12 UTC
Weird memory leak for phoenix tracing
Hi,all
Recently we had got super weird things for phoenix tracing. With phoenix 4.2.2 on hbase 0.98.6-cdh5.2.0,
we set phoenix.trace.frequency to always and execute queries.
We are loading data into phoenix tables via mapreduce framework and got jvm memory leak with higher rate
full gc. The statistics of memory holding within jvm are listed as below:
We can observe that tracing-related memory had not been effectively released. This is quite weird. Maybe one
possible cause is that we didnot actually close the connection after each bulkload process?
The questions are:
1. Anyone had encounted such problems using Phoenix tracing before? If so, what are your correct response?
Please kindly share any available points.
2. Can any experts explain this in deep? Good to provide any information in need.
3. Would phoenix connection.close() method be invoked with gc related operations? Do we need to invoke connection.close()
just after each load process? Sorry to get some misunderstanding for my expressing.
Thanks,
Sun.
num #instances #bytes class name
----------------------------------------------
1: 6906472 6602836928 [C
2: 13750988 330023712 java.lang.Long
3: 13750672 330016128 org.apache.hadoop.hbase.util.Pair
4: 3440107 209105432 [Ljava.lang.Object;
5: 6906310 165751440 java.lang.String
6: 6876414 165033936 java.util.ArrayList
7: 3437668 110005376 org.apache.phoenix.trace.TraceMetricSource$Metric
8: 30007 104481080 [B
9: 119567 15317696 <methodKlass>
10: 119567 15016776 <constMethodKlass>
11: 16193 12576128 [S
12: 9202 10834712 <constantPoolKlass>
13: 9202 8254488 <instanceKlassKlass>
14: 7458 5743712 <constantPoolCacheKlass>
15: 105984 2543616 io.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry
16: 4089 1633728 <methodDataKlass>
17: 9775 1167960 java.lang.Class
18: 17236 951624 [[I
19: 1313 808720 [I
20: 21 688464 [Lscala.concurrent.forkjoin.ForkJoinTask;
21: 15823 506336 java.util.concurrent.ConcurrentHashMap$HashEntry
22: 240 427776 [Lio.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry;
23: 11930 381760 java.util.HashMap$Entry
24: 556 298016 <objArrayKlassKlass>
25: 7970 255040 java.util.Hashtable$Entry
26: 15287 244592 java.lang.Object
27: 142 191136 [Lio.netty.buffer.PoolSubpage;
28: 7066 179224 [Ljava.lang.String;
29: 4096 163840 org.jboss.netty.util.internal.ConcurrentIdentityHashMap$Segment
30: 4831 154592 java.util.concurrent.locks.ReentrantLock$NonfairSync
31: 953 153920 [Ljava.util.HashMap$Entry;
32: 536 148424 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
33: 2263 144832 io.netty.buffer.PoolSubpage
34: 4096 131072 [Lorg.jboss.netty.util.internal.ConcurrentIdentityHashMap$HashEntry;
CertusNet
Re: Re: Weird memory leak for phoenix tracing
Posted by "sunfl@certusnet.com.cn" <su...@certusnet.com.cn>.
Hi, Samarth
So good to get your reply. That would make sense.
Thanks,
Sun.
CertusNet
From: Samarth Jain
Date: 2015-01-28 16:48
To: user@phoenix.apache.org
CC: dev
Subject: Re: Weird memory leak for phoenix tracing
Hey Sun,
I believe you are running into an HTrace bug. See this: https://issues.apache.org/jira/browse/HTRACE-92
With the tracing on, we end up publishing a lot many metrics record than we should. These records find there way to the tracing table which ends up causing an infinite loop which ends up creating even more metrics records.
Also see, Phoenix JIRA: https://issues.apache.org/jira/browse/PHOENIX-1596
Thanks,
Samarth
On Mon, Jan 26, 2015 at 12:19 AM, sunfl@certusnet.com.cn <su...@certusnet.com.cn> wrote:
Hi,all
Recently we had got super weird things for phoenix tracing. With phoenix 4.2.2 on hbase 0.98.6-cdh5.2.0,
we set phoenix.trace.frequency to always and execute queries.
We are loading data into phoenix tables via mapreduce framework and got jvm memory leak with higher rate
full gc. The statistics of memory holding within jvm are listed as below:
We can observe that tracing-related memory had not been effectively released. This is quite weird. Maybe one
possible cause is that we didnot actually close the connection after each bulkload process?
The questions are:
1. Anyone had encounted such problems using Phoenix tracing before? If so, what are your correct response?
Please kindly share any available points.
2. Can any experts explain this in deep? Good to provide any information in need.
3. Would phoenix connection.close() method be invoked with gc related operations? Do we need to invoke connection.close()
just after each load process? Sorry to get some misunderstanding for my expressing.
Thanks,
Sun.
num #instances #bytes class name
----------------------------------------------
1: 6906472 6602836928 [C
2: 13750988 330023712 java.lang.Long
3: 13750672 330016128 org.apache.hadoop.hbase.util.Pair
4: 3440107 209105432 [Ljava.lang.Object;
5: 6906310 165751440 java.lang.String
6: 6876414 165033936 java.util.ArrayList
7: 3437668 110005376 org.apache.phoenix.trace.TraceMetricSource$Metric
8: 30007 104481080 [B
9: 119567 15317696 <methodKlass>
10: 119567 15016776 <constMethodKlass>
11: 16193 12576128 [S
12: 9202 10834712 <constantPoolKlass>
13: 9202 8254488 <instanceKlassKlass>
14: 7458 5743712 <constantPoolCacheKlass>
15: 105984 2543616 io.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry
16: 4089 1633728 <methodDataKlass>
17: 9775 1167960 java.lang.Class
18: 17236 951624 [[I
19: 1313 808720 [I
20: 21 688464 [Lscala.concurrent.forkjoin.ForkJoinTask;
21: 15823 506336 java.util.concurrent.ConcurrentHashMap$HashEntry
22: 240 427776 [Lio.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry;
23: 11930 381760 java.util.HashMap$Entry
24: 556 298016 <objArrayKlassKlass>
25: 7970 255040 java.util.Hashtable$Entry
26: 15287 244592 java.lang.Object
27: 142 191136 [Lio.netty.buffer.PoolSubpage;
28: 7066 179224 [Ljava.lang.String;
29: 4096 163840 org.jboss.netty.util.internal.ConcurrentIdentityHashMap$Segment
30: 4831 154592 java.util.concurrent.locks.ReentrantLock$NonfairSync
31: 953 153920 [Ljava.util.HashMap$Entry;
32: 536 148424 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
33: 2263 144832 io.netty.buffer.PoolSubpage
34: 4096 131072 [Lorg.jboss.netty.util.internal.ConcurrentIdentityHashMap$HashEntry;
CertusNet
Re: Re: Weird memory leak for phoenix tracing
Posted by "sunfl@certusnet.com.cn" <su...@certusnet.com.cn>.
Hi, Samarth
So good to get your reply. That would make sense.
Thanks,
Sun.
CertusNet
From: Samarth Jain
Date: 2015-01-28 16:48
To: user@phoenix.apache.org
CC: dev
Subject: Re: Weird memory leak for phoenix tracing
Hey Sun,
I believe you are running into an HTrace bug. See this: https://issues.apache.org/jira/browse/HTRACE-92
With the tracing on, we end up publishing a lot many metrics record than we should. These records find there way to the tracing table which ends up causing an infinite loop which ends up creating even more metrics records.
Also see, Phoenix JIRA: https://issues.apache.org/jira/browse/PHOENIX-1596
Thanks,
Samarth
On Mon, Jan 26, 2015 at 12:19 AM, sunfl@certusnet.com.cn <su...@certusnet.com.cn> wrote:
Hi,all
Recently we had got super weird things for phoenix tracing. With phoenix 4.2.2 on hbase 0.98.6-cdh5.2.0,
we set phoenix.trace.frequency to always and execute queries.
We are loading data into phoenix tables via mapreduce framework and got jvm memory leak with higher rate
full gc. The statistics of memory holding within jvm are listed as below:
We can observe that tracing-related memory had not been effectively released. This is quite weird. Maybe one
possible cause is that we didnot actually close the connection after each bulkload process?
The questions are:
1. Anyone had encounted such problems using Phoenix tracing before? If so, what are your correct response?
Please kindly share any available points.
2. Can any experts explain this in deep? Good to provide any information in need.
3. Would phoenix connection.close() method be invoked with gc related operations? Do we need to invoke connection.close()
just after each load process? Sorry to get some misunderstanding for my expressing.
Thanks,
Sun.
num #instances #bytes class name
----------------------------------------------
1: 6906472 6602836928 [C
2: 13750988 330023712 java.lang.Long
3: 13750672 330016128 org.apache.hadoop.hbase.util.Pair
4: 3440107 209105432 [Ljava.lang.Object;
5: 6906310 165751440 java.lang.String
6: 6876414 165033936 java.util.ArrayList
7: 3437668 110005376 org.apache.phoenix.trace.TraceMetricSource$Metric
8: 30007 104481080 [B
9: 119567 15317696 <methodKlass>
10: 119567 15016776 <constMethodKlass>
11: 16193 12576128 [S
12: 9202 10834712 <constantPoolKlass>
13: 9202 8254488 <instanceKlassKlass>
14: 7458 5743712 <constantPoolCacheKlass>
15: 105984 2543616 io.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry
16: 4089 1633728 <methodDataKlass>
17: 9775 1167960 java.lang.Class
18: 17236 951624 [[I
19: 1313 808720 [I
20: 21 688464 [Lscala.concurrent.forkjoin.ForkJoinTask;
21: 15823 506336 java.util.concurrent.ConcurrentHashMap$HashEntry
22: 240 427776 [Lio.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry;
23: 11930 381760 java.util.HashMap$Entry
24: 556 298016 <objArrayKlassKlass>
25: 7970 255040 java.util.Hashtable$Entry
26: 15287 244592 java.lang.Object
27: 142 191136 [Lio.netty.buffer.PoolSubpage;
28: 7066 179224 [Ljava.lang.String;
29: 4096 163840 org.jboss.netty.util.internal.ConcurrentIdentityHashMap$Segment
30: 4831 154592 java.util.concurrent.locks.ReentrantLock$NonfairSync
31: 953 153920 [Ljava.util.HashMap$Entry;
32: 536 148424 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
33: 2263 144832 io.netty.buffer.PoolSubpage
34: 4096 131072 [Lorg.jboss.netty.util.internal.ConcurrentIdentityHashMap$HashEntry;
CertusNet
Re: Weird memory leak for phoenix tracing
Posted by Samarth Jain <sa...@gmail.com>.
Hey Sun,
I believe you are running into an HTrace bug. See this:
https://issues.apache.org/jira/browse/HTRACE-92
With the tracing on, we end up publishing a lot many metrics record than we
should. These records find there way to the tracing table which ends up
causing an infinite loop which ends up creating even more metrics records.
Also see, Phoenix JIRA: https://issues.apache.org/jira/browse/PHOENIX-1596
Thanks,
Samarth
On Mon, Jan 26, 2015 at 12:19 AM, sunfl@certusnet.com.cn <
sunfl@certusnet.com.cn> wrote:
> Hi,all
> Recently we had got super weird things for phoenix tracing. With phoenix
> 4.2.2 on hbase 0.98.6-cdh5.2.0,
> we set phoenix.trace.frequency to always and execute queries.
> We are loading data into phoenix tables via mapreduce framework and got
> jvm memory leak with higher rate
> full gc. The statistics of memory holding within jvm are listed as below:
>
> We can observe that tracing-related memory had not been effectively
> released. This is quite weird. Maybe one
> possible cause is that we didnot actually close the connection after each
> bulkload process?
>
> The questions are:
> 1. Anyone had encounted such problems using Phoenix tracing before? If so,
> what are your correct response?
> Please kindly share any available points.
> 2. Can any experts explain this in deep? Good to provide any information
> in need.
> 3. Would phoenix connection.close() method be invoked with gc related
> operations? Do we need to invoke connection.close()
> just after each load process? Sorry to get some misunderstanding for my
> expressing.
>
> Thanks,
> Sun.
>
>
> num #instances #bytes class name
> ----------------------------------------------
> 1: 6906472 6602836928 [C
> 2: 13750988 330023712 java.lang.Long
> 3: 13750672 330016128 org.apache.hadoop.hbase.util.Pair
> 4: 3440107 209105432 [Ljava.lang.Object;
> 5: 6906310 165751440 java.lang.String
> 6: 6876414 165033936 java.util.ArrayList
> 7: 3437668 110005376 org.apache.phoenix.trace.TraceMetricSource$Metric
> 8: 30007 104481080 [B
> 9: 119567 15317696 <methodKlass>
> 10: 119567 15016776 <constMethodKlass>
> 11: 16193 12576128 [S
> 12: 9202 10834712 <constantPoolKlass>
> 13: 9202 8254488 <instanceKlassKlass>
> 14: 7458 5743712 <constantPoolCacheKlass>
> 15: 105984 2543616 io.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry
> 16: 4089 1633728 <methodDataKlass>
> 17: 9775 1167960 java.lang.Class
> 18: 17236 951624 [[I
> 19: 1313 808720 [I
> 20: 21 688464 [Lscala.concurrent.forkjoin.ForkJoinTask;
> 21: 15823 506336 java.util.concurrent.ConcurrentHashMap$HashEntry
> 22: 240 427776 [Lio.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry;
> 23: 11930 381760 java.util.HashMap$Entry
> 24: 556 298016 <objArrayKlassKlass>
> 25: 7970 255040 java.util.Hashtable$Entry
> 26: 15287 244592 java.lang.Object
> 27: 142 191136 [Lio.netty.buffer.PoolSubpage;
> 28: 7066 179224 [Ljava.lang.String;
> 29: 4096 163840
> org.jboss.netty.util.internal.ConcurrentIdentityHashMap$Segment
> 30: 4831 154592 java.util.concurrent.locks.ReentrantLock$NonfairSync
> 31: 953 153920 [Ljava.util.HashMap$Entry;
> 32: 536 148424 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
> 33: 2263 144832 io.netty.buffer.PoolSubpage
> 34: 4096 131072
> [Lorg.jboss.netty.util.internal.ConcurrentIdentityHashMap$HashEntry;
>
> ------------------------------
> ------------------------------
>
> CertusNet
>
>
>
Re: Weird memory leak for phoenix tracing
Posted by Samarth Jain <sa...@gmail.com>.
Hey Sun,
I believe you are running into an HTrace bug. See this:
https://issues.apache.org/jira/browse/HTRACE-92
With the tracing on, we end up publishing a lot many metrics record than we
should. These records find there way to the tracing table which ends up
causing an infinite loop which ends up creating even more metrics records.
Also see, Phoenix JIRA: https://issues.apache.org/jira/browse/PHOENIX-1596
Thanks,
Samarth
On Mon, Jan 26, 2015 at 12:19 AM, sunfl@certusnet.com.cn <
sunfl@certusnet.com.cn> wrote:
> Hi,all
> Recently we had got super weird things for phoenix tracing. With phoenix
> 4.2.2 on hbase 0.98.6-cdh5.2.0,
> we set phoenix.trace.frequency to always and execute queries.
> We are loading data into phoenix tables via mapreduce framework and got
> jvm memory leak with higher rate
> full gc. The statistics of memory holding within jvm are listed as below:
>
> We can observe that tracing-related memory had not been effectively
> released. This is quite weird. Maybe one
> possible cause is that we didnot actually close the connection after each
> bulkload process?
>
> The questions are:
> 1. Anyone had encounted such problems using Phoenix tracing before? If so,
> what are your correct response?
> Please kindly share any available points.
> 2. Can any experts explain this in deep? Good to provide any information
> in need.
> 3. Would phoenix connection.close() method be invoked with gc related
> operations? Do we need to invoke connection.close()
> just after each load process? Sorry to get some misunderstanding for my
> expressing.
>
> Thanks,
> Sun.
>
>
> num #instances #bytes class name
> ----------------------------------------------
> 1: 6906472 6602836928 [C
> 2: 13750988 330023712 java.lang.Long
> 3: 13750672 330016128 org.apache.hadoop.hbase.util.Pair
> 4: 3440107 209105432 [Ljava.lang.Object;
> 5: 6906310 165751440 java.lang.String
> 6: 6876414 165033936 java.util.ArrayList
> 7: 3437668 110005376 org.apache.phoenix.trace.TraceMetricSource$Metric
> 8: 30007 104481080 [B
> 9: 119567 15317696 <methodKlass>
> 10: 119567 15016776 <constMethodKlass>
> 11: 16193 12576128 [S
> 12: 9202 10834712 <constantPoolKlass>
> 13: 9202 8254488 <instanceKlassKlass>
> 14: 7458 5743712 <constantPoolCacheKlass>
> 15: 105984 2543616 io.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry
> 16: 4089 1633728 <methodDataKlass>
> 17: 9775 1167960 java.lang.Class
> 18: 17236 951624 [[I
> 19: 1313 808720 [I
> 20: 21 688464 [Lscala.concurrent.forkjoin.ForkJoinTask;
> 21: 15823 506336 java.util.concurrent.ConcurrentHashMap$HashEntry
> 22: 240 427776 [Lio.netty.buffer.PoolThreadCache$MemoryRegionCache$Entry;
> 23: 11930 381760 java.util.HashMap$Entry
> 24: 556 298016 <objArrayKlassKlass>
> 25: 7970 255040 java.util.Hashtable$Entry
> 26: 15287 244592 java.lang.Object
> 27: 142 191136 [Lio.netty.buffer.PoolSubpage;
> 28: 7066 179224 [Ljava.lang.String;
> 29: 4096 163840
> org.jboss.netty.util.internal.ConcurrentIdentityHashMap$Segment
> 30: 4831 154592 java.util.concurrent.locks.ReentrantLock$NonfairSync
> 31: 953 153920 [Ljava.util.HashMap$Entry;
> 32: 536 148424 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
> 33: 2263 144832 io.netty.buffer.PoolSubpage
> 34: 4096 131072
> [Lorg.jboss.netty.util.internal.ConcurrentIdentityHashMap$HashEntry;
>
> ------------------------------
> ------------------------------
>
> CertusNet
>
>
>