[apache/rocketmq]rocketmq4.6 事物消息全部回滚 transactionListener设置没有效果

rocketmq4.6 事物消息全部回滚 transactionListener设置没有效果 broken返回来的transactionID的全是null 用console查看RQM_HALF队列消息全部报错org.apache.rocketmq.client.exception.MQClientException: CODE: 17 DESC: No topic route info in name server for the topic: %RETRY%CID_RMQ_SYS_TRANS See http://rocketmq.apache.org/docs/faq/ for further details.

demoCow

我也遇到了，请问后来是怎么解决的？

Zzaniu

我也遇到了，请问后来是怎么解决的？

建议升级到 4.7.1 之后的版本，做了大量的bug 修复跟优化

duhenglucky

我也遇到了，请问后来是怎么解决的？

建议升级到 4.7.1 之后的版本，做了大量的bug 修复跟优化

升级到4.8.0，还是没用。。。

Zzaniu

我也遇到了，请问后来是怎么解决的？

建议升级到 4.7.1 之后的版本，做了大量的bug 修复跟优化

升级到4.8.0，还是没用。。。客户端的版本是什么？能不能提供一下服务端的 broker.log，store.log, transaction.log? 这里面较为详细一些的堆栈就好

duhenglucky

我也遇到了，请问后来是怎么解决的？

建议升级到 4.7.1 之后的版本，做了大量的bug 修复跟优化

升级到4.8.0，还是没用。。。客户端的版本是什么？能不能提供一下服务端的 broker.log，store.log, transaction.log? 这里面较为详细一些的堆栈就好

docker-compose.yml

version: '3.5'

services:
  rmqnamesrv:
    image: foxiswho/rocketmq:4.8.0
    container_name: rmqnamesrv
    ports:
      - 9876:9876
    volumes:
      - ./rmqs/logs:/home/rocketmq/logs
      - ./rmqs/store:/home/rocketmq/store
    environment:
      JAVA_OPT_EXT: "-Duser.home=/home/rocketmq -Xms256M -Xmx256M -Xmn128m"
    command: ["sh","mqnamesrv"]
    networks:
        rmq:
          aliases:
            - rmqnamesrv
  rmqbroker:
    image: foxiswho/rocketmq:4.8.0
    container_name: rmqbroker
    ports:
      - 10909:10909
      - 10911:10911
    volumes:
      - ./rmq/logs:/home/rocketmq/logs
      - ./rmq/store:/home/rocketmq/store
      - ./rmq/brokerconf/broker.conf:/etc/rocketmq/broker.conf
    environment:
        JAVA_OPT_EXT: "-Duser.home=/home/rocketmq -Xms256M -Xmx256M -Xmn128m"
    command: ["sh","mqbroker","-c","/etc/rocketmq/broker.conf","-n","rmqnamesrv:9876","autoCreateTopicEnable=true"]
    depends_on:
      - rmqnamesrv
    networks:
      rmq:
        aliases:
          - rmqbroker

  rmqconsole:
    image: styletang/rocketmq-console-ng
    container_name: rmqconsole
    ports:
      - 8080:8080
    environment:
        JAVA_OPTS: "-Drocketmq.namesrv.addr=rmqnamesrv:9876 -Dcom.rocketmq.sendMessageWithVIPChannel=false"
    depends_on:
      - rmqnamesrv
    networks:
      rmq:
        aliases:
          - rmqconsole

networks:
  rmq:
    name: rmq
    driver: bridge

broker.conf

brokerClusterName=DefaultCluster
brokerName=broker-a
brokerId=0
namesrvAddr=rmqnamesrv:9876
brokerIP1=172.18.2.249
defaultTopicQueueNums=4
autoCreateTopicEnable=true
autoCreateSubscriptionGroup=true
listenPort=10911
deleteWhen=04
fileReservedTime=120
mapedFileSizeCommitLog=1073741824
mapedFileSizeConsumeQueue=300000
diskMaxUsedSpaceRatio=88
maxMessageSize=65536
brokerRole=ASYNC_MASTER
flushDiskType=ASYNC_FLUSH

==broker.log==

