最近在日志中发现一些特别奇怪的日志，疑似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()和HeartBeatMonitor的subscribe node add来并发添加jobtracker到jobtracker列表，有可能加入重复的jobtracker对象，影响业务逻辑（发送大的tasktracker result到jobtracker上出现异常，会把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”异常。这种情况不常出现，因为market每500ms就和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. 设置tasktracker从leveldb中取出数据进行重发的最大次数 ，不能无限重发
3. 下阶段准备增加更多的埋点，记录更多的异常日志，方便以后问题的定位