Pinpoint: NioClientSocketChannel cause memory leak

Created on 27 May 2019 · 10Comments · Source: pinpoint-apm/pinpoint

Prerequisites

Please check the FAQ, and search existing issues for similar questions before creating a new issue.YOU MAY DELETE THIS PREREQUISITES SECTION.

[x] I have checked the FAQ, and issues and found no answer.

What version of pinpoint are you using?

master/v1.7.1

Describe your problem**

After the program runs normally for a long time, suddenly the memory overhead increases and frequent FullGC appears.I dump the memory and use MAT to analysis it found it related to pinpoint.

What have you done?

I don't know.
I have an application deploys 5 instances and mounts the pinpoint agent, but this problem only occurs in one instance.

Screenshots

Logs

2019-05-24 19:16:36,984 Pinpoint-Client-Worker(18-0) DefaultPinpointClientHandler.java WARN  - DefaultPinpointClientHandler@1ca5d98c exceptionCaught() occurred. state:RUN_SIMPLEX. Caused:null
org.jboss.netty.handler.timeout.WriteTimeoutException: null
    at org.jboss.netty.handler.timeout.WriteTimeoutHandler.<clinit>(WriteTimeoutHandler.java:79)
    at com.navercorp.pinpoint.rpc.client.PinpointClientPipelineFactory.getPipeline(PinpointClientPipelineFactory.java:57)
    at org.jboss.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:206)
    at org.jboss.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:182)
    at com.navercorp.pinpoint.rpc.client.DefaultPinpointClientFactory.connect(DefaultPinpointClientFactory.java:219)
    at com.navercorp.pinpoint.rpc.client.DefaultPinpointClientFactory.connect(DefaultPinpointClientFactory.java:215)
    at com.navercorp.pinpoint.rpc.ClassPreLoader.preload(ClassPreLoader.java:50)
    at com.navercorp.pinpoint.rpc.ClassPreLoader.preload(ClassPreLoader.java:35)
    at com.navercorp.pinpoint.profiler.DefaultAgent.<clinit>(DefaultAgent.java:67)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.navercorp.pinpoint.bootstrap.AgentClassLoader$2.call(AgentClassLoader.java:78)
    at com.navercorp.pinpoint.bootstrap.ContextClassLoaderExecuteTemplate.execute(ContextClassLoaderExecuteTemplate.java:42)
    at com.navercorp.pinpoint.bootstrap.AgentClassLoader.boot(AgentClassLoader.java:73)
    at com.navercorp.pinpoint.bootstrap.PinpointStarter.start(PinpointStarter.java:132)
    at com.navercorp.pinpoint.bootstrap.PinpointBootStrap.premain(PinpointBootStrap.java:61)
    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 sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
    at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
2019-05-24 19:16:36,984 Pinpoint-Client-Worker(18-0) DefaultPinpointClientHandler.java WARN  - DefaultPinpointClientHandler@1ca5d98c exceptionCaught() occurred. state:RUN_SIMPLEX. Caused:null
org.jboss.netty.handler.timeout.WriteTimeoutException: null
    at org.jboss.netty.handler.timeout.WriteTimeoutHandler.<clinit>(WriteTimeoutHandler.java:79)
    at com.navercorp.pinpoint.rpc.client.PinpointClientPipelineFactory.getPipeline(PinpointClientPipelineFactory.java:57)
    at org.jboss.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:206)
    at org.jboss.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:182)
    at com.navercorp.pinpoint.rpc.client.DefaultPinpointClientFactory.connect(DefaultPinpointClientFactory.java:219)
    at com.navercorp.pinpoint.rpc.client.DefaultPinpointClientFactory.connect(DefaultPinpointClientFactory.java:215)
    at com.navercorp.pinpoint.rpc.ClassPreLoader.preload(ClassPreLoader.java:50)
    at com.navercorp.pinpoint.rpc.ClassPreLoader.preload(ClassPreLoader.java:35)
    at com.navercorp.pinpoint.profiler.DefaultAgent.<clinit>(DefaultAgent.java:67)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.navercorp.pinpoint.bootstrap.AgentClassLoader$2.call(AgentClassLoader.java:78)
    at com.navercorp.pinpoint.bootstrap.ContextClassLoaderExecuteTemplate.execute(ContextClassLoaderExecuteTemplate.java:42)
    at com.navercorp.pinpoint.bootstrap.AgentClassLoader.boot(AgentClassLoader.java:73)
    at com.navercorp.pinpoint.bootstrap.PinpointStarter.start(PinpointStarter.java:132)
    at com.navercorp.pinpoint.bootstrap.PinpointBootStrap.premain(PinpointBootStrap.java:61)
    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 sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
    at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
