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 2020/12/07 12:57:44 UTC
[GitHub] [pulsar] skyrocknroll opened a new issue #8849: Failed to create Producer
skyrocknroll opened a new issue #8849:
URL: https://github.com/apache/pulsar/issues/8849
**Describe the bug**
We are getting lot of following logs
```
[2020-12-07T12:50:33.970Z] INFO pulsar-io-23-3 ServerCnx:214 Closed connection from /10.0.98.14:55262
[2020-12-07T12:50:34.075Z] INFO pulsar-io-23-2 ServerCnx:206 New connection from /10.0.98.14:55854
[2020-12-07T12:50:34.084Z] INFO pulsar-io-23-3 ServerCnx:206 New connection from /10.0.98.14:55856
[2020-12-07T12:50:34.089Z] INFO pulsar-io-23-3 ServerCnx:1078 [/10.0.98.14:55856][persistent://tenant1/ns1/topic-1] Creating producer. producerId=0
[2020-12-07T12:50:34.092Z] INFO BookKeeperClientWorker-OrderedExecutor-0-0 ServerCnx:1131 [/10.0.98.14:55856] Created new producer: Producer{topic=PersistentTopic{topic=persistent://tenant1/ns1/topic-1}, client=/10.0.98.14:55856, producerName=pulsarcluster1-156-106655, producerId=0}
[2020-12-07T12:50:35.421Z] INFO prometheus-stats-44-1 RequestLog:62 10.0.71.196 - - [07/Dec/2020:12:50:35 +0000] "GET /metrics/ HTTP/1.1" 200 10908452 "-" "vm_promscrape" 194
[2020-12-07T12:50:39.762Z] INFO pulsar-web-43-3 RequestLog:62 10.0.34.190 - - [07/Dec/2020:12:50:39 +0000] "GET /admin/v2/clusters HTTP/1.1" 200 18 "-" "Consul Health Check" 2
[2020-12-07T12:50:42.903Z] WARN pulsar-io-23-4 PulsarHandler:99 [[id: 0x26c66e2f, L:/10.0.34.190:6651 - R:/10.0.98.14:55342]] Forcing connection to close after keep-alive timeout
[2020-12-07T12:50:42.903Z] INFO pulsar-io-23-4 ServerCnx:214 Closed connection from /10.0.98.14:55342
[2020-12-07T12:50:43.016Z] INFO pulsar-io-23-4 ServerCnx:206 New connection from /10.0.98.14:55898
[2020-12-07T12:50:43.022Z] INFO pulsar-io-23-4 ServerCnx:1078 [/10.0.98.14:55898][persistent://tenant1/ns1/topic-1] Creating producer. producerId=0
[2020-12-07T12:50:43.024Z] INFO BookKeeperClientWorker-OrderedExecutor-0-0 ServerCnx:1131 [/10.0.98.14:55898] Created new producer: Producer{topic=PersistentTopic{topic=persistent://tenant1/ns1/topic-1}, client=/10.0.98.14:55898, producerName=pulsarcluster1-156-106654, producerId=0}
[2020-12-07T12:50:50.152Z] ERROR bookkeeper-ml-workers-OrderedExecutor-5-0 SafeRunnable:38 Unexpected throwable caught
java.lang.IllegalArgumentException: null
at com.google.common.base.Preconditions.checkArgument(Preconditions.java:127) ~[com.google.guava-guava-25.1-jre.jar:?]
at org.apache.bookkeeper.mledger.impl.OpAddEntry.safeRun(OpAddEntry.java:165) ~[org.apache.pulsar-managed-ledger-2.6.1.jar:2.6.1]
at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) [org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.common.util.OrderedExecutor$TimedRunnable.run(OrderedExecutor.java:203) [org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_265]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_265]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.48.Final.jar:4.1.48.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]
[2020-12-07T12:50:50.412Z] INFO prometheus-stats-44-1 RequestLog:62 10.0.71.196 - - [07/Dec/2020:12:50:50 +0000] "GET /metrics/ HTTP/1.1" 200 10908451 "-" "vm_promscrape" 184
[2020-12-07T12:50:56.619Z] INFO pulsar-web-43-8 RequestLog:62 10.0.96.197 - - [07/Dec/2020:12:50:56 +0000] "GET /admin/v2/clusters HTTP/1.1" 200 18 "-" "Go-http-client/1.1" 3
[2020-12-07T12:50:59.770Z] INFO pulsar-web-43-3 RequestLog:62 10.0.34.190 - - [07/Dec/2020:12:50:59 +0000] "GET /admin/v2/clusters HTTP/1.1" 200 18 "-" "Consul Health Check" 2
[2020-12-07T12:51:05.458Z] INFO prometheus-stats-44-1 RequestLog:62 10.0.71.196 - - [07/Dec/2020:12:51:05 +0000] "GET /metrics/ HTTP/1.1" 200 10908292 "-" "vm_promscrape" 229
[2020-12-07T12:51:19.780Z] INFO pulsar-web-43-5 RequestLog:62 10.0.34.190 - - [07/Dec/2020:12:51:19 +0000] "GET /admin/v2/clusters HTTP/1.1" 200 18 "-" "Consul Health Check" 2
[2020-12-07T12:51:20.150Z] ERROR bookkeeper-ml-workers-OrderedExecutor-5-0 SafeRunnable:38 Unexpected throwable caught
java.lang.IllegalArgumentException: null
at com.google.common.base.Preconditions.checkArgument(Preconditions.java:127) ~[com.google.guava-guava-25.1-jre.jar:?]
at org.apache.bookkeeper.mledger.impl.OpAddEntry.safeRun(OpAddEntry.java:165) ~[org.apache.pulsar-managed-ledger-2.6.1.jar:2.6.1]
at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) [org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.common.util.OrderedExecutor$TimedRunnable.run(OrderedExecutor.java:203) [org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_265]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_265]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.48.Final.jar:4.1.48.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]
[2020-12-07T12:51:20.434Z] INFO prometheus-stats-44-1 RequestLog:62 10.0.71.196 - - [07/Dec/2020:12:51:20 +0000] "GET /metrics/ HTTP/1.1" 200 10908295 "-" "vm_promscrape" 207
```
* Once we restart the broker the exception stopped and we are able to create producer.
Environment
* ubuntu 18.04 x86_64
* Java 1.8
* Pulsar version 2.6.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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] sijie commented on issue #8849: Failed to create Producer
Posted by GitBox <gi...@apache.org>.
sijie commented on issue #8849:
URL: https://github.com/apache/pulsar/issues/8849#issuecomment-741568864
loop @codelipenghui to see if it is already fixed or not.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] dojiao commented on issue #8849: Failed to create Producer
Posted by GitBox <gi...@apache.org>.
dojiao commented on issue #8849:
URL: https://github.com/apache/pulsar/issues/8849#issuecomment-741556038
i meet the same issue using v2.6.1.
```
13:25:36.723 [BookKeeperClientWorker-OrderedExecutor-50-0] ERROR org.apache.bookkeeper.client.PendingAddOp - Write of ledger entry to quorum failed: L489090 E126369
13:25:36.723 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [tenant/cross3cities/persistent/abcd-partition-0] Creating a new ledger
13:25:36.723 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [tenant/cross3cities/persistent/abcd-partition-0] Creating ledger, metadata: {component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114], pulsar/managed-ledger=[111, 99, 112, 97, 95, 114, 101, 97, 108, 116, 105, 109, 101, 95, 97, 100, 106, 117, 115, 116, 47, 99, 114, 111, 115, 115, 51, 99, 105, 116, 105, 101, 115, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110, 116, 47, 111, 99, 112, 97, 45, 112, 97, 114, 116, 105, 116, 105, 111, 110, 45, 48], application=[112, 117, 108, 115, 97, 114]} - metadata ops timeout : 60 seconds
13:25:36.725 [main-EventThread] INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [tenant/cross3cities/persistent/abcd-partition-0] Creating ledger, metadata: {component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114], pulsar/managed-ledger=[111, 99, 112, 97, 95, 114, 101, 97, 108, 116, 105, 109, 101, 95, 97, 100, 106, 117, 115, 116, 47, 99, 114, 111, 115, 115, 51, 99, 105, 116, 105, 101, 115, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110, 116, 47, 111, 99, 112, 97, 45, 112, 97, 114, 116, 105, 116, 105, 111, 110, 45, 48], application=[112, 117, 108, 115, 97, 114]} - metadata ops timeout : 60 seconds
13:25:36.727 [main-EventThread] INFO org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [bookie1:3181, bookie2:3181, bookie3:3181, bookie4:3181] for ledger: 490692
13:25:36.727 [main-EventThread] INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [tenant/cross3cities/persistent/abcd-partition-0] Created new ledger 490692
13:25:36.729 [main-EventThread] INFO org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [bookie2:3181, bookie3:3181, bookie4:3181, bookie5:3181] for ledger: 490693
13:25:36.729 [main-EventThread] INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [tenant/cross3cities/persistent/abcd-partition-0] Created new ledger 490693
13:25:36.843 [bookkeeper-ml-workers-OrderedExecutor-0-0] ERROR org.apache.bookkeeper.common.util.SafeRunnable - Unexpected throwable caught
java.lang.IllegalArgumentException: null
at com.google.common.base.Preconditions.checkArgument(Preconditions.java:127) ~[com.google.guava-guava-25.1-jre.jar:?]
at org.apache.bookkeeper.mledger.impl.OpAddEntry.safeRun(OpAddEntry.java:165) ~[org.apache.pulsar-managed-ledger-2.6.1.jar:2.6.1]
at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) [org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.common.util.OrderedExecutor$TimedRunnable.run(OrderedExecutor.java:203) [org.apache.bookkeeper-bookkeeper-common-4.10.0.jar:4.10.0]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.48.Final.jar:4.1.48.Final]
at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
13:25:36.844 [bookkeeper-ml-workers-OrderedExecutor-0-0] ERROR org.apache.bookkeeper.common.util.SafeRunnable - Unexpected throwable caught
......
```
the log "Unexpected throwable caught" lasted about 200~300ms then got over it.
it seems like the check failed at
```java
checkArgument(this == firstInQueue);
```
in OpAddEntry::safeRun() when creating ledgers
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] sijie commented on issue #8849: Failed to create Producer
Posted by GitBox <gi...@apache.org>.
sijie commented on issue #8849:
URL: https://github.com/apache/pulsar/issues/8849#issuecomment-741155834
@skyrocknroll Can you provide more context on this issue?
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org