You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by GitBox <gi...@apache.org> on 2022/03/25 16:27:28 UTC

[GitHub] [pulsar] codelipenghui opened a new issue #14882: Compaction stop on topic __transaction_buffer_snapshot

codelipenghui opened a new issue #14882:
URL: https://github.com/apache/pulsar/issues/14882


   **Describe the bug**
   
   ```json
   {
     "entriesAddedCounter" : 4082,
     "numberOfEntries" : 4082,
     "totalSize" : 891109,
     "currentLedgerEntries" : 4082,
     "currentLedgerSize" : 891109,
     "lastLedgerCreatedTimestamp" : "2022-03-25T23:56:55.202+08:00",
     "waitingCursorsCount" : 0,
     "pendingAddEntriesCount" : 0,
     "lastConfirmedEntry" : "48:4081",
     "state" : "LedgerOpened",
     "ledgers" : [ {
       "ledgerId" : 48,
       "entries" : 0,
       "size" : 0,
       "offloaded" : false,
       "underReplicated" : false
     } ],
     "cursors" : {
       "__compaction" : {
         "markDeletePosition" : "48:-1",
         "readPosition" : "48:0",
         "waitingReadOp" : false,
         "pendingReadOps" : 0,
         "messagesConsumedCounter" : 0,
         "cursorLedger" : 52,
         "cursorLedgerLastEntry" : 55,
         "individuallyDeletedMessages" : "[]",
         "lastLedgerSwitchTimestamp" : "2022-03-25T23:56:55.225+08:00",
         "state" : "Open",
         "numberOfEntriesSinceFirstNotAckedMessage" : 1,
         "totalNonContiguousDeletedMessagesRange" : 0,
         "subscriptionHavePendingRead" : false,
         "subscriptionHavePendingReplayRead" : false,
         "properties" : {
           "CompactedTopicLedger" : 204
         }
       }
     },
     "schemaLedgers" : [ {
       "ledgerId" : 65,
       "entries" : 1,
       "size" : 809,
       "offloaded" : false,
       "underReplicated" : false
     }, {
       "ledgerId" : 53,
       "entries" : 1,
       "size" : 783,
       "offloaded" : false,
       "underReplicated" : false
     }, {
       "ledgerId" : 73,
       "entries" : 1,
       "size" : 853,
       "offloaded" : false,
       "underReplicated" : false
     }, {
       "ledgerId" : 75,
       "entries" : 1,
       "size" : 897,
       "offloaded" : false,
       "underReplicated" : false
     }, {
       "ledgerId" : 60,
       "entries" : 1,
       "size" : 765,
       "offloaded" : false,
       "underReplicated" : false
     } ]
   ```
   
   The broker logs show the the compaction task not able to create reader on original topic:
   
   ```shell
   127.0.0.1:6650", "local":"/127.0.0.1:59799"} -- Will try again in 0.738 s
   00:14:11.306 [pulsar-timer-53-1] INFO  org.apache.pulsar.client.impl.ConnectionHandler - [persistent://public/default/__transaction_buffer_snapshot] [__compaction] Reconnecting after connection was closed
   00:14:11.351 [pulsar-io-16-4] INFO  org.apache.pulsar.client.impl.ConsumerImpl - [persistent://public/default/__transaction_buffer_snapshot][__compaction] Subscribing to topic on cnx [id: 0x9d3c3adc, L:/127.0.0.1:59799 - R:/127.0.0.1:6650], consumerId 23
   00:14:11.448 [pulsar-io-16-6] INFO  org.apache.pulsar.broker.service.ServerCnx - [/127.0.0.1:59799] Subscribing on topic persistent://public/default/__transaction_buffer_snapshot / __compaction
   00:14:11.509 [pulsar-io-16-6] WARN  org.apache.pulsar.broker.service.persistent.PersistentSubscription - Attempting to add consumer Consumer{subscription=CompactorSubscription{topic=persistent://public/default/__transaction_buffer_snapshot, name=__compaction}, consumerId=23, consumerName=f4b2b, address=/127.0.0.1:59799} on a fenced subscription
   00:14:11.599 [pulsar-io-16-6] ERROR org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://public/default/__transaction_buffer_snapshot] Failed to create subscription: __compaction
   java.util.concurrent.CompletionException: org.apache.pulsar.broker.service.BrokerServiceException$SubscriptionFencedException: Subscription is fenced
   	at java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:367) ~[?:?]
   	at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1108) ~[?:?]
   	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
   	at org.apache.pulsar.broker.service.persistent.PersistentSubscription.addConsumer(PersistentSubscription.java:197) ~[org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at org.apache.pulsar.broker.service.AbstractTopic.addConsumerToSubscription(AbstractTopic.java:252) ~[org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$null$17(PersistentTopic.java:760) ~[org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
   	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
   	at org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$subscribe$19(PersistentTopic.java:756) ~[org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
   	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
   	at org.apache.pulsar.broker.service.persistent.PersistentTopic.subscribe(PersistentTopic.java:674) ~[org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at org.apache.pulsar.broker.service.ServerCnx.lambda$null$12(ServerCnx.java:1035) ~[org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
   	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
   	at org.apache.pulsar.broker.service.ServerCnx.lambda$handleSubscribe$15(ServerCnx.java:1005) ~[org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:680) [?:?]
   	at java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658) [?:?]
   	at java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094) [?:?]
   	at org.apache.pulsar.broker.service.ServerCnx.handleSubscribe(ServerCnx.java:953) [org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at org.apache.pulsar.common.protocol.PulsarDecoder.channelRead(PulsarDecoder.java:228) [org.apache.pulsar-pulsar-common-2.9.2.jar:2.9.2]
   	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.handler.flow.FlowControlHandler.dequeue(FlowControlHandler.java:200) [io.netty-netty-handler-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.handler.flow.FlowControlHandler.channelRead(FlowControlHandler.java:162) [io.netty-netty-handler-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327) [io.netty-netty-codec-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299) [io.netty-netty-codec-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) [io.netty-netty-transport-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) [io.netty-netty-common-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [io.netty-netty-common-4.1.74.Final.jar:4.1.74.Final]
   	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.74.Final.jar:4.1.74.Final]
   	at java.lang.Thread.run(Thread.java:829) [?:?]
   Caused by: org.apache.pulsar.broker.service.BrokerServiceException$SubscriptionFencedException: Subscription is fenced
   	at org.apache.pulsar.broker.service.persistent.PersistentSubscription.lambda$addConsumer$2(PersistentSubscription.java:202) ~[org.apache.pulsar-pulsar-broker-2.9.2.jar:2.9.2]
   	at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
   	... 45 more
   
   ```
   
   The log file 
   [broker.log](https://github.com/apache/pulsar/files/8352243/broker.log)
   
   **Expected behavior**
   The topic compaction should not stop
   
   **Additional context**
   https://github.com/apache/pulsar/commit/f0a2171cbad894cec5bfb2d4de31cb8de32a3183
   


-- 
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] Technoboy- commented on issue #14882: Compaction stop on topic __transaction_buffer_snapshot

Posted by GitBox <gi...@apache.org>.
Technoboy- commented on issue #14882:
URL: https://github.com/apache/pulsar/issues/14882#issuecomment-1081610639


   Hi @codelipenghui 
   This is because: when do compaction, the compactor will do seek, and cause itself to reconnect.
   We can avoid log if the sub is `__compaction`. 
   @mattisonchao 


-- 
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