2019-05-24 19:16:36,984 Pinpoint-Client-Worker(18-0) DefaultPinpointClientHandler.java WARN  - DefaultPinpointClientHandler@1ca5d98c exceptionCaught() occurred. state:RUN_SIMPLEX. Caused:null
org.jboss.netty.handler.timeout.WriteTimeoutException: null
    at org.jboss.netty.handler.timeout.WriteTimeoutHandler.<clinit>(WriteTimeoutHandler.java:79)
    at com.navercorp.pinpoint.rpc.client.PinpointClientPipelineFactory.getPipeline(PinpointClientPipelineFactory.java:57)
    at org.jboss.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:206)
    at org.jboss.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:182)
    at com.navercorp.pinpoint.rpc.client.DefaultPinpointClientFactory.connect(DefaultPinpointClientFactory.java:219)
    at com.navercorp.pinpoint.rpc.client.DefaultPinpointClientFactory.connect(DefaultPinpointClientFactory.java:215)
    at com.navercorp.pinpoint.rpc.ClassPreLoader.preload(ClassPreLoader.java:50)
    at com.navercorp.pinpoint.rpc.ClassPreLoader.preload(ClassPreLoader.java:35)
    at com.navercorp.pinpoint.profiler.DefaultAgent.<clinit>(DefaultAgent.java:67)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.navercorp.pinpoint.bootstrap.AgentClassLoader$2.call(AgentClassLoader.java:78)
    at com.navercorp.pinpoint.bootstrap.ContextClassLoaderExecuteTemplate.execute(ContextClassLoaderExecuteTemplate.java:42)
    at com.navercorp.pinpoint.bootstrap.AgentClassLoader.boot(AgentClassLoader.java:73)
    at com.navercorp.pinpoint.bootstrap.PinpointStarter.start(PinpointStarter.java:132)
    at com.navercorp.pinpoint.bootstrap.PinpointBootStrap.premain(PinpointBootStrap.java:61)
    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 sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
    at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
...

Source

linxiaobai

Most helpful comment

@koo-taejin
Thank you for your explanation, could you give further direction for the following details.

in DefaultPinpointClientHandler#write0(Object message, ChannelFutureListener futureListener) method, when pinpoint agent write data to collector, the data is stored in AbstractNioChannel#writeBufferQueue rather than to be sent to collector immediately?
netty write data use direct memory, it is the direct memory occupied system memory？
is it appropriate to add the channel writable check in DefaultPinpointClientHandler#write0 method

//DefaultPinpointClientHandler.java
private ChannelFuture write0(Object message, ChannelFutureListener futureListener) {
        if (!channel.isWritable()) {
            //do something, like drop the message and give some warning log
        } else {
            ChannelFuture future = channel.write(message);
            if (futureListener != null) {
                future.addListener(futureListener);
            }

            return future;
        }
    }

If we use UDP or TCP with a lower sampling as you mentioned, the data will be discarded.

Is it possible to discard the data directly when it is sent via TCP, to avoid excessive memory usage and to generate a large amount of FullGC?

linxiaobai on 27 May 2019

👍2

All 10 comments

hi @linxiaobai

It is difficult to analyze the problem with the information that you gave me.
Can you pass me the full heapdump file?

please can send me a file or a link to my email ([email protected])

Thanks :)

koo-taejin on 27 May 2019

hi @linxiaobai

It is difficult to analyze the problem with the information that you gave me.
Can you pass me the full heapdump file?

please can send me a file or a link to my email (koo.[email protected])

Thanks :)

Already sent to you @koo-taejin

linxiaobai on 27 May 2019

