DelayedOperationPurgatory机制(二):SystemTimer

本文深入探讨了Kafka中SystemTimer的设计与实现,SystemTimer基于TimeWheel,支持定时任务执行及阻塞等待功能。文章详细介绍了其核心组件,如taskExecutor、delayQueue、taskCounter、timingWheel等,以及关键方法add和advanceClock的工作原理。

SystemTimer是kafka中定时器的实现,它在TimeWheel的基础上添加了执行到期任务、阻塞等待最近到期任务的功能

class SystemTimer(executorName: String,
                  tickMs: Long = 1,
                  wheelSize: Int = 20,
                  startMs: Long = System.currentTimeMillis) extends Timer {
  // timeout timer
  // JDK提供的固定线程数的线程池实现,由此线程执行到期任务
  private[this] val taskExecutor = Executors.newFixedThreadPool(1, new ThreadFactory() {
    def newThread(runnable: Runnable): Thread =
      Utils.newThread("executor-"+executorName, runnable, false)
  })
  // 各个层级的时间轮共用的DelayQueue队列,主要作用是阻塞推进时间表针的线程,等待最近到期任务到期
  private[this] val delayQueue = new DelayQueue[TimerTaskList]()
  // 各个层级时间轮共用的任务个数计时器
  private[this] val taskCounter = new AtomicInteger(0)
  // 层级时间轮中最底层的时间轮
  private[this] val timingWheel = new TimingWheel(
    tickMs = tickMs,
    wheelSize = wheelSize,
    startMs = startMs,
    taskCounter = taskCounter,
    delayQueue
  )

  // Locks used to protect data structures while ticking
  // 同步时间轮表针currentTime修改的读写锁
  private[this] val readWriteLock = new ReentrantReadWriteLock()
  private[this] val readLock = readWriteLock.readLock()
  private[this] val writeLock = readWriteLock.writeLock()
}

add方法添加过程中如果发现任务已经到期,则将任务提交到taskExecutor中执行,如果任务没有到期,就调用TimeWheel.add方法提交到时间轮中等到到期后执行。

  def add(timerTask: TimerTask): Unit = {
    readLock.lock()
    try {
        // 将TimerTask封装成TimerTaskEntry,并计算到期时间
      addTimerTaskEntry(new TimerTaskEntry(timerTask, timerTask.delayMs + System.currentTimeMillis()))
    } finally {
      readLock.unlock()
    }
  }
  
  private def addTimerTaskEntry(timerTaskEntry: TimerTaskEntry): Unit = {
      // 向时间轮提交添加任务失败,任务可能已经到期或者已经取消
    if (!timingWheel.add(timerTaskEntry)) {
      // Already expired or cancelled
      if (!timerTaskEntry.cancelled)// 将到期任务提交给taskExecutor执行
        taskExecutor.submit(timerTaskEntry.timerTask)
    }
  }

advanceClock完成了时间轮表针的推进。

  def advanceClock(timeoutMs: Long): Boolean = {
    var bucket = delayQueue.poll(timeoutMs, TimeUnit.MILLISECONDS)
    if (bucket != null) {
      writeLock.lock()
      try {
        while (bucket != null) {
            // 推动时间轮表针
          timingWheel.advanceClock(bucket.getExpiration())
          // 调用reinsert,尝试将bucket中的任务重新添加到时间轮中,此过程不一定是将任务提交给taskExecutor执行,对于未到期的任务只是从原来的时间轮降级继续等待
          bucket.flush(reinsert)
          bucket = delayQueue.poll()
        }
      } finally {
        writeLock.unlock()
      }
      true
    } else {
      false
    }
  }
  // timerTaskList重新提交到时间轮中
  private[this] val reinsert = (timerTaskEntry: TimerTaskEntry) => addTimerTaskEntry(timerTaskEntry)

 

