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 2021/02/03 17:37:40 UTC
[GitHub] [pulsar] lhotari opened a new issue #9450: Flaky-test: org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail
lhotari opened a new issue #9450:
URL: https://github.com/apache/pulsar/issues/9450
org.apache.pulsar.broker.service.ReplicatorTest is flaky. The testResetCursorNotFail test method fails sporadically.
```
org.testng.internal.thread.ThreadTimeoutException: Method org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail() didn't finish within the time-out 30000
```
Usage tip: To enable automatic navigation to failure message, open the links with CTRL/CMD-click.
[example failure 2021-02-03T01:05:58.8564231Z](https://github.com/apache/pulsar/runs/1818716441?check_suite_focus=true#step:9:220)
[example failure 2021-02-02T16:11:47.7564123Z](https://github.com/apache/pulsar/runs/1813603235?check_suite_focus=true#step:9:368)
[example failure 2021-02-02T16:03:18.2799391Z](https://github.com/apache/pulsar/runs/1813537588?check_suite_focus=true#step:9:379)
[example failure 2021-02-02T16:01:08.0326536Z](https://github.com/apache/pulsar/runs/1813537588?check_suite_focus=true#step:9:220)
[example failure 2021-02-02T13:49:56.6101213Z](https://github.com/apache/pulsar/runs/1813006738?check_suite_focus=true#step:9:1045)
[example failure 2021-02-01T23:49:57.6075482Z](https://github.com/apache/pulsar/runs/1810789556?check_suite_focus=true#step:9:220)
[example failure 2021-02-01T23:16:15.9997490Z](https://github.com/apache/pulsar/runs/1810616944?check_suite_focus=true#step:9:220)
[example failure 2021-02-01T20:11:13.5145694Z](https://github.com/apache/pulsar/runs/1809549378?check_suite_focus=true#step:9:220)
[example failure 2021-02-01T18:24:10.9311136Z](https://github.com/apache/pulsar/runs/1808358118?check_suite_focus=true#step:9:220)
[example failure 2021-02-01T16:24:25.1910906Z](https://github.com/apache/pulsar/runs/1807470436?check_suite_focus=true#step:9:220)
[example failure 2021-02-01T15:44:16.9748908Z](https://github.com/apache/pulsar/runs/1807437482?check_suite_focus=true#step:9:538)
[example failure 2021-02-01T15:42:02.4182452Z](https://github.com/apache/pulsar/runs/1807437482?check_suite_focus=true#step:9:379)
[example failure 2021-02-01T15:39:41.2878811Z](https://github.com/apache/pulsar/runs/1807437482?check_suite_focus=true#step:9:220)
[example failure 2021-02-01T09:27:54.9174939Z](https://github.com/apache/pulsar/runs/1804639268?check_suite_focus=true#step:9:599)
[example failure 2021-02-01T09:25:44.3137183Z](https://github.com/apache/pulsar/runs/1804639268?check_suite_focus=true#step:9:440)
[example failure 2021-02-01T03:58:24.9345942Z](https://github.com/apache/pulsar/runs/1803769568?check_suite_focus=true#step:9:1139)
[example failure 2021-02-01T03:54:51.8139627Z](https://github.com/apache/pulsar/runs/1803769568?check_suite_focus=true#step:9:220)
[example failure 2021-01-31T12:12:19.0872946Z](https://github.com/apache/pulsar/runs/1800964447?check_suite_focus=true#step:8:368)
[example failure 2021-01-21T23:26:21.8643558Z](https://github.com/apache/pulsar/runs/1745443217?check_suite_focus=true#step:8:220)
<details>
<summary>Full exception stacktrace</summary>
<code><pre>
org.testng.internal.thread.ThreadTimeoutException: Method org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail() didn't finish within the time-out 30000
at org.testng.internal.MethodInvocationHelper.invokeWithTimeoutWithNewExecutor(MethodInvocationHelper.java:371)
at org.testng.internal.MethodInvocationHelper.invokeWithTimeout(MethodInvocationHelper.java:282)
at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:605)
at org.testng.internal.TestInvoker.retryFailed(TestInvoker.java:214)
at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:58)
at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822)
at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
at java.util.ArrayList.forEach(ArrayList.java:1257)
at org.testng.TestRunner.privateRun(TestRunner.java:764)
at org.testng.TestRunner.run(TestRunner.java:585)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
at org.testng.SuiteRunner.run(SuiteRunner.java:286)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
at org.testng.TestNG.runSuites(TestNG.java:1069)
at org.testng.TestNG.run(TestNG.java:1037)
at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:135)
at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeSingleClass(TestNGDirectoryTestSuite.java:112)
at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:99)
at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:146)
at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
</pre></code>
</details>
```
org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Client is not authorized to Produce
at org.apache.pulsar.client.api.PulsarClientException.unwrap(PulsarClientException.java:979)
at org.apache.pulsar.client.impl.ProducerBuilderImpl.create(ProducerBuilderImpl.java:95)
at org.apache.pulsar.broker.service.ReplicatorTestBase$MessageProducer.<init>(ReplicatorTestBase.java:301)
at org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail(ReplicatorTest.java:507)
```
Usage tip: To enable automatic navigation to failure message, open the links with CTRL/CMD-click.
[example failure 2021-02-02T13:46:14.3674803Z](https://github.com/apache/pulsar/runs/1813006738?check_suite_focus=true#step:9:714)
[example failure 2021-02-01T03:56:01.6136236Z](https://github.com/apache/pulsar/runs/1803769568?check_suite_focus=true#step:9:873)
<details>
<summary>Full exception stacktrace</summary>
<code><pre>
org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Client is not authorized to Produce
at org.apache.pulsar.client.api.PulsarClientException.unwrap(PulsarClientException.java:979)
at org.apache.pulsar.client.impl.ProducerBuilderImpl.create(ProducerBuilderImpl.java:95)
at org.apache.pulsar.broker.service.ReplicatorTestBase$MessageProducer.<init>(ReplicatorTestBase.java:301)
at org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail(ReplicatorTest.java:507)
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 org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:45)
at org.testng.internal.InvokeMethodRunnable.call(InvokeMethodRunnable.java:73)
at org.testng.internal.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
</pre></code>
</details>
```
org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Client is not authorized to Produce
at org.apache.pulsar.client.api.PulsarClientException.unwrap(PulsarClientException.java:979)
at org.apache.pulsar.client.impl.ProducerBuilderImpl.create(ProducerBuilderImpl.java:94)
at org.apache.pulsar.broker.service.ReplicatorTestBase$MessageProducer.<init>(ReplicatorTestBase.java:301)
at org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail(ReplicatorTest.java:507)
```
Usage tip: To enable automatic navigation to failure message, open the links with CTRL/CMD-click.
[example failure 2021-02-01T01:35:59.5083094Z](https://github.com/apache/pulsar/runs/1803320722?check_suite_focus=true#step:9:714)
<details>
<summary>Full exception stacktrace</summary>
<code><pre>
org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Client is not authorized to Produce
at org.apache.pulsar.client.api.PulsarClientException.unwrap(PulsarClientException.java:979)
at org.apache.pulsar.client.impl.ProducerBuilderImpl.create(ProducerBuilderImpl.java:94)
at org.apache.pulsar.broker.service.ReplicatorTestBase$MessageProducer.<init>(ReplicatorTestBase.java:301)
at org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail(ReplicatorTest.java:507)
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 org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:45)
at org.testng.internal.InvokeMethodRunnable.call(InvokeMethodRunnable.java:73)
at org.testng.internal.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
</pre></code>
</details>
----------------------------------------------------------------
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] michaeljmarshall edited a comment on issue #9450: Flaky-test: org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail
Posted by GitBox <gi...@apache.org>.
michaeljmarshall edited a comment on issue #9450:
URL: https://github.com/apache/pulsar/issues/9450#issuecomment-777984844
I also noticed that there are also failures in this test class for `activeBrokerParse`. This test runs before the `testResetCursorNotFail` test. It seems like an additional test failure, but I haven't been able to figure that out yet. I'll look into both. Seems like some of the failures @lhotari references above have a failure from `activeBrokerParse`.
```
------- Starting test [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].activeBrokerParse([])-------
04:21:18.761 [pulsar-web-77-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:18 +0000] "DELETE /admin/namespaces/pulsar/global/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 13
04:21:18.805 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810001 local:/127.0.0.1:56928 remoteserver:localhost/127.0.0.1:33175 lastZxid:32 xid:31 sent:37 recv:42 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/admin/clusters
04:21:18.815 [pulsar-web-157-1] INFO org.apache.pulsar.broker.admin.impl.ClustersBase - [null] Created cluster activeCLuster2
04:21:18.816 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - reloadCache called in zookeeperChildrenCache for path /admin/clusters
04:21:18.817 [pulsar-web-157-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:18 +0000] "PUT /admin/v2/clusters/activeCLuster2 HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 30
04:21:19.035 [pulsar-web-157-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/clusters/activeCLuster2 HTTP/1.1" 200 69 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 2
04:21:19.077 [pulsar-web-77-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 23
04:21:19.089 [pulsar-web-77-7] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 5
04:21:19.095 [pulsar-web-77-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 2
04:21:19.104 [pulsar-web-77-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 3
04:21:19.112 [pulsar-web-77-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 3
04:21:19.121 [pulsar-web-77-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 3
~~~~~~~~~ SKIPPED -- [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].activeBrokerParse([])-------04:21:19.154 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns
04:21:19.154 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns, quota=destination_storage
04:21:19.155 [pulsar-web-77-7] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/v2/namespaces/pulsar/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 14
04:21:19.163 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810001 local:/127.0.0.1:56928 remoteserver:localhost/127.0.0.1:33175 lastZxid:34 xid:33 sent:39 recv:45 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:21:19.164 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810003 local:/127.0.0.1:56950 remoteserver:localhost/127.0.0.1:33175 lastZxid:32 xid:22 sent:26 recv:31 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:21:19.165 [pulsar-web-77-8] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns1
04:21:19.165 [pulsar-web-77-8] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns1, quota=destination_storage
04:21:19.166 [pulsar-web-77-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/v2/namespaces/pulsar/ns1/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 8
04:21:19.170 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.BrokerService - /admin/policies/pulsar/ns1 updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[r2, r1], bundles=BundlesData{numBundles=1, boundaries=[0x00000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, autoTopicCreationOverride=null, autoSubscriptionCreationOverride=null, clusterDispatchRate={}, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, message_ttl_in_seconds=null, subscription_expiration_time_minutes=0, retention_policies=null, deleted=false, encryption_required=false, delayed_delivery_policies=null, inactive_topic_policies=null, subscription_auth_mode=None, max_producers_per_topic=null, max_consumers_per_topic=null, max_consumers_per_subscription=null, max_unacked_messages_p
er_consumer=-1, max_unacked_messages_per_subscription=-1, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true, offload_policies=null}
04:21:19.170 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.171 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_request_hold-1613103670515] Policies updated successfully
04:21:19.171 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.171 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.171 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_exception-1613103652346] Policies updated successfully
04:21:19.172 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.176 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.BrokerService - /admin/policies/pulsar/ns1 updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[r2, r1], bundles=BundlesData{numBundles=1, boundaries=[0x00000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, autoTopicCreationOverride=null, autoSubscriptionCreationOverride=null, clusterDispatchRate={}, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, message_ttl_in_seconds=null, subscription_expiration_time_minutes=0, retention_policies=null, deleted=false, encryption_required=false, delayed_delivery_policies=null, inactive_topic_policies=null, subscription_auth_mode=None, max_producers_per_topic=null, max_consumers_per_topic=null, max_consumers_per_subscription=null, max_unacked_messages_p
er_consumer=-1, max_unacked_messages_per_subscription=-1, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true, offload_policies=null}
04:21:19.177 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.180 [pulsar-web-77-1] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/global/ns
04:21:19.181 [pulsar-web-77-1] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/global/ns, quota=destination_storage
04:21:19.181 [pulsar-web-77-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/namespaces/pulsar/global/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 11
------- Starting test [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].activeBrokerParse([])-------
04:21:19.188 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.Producer - [null] is not allowed to produce on topic [persistent://pulsar/ns1/producer_request_hold-1613103670515] anymore
04:21:19.189 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.Producer - Disconnecting producer: Producer{topic=PersistentTopic{topic=persistent://pulsar/ns1/producer_request_hold-1613103670515}, client=/127.0.0.1:47894, producerName=pulsar.repl.r2, producerId=1}
04:21:19.189 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_request_hold-1613103670515] Policies updated successfully
04:21:19.190 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.190 [pulsar-io-139-2] INFO org.apache.pulsar.client.impl.ClientCnx - [localhost/127.0.0.1:41689] Broker notification of Closed producer: 1
04:21:19.190 [pulsar-io-139-2] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_request_hold-1613103670515] [pulsar.repl.r2] Closed connection [id: 0x51209843, L:/127.0.0.1:47894 - R:localhost/127.0.0.1:41689] -- Will try again in 0.1 s
04:21:19.190 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.209 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.Producer - [null] is not allowed to produce on topic [persistent://pulsar/ns1/producer_exception-1613103652346] anymore
04:21:19.210 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.Producer - Disconnecting producer: Producer{topic=PersistentTopic{topic=persistent://pulsar/ns1/producer_exception-1613103652346}, client=/127.0.0.1:47960, producerName=pulsar.repl.r2, producerId=0}
04:21:19.210 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_exception-1613103652346] Policies updated successfully
04:21:19.210 [pulsar-io-139-1] INFO org.apache.pulsar.client.impl.ClientCnx - [localhost/127.0.0.1:41689] Broker notification of Closed producer: 0
04:21:19.210 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.210 [pulsar-io-139-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_exception-1613103652346] [pulsar.repl.r2] Closed connection [id: 0xb46cf921, L:/127.0.0.1:47960 - R:localhost/127.0.0.1:41689] -- Will try again in 0.1 s
04:21:19.226 [pulsar-web-157-8] WARN org.apache.pulsar.broker.admin.impl.ClustersBase - [null] Failed to create already existing cluster activeCLuster2
04:21:19.226 [pulsar-web-157-8] ERROR org.apache.pulsar.broker.admin.impl.ClustersBase - [null] Failed to create cluster activeCLuster2
org.apache.pulsar.broker.web.RestException: Cluster already exists
at org.apache.pulsar.broker.admin.impl.ClustersBase.createCluster(ClustersBase.java:171) ~[classes/:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_275]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_275]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_275]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_275]
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:159) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:253) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:292) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:274) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:244) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:232) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:680) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:366) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:319) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205) ~[jersey-container-servlet-core-2.31.jar:?]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:791) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1626) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.apache.pulsar.broker.web.ResponseHandlerFilter.doFilter(ResponseHandlerFilter.java:58) ~[classes/:?]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:234) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:179) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633) [jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380) [jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273) [jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [jetty-io-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [jetty-io-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [jetty-io-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
04:21:19.230 [pulsar-web-157-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "PUT /admin/v2/clusters/activeCLuster2 HTTP/1.1" 409 35 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 22
04:21:19.237 [AsyncHttpClient-248-1] WARN org.apache.pulsar.client.admin.internal.BaseResource - [http://localhost:44131/admin/v2/clusters/activeCLuster2] Failed to perform http put request: javax.ws.rs.ClientErrorException: HTTP 409 Conflict
!!!!!!!!! FAILURE-- [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].activeBrokerParse([])-------
04:21:19.287 [pulsar-web-77-6] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns
04:21:19.288 [pulsar-web-77-6] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns, quota=destination_storage
04:21:19.290 [pulsar-web-77-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/v2/namespaces/pulsar/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 10
04:21:19.291 [pulsar-timer-266-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_request_hold-1613103670515] [pulsar.repl.r2] Reconnecting after timeout
04:21:19.292 [pulsar-io-139-3] INFO org.apache.pulsar.client.impl.ConnectionPool - [[id: 0x72857fce, L:/127.0.0.1:47990 - R:localhost/127.0.0.1:41689]] Connected to server
04:21:19.293 [pulsar-io-59-4] INFO org.apache.pulsar.broker.service.ServerCnx - New connection from /127.0.0.1:47990
04:21:19.301 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810003 local:/127.0.0.1:56950 remoteserver:localhost/127.0.0.1:33175 lastZxid:36 xid:23 sent:27 recv:33 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:21:19.302 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810001 local:/127.0.0.1:56928 remoteserver:localhost/127.0.0.1:33175 lastZxid:36 xid:34 sent:40 recv:47 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:21:19.307 [pulsar-web-77-5] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns1
04:21:19.307 [pulsar-web-77-5] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns1, quota=destination_storage
04:21:19.310 [pulsar-web-77-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/v2/namespaces/pulsar/ns1/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 17
04:21:19.311 [pulsar-timer-266-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_exception-1613103652346] [pulsar.repl.r2] Reconnecting after timeout
04:21:19.315 [pulsar-io-59-4] WARN org.apache.pulsar.broker.service.ServerCnx - Role null is not authorized to perform operation LOOKUP on topic persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.315 [pulsar-io-59-4] WARN org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:47990] Proxy Client is not authorized to Lookup with role null on topic persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.317 [pulsar-io-139-3] WARN org.apache.pulsar.client.impl.BinaryProtoLookupService - [persistent://pulsar/ns1/producer_request_hold-1613103670515] failed to send lookup request : Proxy Client is not authorized to Lookup
04:21:19.314 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.BrokerService - /admin/policies/pulsar/ns1 updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[r2, r1], bundles=BundlesData{numBundles=1, boundaries=[0x00000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, autoTopicCreationOverride=null, autoSubscriptionCreationOverride=null, clusterDispatchRate={}, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, message_ttl_in_seconds=null, subscription_expiration_time_minutes=0, retention_policies=null, deleted=false, encryption_required=false, delayed_delivery_policies=null, inactive_topic_policies=null, subscription_auth_mode=None, max_producers_per_topic=null, max_consumers_per_topic=null, max_consumers_per_subscription=null, max_unacked_messages_p
er_consumer=-1, max_unacked_messages_per_subscription=-1, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true, offload_policies=null}
04:21:19.317 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.319 [pulsar-io-139-3] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_request_hold-1613103670515] [pulsar.repl.r2] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Proxy Client is not authorized to Lookup
04:21:19.319 [pulsar-io-139-3] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_request_hold-1613103670515] [pulsar.repl.r2] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Proxy Client is not authorized to Lookup -- Will try again in 0.1 s
04:21:19.319 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_request_hold-1613103670515] Policies updated successfully
04:21:19.319 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.319 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.320 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_exception-1613103652346] Policies updated successfully
04:21:19.320 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.320 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.ServerCnx - Role null is not authorized to perform operation LOOKUP on topic persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.320 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:47960] Proxy Client is not authorized to Lookup with role null on topic persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.320 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.BrokerService - /admin/policies/pulsar/ns1 updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[r2, r1], bundles=BundlesData{numBundles=1, boundaries=[0x00000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, autoTopicCreationOverride=null, autoSubscriptionCreationOverride=null, clusterDispatchRate={}, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, message_ttl_in_seconds=null, subscription_expiration_time_minutes=0, retention_policies=null, deleted=false, encryption_required=false, delayed_delivery_policies=null, inactive_topic_policies=null, subscription_auth_mode=None, max_producers_per_topic=null, max_consumers_per_topic=null, max_consumers_per_subscription=null, max_unacked_messages_p
er_consumer=-1, max_unacked_messages_per_subscription=-1, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true, offload_policies=null}
04:21:19.321 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.321 [pulsar-io-139-1] WARN org.apache.pulsar.client.impl.BinaryProtoLookupService - [persistent://pulsar/ns1/producer_exception-1613103652346] failed to send lookup request : Proxy Client is not authorized to Lookup
04:21:19.321 [pulsar-io-139-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_exception-1613103652346] [pulsar.repl.r2] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Proxy Client is not authorized to Lookup
04:21:19.321 [pulsar-io-139-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_exception-1613103652346] [pulsar.repl.r2] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Proxy Client is not authorized to Lookup -- Will try again in 0.1 s
04:21:19.321 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_request_hold-1613103670515] Policies updated successfully
04:21:19.321 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.321 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.321 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_exception-1613103652346] Policies updated successfully
04:21:19.321 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.326 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/global/ns
04:21:19.326 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/global/ns, quota=destination_storage
04:21:19.327 [pulsar-web-77-7] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/namespaces/pulsar/global/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 9
```
----------------------------------------------------------------
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] lhotari commented on issue #9450: Flaky-test: org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail
Posted by GitBox <gi...@apache.org>.
lhotari commented on issue #9450:
URL: https://github.com/apache/pulsar/issues/9450#issuecomment-778032781
> I also noticed that there are also failures in this test class for `activeBrokerParse`. This test runs before the `testResetCursorNotFail` test. It seems like an additional test failure, but I haven't been able to figure that out yet. I'll look into both. Seems like some of the failures @lhotari references above have a failure from `activeBrokerParse`.
Yes, it's possible that the last failure in the logs isn't the root cause. There are test retries in place for most unit tests so that a test failure gets retried once. It's possible to disable the custom test retry solution for TestNG tests by passing `-DtestRetryCount=0`.
There are quite a few different failures in ReplicatorTest class. I have also reported #9457 and #9458 . It probably makes sense to handle those at the same time.
----------------------------------------------------------------
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] codelipenghui commented on issue #9450: Flaky-test: org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail
Posted by GitBox <gi...@apache.org>.
codelipenghui commented on issue #9450:
URL: https://github.com/apache/pulsar/issues/9450#issuecomment-1058893722
The issue had no activity for 30 days, mark with Stale label.
--
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] michaeljmarshall commented on issue #9450: Flaky-test: org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail
Posted by GitBox <gi...@apache.org>.
michaeljmarshall commented on issue #9450:
URL: https://github.com/apache/pulsar/issues/9450#issuecomment-777984844
I also noticed that there are also failures in this test class for `activeBrokerParse`. This test runs before the `testResetCursorNotFail` test. It seems like an additional test failure, but I haven't been able to figure that out yet. I'll look into both. Seems like some of the failures @lhotari references above have a failure from `activeBrokerParse`.
```------- Starting test [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].activeBrokerParse([])-------
04:21:18.761 [pulsar-web-77-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:18 +0000] "DELETE /admin/namespaces/pulsar/global/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 13
04:21:18.805 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810001 local:/127.0.0.1:56928 remoteserver:localhost/127.0.0.1:33175 lastZxid:32 xid:31 sent:37 recv:42 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/admin/clusters
04:21:18.815 [pulsar-web-157-1] INFO org.apache.pulsar.broker.admin.impl.ClustersBase - [null] Created cluster activeCLuster2
04:21:18.816 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperChildrenCache - reloadCache called in zookeeperChildrenCache for path /admin/clusters
04:21:18.817 [pulsar-web-157-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:18 +0000] "PUT /admin/v2/clusters/activeCLuster2 HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 30
04:21:19.035 [pulsar-web-157-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/clusters/activeCLuster2 HTTP/1.1" 200 69 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 2
04:21:19.077 [pulsar-web-77-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 23
04:21:19.089 [pulsar-web-77-7] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 5
04:21:19.095 [pulsar-web-77-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 2
04:21:19.104 [pulsar-web-77-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 3
04:21:19.112 [pulsar-web-77-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 3
04:21:19.121 [pulsar-web-77-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "GET /admin/v2/brokers/activeCLuster2 HTTP/1.1" 307 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 3
~~~~~~~~~ SKIPPED -- [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].activeBrokerParse([])-------04:21:19.154 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns
04:21:19.154 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns, quota=destination_storage
04:21:19.155 [pulsar-web-77-7] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/v2/namespaces/pulsar/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 14
04:21:19.163 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810001 local:/127.0.0.1:56928 remoteserver:localhost/127.0.0.1:33175 lastZxid:34 xid:33 sent:39 recv:45 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:21:19.164 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810003 local:/127.0.0.1:56950 remoteserver:localhost/127.0.0.1:33175 lastZxid:32 xid:22 sent:26 recv:31 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:21:19.165 [pulsar-web-77-8] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns1
04:21:19.165 [pulsar-web-77-8] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns1, quota=destination_storage
04:21:19.166 [pulsar-web-77-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/v2/namespaces/pulsar/ns1/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 8
04:21:19.170 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.BrokerService - /admin/policies/pulsar/ns1 updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[r2, r1], bundles=BundlesData{numBundles=1, boundaries=[0x00000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, autoTopicCreationOverride=null, autoSubscriptionCreationOverride=null, clusterDispatchRate={}, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, message_ttl_in_seconds=null, subscription_expiration_time_minutes=0, retention_policies=null, deleted=false, encryption_required=false, delayed_delivery_policies=null, inactive_topic_policies=null, subscription_auth_mode=None, max_producers_per_topic=null, max_consumers_per_topic=null, max_consumers_per_subscription=null, max_unacked_messages_p
er_consumer=-1, max_unacked_messages_per_subscription=-1, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true, offload_policies=null}
04:21:19.170 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.171 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_request_hold-1613103670515] Policies updated successfully
04:21:19.171 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.171 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.171 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_exception-1613103652346] Policies updated successfully
04:21:19.172 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.176 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.BrokerService - /admin/policies/pulsar/ns1 updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[r2, r1], bundles=BundlesData{numBundles=1, boundaries=[0x00000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, autoTopicCreationOverride=null, autoSubscriptionCreationOverride=null, clusterDispatchRate={}, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, message_ttl_in_seconds=null, subscription_expiration_time_minutes=0, retention_policies=null, deleted=false, encryption_required=false, delayed_delivery_policies=null, inactive_topic_policies=null, subscription_auth_mode=None, max_producers_per_topic=null, max_consumers_per_topic=null, max_consumers_per_subscription=null, max_unacked_messages_p
er_consumer=-1, max_unacked_messages_per_subscription=-1, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true, offload_policies=null}
04:21:19.177 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.180 [pulsar-web-77-1] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/global/ns
04:21:19.181 [pulsar-web-77-1] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/global/ns, quota=destination_storage
04:21:19.181 [pulsar-web-77-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/namespaces/pulsar/global/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 11
------- Starting test [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].activeBrokerParse([])-------
04:21:19.188 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.Producer - [null] is not allowed to produce on topic [persistent://pulsar/ns1/producer_request_hold-1613103670515] anymore
04:21:19.189 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.Producer - Disconnecting producer: Producer{topic=PersistentTopic{topic=persistent://pulsar/ns1/producer_request_hold-1613103670515}, client=/127.0.0.1:47894, producerName=pulsar.repl.r2, producerId=1}
04:21:19.189 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_request_hold-1613103670515] Policies updated successfully
04:21:19.190 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.190 [pulsar-io-139-2] INFO org.apache.pulsar.client.impl.ClientCnx - [localhost/127.0.0.1:41689] Broker notification of Closed producer: 1
04:21:19.190 [pulsar-io-139-2] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_request_hold-1613103670515] [pulsar.repl.r2] Closed connection [id: 0x51209843, L:/127.0.0.1:47894 - R:localhost/127.0.0.1:41689] -- Will try again in 0.1 s
04:21:19.190 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.209 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.Producer - [null] is not allowed to produce on topic [persistent://pulsar/ns1/producer_exception-1613103652346] anymore
04:21:19.210 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.Producer - Disconnecting producer: Producer{topic=PersistentTopic{topic=persistent://pulsar/ns1/producer_exception-1613103652346}, client=/127.0.0.1:47960, producerName=pulsar.repl.r2, producerId=0}
04:21:19.210 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_exception-1613103652346] Policies updated successfully
04:21:19.210 [pulsar-io-139-1] INFO org.apache.pulsar.client.impl.ClientCnx - [localhost/127.0.0.1:41689] Broker notification of Closed producer: 0
04:21:19.210 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.210 [pulsar-io-139-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_exception-1613103652346] [pulsar.repl.r2] Closed connection [id: 0xb46cf921, L:/127.0.0.1:47960 - R:localhost/127.0.0.1:41689] -- Will try again in 0.1 s
04:21:19.226 [pulsar-web-157-8] WARN org.apache.pulsar.broker.admin.impl.ClustersBase - [null] Failed to create already existing cluster activeCLuster2
04:21:19.226 [pulsar-web-157-8] ERROR org.apache.pulsar.broker.admin.impl.ClustersBase - [null] Failed to create cluster activeCLuster2
org.apache.pulsar.broker.web.RestException: Cluster already exists
at org.apache.pulsar.broker.admin.impl.ClustersBase.createCluster(ClustersBase.java:171) ~[classes/:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_275]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_275]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_275]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_275]
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:159) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:253) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:292) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:274) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:244) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:232) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:680) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:366) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:319) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205) ~[jersey-container-servlet-core-2.31.jar:?]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:791) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1626) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.apache.pulsar.broker.web.ResponseHandlerFilter.doFilter(ResponseHandlerFilter.java:58) ~[classes/:?]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[jetty-servlet-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:234) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:179) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388) ~[jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633) [jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380) [jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273) [jetty-server-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [jetty-io-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [jetty-io-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [jetty-io-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375) [jetty-util-9.4.35.v20201120.jar:9.4.35.v20201120]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
04:21:19.230 [pulsar-web-157-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "PUT /admin/v2/clusters/activeCLuster2 HTTP/1.1" 409 35 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 22
04:21:19.237 [AsyncHttpClient-248-1] WARN org.apache.pulsar.client.admin.internal.BaseResource - [http://localhost:44131/admin/v2/clusters/activeCLuster2] Failed to perform http put request: javax.ws.rs.ClientErrorException: HTTP 409 Conflict
!!!!!!!!! FAILURE-- [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].activeBrokerParse([])-------
04:21:19.287 [pulsar-web-77-6] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns
04:21:19.288 [pulsar-web-77-6] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns, quota=destination_storage
04:21:19.290 [pulsar-web-77-6] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/v2/namespaces/pulsar/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 10
04:21:19.291 [pulsar-timer-266-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_request_hold-1613103670515] [pulsar.repl.r2] Reconnecting after timeout
04:21:19.292 [pulsar-io-139-3] INFO org.apache.pulsar.client.impl.ConnectionPool - [[id: 0x72857fce, L:/127.0.0.1:47990 - R:localhost/127.0.0.1:41689]] Connected to server
04:21:19.293 [pulsar-io-59-4] INFO org.apache.pulsar.broker.service.ServerCnx - New connection from /127.0.0.1:47990
04:21:19.301 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810003 local:/127.0.0.1:56950 remoteserver:localhost/127.0.0.1:33175 lastZxid:36 xid:23 sent:27 recv:33 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:21:19.302 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x10000142f810001 local:/127.0.0.1:56928 remoteserver:localhost/127.0.0.1:33175 lastZxid:36 xid:34 sent:40 recv:47 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:21:19.307 [pulsar-web-77-5] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns1
04:21:19.307 [pulsar-web-77-5] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns1, quota=destination_storage
04:21:19.310 [pulsar-web-77-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/v2/namespaces/pulsar/ns1/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 17
04:21:19.311 [pulsar-timer-266-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_exception-1613103652346] [pulsar.repl.r2] Reconnecting after timeout
04:21:19.315 [pulsar-io-59-4] WARN org.apache.pulsar.broker.service.ServerCnx - Role null is not authorized to perform operation LOOKUP on topic persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.315 [pulsar-io-59-4] WARN org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:47990] Proxy Client is not authorized to Lookup with role null on topic persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.317 [pulsar-io-139-3] WARN org.apache.pulsar.client.impl.BinaryProtoLookupService - [persistent://pulsar/ns1/producer_request_hold-1613103670515] failed to send lookup request : Proxy Client is not authorized to Lookup
04:21:19.314 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.BrokerService - /admin/policies/pulsar/ns1 updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[r2, r1], bundles=BundlesData{numBundles=1, boundaries=[0x00000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, autoTopicCreationOverride=null, autoSubscriptionCreationOverride=null, clusterDispatchRate={}, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, message_ttl_in_seconds=null, subscription_expiration_time_minutes=0, retention_policies=null, deleted=false, encryption_required=false, delayed_delivery_policies=null, inactive_topic_policies=null, subscription_auth_mode=None, max_producers_per_topic=null, max_consumers_per_topic=null, max_consumers_per_subscription=null, max_unacked_messages_p
er_consumer=-1, max_unacked_messages_per_subscription=-1, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true, offload_policies=null}
04:21:19.317 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.319 [pulsar-io-139-3] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_request_hold-1613103670515] [pulsar.repl.r2] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Proxy Client is not authorized to Lookup
04:21:19.319 [pulsar-io-139-3] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_request_hold-1613103670515] [pulsar.repl.r2] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Proxy Client is not authorized to Lookup -- Will try again in 0.1 s
04:21:19.319 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_request_hold-1613103670515] Policies updated successfully
04:21:19.319 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.319 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.320 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_exception-1613103652346] Policies updated successfully
04:21:19.320 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.320 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.ServerCnx - Role null is not authorized to perform operation LOOKUP on topic persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.320 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:47960] Proxy Client is not authorized to Lookup with role null on topic persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.320 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.BrokerService - /admin/policies/pulsar/ns1 updating with Policies{auth_policies=org.apache.pulsar.common.policies.data.AuthPolicies@745f, replication_clusters=[r2, r1], bundles=BundlesData{numBundles=1, boundaries=[0x00000000, 0xffffffff]}, backlog_quota_map={}, persistence=null, deduplicationEnabled=null, autoTopicCreationOverride=null, autoSubscriptionCreationOverride=null, clusterDispatchRate={}, topicDispatchRate={}, subscriptionDispatchRate={}, replicatorDispatchRate={}, clusterSubscribeRate={}, publishMaxMessageRate={}, latency_stats_sample_rate={}, message_ttl_in_seconds=null, subscription_expiration_time_minutes=0, retention_policies=null, deleted=false, encryption_required=false, delayed_delivery_policies=null, inactive_topic_policies=null, subscription_auth_mode=None, max_producers_per_topic=null, max_consumers_per_topic=null, max_consumers_per_subscription=null, max_unacked_messages_p
er_consumer=-1, max_unacked_messages_per_subscription=-1, compaction_threshold=0, offload_threshold=-1, offload_deletion_lag_ms=null, schema_auto_update_compatibility_strategy=Full, schema_validation_enforced=false, schema_compatibility_Strategy=UNDEFINED, is_allow_auto_update_Schema=true, offload_policies=null}
04:21:19.321 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_request_hold-1613103670515
04:21:19.321 [pulsar-io-139-1] WARN org.apache.pulsar.client.impl.BinaryProtoLookupService - [persistent://pulsar/ns1/producer_exception-1613103652346] failed to send lookup request : Proxy Client is not authorized to Lookup
04:21:19.321 [pulsar-io-139-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_exception-1613103652346] [pulsar.repl.r2] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Proxy Client is not authorized to Lookup
04:21:19.321 [pulsar-io-139-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/ns1/producer_exception-1613103652346] [pulsar.repl.r2] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$AuthorizationException: Proxy Client is not authorized to Lookup -- Will try again in 0.1 s
04:21:19.321 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_request_hold-1613103670515] Policies updated successfully
04:21:19.321 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.321 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/ns1/producer_exception-1613103652346
04:21:19.321 [ForkJoinPool.commonPool-worker-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/ns1/producer_exception-1613103652346] Policies updated successfully
04:21:19.321 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:21:19.326 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/global/ns
04:21:19.326 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/global/ns, quota=destination_storage
04:21:19.327 [pulsar-web-77-7] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:21:19 +0000] "DELETE /admin/namespaces/pulsar/global/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 9
```
----------------------------------------------------------------
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] michaeljmarshall commented on issue #9450: Flaky-test: org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail
Posted by GitBox <gi...@apache.org>.
michaeljmarshall commented on issue #9450:
URL: https://github.com/apache/pulsar/issues/9450#issuecomment-777227642
Just had this one fail for one of my PRs. I am going to start digging into this test.
----------------------------------------------------------------
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] michaeljmarshall commented on issue #9450: Flaky-test: org.apache.pulsar.broker.service.ReplicatorTest.testResetCursorNotFail
Posted by GitBox <gi...@apache.org>.
michaeljmarshall commented on issue #9450:
URL: https://github.com/apache/pulsar/issues/9450#issuecomment-777983886
These are the logs (and possibly a little extra) from the pulsar cluster (out of surefire reports) for a failed `testResetCursorNotFail`. I haven't been able to narrow in on the problem yet.
```
------- Starting test [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].testResetCursorNotFail([])-------
04:50:59.325 [TestNG-method=testResetCursorNotFail-1] INFO org.apache.pulsar.broker.service.ReplicatorTest - --- Starting ReplicatorTest::testResetCursorNotFail ---
04:50:59.325 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl - [pulsar/partitionedNs-false/persistent/dummyTopic] Successfully initialize managed ledger
04:50:59.325 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling for persistent://pulsar/partitionedNs-false/dummyTopic
04:50:59.326 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN org.apache.pulsar.broker.service.BrokerService - Topic level policies are not enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on broker.conf
04:50:59.326 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/partitionedNs-false/dummyTopic] There are no replicated subscriptions on the topic
04:50:59.326 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/partitionedNs-false/dummyTopic] Starting replicator to remote: r1
04:51:00.427 [SyncThread-87-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file because current active log channel has not initialized yet
04:51:00.433 [SyncThread-87-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk0test7266224708557895544/current/0.log for logId 0.
04:51:00.451 [pool-47-thread-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk0test7266224708557895544/current/1.log for logId 1.
04:51:00.456 [db-storage-cleanup-90-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes for ledgers: [32, 34, 36, 38, 39, 40, 41, 12, 15, 17, 18, 19, 20, 24, 26, 27, 28, 30, 31]
04:51:00.460 [db-storage-cleanup-90-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes for 38 entries from 19 ledgers in 0.004 seconds
04:51:00.825 [SyncThread-97-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file because current active log channel has not initialized yet
04:51:00.825 [SyncThread-97-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk1test4008531672981107329/current/0.log for logId 0.
04:51:00.835 [pool-53-thread-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk1test4008531672981107329/current/1.log for logId 1.
04:51:00.848 [db-storage-cleanup-100-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes for ledgers: [33, 35, 36, 37, 38, 39, 40, 41, 13, 14, 16, 17, 18, 19, 21, 22, 23, 24, 25, 27, 29]
04:51:00.853 [db-storage-cleanup-100-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes for 42 entries from 21 ledgers in 0.004 seconds
04:51:01.218 [SyncThread-107-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file because current active log channel has not initialized yet
04:51:01.221 [SyncThread-107-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk2test5422802886547866332/current/0.log for logId 0.
04:51:01.230 [pool-59-thread-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk2test5422802886547866332/current/1.log for logId 1.
04:51:01.239 [db-storage-cleanup-110-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes for ledgers: [32, 33, 34, 35, 37, 12, 13, 14, 15, 16, 20, 21, 22, 23, 25, 26, 28, 29, 30, 31]
04:51:01.243 [db-storage-cleanup-110-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes for 40 entries from 20 ledgers in 0.004 seconds
04:51:01.291 [pulsar-io-59-2] ERROR org.apache.pulsar.broker.service.persistent.PersistentReplicator - [PersistentTopic{topic=persistent://pulsar/ns/clearBacklogTopic-1613105457814}][r1 -> r2] Error reading entries at null. Retrying to read in 3.746s. (We can only have a single waiting callback)
org.apache.bookkeeper.mledger.ManagedLedgerException: We can only have a single waiting callback
04:51:04.211 [pulsar-load-manager-113-1] INFO org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Only 1 broker available: no load shedding will be performed
04:51:04.302 [pulsar-load-manager-113-1] INFO org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Writing local data to ZooKeeper because maximum change Infinity% exceeded threshold 10%; time since last report written is 54.955 seconds
04:51:04.310 [pulsar-ordered-OrderedExecutor-2-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000 sessionid:0x100002f6a530005 local:/127.0.0.1:50956 remoteserver:localhost/127.0.0.1:45671 lastZxid:885 xid:810 sent:810 recv:932 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/loadbalance/brokers/localhost:36981
04:51:04.601 [SyncThread-167-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file because current active log channel has not initialized yet
04:51:04.602 [SyncThread-167-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk0test7520240603864159631/current/0.log for logId 0.
04:51:04.609 [pool-87-thread-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk0test7520240603864159631/current/1.log for logId 1.
04:51:04.620 [db-storage-cleanup-170-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes for ledgers: [32, 3, 4, 5, 9, 12, 13, 14, 15, 16, 18, 22, 23, 24, 25, 26, 27, 29]
04:51:04.624 [db-storage-cleanup-170-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes for 36 entries from 18 ledgers in 0.003 seconds
04:51:04.997 [SyncThread-177-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file because current active log channel has not initialized yet
04:51:04.999 [SyncThread-177-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk1test4511514577938667183/current/0.log for logId 0.
04:51:05.010 [pool-93-thread-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk1test4511514577938667183/current/1.log for logId 1.
04:51:05.012 [db-storage-cleanup-180-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes for ledgers: [3, 6, 7, 8, 9, 10, 11, 13, 14, 16, 17, 18, 19, 20, 22, 25, 26, 27, 28, 29, 30, 31]
04:51:05.017 [db-storage-cleanup-180-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes for 44 entries from 22 ledgers in 0.004 seconds
04:51:05.038 [pulsar-io-59-3] ERROR org.apache.pulsar.broker.service.persistent.PersistentReplicator - [PersistentTopic{topic=persistent://pulsar/ns/clearBacklogTopic-1613105457814}][r1 -> r2] Error reading entries at null. Retrying to read in 7.413s. (We can only have a single waiting callback)
org.apache.bookkeeper.mledger.ManagedLedgerException: We can only have a single waiting callback
04:51:05.370 [SyncThread-187-1] INFO org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log file because current active log channel has not initialized yet
04:51:05.370 [SyncThread-187-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk2test4463933633007020671/current/0.log for logId 0.
04:51:05.382 [pool-99-thread-1] INFO org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file /tmp/bk2test4463933633007020671/current/1.log for logId 1.
04:51:05.389 [db-storage-cleanup-190-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes for ledgers: [32, 4, 5, 6, 7, 8, 10, 11, 12, 15, 17, 19, 20, 23, 24, 28, 30, 31]
04:51:05.394 [db-storage-cleanup-190-1] INFO org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes for 36 entries from 18 ledgers in 0.004 seconds
04:51:08.223 [pulsar-load-manager-193-1] INFO org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Only 1 broker available: no load shedding will be performed
04:51:08.300 [pulsar-load-manager-193-1] INFO org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Writing local data to ZooKeeper because maximum change Infinity% exceeded threshold 10%; time since last report written is 54.958 seconds
04:51:08.306 [pulsar-ordered-OrderedExecutor-4-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000 sessionid:0x100002f7a8c0005 local:/127.0.0.1:48342 remoteserver:localhost/127.0.0.1:46567 lastZxid:820 xid:763 sent:763 recv:872 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/loadbalance/brokers/localhost:38401
04:51:12.451 [pulsar-io-59-4] ERROR org.apache.pulsar.broker.service.persistent.PersistentReplicator - [PersistentTopic{topic=persistent://pulsar/ns/clearBacklogTopic-1613105457814}][r1 -> r2] Error reading entries at null. Retrying to read in 15.35s. (We can only have a single waiting callback)
org.apache.bookkeeper.mledger.ManagedLedgerException: We can only have a single waiting callback
04:51:27.781 [pulsar-io-59-1] ERROR org.apache.pulsar.broker.service.persistent.PersistentReplicator - [PersistentTopic{topic=persistent://pulsar/ns/clearBacklogTopic-1613105457814}][r1 -> r2] Error reading entries at null. Retrying to read in 31.735s. (We can only have a single waiting callback)
org.apache.bookkeeper.mledger.ManagedLedgerException: We can only have a single waiting callback
04:51:29.259 [pulsar-io-139-4] WARN org.apache.pulsar.broker.service.AbstractReplicator - Failed to verify partitioned topic non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false-null
04:51:29.260 [pulsar-io-139-4] INFO org.apache.pulsar.broker.service.AbstractReplicator - [non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false][r2 -> r3] Starting replicator
04:51:29.260 [pulsar-io-139-4] INFO org.apache.pulsar.broker.service.nonpersistent.NonPersistentTopic - [non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false] Starting replicator to remote: r1
04:51:29.264 [pulsar-io-219-2] WARN org.apache.pulsar.broker.service.AbstractReplicator - Failed to verify partitioned topic non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false-null
04:51:29.264 [pulsar-io-219-2] INFO org.apache.pulsar.broker.service.AbstractReplicator - [non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false][r3 -> r1] Starting replicator
04:51:29.264 [pulsar-io-219-2] INFO org.apache.pulsar.broker.service.BrokerService - Created topic NonPersistentTopic{topic=non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false}
04:51:29.272 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN org.apache.pulsar.broker.service.AbstractReplicator - Failed to verify partitioned topic persistent://pulsar/partitionedNs-false/dummyTopic-null
04:51:29.272 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.AbstractReplicator - [persistent://pulsar/partitionedNs-false/dummyTopic][r2 -> r1] Starting replicator
04:51:29.272 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.persistent.PersistentReplicator - [persistent://pulsar/partitionedNs-false/dummyTopic][r2 -> r1] Starting open cursor for replicator
04:51:29.272 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [pulsar/partitionedNs-false/persistent/dummyTopic] Cursor pulsar.repl.r1 recovered to position 155:-1
04:51:29.273 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [pulsar/partitionedNs-false/persistent/dummyTopic] Creating ledger, metadata: {component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114], pulsar/managed-ledger=[112, 117, 108, 115, 97, 114, 47, 112, 97, 114, 116, 105, 116, 105, 111, 110, 101, 100, 78, 115, 45, 102, 97, 108, 115, 101, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110, 116, 47, 100, 117, 109, 109, 121, 84, 111, 112, 105, 99], pulsar/cursor=[112, 117, 108, 115, 97, 114, 46, 114, 101, 112, 108, 46, 114, 49], application=[112, 117, 108, 115, 97, 114]} - metadata ops timeout : 60 seconds
04:51:29.273 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [172.17.0.2:37467, 172.17.0.2:40707] is not adhering to Placement Policy. quarantinedBookies: []
04:51:29.271 [pulsar-io-59-1] WARN org.apache.pulsar.client.impl.BinaryProtoLookupService - [persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false] failed to get Partitioned metadata : 145 lookup request timedout after ms 30000
org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 145 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.lambda$addPendingLookupRequests$8(ClientCnx.java:617) ~[pulsar-client-original-2.8.0-SNAPSHOT.jar:2.8.0-SNAPSHOT]
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) [netty-transport-native-epoll-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
04:51:29.271 [pulsar-io-59-4] WARN org.apache.pulsar.client.impl.BinaryProtoLookupService - [persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false] failed to get Partitioned metadata : 184 lookup request timedout after ms 30000
org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 184 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.lambda$addPendingLookupRequests$8(ClientCnx.java:617) ~[pulsar-client-original-2.8.0-SNAPSHOT.jar:2.8.0-SNAPSHOT]
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) [netty-transport-native-epoll-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
04:51:29.274 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/partitionedNs-false/dummyTopic] Starting replicator to remote: r3
04:51:29.290 [TestNG-method=setup-1-EventThread] INFO org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [172.17.0.2:37467, 172.17.0.2:40707] for ledger: 156
04:51:29.292 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO org.apache.bookkeeper.mledger.impl.MetaStoreImpl - [pulsar/partitionedNs-false/persistent/dummyTopic] [pulsar.repl.r1] Updating cursor info ledgerId=156 mark-delete=155:-1
04:51:29.279 [pulsar-io-219-2] WARN org.apache.pulsar.client.impl.BinaryProtoLookupService - [non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false] failed to get Partitioned metadata : 139 lookup request timedout after ms 30000
org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 139 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.lambda$addPendingLookupRequests$8(ClientCnx.java:617) ~[pulsar-client-original-2.8.0-SNAPSHOT.jar:2.8.0-SNAPSHOT]
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) [netty-transport-native-epoll-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
04:51:29.306 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN org.apache.pulsar.broker.service.AbstractReplicator - Failed to verify partitioned topic persistent://pulsar/partitionedNs-false/dummyTopic-null
04:51:29.306 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.AbstractReplicator - [persistent://pulsar/partitionedNs-false/dummyTopic][r3 -> r1] Starting replicator
04:51:29.306 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.persistent.PersistentReplicator - [persistent://pulsar/partitionedNs-false/dummyTopic][r3 -> r1] Starting open cursor for replicator
~~~~~~~~~ SKIPPED -- [TestClass name=class org.apache.pulsar.broker.service.ReplicatorTest].testResetCursorNotFail([])-------04:51:29.306 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [pulsar/partitionedNs-false/persistent/dummyTopic] Cursor pulsar.repl.r1 recovered to position 142:-1
04:51:29.307 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [pulsar/partitionedNs-false/persistent/dummyTopic] Creating ledger, metadata: {component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114], pulsar/managed-ledger=[112, 117, 108, 115, 97, 114, 47, 112, 97, 114, 116, 105, 116, 105, 111, 110, 101, 100, 78, 115, 45, 102, 97, 108, 115, 101, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110, 116, 47, 100, 117, 109, 109, 121, 84, 111, 112, 105, 99], pulsar/cursor=[112, 117, 108, 115, 97, 114, 46, 114, 101, 112, 108, 46, 114, 49], application=[112, 117, 108, 115, 97, 114]} - metadata ops timeout : 60 seconds
04:51:29.307 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [172.17.0.2:34697, 172.17.0.2:34779] is not adhering to Placement Policy. quarantinedBookies: []
04:51:29.308 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://pulsar/partitionedNs-false/dummyTopic] Starting replicator to remote: r2
04:51:29.317 [pulsar-ordered-OrderedExecutor-7-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x100002f0aaf0003 local:/127.0.0.1:39986 remoteserver:localhost/127.0.0.1:35957 lastZxid:109 xid:318 sent:325 recv:366 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns
04:51:29.318 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x100002f0aaf0001 local:/127.0.0.1:39964 remoteserver:localhost/127.0.0.1:35957 lastZxid:109 xid:384 sent:393 recv:435 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns
04:51:29.319 [pulsar-ordered-OrderedExecutor-6-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x100002f0aaf0005 local:/127.0.0.1:40008 remoteserver:localhost/127.0.0.1:35957 lastZxid:109 xid:283 sent:291 recv:312 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns
04:51:29.318 [pulsar-web-77-8] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns
04:51:29.319 [pulsar-web-77-8] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns, quota=destination_storage
04:51:29.320 [TestNG-method=setup-1-EventThread] INFO org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [172.17.0.2:34697, 172.17.0.2:34779] for ledger: 143
04:51:29.321 [pulsar-web-77-8] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:51:29 +0000] "DELETE /admin/v2/namespaces/pulsar/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 8
04:51:29.332 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x100002f0aaf0001 local:/127.0.0.1:39964 remoteserver:localhost/127.0.0.1:35957 lastZxid:110 xid:385 sent:394 recv:437 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:51:29.333 [pulsar-ordered-OrderedExecutor-7-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x100002f0aaf0003 local:/127.0.0.1:39986 remoteserver:localhost/127.0.0.1:35957 lastZxid:110 xid:319 sent:326 recv:368 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/ns1
04:51:29.333 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/ns1
04:51:29.333 [pulsar-web-77-7] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/ns1, quota=destination_storage
04:51:29.334 [pulsar-web-77-7] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:51:29 +0000] "DELETE /admin/v2/namespaces/pulsar/ns1/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 8
04:51:29.341 [pulsar-ordered-OrderedExecutor-7-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x100002f0aaf0003 local:/127.0.0.1:39986 remoteserver:localhost/127.0.0.1:35957 lastZxid:111 xid:320 sent:327 recv:370 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/global/ns
04:51:29.341 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x100002f0aaf0001 local:/127.0.0.1:39964 remoteserver:localhost/127.0.0.1:35957 lastZxid:111 xid:386 sent:395 recv:439 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/global/ns
04:51:29.341 [pulsar-ordered-OrderedExecutor-6-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000 sessionid:0x100002f0aaf0005 local:/127.0.0.1:40008 remoteserver:localhost/127.0.0.1:35957 lastZxid:110 xid:284 sent:292 recv:314 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/admin/policies/pulsar/global/ns
04:51:29.341 [pulsar-web-77-5] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully updated the on namespace /admin/policies/pulsar/global/ns
04:51:29.342 [pulsar-web-77-5] INFO org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully removed backlog namespace=pulsar/global/ns, quota=destination_storage
04:51:29.344 [pulsar-web-77-5] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [12/Feb/2021:04:51:29 +0000] "DELETE /admin/namespaces/pulsar/global/ns/backlogQuota?backlogQuotaType=destination_storage HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 8
```
----------------------------------------------------------------
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