CAT消息丢失问题排查Sorry, the message is not there. It could be missing or archived.

当点击CAT的查看LogViews时出现Sorry, the message is not there. It could be missing or archived.

这时候出现这种问题会一头雾水,去github上查看貌似也没有给出明确答复。

这里根据自己的猜想以及源码角度的查看来定位问题。

首先咨询CAT维护相关人员得到一个非常重要的信息就是消息编号中的小时数不同

项目名-ac13bd78-430207-91
项目名-ac13bd78-430208-91

第二段代表的是IP,第三段代表小时数,第四段代表当前自增数
举例:
从LogViews中的消息编号列表中发现当前小时如果属于430207的话,是可以打开的,非430207的话就是消息丢失。

然后从CAT的state报表中发现有一列消息丢失数据:

两台机器时钟不准导致消息存储丢失 这个场景用于Pigeon,服务端id是由客户端产生,客户端和服务端时钟差2小时,会导致存储丢失

猜想这一列是不是统计了我刚好消息丢失的数据。

有了这些线索,我们开始假设和验证!

从客户端编号的消息编号生成开始入手。

我的客户端版本是 2.0

源码查看

  1. 发送消息的时候会判断该消息是否是EVENT消息,如果有则放入m_atomicTrees对象中

TcpSocketSender.java

public void send(MessageTree tree) {
   if (isAtomicMessage(tree)) {
      boolean result = m_atomicTrees.offer(tree, m_manager.getSample());

      if (!result) {
         logQueueFullInfo(tree);
      }
   } else {
      boolean result = m_queue.offer(tree, m_manager.getSample());

      if (!result) {
         logQueueFullInfo(tree);
      }
   }
}
  1. 一旦放入m_atomicTrees对象时,则会被一个单独监控的线程检测到
public class MergeAtomicTask implements Task {

   @Override
   public String getName() {
      return "merge-atomic-task";
   }

   @Override
   public void run() {
      while (true) {
        // 时刻监控这个队列,一旦有并且是当前小时的消息则会满足
         if (shouldMerge(m_atomicTrees)) {
            MessageTree tree = mergeTree(m_atomicTrees);
            boolean result = m_queue.offer(tree);

            if (!result) {
               logQueueFullInfo(tree);
            }
         } else {
            try {
               Thread.sleep(5);
            } catch (InterruptedException e) {
               break;
            }
         }
      }
   }

   @Override
   public void shutdown() {
   }
}

mergeTree这个方法有点重要,其实就是将当前的消息进行合并,为什么需要合并?

我猜的话应该是在同一个消息树中,每条消息都对应了一个消息编号,但是对于消息树的编号来说只要第一条消息的消息编号就能够定位到,而第二条往后走的消息这个编号根本就没用了,但是不想浪费了,放入消息编号队列中,为下一条消息树的编号生成所用。

private MessageTree mergeTree(MessageQueue trees) {
   int max = MAX_CHILD_NUMBER;
   DefaultTransaction t = new DefaultTransaction("_CatMergeTree", "_CatMergeTree", null);
   // 先获取消息树中的第一条消息
   MessageTree first = trees.poll();

   t.setStatus(Transaction.SUCCESS);
   t.setCompleted(true);
   t.addChild(first.getMessage());
   t.setTimestamp(first.getMessage().getTimestamp());
   long lastTimestamp = 0;
   long lastDuration = 0;

   while (max >= 0) {
      // 注意这里是从第二条开始
      MessageTree tree = trees.poll();

      if (tree == null) {
         t.setDurationInMillis(lastTimestamp - t.getTimestamp() + lastDuration);
         break;
      }
      lastTimestamp = tree.getMessage().getTimestamp();
      if (tree.getMessage() instanceof DefaultTransaction) {
         lastDuration = ((DefaultTransaction) tree.getMessage()).getDurationInMillis();
      } else {
         lastDuration = 0;
      }
      t.addChild(tree.getMessage());
     // 这里非常关键,会将本次产生的id编号重新放入生成的队列中。
      m_factory.reuse(tree.getMessageId());
      max--;
   }

   ((DefaultMessageTree) first).setMessage(t);
   return first;
}
// D:\lib\maven\com\dianping\cat\cat-client\2.0.0\cat-client-2.0.0-sources.jar!\com\dianping\cat\message\internal\MessageIdFactory.java
// m_factory.reuse(tree.getMessageId()); 对应的实现
public void reuse(String id) {
  m_reusedIds.offer(id);
}

