最近一段时间LTS多个问题的总结

【声明】本文为AdamsLee原创,转载请注明出自围炉网并保留本文有效链接:最近一段时间LTS多个问题的总结, 转载请保留本声明!

最近在日志中发现一些特别奇怪的日志,疑似LTS的任务执行失败结果无法发出去

timestamp 2017-03-06 15:18:58.307
[LTS] Retry send job result failed! jobResults=[{"action":"EXECUTE_EXCEPTION","jobWrapper"……"triggerTime":1484529900000}

经过排查是因为异常message太大,导致无法把整个执行失败的结果发出去。但查了一下数据发现当天任务是执行成功的。百思不得其解,突然注意到 triggerTime,直接转成Date看了一下时间发现是Mon Jan 16 09:25:00 CST 2017。与日志的时间完全不符合。这是怎么回事呢?

初步判断可能是很久之前的失败结果一直保存在机器本地,LTS会定时尝试把这些失败的结果发出去,但无论怎么尝试,都会遇到message太大而无法发出。

最近一段时间公司LTS出现多次问题,中间件团队进行了深入研究

主要是下面这些问题:

1. 年前年后都爆出的job一直在执行状态的问题

2. 偶尔出现在服务器上的jobtracker not found异常

3. 经常出现“invokeSync: wait response timeout exception”

4. 偶尔出现的leveldb异常,“org.fusesource.leveldbjni.internal.NativeDB$DBException: IO error: lock /home/work/.lts/TASK_TRACKER/market_task_tracker/failstore/leveldb/94735A3FD25A4CA5A4AAA1836EB9A3D6/LOCK: already held by process“

5. 偶尔出现“IOException: Connection reset by peer”异常

这些问题初步排查结果如下:

首先,排查问题时发现lts tasktracker上有一个线程安全问题:

多线程并发时的bug。对于tasktracker启动的时候,会同时通过HeartBeatMonitor.ping()HeartBeatMonitorsubscribe node add来并发添加jobtrackerjobtracker列表,有可能加入重复的jobtracker对象,影响业务逻辑(发送大的tasktracker resultjobtracker上出现异常,会把jobtracker对象临时从列表删除,下次发往新的jobtracker,结果却又一次拿到原来的jobtracker,会导致发送到jobtracker上次数增多,而且不容易抛出jobtracker not found异常)

具体原因是HeartBeatMonitor.check(Node jobTracker)方法中,调用了remotingClient.addJobTracker(jobTracker),这个方法不是线程安全的

    public   void addJobTracker(Node jobTracker) {

        boolean contains = contains(jobTracker);

        System.out.println(">>>>>>>>>>>>>>>>>>>>> contains:" +contains);

if (!contains) {

            jobTrackers.add(jobTracker);

        }

    }

测试这个线程安全问题的日志在附件中。还好这个线程安全问题影响不大。

下面是主要发送逻辑:

1. 在发送大的job执行异常消息到jobtracker时,会发送失败,发送的对象会存储到leveldb中。而

2. 然后每隔1分钟定时遍历leveldb中的失败消息,进行重发(重发成功会删除leveldb数据,但没发送成功过也就从没被删过),再次重发还会失败,重发失败后会把当前jobtracker对象从发送列表删除。切换到一个jobtracker发送,发送失败会删除这个jobtracker,两个都删除了再发时就会出现“jobtracker not found”异常。这种情况不常出现,因为market500ms就和jobtracker心跳,实时更新jobtracker列表。

RemotingClientDelegate的同步发送逻辑是个无限循环发送的逻辑,只有jobtrakcer列表有数据就会一直发送

3. 无限循环发送的逻辑,而且每次发送消息的超时时间是1分钟,所以会每隔一分钟就会出现一次“invokeSync: wait response timeout exception”,如下图:

4. jobtracker收到这个大的发送对象,解码失败后会把这个发送channel关闭掉,就会出现“connection reset by peer” ioexception 可以看到wait response timeout异常和connection reset by peer异常是伴随发生的。且一直存在。

5. jobtracker拿不到执行结果对象,会判定为dead job,随后重新分发这个任务,market继续执行这个job,永不停息,就会处于一直执行状态。直到下次job执行成功为止。

6. 至于偶尔发生的leveldb异常,还没查清原因,但是我模拟对leveldb多线程访问的环境,就会导致这个“Could not lock file”异常,初步怀疑也是多线程安全性问题,需要加些日志继续排查。

最后,解决方案:

1. 设置发送异常的大小,最大值不要超过10k,以后修改tasktracker代码限制消息大小

2. 设置tasktrackerleveldb中取出数据进行重发的最大次数 ,不能无限重发

3. 下阶段准备增加更多的埋点,记录更多的异常日志,方便以后问题的定位

此条目发表在未分类分类目录,贴了标签。将固定链接加入收藏夹。