2021-08-24 20:20:06 INFO main - rocketmqHome=/home/rocketmq/rocketmq-4.8.0
2021-08-24 20:20:06 INFO main - namesrvAddr=rmqnamesrv:9876
2021-08-24 20:20:06 INFO main - brokerIP1=192.168.240.3
2021-08-24 20:20:06 INFO main - brokerIP2=192.168.240.3
2021-08-24 20:20:06 INFO main - brokerName=broker-a
2021-08-24 20:20:06 INFO main - brokerClusterName=DefaultCluster
2021-08-24 20:20:06 INFO main - brokerId=0
2021-08-24 20:20:06 INFO main - brokerPermission=6
2021-08-24 20:20:06 INFO main - defaultTopicQueueNums=4
2021-08-24 20:20:06 INFO main - autoCreateTopicEnable=true
2021-08-24 20:20:06 INFO main - clusterTopicEnable=true
2021-08-24 20:20:06 INFO main - brokerTopicEnable=true
2021-08-24 20:20:06 INFO main - autoCreateSubscriptionGroup=true
2021-08-24 20:20:06 INFO main - messageStorePlugIn=
2021-08-24 20:20:06 INFO main - msgTraceTopicName=RMQ_SYS_TRACE_TOPIC
2021-08-24 20:20:06 INFO main - traceTopicEnable=false
2021-08-24 20:20:06 INFO main - sendMessageThreadPoolNums=1
2021-08-24 20:20:06 INFO main - pullMessageThreadPoolNums=24
2021-08-24 20:20:06 INFO main - processReplyMessageThreadPoolNums=24
2021-08-24 20:20:06 INFO main - queryMessageThreadPoolNums=12
2021-08-24 20:20:06 INFO main - adminBrokerThreadPoolNums=16
2021-08-24 20:20:06 INFO main - clientManageThreadPoolNums=32
2021-08-24 20:20:06 INFO main - consumerManageThreadPoolNums=32
2021-08-24 20:20:06 INFO main - heartbeatThreadPoolNums=4
2021-08-24 20:20:06 INFO main - endTransactionThreadPoolNums=16
2021-08-24 20:20:06 INFO main - flushConsumerOffsetInterval=5000
2021-08-24 20:20:06 INFO main - flushConsumerOffsetHistoryInterval=60000
2021-08-24 20:20:06 INFO main - rejectTransactionMessage=false
2021-08-24 20:20:06 INFO main - fetchNamesrvAddrByAddressServer=false
2021-08-24 20:20:06 INFO main - sendThreadPoolQueueCapacity=10000
2021-08-24 20:20:06 INFO main - pullThreadPoolQueueCapacity=100000
2021-08-24 20:20:06 INFO main - replyThreadPoolQueueCapacity=10000
2021-08-24 20:20:06 INFO main - queryThreadPoolQueueCapacity=20000
2021-08-24 20:20:06 INFO main - clientManagerThreadPoolQueueCapacity=1000000
2021-08-24 20:20:06 INFO main - consumerManagerThreadPoolQueueCapacity=1000000
2021-08-24 20:20:06 INFO main - heartbeatThreadPoolQueueCapacity=50000
2021-08-24 20:20:06 INFO main - endTransactionPoolQueueCapacity=100000
2021-08-24 20:20:06 INFO main - filterServerNums=0
2021-08-24 20:20:06 INFO main - longPollingEnable=true
2021-08-24 20:20:06 INFO main - shortPollingTimeMills=1000
2021-08-24 20:20:06 INFO main - notifyConsumerIdsChangedEnable=true
2021-08-24 20:20:06 INFO main - highSpeedMode=false
2021-08-24 20:20:06 INFO main - commercialEnable=true
2021-08-24 20:20:06 INFO main - commercialTimerCount=1
2021-08-24 20:20:06 INFO main - commercialTransCount=1
2021-08-24 20:20:06 INFO main - commercialBigCount=1
2021-08-24 20:20:06 INFO main - commercialBaseCount=1
2021-08-24 20:20:06 INFO main - transferMsgByHeap=true
2021-08-24 20:20:06 INFO main - maxDelayTime=40
2021-08-24 20:20:06 INFO main - regionId=DefaultRegion
2021-08-24 20:20:06 INFO main - registerBrokerTimeoutMills=6000
2021-08-24 20:20:06 INFO main - slaveReadEnable=false
2021-08-24 20:20:06 INFO main - disableConsumeIfConsumerReadSlowly=false
2021-08-24 20:20:06 INFO main - consumerFallbehindThreshold=17179869184
2021-08-24 20:20:06 INFO main - brokerFastFailureEnable=true
2021-08-24 20:20:06 INFO main - waitTimeMillsInSendQueue=200
2021-08-24 20:20:06 INFO main - waitTimeMillsInPullQueue=5000
2021-08-24 20:20:06 INFO main - waitTimeMillsInHeartbeatQueue=31000
2021-08-24 20:20:06 INFO main - waitTimeMillsInTransactionQueue=3000
2021-08-24 20:20:06 INFO main - startAcceptSendRequestTimeStamp=0
2021-08-24 20:20:06 INFO main - traceOn=true
2021-08-24 20:20:06 INFO main - enableCalcFilterBitMap=false
2021-08-24 20:20:06 INFO main - expectConsumerNumUseFilter=32
2021-08-24 20:20:06 INFO main - maxErrorRateOfBloomFilter=20
2021-08-24 20:20:06 INFO main - filterDataCleanTimeSpan=86400000
2021-08-24 20:20:06 INFO main - filterSupportRetry=false
2021-08-24 20:20:06 INFO main - enablePropertyFilter=false
2021-08-24 20:20:06 INFO main - compressedRegister=false
2021-08-24 20:20:06 INFO main - forceRegister=true
2021-08-24 20:20:06 INFO main - registerNameServerPeriod=30000
2021-08-24 20:20:06 INFO main - transactionTimeOut=6000
2021-08-24 20:20:06 INFO main - transactionCheckMax=15
2021-08-24 20:20:06 INFO main - transactionCheckInterval=60000
2021-08-24 20:20:06 INFO main - aclEnable=false
2021-08-24 20:20:06 INFO main - storeReplyMessageEnable=true
2021-08-24 20:20:06 INFO main - autoDeleteUnusedStats=false
2021-08-24 20:20:06 INFO main - listenPort=10911
2021-08-24 20:20:06 INFO main - serverWorkerThreads=8
2021-08-24 20:20:06 INFO main - serverCallbackExecutorThreads=0
2021-08-24 20:20:06 INFO main - serverSelectorThreads=3
2021-08-24 20:20:06 INFO main - serverOnewaySemaphoreValue=256
2021-08-24 20:20:06 INFO main - serverAsyncSemaphoreValue=64
2021-08-24 20:20:06 INFO main - serverChannelMaxIdleTimeSeconds=120
2021-08-24 20:20:06 INFO main - serverSocketSndBufSize=131072
2021-08-24 20:20:06 INFO main - serverSocketRcvBufSize=131072
2021-08-24 20:20:06 INFO main - serverPooledByteBufAllocatorEnable=true
2021-08-24 20:20:06 INFO main - useEpollNativeSelector=false
2021-08-24 20:20:06 INFO main - clientWorkerThreads=4
2021-08-24 20:20:06 INFO main - clientCallbackExecutorThreads=4
2021-08-24 20:20:06 INFO main - clientOnewaySemaphoreValue=65535
2021-08-24 20:20:06 INFO main - clientAsyncSemaphoreValue=65535
2021-08-24 20:20:06 INFO main - connectTimeoutMillis=3000
2021-08-24 20:20:06 INFO main - channelNotActiveInterval=60000
2021-08-24 20:20:06 INFO main - clientChannelMaxIdleTimeSeconds=120
2021-08-24 20:20:06 INFO main - clientSocketSndBufSize=131072
2021-08-24 20:20:06 INFO main - clientSocketRcvBufSize=131072
2021-08-24 20:20:06 INFO main - clientPooledByteBufAllocatorEnable=false
2021-08-24 20:20:06 INFO main - clientCloseSocketIfTimeout=false
2021-08-24 20:20:06 INFO main - useTLS=false
2021-08-24 20:20:06 INFO main - storePathRootDir=/home/rocketmq/store
2021-08-24 20:20:06 INFO main - storePathCommitLog=/home/rocketmq/store/commitlog
2021-08-24 20:20:06 INFO main - mappedFileSizeCommitLog=1073741824
2021-08-24 20:20:06 INFO main - mappedFileSizeConsumeQueue=6000000
2021-08-24 20:20:06 INFO main - enableConsumeQueueExt=false
2021-08-24 20:20:06 INFO main - mappedFileSizeConsumeQueueExt=50331648
2021-08-24 20:20:06 INFO main - bitMapLengthConsumeQueueExt=64
2021-08-24 20:20:06 INFO main - flushIntervalCommitLog=500
2021-08-24 20:20:06 INFO main - commitIntervalCommitLog=200
2021-08-24 20:20:06 INFO main - useReentrantLockWhenPutMessage=false
2021-08-24 20:20:06 INFO main - flushCommitLogTimed=false
2021-08-24 20:20:06 INFO main - flushIntervalConsumeQueue=1000
2021-08-24 20:20:06 INFO main - cleanResourceInterval=10000
2021-08-24 20:20:06 INFO main - deleteCommitLogFilesInterval=100
2021-08-24 20:20:06 INFO main - deleteConsumeQueueFilesInterval=100
2021-08-24 20:20:06 INFO main - destroyMapedFileIntervalForcibly=120000
2021-08-24 20:20:06 INFO main - redeleteHangedFileInterval=120000
2021-08-24 20:20:06 INFO main - deleteWhen=04
2021-08-24 20:20:06 INFO main - diskMaxUsedSpaceRatio=88
2021-08-24 20:20:06 INFO main - fileReservedTime=120
2021-08-24 20:20:06 INFO main - putMsgIndexHightWater=600000
2021-08-24 20:20:06 INFO main - maxMessageSize=65536
2021-08-24 20:20:06 INFO main - checkCRCOnRecover=true
2021-08-24 20:20:06 INFO main - flushCommitLogLeastPages=4
2021-08-24 20:20:06 INFO main - commitCommitLogLeastPages=4
2021-08-24 20:20:06 INFO main - flushLeastPagesWhenWarmMapedFile=4096
2021-08-24 20:20:06 INFO main - flushConsumeQueueLeastPages=2
2021-08-24 20:20:06 INFO main - flushCommitLogThoroughInterval=10000
2021-08-24 20:20:06 INFO main - commitCommitLogThoroughInterval=200
2021-08-24 20:20:06 INFO main - flushConsumeQueueThoroughInterval=60000
2021-08-24 20:20:06 INFO main - maxTransferBytesOnMessageInMemory=262144
2021-08-24 20:20:06 INFO main - maxTransferCountOnMessageInMemory=32
2021-08-24 20:20:06 INFO main - maxTransferBytesOnMessageInDisk=65536
2021-08-24 20:20:06 INFO main - maxTransferCountOnMessageInDisk=8
2021-08-24 20:20:06 INFO main - accessMessageInMemoryMaxRatio=40
2021-08-24 20:20:06 INFO main - messageIndexEnable=true
2021-08-24 20:20:06 INFO main - maxHashSlotNum=5000000
2021-08-24 20:20:06 INFO main - maxIndexNum=20000000
2021-08-24 20:20:06 INFO main - maxMsgsNumBatch=64
2021-08-24 20:20:06 INFO main - messageIndexSafe=false
2021-08-24 20:20:06 INFO main - haListenPort=10912
2021-08-24 20:20:06 INFO main - haSendHeartbeatInterval=5000
2021-08-24 20:20:06 INFO main - haHousekeepingInterval=20000
2021-08-24 20:20:06 INFO main - haTransferBatchSize=32768
2021-08-24 20:20:06 INFO main - haMasterAddress=
2021-08-24 20:20:06 INFO main - haSlaveFallbehindMax=268435456
2021-08-24 20:20:06 INFO main - brokerRole=ASYNC_MASTER
2021-08-24 20:20:06 INFO main - flushDiskType=ASYNC_FLUSH
2021-08-24 20:20:06 INFO main - syncFlushTimeout=5000
2021-08-24 20:20:06 INFO main - messageDelayLevel=1s 5s 10s 30s 1m 2m 3m 4m 5m 6m 7m 8m 9m 10m 20m 30m 1h 2h
2021-08-24 20:20:06 INFO main - flushDelayOffsetInterval=10000
2021-08-24 20:20:06 INFO main - cleanFileForciblyEnable=true
2021-08-24 20:20:06 INFO main - warmMapedFileEnable=false
2021-08-24 20:20:06 INFO main - offsetCheckInSlave=false
2021-08-24 20:20:06 INFO main - debugLockEnable=false
2021-08-24 20:20:06 INFO main - duplicationEnable=false
2021-08-24 20:20:06 INFO main - diskFallRecorded=true
2021-08-24 20:20:06 INFO main - osPageCacheBusyTimeOutMills=1000
2021-08-24 20:20:06 INFO main - defaultQueryMaxNum=32
2021-08-24 20:20:06 INFO main - transientStorePoolEnable=false
2021-08-24 20:20:06 INFO main - transientStorePoolSize=5
2021-08-24 20:20:06 INFO main - fastFailIfNoBufferInStorePool=false
2021-08-24 20:20:06 INFO main - enableDLegerCommitLog=false
2021-08-24 20:20:06 INFO main - dLegerGroup=
2021-08-24 20:20:06 INFO main - dLegerPeers=
2021-08-24 20:20:06 INFO main - dLegerSelfId=
2021-08-24 20:20:06 INFO main - preferredLeaderId=
2021-08-24 20:20:06 INFO main - isEnableBatchPush=false
2021-08-24 20:20:06 INFO main - Try to start service thread:AllocateMappedFileService started:false lastThread:null
2021-08-24 20:20:07 INFO main - Set user specified name server address: rmqnamesrv:9876
2021-08-24 20:20:07 WARN main - Load default transaction message hook service: TransactionalMessageServiceImpl
2021-08-24 20:20:07 WARN main - Load default discard message hook service: DefaultTransactionalMessageCheckListener
2021-08-24 20:20:07 INFO main - The broker dose not enable acl
2021-08-24 20:20:07 INFO main - Try to start service thread:ReputMessageService started:false lastThread:null
2021-08-24 20:20:07 INFO main - Try to start service thread:AcceptSocketService started:false lastThread:null
2021-08-24 20:20:07 INFO main - Try to start service thread:GroupTransferService started:false lastThread:null
2021-08-24 20:20:07 INFO main - Try to start service thread:HAClient started:false lastThread:null
2021-08-24 20:20:07 INFO main - Try to start service thread:FlushConsumeQueueService started:false lastThread:null
2021-08-24 20:20:07 INFO main - Try to start service thread:FlushRealTimeService started:false lastThread:null
2021-08-24 20:20:07 INFO main - Try to start service thread:StoreStatsService started:false lastThread:null
2021-08-24 20:20:07 INFO main - Try to start service thread:FileWatchService started:false lastThread:null
2021-08-24 20:20:07 INFO main - Try to start service thread:PullRequestHoldService started:false lastThread:null
2021-08-24 20:20:07 INFO FileWatchService - FileWatchService service started
2021-08-24 20:20:07 INFO PullRequestHoldService - PullRequestHoldService service started
2021-08-24 20:20:07 INFO main - Try to start service thread:TransactionalMessageCheckService started:false lastThread:null
2021-08-24 20:20:07 INFO brokerOutApi_thread_1 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:20:07 INFO main - The broker[broker-a, 192.168.240.3:10911] boot success. serializeType=JSON and name server is rmqnamesrv:9876
2021-08-24 20:20:08 ERROR DiskCheckScheduledThread1 - Error when measuring disk space usage, file doesn't exist on this path: /home/rocketmq/store/commitlog
2021-08-24 20:20:17 INFO BrokerControllerScheduledThread1 - dispatch behind commit log 0 bytes
2021-08-24 20:20:17 INFO BrokerControllerScheduledThread1 - Slave fall behind master: 0 bytes
2021-08-24 20:20:17 INFO brokerOutApi_thread_2 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:20:18 ERROR DiskCheckScheduledThread1 - Error when measuring disk space usage, file doesn't exist on this path: /home/rocketmq/store/commitlog
2021-08-24 20:20:28 ERROR DiskCheckScheduledThread1 - Error when measuring disk space usage, file doesn't exist on this path: /home/rocketmq/store/commitlog
2021-08-24 20:20:38 ERROR DiskCheckScheduledThread1 - Error when measuring disk space usage, file doesn't exist on this path: /home/rocketmq/store/commitlog
2021-08-24 20:20:41 INFO HeartbeatThread_1 - auto create a subscription group, SubscriptionGroupConfig [groupName=249ClientTest, consumeEnable=true, consumeFromMinEnable=true, consumeBroadcastEnable=true, retryQueueNums=1, retryMaxTimes=16, brokerId=0, whichBrokerWhenConsumeSlowly=1, notifyConsumerIdsChangedEnable=true]
2021-08-24 20:20:41 INFO HeartbeatThread_1 - create new topic TopicConfig [topicName=%RETRY%249ClientTest, readQueueNums=1, writeQueueNums=1, perm=RW-, topicFilterType=SINGLE_TAG, topicSysFlag=0, order=false]
2021-08-24 20:20:41 INFO brokerOutApi_thread_3 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:20:41 INFO HeartbeatThread_1 - new consumer connected, group: 249ClientTest CONSUME_PASSIVELY CLUSTERING channel: ClientChannelInfo [channel=[id: 0x30432a90, L:/192.168.240.3:10911 - R:/192.168.240.1:54884], clientId=192.168.240.1@1354#DEFAULT, language=CPP, version=333, lastUpdateTimestamp=1629807641087]
2021-08-24 20:20:41 INFO HeartbeatThread_1 - subscription changed, add new topic, group: 249ClientTest SubscriptionData [classFilterMode=false, topic=rocketTest, subString=*, tagsSet=[], codeSet=[], subVersion=1629807611040, expressionType=TAG]
2021-08-24 20:20:41 INFO HeartbeatThread_1 - subscription changed, add new topic, group: 249ClientTest SubscriptionData [classFilterMode=false, topic=%RETRY%249ClientTest, subString=*, tagsSet=[], codeSet=[], subVersion=1629807611040, expressionType=TAG]
2021-08-24 20:20:41 INFO HeartbeatThread_1 - registerConsumer info changed ConsumerData [groupName=249ClientTest, consumeType=CONSUME_PASSIVELY, messageModel=CLUSTERING, consumeFromWhere=CONSUME_FROM_LAST_OFFSET, unitMode=false, subscriptionDataSet=[SubscriptionData [classFilterMode=false, topic=rocketTest, subString=*, tagsSet=[], codeSet=[], subVersion=1629807611040, expressionType=TAG], SubscriptionData [classFilterMode=false, topic=%RETRY%249ClientTest, subString=*, tagsSet=[], codeSet=[], subVersion=1629807611040, expressionType=TAG]]] 192.168.240.1:54884
2021-08-24 20:20:41 WARN SendMessageThread_1 - the topic rocketTest not exist, producer: /192.168.240.1:54888
2021-08-24 20:20:41 INFO SendMessageThread_1 - Create new topic by default topic:[TBW102] config:[TopicConfig [topicName=rocketTest, readQueueNums=4, writeQueueNums=4, perm=RW-, topicFilterType=SINGLE_TAG, topicSysFlag=0, order=false]] producer:[192.168.240.1:54888]
2021-08-24 20:20:41 INFO brokerOutApi_thread_4 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:20:41 INFO HeartbeatThread_2 - new producer connected, group: 249ServerTest channel: ClientChannelInfo [channel=[id: 0xd8422204, L:/192.168.240.3:10911 - R:/192.168.240.1:54888], clientId=192.168.240.1@4158#DEFAULT, language=CPP, version=333, lastUpdateTimestamp=1629807641323]
2021-08-24 20:20:47 INFO brokerOutApi_thread_1 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:21:07 INFO TransactionalMessageCheckService - create new topic TopicConfig [topicName=RMQ_SYS_TRANS_HALF_TOPIC, readQueueNums=1, writeQueueNums=1, perm=RW-, topicFilterType=SINGLE_TAG, topicSysFlag=0, order=false]
2021-08-24 20:21:07 INFO brokerOutApi_thread_2 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:21:17 INFO BrokerControllerScheduledThread1 - dispatch behind commit log 0 bytes
2021-08-24 20:21:17 INFO BrokerControllerScheduledThread1 - Slave fall behind master: 668 bytes
2021-08-24 20:21:17 INFO brokerOutApi_thread_3 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:21:47 INFO brokerOutApi_thread_4 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:22:17 INFO BrokerControllerScheduledThread1 - dispatch behind commit log 0 bytes
2021-08-24 20:22:17 INFO BrokerControllerScheduledThread1 - Slave fall behind master: 1015 bytes
2021-08-24 20:22:17 INFO brokerOutApi_thread_1 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:22:47 INFO brokerOutApi_thread_2 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:23:17 INFO BrokerControllerScheduledThread1 - dispatch behind commit log 0 bytes
2021-08-24 20:23:17 INFO BrokerControllerScheduledThread1 - Slave fall behind master: 1362 bytes
2021-08-24 20:23:17 INFO brokerOutApi_thread_3 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:23:47 INFO brokerOutApi_thread_4 - register broker[0]to name server rmqnamesrv:9876 OK
2021-08-24 20:24:17 INFO BrokerControllerScheduledThread1 - dispatch behind commit log 0 bytes
2021-08-24 20:24:17 INFO BrokerControllerScheduledThread1 - Slave fall behind master: 1709 bytes
2021-08-24 20:24:17 INFO brokerOutApi_thread_1 - register broker[0]to name server rmqnamesrv:9876 OK

==store.log==

2021-08-24 20:20:06 INFO AllocateMappedFileService - AllocateMappedFileService service started
2021-08-24 20:20:06 INFO main - last shutdown normally
2021-08-24 20:20:06 INFO main - load commit log OK
2021-08-24 20:20:06 INFO main - load logics queue all over, OK
2021-08-24 20:20:06 INFO main - store checkpoint file not exists, /home/rocketmq/store/checkpoint
2021-08-24 20:20:06 WARN main - The commitlog files are deleted, and delete the consume queue files
2021-08-24 20:20:06 INFO main - load over, and the max phy offset = 0
2021-08-24 20:20:07 INFO main - [SetReputOffset] maxPhysicalPosInLogicQueue=0 clMinOffset=-1 clMaxOffset=0 clConfirmedOffset=-1
2021-08-24 20:20:07 INFO ReputMessageService - ReputMessageService service started
2021-08-24 20:20:07 INFO AcceptSocketService - AcceptSocketService service started
2021-08-24 20:20:07 INFO GroupTransferService - GroupTransferService service started
2021-08-24 20:20:07 INFO HAClient - HAClient service started
2021-08-24 20:20:07 INFO FlushRealTimeService - FlushRealTimeService service started
2021-08-24 20:20:07 INFO FlushConsumeQueueService - FlushConsumeQueueService service started
2021-08-24 20:20:07 INFO main - /home/rocketmq/store/abort create OK
2021-08-24 20:20:07 INFO StoreStatsService - StoreStatsService service started
2021-08-24 20:20:41 INFO AllocateMappedFileService - /home/rocketmq/store/commitlog mkdir OK
2021-08-24 20:20:41 INFO ReputMessageService - /home/rocketmq/store/consumequeue/RMQ_SYS_TRANS_HALF_TOPIC/0 mkdir OK
2021-08-24 20:20:41 INFO ReputMessageService - /home/rocketmq/store/index mkdir OK
2021-08-24 20:21:00 WARN AdminBrokerThread_9 - selectMappedBuffer request pos invalid, request pos: 0, size: 131072, fileFromOffset: 0
2021-08-24 20:21:07 INFO StoreStatsService - [STORETPS] put_tps  get_found_tps  get_miss_tps  get_transfered_tps 
2021-08-24 20:21:07 INFO StoreStatsService - [PAGECACHERT] TotalPut 1, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:0 [10~50ms]:1 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0 
2021-08-24 20:21:24 WARN AdminBrokerThread_2 - selectMappedBuffer request pos invalid, request pos: 0, size: 131072, fileFromOffset: 0
2021-08-24 20:22:00 WARN AdminBrokerThread_5 - selectMappedBuffer request pos invalid, request pos: 0, size: 131072, fileFromOffset: 0
2021-08-24 20:22:07 INFO StoreStatsService - [STORETPS] put_tps 0.016663611671193613 get_found_tps 0.033327223342387226 get_miss_tps 0.7665261368749062 get_transfered_tps 0.04999083501358084
2021-08-24 20:22:07 INFO StoreStatsService - [PAGECACHERT] TotalPut 1, PutMessageDistributeTime [<=0ms]:0 [0~10ms]:1 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0 
2021-08-24 20:23:00 WARN AdminBrokerThread_2 - selectMappedBuffer request pos invalid, request pos: 0, size: 131072, fileFromOffset: 0
2021-08-24 20:23:07 INFO StoreStatsService - [STORETPS] put_tps 0.016663333999866695 get_found_tps 0.016663333999866695 get_miss_tps 0.5332266879957342 get_transfered_tps 0.016663333999866695
2021-08-24 20:23:07 INFO StoreStatsService - [PAGECACHERT] TotalPut 1, PutMessageDistributeTime [<=0ms]:1 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0 
2021-08-24 20:24:00 WARN AdminBrokerThread_15 - selectMappedBuffer request pos invalid, request pos: 0, size: 131072, fileFromOffset: 0
2021-08-24 20:24:07 INFO StoreStatsService - [STORETPS] put_tps 0.016663333999866695 get_found_tps 0.016663333999866695 get_miss_tps 0.5332266879957342 get_transfered_tps 0.016663333999866695
2021-08-24 20:24:07 INFO StoreStatsService - [PAGECACHERT] TotalPut 1, PutMessageDistributeTime [<=0ms]:1 [0~10ms]:0 [10~50ms]:0 [50~100ms]:0 [100~200ms]:0 [200~500ms]:0 [500ms~1s]:0 [1~2s]:0 [2~3s]:0 [3~4s]:0 [4~5s]:0 [5~10s]:0 [10s~]:0

==transaction.log==

2021-08-24 20:20:07 INFO TransactionalMessageCheckService - Start transaction check service thread!
2021-08-24 20:20:41 WARN EndTransactionThread_1 - The producer[192.168.240.1:54888] end transaction in sending message,  and it's pending status.RequestHeader: EndTransactionRequestHeader{producerGroup='249ServerTest', tranStateTableOffset=0, commitLogOffset=0, commitOrRollback=0, fromTransactionCheck=false, msgId='C0A8F001103E214D29547ACFD6E30000', transactionId=''} Remark: 
2021-08-24 20:21:07 INFO TransactionalMessageCheckService - Begin to check prepare message, begin time:1629807667523
2021-08-24 20:21:07 INFO TransactionalMessageCheckService - Before check, the queue=MessageQueue [topic=RMQ_SYS_TRANS_HALF_TOPIC, brokerName=broker-a, queueId=0] msgOffset=0 opOffset=0
2021-08-24 20:21:07 WARN TransactionalMessageCheckService - No new message. GetMessageStatus=NO_MESSAGE_IN_QUEUE, topic=RMQ_SYS_TRANS_OP_HALF_TOPIC, groupId=CID_RMQ_SYS_TRANS, requestOffset=0
2021-08-24 20:21:07 WARN TransactionalMessageCheckService - The miss op offset=0 in queue=MessageQueue [topic=RMQ_SYS_TRANS_OP_HALF_TOPIC, brokerName=broker-a, queueId=0] is NO_NEW_MSG, pullResult=PullResult [pullStatus=NO_NEW_MSG, nextBeginOffset=0, minOffset=0, maxOffset=0, msgFoundList=0]
2021-08-24 20:21:07 WARN TransactionalMessageCheckService - No new message. GetMessageStatus=OFFSET_OVERFLOW_ONE, topic=RMQ_SYS_TRANS_HALF_TOPIC, groupId=CID_RMQ_SYS_TRANS, requestOffset=1
2021-08-24 20:21:07 INFO TransactionalMessageCheckService - End to check prepare message, consumed time:38
2021-08-24 20:22:07 INFO TransactionalMessageCheckService - Begin to check prepare message, begin time:1629807727561
2021-08-24 20:22:07 INFO TransactionalMessageCheckService - Before check, the queue=MessageQueue [topic=RMQ_SYS_TRANS_HALF_TOPIC, brokerName=broker-a, queueId=0] msgOffset=1 opOffset=0
2021-08-24 20:22:07 WARN TransactionalMessageCheckService - No new message. GetMessageStatus=NO_MESSAGE_IN_QUEUE, topic=RMQ_SYS_TRANS_OP_HALF_TOPIC, groupId=CID_RMQ_SYS_TRANS, requestOffset=0
2021-08-24 20:22:07 WARN TransactionalMessageCheckService - The miss op offset=0 in queue=MessageQueue [topic=RMQ_SYS_TRANS_OP_HALF_TOPIC, brokerName=broker-a, queueId=0] is NO_NEW_MSG, pullResult=PullResult [pullStatus=NO_NEW_MSG, nextBeginOffset=0, minOffset=0, maxOffset=0, msgFoundList=0]
2021-08-24 20:22:07 WARN TransactionalMessageCheckService - No new message. GetMessageStatus=OFFSET_OVERFLOW_ONE, topic=RMQ_SYS_TRANS_HALF_TOPIC, groupId=CID_RMQ_SYS_TRANS, requestOffset=2
2021-08-24 20:22:07 INFO TransactionalMessageCheckService - End to check prepare message, consumed time:2
2021-08-24 20:23:07 INFO TransactionalMessageCheckService - Begin to check prepare message, begin time:1629807787564
2021-08-24 20:23:07 INFO TransactionalMessageCheckService - Before check, the queue=MessageQueue [topic=RMQ_SYS_TRANS_HALF_TOPIC, brokerName=broker-a, queueId=0] msgOffset=2 opOffset=0
2021-08-24 20:23:07 WARN TransactionalMessageCheckService - No new message. GetMessageStatus=NO_MESSAGE_IN_QUEUE, topic=RMQ_SYS_TRANS_OP_HALF_TOPIC, groupId=CID_RMQ_SYS_TRANS, requestOffset=0
2021-08-24 20:23:07 WARN TransactionalMessageCheckService - The miss op offset=0 in queue=MessageQueue [topic=RMQ_SYS_TRANS_OP_HALF_TOPIC, brokerName=broker-a, queueId=0] is NO_NEW_MSG, pullResult=PullResult [pullStatus=NO_NEW_MSG, nextBeginOffset=0, minOffset=0, maxOffset=0, msgFoundList=0]
2021-08-24 20:23:07 WARN TransactionalMessageCheckService - No new message. GetMessageStatus=OFFSET_OVERFLOW_ONE, topic=RMQ_SYS_TRANS_HALF_TOPIC, groupId=CID_RMQ_SYS_TRANS, requestOffset=3
2021-08-24 20:23:07 INFO TransactionalMessageCheckService - End to check prepare message, consumed time:1
2021-08-24 20:24:07 INFO TransactionalMessageCheckService - Begin to check prepare message, begin time:1629807847566
2021-08-24 20:24:07 INFO TransactionalMessageCheckService - Before check, the queue=MessageQueue [topic=RMQ_SYS_TRANS_HALF_TOPIC, brokerName=broker-a, queueId=0] msgOffset=3 opOffset=0
2021-08-24 20:24:07 WARN TransactionalMessageCheckService - No new message. GetMessageStatus=NO_MESSAGE_IN_QUEUE, topic=RMQ_SYS_TRANS_OP_HALF_TOPIC, groupId=CID_RMQ_SYS_TRANS, requestOffset=0
2021-08-24 20:24:07 WARN TransactionalMessageCheckService - The miss op offset=0 in queue=MessageQueue [topic=RMQ_SYS_TRANS_OP_HALF_TOPIC, brokerName=broker-a, queueId=0] is NO_NEW_MSG, pullResult=PullResult [pullStatus=NO_NEW_MSG, nextBeginOffset=0, minOffset=0, maxOffset=0, msgFoundList=0]
2021-08-24 20:24:07 WARN TransactionalMessageCheckService - No new message. GetMessageStatus=OFFSET_OVERFLOW_ONE, topic=RMQ_SYS_TRANS_HALF_TOPIC, groupId=CID_RMQ_SYS_TRANS, requestOffset=4
2021-08-24 20:24:07 INFO TransactionalMessageCheckService - End to check prepare message, consumed time:1

我是用的python.用的是rocketmq-client-python 2.0.0.我的问题是check_callback不会被执行

import json
import time

from rocketmq.client import TransactionMQProducer, Message, TransactionStatus

topic = "rocketTest"

def create_message(n):
    msg = Message(topic)
    msg.set_keys('deca')
    msg.set_tags('declare12')
    msg.set_property('property', 'test12')
    msg.set_body(json.dumps(f'大胖子-{n}'))
    return msg

def check_callback(msg):
    print("回查")
    print('check: ' + json.loads(msg.body.decode('utf-8')))
    return TransactionStatus.COMMIT

def local_execute(msg, user_args):
    print('local:   ' + msg.body.decode('utf-8'))
    return TransactionStatus.UNKNOWN

def send_transaction_message(count):
    producer = TransactionMQProducer("249ServerTest", check_callback)
    producer.set_name_server_address('172.18.2.249:9876')
    producer.start()
    # for n in range(count):
    msg = create_message(count)
    ret = producer.send_message_in_transaction(msg, local_execute, None)
    print('send message status: ' + str(ret.status) + ' msgId: ' + ret.msg_id)
    print('send transaction message done')

    time.sleep(3600)
    producer.shutdown()

if __name__ == '__main__':
    send_transaction_message(1)

Zzaniu

[apache/rocketmq]rocketmq4.6 事物消息全部回滚 transactionListener设置没有效果

回答