2025-10-27 17:01:20,950] INFO [ThrottledChannelReaper-Request]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper) [2025-10-27 17:01:20,958] INFO [ThrottledChannelReaper-ControllerMutation]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper) [2025-10-27 17:01:21,055] INFO Loading logs from log dirs ArrayBuffer(/export/servers/kafka/kafka-logs) (kafka.log.LogManager) [2025-10-27 17:01:21,065] INFO Skipping recovery for all logs in /export/servers/kafka/kafka-logs since clean shutdown file was found (kafka.log.LogManager) [2025-10-27 17:01:21,095] INFO Loaded 0 logs in 40ms. (kafka.log.LogManager) [2025-10-27 17:01:21,096] INFO Starting log cleanup with a period of 300000 ms. (kafka.log.LogManager) [2025-10-27 17:01:21,109] INFO Starting log flusher with a default period of 9223372036854775807 ms. (kafka.log.LogManager) [2025-10-27 17:01:23,477] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas) [2025-10-27 17:01:23,554] INFO Awaiting socket connections on slaver1:9092. (kafka.network.Acceptor) [2025-10-27 17:01:23,758] INFO [SocketServer listenerType=ZK_BROKER, nodeId=2] Created data-plane acceptor and processors for endpoint : ListenerName(PLAINTEXT) (kafka.network.SocketServer) [2025-10-27 17:01:23,908] INFO [broker-2-to-controller-send-thread]: Starting (kafka.server.BrokerToControllerRequestThread) [2025-10-27 17:01:23,947] INFO [ExpirationReaper-2-Produce]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper) [2025-10-27 17:01:23,964] INFO [ExpirationReaper-2-ElectLeader]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper) [2025-10-27 17:01:23,962] INFO [ExpirationReaper-2-Fetch]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper) [2025-10-27 17:01:23,962] INFO [ExpirationReaper-2-DeleteRecords]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper) [2025-10-27 17:01:24,002] INFO [LogDirFailureHandler]: Starting (kafka.server.ReplicaManager$LogDirFailureHandler) [2025-10-27 17:01:24,191] INFO Creating /brokers/ids/2 (is it secure? false) (kafka.zk.KafkaZkClient) [2025-10-27 17:01:24,246] INFO Stat of the created znode at /brokers/ids/2 is: 51539607715,51539607715,1761555684227,1761555684227,1,0,0,216173873305944069,212,0,51539607715 (kafka.zk.KafkaZkClient) [2025-10-27 17:01:24,249] INFO Registered broker 2 at path /brokers/ids/2 with addresses: PLAINTEXT://192.168.10.161:9092, czxid (broker epoch): 51539607715 (kafka.zk.KafkaZkClient) [2025-10-27 17:01:24,561] INFO [ExpirationReaper-2-topic]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper) [2025-10-27 17:01:24,583] INFO [ExpirationReaper-2-Heartbeat]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper) [2025-10-27 17:01:24,598] INFO [ExpirationReaper-2-Rebalance]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper) [2025-10-27 17:01:24,668] INFO [GroupCoordinator 2]: Starting up. (kafka.coordinator.group.GroupCoordinator) [2025-10-27 17:01:24,687] INFO [GroupCoordinator 2]: Startup complete. (kafka.coordinator.group.GroupCoordinator) [2025-10-27 17:01:24,923] INFO [ProducerId Manager 2]: Acquired new producerId block (brokerId:2,blockStartProducerId:1000,blockEndProducerId:1999) by writing to Zk with path version 2 (kafka.coordinator.transaction.ProducerIdManager) [2025-10-27 17:01:24,926] INFO [TransactionCoordinator id=2] Starting up. (kafka.coordinator.transaction.TransactionCoordinator) [2025-10-27 17:01:24,936] INFO [TransactionCoordinator id=2] Startup complete. (kafka.coordinator.transaction.TransactionCoordinator) [2025-10-27 17:01:24,950] INFO [Transaction Marker Channel Manager 2]: Starting (kafka.coordinator.transaction.TransactionMarkerChannelManager) [2025-10-27 17:01:25,272] INFO [ExpirationReaper-2-AlterAcls]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper) [2025-10-27 17:01:25,388] INFO [/config/changes-event-process-thread]: Starting (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread) [2025-10-27 17:01:25,471] INFO [SocketServer listenerType=ZK_BROKER, nodeId=2] Starting socket server acceptors and processors (kafka.network.SocketServer) [2025-10-27 17:01:25,557] INFO [SocketServer listenerType=ZK_BROKER, nodeId=2] Started data-plane acceptor and processor(s) for endpoint : ListenerName(PLAINTEXT) (kafka.network.SocketServer) [2025-10-27 17:01:25,558] INFO [SocketServer listenerType=ZK_BROKER, nodeId=2] Started socket server acceptors and processors (kafka.network.SocketServer) [2025-10-27 17:01:25,613] INFO Kafka version: 2.8.2 (org.apache.kafka.common.utils.AppInfoParser) [2025-10-27 17:01:25,613] INFO Kafka commitId: 3146c6ff4a24cc24 (org.apache.kafka.common.utils.AppInfoParser) [2025-10-27 17:01:25,613] INFO Kafka startTimeMs: 1761555685559 (org.apache.kafka.common.utils.AppInfoParser) [2025-10-27 17:01:25,618] INFO [KafkaServer id=2] started (kafka.server.KafkaServer) [2025-10-27 17:01:26,019] INFO [broker-2-to-controller-send-thread]: Recorded new controller, from now on will use broker master:9092 (id: 1 rack: null) (kafka.server.BrokerToControllerRequestThread)
最新发布
10-28
### ThrottledChannelReaper 组件 日志中显示了多个 `ThrottledChannelReaper` 线程的启动信息,如 `[ThrottledChannelReaper-Fetch]`、`[ThrottledChannelReaper-Produce]`、`[ThrottledChannelReaper-Request]` 和 `[ThrottledChannelReaper-ControllerMutation]`。这些线程属于 `kafka.server.ClientQuotaManager$ThrottledChannelReaper`,用于处理客户端配额相关的限流操作。启动信息如下: ```plaintext [2025-10-27 16:52:42,467] INFO [ThrottledChannelReaper-Fetch]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper) [2025-10-27 16:52:42,467] INFO [ThrottledChannelReaper-Produce]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper) [2025-10-27 16:52:42,481] INFO [ThrottledChannelReaper-Request]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper) [2025-10-27 16:52:42,495] INFO [ThrottledChannelReaper-ControllerMutation]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper) ``` 在 Kafka 关闭时,这些线程也会相应地关闭,如: ```plaintext [2025-10-27 16:52:47,503] INFO [ThrottledChannelReaper-Fetch]: Shutting down (kafka.server.ClientQuotaManager$ThrottledChannelReaper) [2025-10-27 16:52:47,588] INFO [ThrottledChannelReaper-Fetch]: Stopped (kafka.server.ClientQuotaManager$ThrottledChannelReaper) [2025-10-27 16:52:47,589] INFO [ThrottledChannelReaper-Fetch]: Shutdown completed (kafka.server.ClientQuotaManager$ThrottledChannelReaper) ``` ### LogManager 组件 `LogManager` 负责管理 Kafka 的日志存储。启动时,它会加载日志目录中的日志: ```plaintext [2025-10-27 16:52:42,621] INFO Loading logs from log dirs ArrayBuffer(/export/servers/kafka/kafka-logs) (kafka.log.LogManager) ``` 由于发现了干净关闭文件,所以跳过了日志恢复过程: ```plaintext [2025-10-27 16:52:42,638] INFO Skipping recovery for all logs in /export/servers/kafka/kafka-logs since clean shutdown file was found (kafka.log.LogManager) ``` 加载完日志后,显示加载了 0 个日志,耗时 60ms: ```plaintext [2025-10-27 16:52:42,681] INFO Loaded 0 logs in 60ms. (kafka.log.LogManager) ``` 之后,启动日志清理和日志刷新任务: ```plaintext [2025-10-27 16:52:42,683] INFO Starting log cleanup with a period of 300000 ms. (kafka.log.LogManager) [2025-10-27 16:52:42,692] INFO Starting log flusher with a default period of 9223372036854775807 ms. (kafka.log.LogManager) ``` 在 Kafka 关闭时,`LogManager` 也会进行相应的关闭操作: ```plaintext [2025-10-27 16:52:47,245] INFO Shutting down. (kafka.log.LogManager) [2025-10-27 16:52:47,352] INFO Shutdown complete. (kafka.log.LogManager) ``` ### SocketServer 组件 `SocketServer` 负责处理 Kafka 的网络连接。启动时会更新连接接受率: ```plaintext [2025-10-27 16:52:47,064] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas) ``` 但在尝试绑定到 `slaver2:9092` 时出现错误,导致 Kafka 启动失败: ```plaintext [2025-10-27 16:52:47,160] ERROR [KafkaServer id=3] Fatal error during KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer) org.apache.kafka.common.KafkaException: Socket server failed to bind to slaver2:9092: 无法指定被请求的地址. ``` 随后,Kafka 开始进行关闭操作,包括停止 `SocketServer` 的请求处理器: ```plaintext [2025-10-27 16:52:47,178] INFO [SocketServer listenerType=ZK_BROKER, nodeId=3] Stopping socket server request processors (kafka.network.SocketServer) [2025-10-27 16:52:47,201] INFO [SocketServer listenerType=ZK_BROKER, nodeId=3] Stopped socket server request processors (kafka.network.SocketServer) ``` 最终,`SocketServer` 完成关闭: ```plaintext [2025-10-27 16:52:49,608] INFO [SocketServer listenerType=ZK_BROKER, nodeId=3] Shutting down socket server (kafka.network.SocketServer) [2025-10-27 16:52:49,722] INFO [SocketServer listenerType=ZK_BROKER, nodeId=3] Shutdown completed (kafka.network.SocketServer) ``` ### 其他组件 除了上述组件,日志中还显示了其他组件的启动和关闭信息,如 `FinalizedFeatureChangeListener`、`ZooKeeperClient`、`Metrics` 等。这些组件在 Kafka 的启动和关闭过程中也扮演着重要的角色。 ### 总结 Kafka 启动过程中,首先启动了多个 `ThrottledChannelReaper` 线程用于客户端配额限流,然后 `LogManager` 加载日志并启动日志清理和刷新任务。接着,`SocketServer` 尝试绑定到指定地址和端口,但由于地址无法指定导致启动失败,随后 Kafka 开始进行关闭操作,各个组件依次停止工作。
评论
成就一亿技术人!
拼手气红包6.0元
还能输入1000个字符
 
红包 添加红包
表情包 插入表情
 条评论被折叠 查看
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值