pulsar process shutdown , cpu useed load high

[Leo9866]

Describe the bug
We monitored pulsar process shutdown and saw high CPU utilization. The specific log information before the outage is as follows.

09:54:02.461 [pulsar-zk-session-watcher-5-1] WARN  org.apache.pulsar.zookeeper.ZooKeeperSessionWatcher - zoo keeper disconnected, waiting to reconnect, time remaining = 8 seconds
09:54:02.645 [pulsar-web-42-17] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:02 +0800] "GET /admin/v2/non-persistent/2000087171-harbor/harbor-pool-01/0x40000000_0x80000000?authoritative=false HTTP/1.1" 200 244 "-" "Pulsar-Java-v2.6.0" 1
09:54:02.645 [pulsar-web-42-6] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:02 +0800] "GET /admin/v2/non-persistent/2000087171-harbor/harbor-pool-01/0x00000000_0x40000000?authoritative=false HTTP/1.1" 200 163 "-" "Pulsar-Java-v2.6.0" 1
09:54:02.742 [pulsar-web-42-31] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:02 +0800] "GET /admin/v2/non-persistent/2000087171-test-project/pool1/0x80000000_0xc0000000?authoritative=false HTTP/1.1" 200 79 "-" "Pulsar-Java-v2.6.0" 1
09:54:03.464 [pulsar-web-42-17] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:03 +0800] "GET /admin/v2/non-persistent/2000100247-kmse-test/test/0xc0000000_0xffffffff?authoritative=false HTTP/1.1" 200 75 "-" "Pulsar-Java-v2.6.0" 0
09:54:03.925 [pulsar-web-42-31] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:03 +0800] "GET /admin/v2/non-persistent/2000127883-klog_demo/nginx/0x40000000_0x80000000?authoritative=false HTTP/1.1" 200 76 "-" "Pulsar-Java-v2.6.0" 1
09:54:04.321 [pulsar-web-42-17] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:04 +0800] "GET /admin/v2/non-persistent/2000003485-wntest/test1/0x80000000_0xc0000000?authoritative=false HTTP/1.1" 200 73 "-" "Pulsar-Java-v2.6.0" 0
09:54:04.420 [pulsar-web-42-31] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:04 +0800] "GET /admin/v2/non-persistent/2000003485-lctest/filebeat2/0x80000000_0xc0000000?authoritative=false HTTP/1.1" 200 77 "-" "Pulsar-Java-v2.6.0" 1
09:54:04.425 [pulsar-web-42-17] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:04 +0800] "GET /admin/v2/non-persistent/2000020194-test/test/0x80000000_0xc0000000?authoritative=false HTTP/1.1" 200 70 "-" "Pulsar-Java-v2.6.0" 0
09:54:04.427 [pulsar-web-42-31] INFO  org.eclipse.jetty.server.RequestLog - 10.69.65.74 - - [17/Sep/2020:09:54:04 +0800] "GET /admin/v2/non-persistent/2000087171-harbor/pool-01/0xc0000000_0xffffffff?authoritative=false HTTP/1.1" 200 75 "-" "Pulsar-Java-v2.6.0" 1
09:54:04.462 [pulsar-zk-session-watcher-5-1] WARN  org.apache.pulsar.zookeeper.ZooKeeperSessionWatcher - zoo keeper disconnected, waiting to reconnect, time remaining = 6 seconds
09:54:04.885 [pulsar-web-42-17] INFO  org.apache.pulsar.broker.admin.impl.PersistentTopicsBase - [null][persistent://2000100247-kmse-test/test/bafb612941df43a69fbd5acd27ee0866] received reset cursor on subscription flink-pulsar-a0a931c9-5c13-4e53-b977-b05fe9e9c64e to position 73770:0:-1
09:54:04.886 [pulsar-web-42-17] WARN  org.apache.pulsar.broker.admin.impl.PersistentTopicsBase - [null] [persistent://2000100247-kmse-test/test/bafb612941df43a69fbd5acd27ee0866] Failed to reset cursor on subscription flink-pulsar-a0a931c9-5c13-4e53-b977-b05fe9e9c64e to position 73770:0:-1
java.lang.NullPointerException: null
        at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:877) ~[com.google.guava-guava-25.1-jre.jar:?]
        at org.apache.pulsar.broker.admin.impl.PersistentTopicsBase.internalResetCursorOnPosition(PersistentTopicsBase.java:1801) ~[org.apache.pulsar-pulsar-broker-2.6.0.jar:2.6.0]
        at org.apache.pulsar.broker.admin.v2.PersistentTopics.resetCursorOnPosition(PersistentTopics.java:890) ~[org.apache.pulsar-pulsar-broker-2.6.0.jar:2.6.0]
        at sun.reflect.GeneratedMethodAccessor94.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_231]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_231]
        at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76) ~[org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:183) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272) [org.glassfish.jersey.core-jersey-common-2.27.jar:?]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268) [org.glassfish.jersey.core-jersey-common-2.27.jar:?]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:316) [org.glassfish.jersey.core-jersey-common-2.27.jar:?]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:298) [org.glassfish.jersey.core-jersey-common-2.27.jar:?]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:268) [org.glassfish.jersey.core-jersey-common-2.27.jar:?]
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289) [org.glassfish.jersey.core-jersey-common-2.27.jar:?]
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703) [org.glassfish.jersey.core-jersey-server-2.27.jar:?]
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416) [org.glassfish.jersey.containers-jersey-container-servlet-core-2.27.jar:?]

pulsar node cpu load:

pulsar log info
The process stopped at about 9:54 this morning

pulsar-broker-klog-broker-prod-3.ksyun.com-e.log.gz

Desktop (please complete the following information):

• OS: centos 7.6
  16c64g 2T

Additional context
Add any other context about the problem here.

[Leo9866]

After the first pulsar node-1 stopped, CPU utilization of the remaining two pulsar nodes began to increase.

This cluster has a three-node, with 20 tenants and 80 namespaces 200+topic. The back end use flink on Pulsar Consumer to write to ES.

The machine is configured as 16C64G2T

[Technoboy-]

Task a look at the relative code and find that should we be used if check to avoid throw NPE?

if(null == sub){
   asyncResponse.resume(new RestException(Status.NOT_FOUND, "Subscription not found"));
   return;
}

@sijie @jiazhai

[Leo9866]

This is a screenshot of the high occupancy of those classes when there was a problem

[lhotari]

I'm running into a similar problem. However I didn't see a NPE, but there is high CPU usage. If anyone is interested, I have shared the details on the Pulsar Slack at https://apache-pulsar.slack.com/archives/C5Z4T36F7/p1602159831227900 .
async-profiler seems to be the best way to observe what is going on when Pulsar is running on high CPU. It's possible to get it copied inside a k8s container and do profiling on-the-fly.

[tisonkun]

Closed as stale. Please create a new issue if it's still relevant to the maintained versions.