2019-05-24 19:16:37,182 Pinpoint-Client-Worker(18-0) DefaultPinpointClientHandler.java WARN  - DefaultPinpointClientHandler@1ca5d98c exceptionCaught() occurred. state:RUN_SIMPLEX. Caused:null
org.jboss.netty.handler.timeout.WriteTimeoutException: null
    at org.jboss.netty.handler.timeout.WriteTimeoutHandler.<clinit>(WriteTimeoutHandler.java:79)
    at com.navercorp.pinpoint.rpc.client.PinpointClientPipelineFactory.getPipeline(PinpointClientPipelineFactory.java:57)
    at org.jboss.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:206)
    at org.jboss.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:182)
    at com.navercorp.pinpoint.rpc.client.DefaultPinpointClientFactory.connect(DefaultPinpointClientFactory.java:219)
    at com.navercorp.pinpoint.rpc.client.DefaultPinpointClientFactory.connect(DefaultPinpointClientFactory.java:215)
    at com.navercorp.pinpoint.rpc.ClassPreLoader.preload(ClassPreLoader.java:50)
    at com.navercorp.pinpoint.rpc.ClassPreLoader.preload(ClassPreLoader.java:35)
    at com.navercorp.pinpoint.profiler.DefaultAgent.<clinit>(DefaultAgent.java:67)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.navercorp.pinpoint.bootstrap.AgentClassLoader$2.call(AgentClassLoader.java:78)
    at com.navercorp.pinpoint.bootstrap.ContextClassLoaderExecuteTemplate.execute(ContextClassLoaderExecuteTemplate.java:42)
    at com.navercorp.pinpoint.bootstrap.AgentClassLoader.boot(AgentClassLoader.java:73)
    at com.navercorp.pinpoint.bootstrap.PinpointStarter.start(PinpointStarter.java:132)
    at com.navercorp.pinpoint.bootstrap.PinpointBootStrap.premain(PinpointBootStrap.java:61)
    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 sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
    at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)

Under what circumstances will this error be reported?
I understand that this error will only be reported at startup, but we are not like this now.

linxiaobai on 27 May 2019

@linxiaobai

I've looked at the heap dump you sent.

So in summary, it's not leak, it has really many data.

Pinpoint sends data to tcp 9994 port that must not be lost.
Send data to the udp port taht if it is possible to lose data. (Non important data)
It also supports the ability to send this to tcp, but when excessive span is generated, the problem as mentioned may arise.
If possible, it is recommended to send span using udp transport.
If it is difficult to do so, it is recommended to set lower the sampling or increase the heap for use in you're environment

thanks.

koo-taejin on 27 May 2019

@koo-taejin
Thank you for your explanation, could you give further direction for the following details.

in DefaultPinpointClientHandler#write0(Object message, ChannelFutureListener futureListener) method, when pinpoint agent write data to collector, the data is stored in AbstractNioChannel#writeBufferQueue rather than to be sent to collector immediately?
netty write data use direct memory, it is the direct memory occupied system memory？
is it appropriate to add the channel writable check in DefaultPinpointClientHandler#write0 method

//DefaultPinpointClientHandler.java
private ChannelFuture write0(Object message, ChannelFutureListener futureListener) {
        if (!channel.isWritable()) {
            //do something, like drop the message and give some warning log
        } else {
            ChannelFuture future = channel.write(message);
            if (futureListener != null) {
                future.addListener(futureListener);
            }

            return future;
        }
    }

If we use UDP or TCP with a lower sampling as you mentioned, the data will be discarded.

Is it possible to discard the data directly when it is sent via TCP, to avoid excessive memory usage and to generate a large amount of FullGC?

linxiaobai on 27 May 2019

👍2

@linxiaobai

This is the logic of the netty.
And, this logic is common method to handle a lot of packet in the rpc library.
Netty helps use direct buffers, but not use direct buffers default.
Use direct buffers are very dangerous because they are out of control of the Java process.
In addition, if use direct buffers at point which you mentioned, this will result in poor performance.
Udp transport already exist logic to manage data in to use excessive memory.
However, pinpoint team is focusing on developing grpc transport and plan to encourage the use of grpc transport in the future.
Therefore, there are no plans to make further extensions or improvements to the tcp transport.
(It would be very happy if you will implement it and contribute to use .)

thanks.

koo-taejin on 28 May 2019

@linxiaobai

This is the logic of the netty.
And, this logic is common method to handle a lot of packet in the rpc library.

Netty helps use direct buffers, but not use direct buffers default.
Use direct buffers are very dangerous because they are out of control of the Java process.
In addition, if use direct buffers at point which you mentioned, this will result in poor performance.

Udp transport already exist logic to manage data in to use excessive memory.
However, pinpoint team is focusing on developing grpc transport and plan to encourage the use of grpc transport in the future.
Therefore, there are no plans to make further extensions or improvements to the tcp transport.
(It would be very happy if you will implement it and contribute to use .)

thanks.

ok， thank u for your kind reply.

linxiaobai on 28 May 2019

@linxiaobai

I've reviewed your suggestions, and it seems to be very reasonable.
I will add function and apply it to 1.8.x branch and master branch.

thanks. :)

koo-taejin on 28 May 2019

refer to :
https://stackoverflow.com/questions/25281124/netty-4-high-and-low-write-watermarks