You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by GitBox <gi...@apache.org> on 2022/02/14 09:47:04 UTC
[GitHub] [pulsar] lordcheng10 opened a new issue #14268: [2.8.1] FGC and throw NPE
lordcheng10 opened a new issue #14268:
URL: https://github.com/apache/pulsar/issues/14268
**Describe the bug**
The phenomenon of our online problem is as follows:
1. NPE exception: (This is the same as the NPE exception in your PR, but only this type of NPE was found. I see two NPEs mentioned in your PR)
03:22:50.442 [BookKeeperClientWorker-OrderedExecutor-4-0] ERROR org.apache.bookkeeper.common.util.SafeRunnable - Unexpected throwable caught
java.lang.NullPointerException: null
at org.apache.bookkeeper.mledger.impl.OpAddEntry.addComplete(OpAddEntry.java:153) ~[org.apache.pulsar-managed-ledger-2.8.1.2.jar:2.8.1.2]
at
2. Frequent FGC, I dumped the memory and found that there are a lot of pendingAddOp objects (more than seven million), but the write traffic has dropped to the bottom:
3.Looking at the log, some thread pools take too long to execute tasks, even reaching the hour level:
03:23:47.838 [bookkeeper-ml-scheduler-OrderedScheduler-54-0] WARN org.apache.bookkeeper.common.util.OrderedExecutor - Runnable org.apache.bookkeeper.mledger.impl.ManagedCursorImpl$$Lambda$1000/1597732433@2fc9a98e:class org.apache.bookkeeper.mledger.impl.ManagedCursorImpl$$Lambda$1000/1597732433 took too long 12721684 micros to execute.
03:24:53.508 [bookkeeper-ml-scheduler-OrderedScheduler-32-0] WARN org.apache.bookkeeper.common.util.OrderedExecutor - Runnable org.apache.bookkeeper.common.util.OrderedExecutor$TimedRunnable@3f387130:class org.apache.bookkeeper.common.util.OrderedExecutor$TimedRunnable took too long 16594876 micros to execute.
03:26:02.079 [bookkeeper-ml-scheduler-OrderedScheduler-35-0] WARN org.apache.bookkeeper.common.util.OrderedExecutor - Runnable org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl$$Lambda$92/1773008684@4ddf5185:class org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl$$Lambda$92/1773008684 took too long 17111879 micros to execute.
4. zookkepeer session timeout:
03:26:02.079 [bookkeeper-ml-scheduler-OrderedScheduler-35-0] WARN org.apache.bookkeeper.common.util.OrderedExecutor - Runnable org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl$$Lambda$92/1773008684@4ddf5185:class org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl$$Lambda$92/1773008684 took too long 17111879 micros to execute.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039880391
> > Unexpected throwable caught
> > java.lang.NullPointerException: null
> > at org.apache.bookkeeper.mledger.impl.OpAddEntry.addComplete(OpAddEntry.java:153) ~[org.apache.pulsar-managed-ledger-2.8.1.2.jar:2.8.1.2]
>
> This looks like a thread safety issue. There's #12606 which improves the situation slightly. The solution in #11387 would help address such issues in better way although that still has some gaps and possible issues.
The most confusing thing is why the FGC is triggered, and the thread pool execution time reaches the hour level：
`04:35:46.571 [bookkeeper-ml-scheduler-OrderedScheduler-18-0] WARN org.apache.bookkeeper.common.util.OrderedExecutor - Runnable org.apache.bookkeeper.mledger.util.SafeRun$1@89aa735:class org.apache.bookkeeper.mledger.util.SafeRun$1 took too long 13450016 micros to execute.`
I even took an execution task to see and found that it is only reading and writing zk, and the timeout time of zk is only 30 seconds, so I can't understand why it reaches the hour level
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039194492
Similar to this issue： https://github.com/apache/pulsar/issues/9234
03:23:47.838 [bookkeeper-ml-scheduler-OrderedScheduler-54-0] WARN org.apache.bookkeeper.common.util.OrderedExecutor - Runnable org.apache.bookkeeper.mledger.impl.ManagedCursorImpl$$Lambda$1000/1597732433@2fc9a98e:class org.apache.bookkeeper.mledger.impl.ManagedCursorImpl$$Lambda$1000/1597732433 took too long 12721684 micros to execute.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039920086
> What do you mean with "reaches the hour level"? [13450016 microseconds is 13.45 seconds](https://www.google.com/search?q=13450016+microseconds+to+seconds) .
Aha,I was wrong, it was 13.45 seconds .
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039868610
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] codelipenghui commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
codelipenghui commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1067807917
close by #14515
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039931672
>
I didn't test 2.8.2, only found NPE in 2.8.1
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039906986
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039952838
I uploaded the dump file to Baidu Cloud Disk, which can be downloaded here:
https://pan.baidu.com/s/1qNMQFS5QtpkwcKpOlK5HiA
Extraction code: cvgr @lhotari
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039880391
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039868610
> Unexpected throwable caught
java.lang.NullPointerException: null
at org.apache.bookkeeper.mledger.impl.OpAddEntry.addComplete(OpAddEntry.java:153) ~[org.apache.pulsar-managed-ledger-2.8.1.2.jar:2.8.1.2]
This looks like a thread safety issue. There's #12606 which improves the situation slightly. The solution in #11387 would help address such issues in better way although that still has some gaps and possible issues.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039931871
> > I noticed there is this PR that may be related to this issue: #12993
>
> Yes, #12993 could help addressing the NPE. Have you tested the behavior with Pulsar 2.8.2 which includes #12993?
I didn't test 2.8.2, only found NPE in 2.8.1
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039950676
> > The most confusing thing is why the FGC is triggered
>
> With FGC, do you mean "Full GC"? The GC log tells the reason why Full GCs get triggered. GC logging was added by #7498 . Have you checked the GC log entries?
The gc log of the node in question is not saved. I found some FULL GC logs from other FULL GC logs on the line, but these nodes are not continuously FULL GC:
2022-02-15T12:45:47.604+0800: 423715.809: [Full GC (Allocation Failure) 23G->10G(24G), 11.4667426 secs]
[Eden: 0.0B(12.0G)->0.0B(12.0G) Survivors: 0.0B->0.0B Heap: 23.9G(24.0G)->10.6G(24.0G)], [Metaspace: 65542K->65542K(1114112K)]
[Times: user=20.56 sys=0.00, real=11.47 secs]
The JVM monitoring of the problem broker is as follows:
It seems that there is a memory leak. The memory size of the old age continues to increase, but the read and write traffic of the node has not increased. @lhotari
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 removed a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 removed a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039931672
>
I didn't test 2.8.2, only found NPE in 2.8.1
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039950676
> > The most confusing thing is why the FGC is triggered
>
> With FGC, do you mean "Full GC"? The GC log tells the reason why Full GCs get triggered. GC logging was added by #7498 . Have you checked the GC log entries?
The gc log of the node in question is not saved. I found some FULL GC logs from other FULL GC logs on the line, but these nodes are not continuously FULL GC:
2022-02-15T12:45:47.604+0800: 423715.809: [Full GC (Allocation Failure) 23G->10G(24G), 11.4667426 secs]
[Eden: 0.0B(12.0G)->0.0B(12.0G) Survivors: 0.0B->0.0B Heap: 23.9G(24.0G)->10.6G(24.0G)], [Metaspace: 65542K->65542K(1114112K)]
[Times: user=20.56 sys=0.00, real=11.47 secs]
The JVM monitoring of the problem broker is as follows:
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039952838
I uploaded the dump file to Baidu Cloud Disk, which can be downloaded here:
https://pan.baidu.com/s/1qNMQFS5QtpkwcKpOlK5HiA
Extraction code: cvgr
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 removed a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 removed a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039931672
>
I didn't test 2.8.2, only found NPE in 2.8.1
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039194492
Similar to this issue： https://github.com/apache/pulsar/issues/9234
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039906986
> I even took an execution task to see and found that it is only reading and writing zk, and the timeout time of zk is only 30 seconds, so I can't understand why it reaches the hour level:
What do you mean with "reaches the hour level"? [13450016 microseconds is 13.45 seconds](https://www.google.com/search?q=13450016+microseconds+to+seconds) .
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039880391
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] codelipenghui closed issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
codelipenghui closed issue #14268:
URL: https://github.com/apache/pulsar/issues/14268
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039911061
> I noticed there is this PR that may be related to this issue: #12993
Yes, #12993 could help addressing the NPE. Have you tested the behavior with Pulsar 2.8.2 which includes #12993?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039911061
> I noticed there is this PR that may be related to this issue: #12993
Yes, #12993 could help addressing the NPE. Have you the behavior with Pulsar 2.8.2 which includes #12993?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1038876994
@eolivelli @codelipenghui @michaeljmarshall PTAL,thanks!
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lordcheng10 edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lordcheng10 edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039880391
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari edited a comment on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari edited a comment on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039906986
> I even took an execution task to see and found that it is only reading and writing zk, and the timeout time of zk is only 30 seconds, so I can't understand why it reaches the hour level:
What do you mean with "reaches the hour level"? [13450016 microseconds is 13,45 seconds](https://www.google.com/search?q=13450016+microseconds+to+seconds) .
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039906986
> I even took an execution task to see and found that it is only reading and writing zk, and the timeout time of zk is only 30 seconds, so I can't understand why it reaches the hour level:
What do you mean with "reaches the hour level"? [13450016 microseconds is 13,45 seconds](https://www.google.com/search?q=12721684+microseconds+to+seconds) .
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] lhotari commented on issue #14268: [2.8.1] FGC and throw NPE
Posted by GitBox <gi...@apache.org>.
lhotari commented on issue #14268:
URL: https://github.com/apache/pulsar/issues/14268#issuecomment-1039909726
> The most confusing thing is why the FGC is triggered
With FGC, do you mean "Full GC"? The GC log tells the reason why Full GCs get triggered. GC logging was added by #7498 . Have you checked the GC log entries?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org