接下来我们只要看它是如何拿id的

MessageIdFactory.java

public String getNextId() {
  // 先从队列里面拿到,这里和上面生成的相关,如果有直接返回。
   String id = m_reusedIds.poll();

   if (id != null) {
      return id;
   } else {
      long timestamp = getTimestamp();

      if (timestamp != m_timestamp) {
         m_index = new AtomicInteger(0);
         m_timestamp = timestamp;
      }

      int index = m_index.getAndIncrement();

      StringBuilder sb = new StringBuilder(m_domain.length() + 32);

      sb.append(m_domain);
      sb.append('-');
      sb.append(m_ipAddress);
      sb.append('-');
      sb.append(timestamp);
      sb.append('-');
      sb.append(index);

      return sb.toString();
   }
}

这里就会出现一个小问题,如果当前小时的id没有拿完,下一个小时来拿id的时候发现还有,则会从队列里面继续获取生成的id编号,生成的消息树发送到服务端,但问题在于,该编号却是上个小时残留的。
这时候服务端是以小时为key存储的,存储的时候会发现这个编号是上一个小时的,则会直接丢弃。从state中的

两台机器时钟不准导致消息存储丢失 | 这个场景用于Pigeon,服务端id是由客户端产生,客户端和服务端时钟差2小时,会导致存储丢失

中查看到!
这部分的源码在 : TcpSocketReceiver.MessageDecoder.decode()中体现出来,最终的实现类是RealtimeConsumer.consume方法

public void consume(MessageTree tree) {      
    long timestamp = tree.getMessage().getTimestamp();
    Period period = m_periodManager.findPeriod(timestamp);

    if (period != null) {
        // 将消息树交给桶处理 , 然后这里会放到队列然后交给另一个PeriodTask线程去处理
        period.distribute(tree);
    } else {
        m_serverStateManager.addNetworkTimeError(1);
    }
}

PeriodTask.run -> AbstractMessageAnalyzer.analyze -> DumpAnalyzer.process -> processWithStorage 处理

DumpAnalyzer.java - 关键代码

public void process(MessageTree tree) {
        try {
            // 根据消息编号做解析
            MessageId messageId = MessageId.parse(tree.getMessageId());

            if (!shouldDiscard(messageId)) {
                 // 这里会获取消息编号的第三段作为参数messageId.getHour()
                processWithStorage(tree, messageId, messageId.getHour());
            }
        } catch (Exception ignored) {
        }
    }
private void processWithStorage(MessageTree tree, MessageId messageId, int hour) {
        // 这个桶是以当前小时为单位 也就是消息编号的第三段
        MessageDumper dumper = m_dumperManager.find(hour);
        tree.setFormatMessageId(messageId);
        // 这里根据消息编号发现消息编号匹配不到
        if (dumper != null) {
            dumper.process(tree);
        } else {
            // 然后state那里就会多一条数据
            m_serverStateManager.addPigeonTimeError(1);
        }
    }

ServerStatistic.Statistic.m_pigeonTimeError

但这个时候是误导了用户,实际上是消息队列中残留了上个小时的消息生成的编号导致的。

解决方案:

客户端升级到3.0吧。它已经把队列去掉了,每次获取当前时间戳,来生成编号。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 216,193评论 6 498
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 92,306评论 3 392
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 162,130评论 0 353
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,110评论 1 292
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,118评论 6 388
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,085评论 1 295
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,007评论 3 417
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,844评论 0 273
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,283评论 1 310
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,508评论 2 332
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,667评论 1 348
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,395评论 5 343
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,985评论 3 325
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,630评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,797评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,653评论 2 368
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,553评论 2 352

推荐阅读更多精彩内容