openlava一日惊魂

2019独角兽企业重金招聘Python工程师标准>>>

    我在国内前五的IC公司，平时负责公司openlava的配置管理。

    今天早上还没下地铁，接到电话，说公司的openlava挂了，于是一阵小跑赶到公司，开始debug。

    发现主要有两个问题。

1. 执行openlava指令频繁报“batch system daemon not responding ... still trying”，执行bhosts多数时候得不到返回结果，偶尔能得到结果也很慢，半天才显示。

2. 投递job会报“No job id can be used now. Job not submitted.”

    然后联系公司IT的同事W帮忙一起debug。

    第一个问题着眼点在两个方面，一是怀疑mbatch<->sbatch之间通讯有问题，所以batch之间总是没有回应，,二是怀疑openlava的master机器本身有问题，因为所有的openlava指令执行都会卡半天，在openlava的master机器上执行任何指令也都很慢。

    第二个问题则更加摸不着头脑，openlava默认设置，job id到达999999后会自动返回，所以不会出现job id不够用的情况，我看了下我们现在所有的未完成job只有不到2000个，最大job id只有960000左右，理应不会出现这个错误信息。

    解决问题的第一步就是重启各个slave机器上的sbatch进程，无效。

    然后尝试重启各个slave机器上的所有openlava进程，无效。

    然后尝试重启master机器上的所有openlava进程，无效。

    最后放大招，重启了master机器，然后启动openlava进程，无效。

    没办法了，求助了业界大牛Y同志，Y同志给出了两点中肯的建议（Y同志乐于助人，此处应有掌声）：

1. 在lsf.conf中打开debug设置，以获取更多的log信息，然后查找master机器的mbatch log来查找问题所在。

2. 将MAX_JOBID设置到更大值以解决job id不足警告的问题。

    如获至宝，赶快在lsf.conf中打开了debug设置，如下。

LSF_LOG_MASK=LOG_DEBUG3

LSF_DEBUG_RES=...

LSB_DEBUG_SBD=...

LSF_DEBUG_LIM=...

    果然在openlava的log文件中获得了更多信息，但是从信息中看不出什么有价值的东西。

    然后将MAX_JOBID设置为1200000（默认应该为999999），然后尝试投递job，job投递成功了，虽然没搞明白这个错误具体导致的原因，但是第二个问题顺利解决（怀疑存储/网络阻塞导致了job id信息不能顺利更新，导致openlava的job id分配出现了偏差）

    这时候IT的同事W一个debug发现让我们发现了解决第一个问题的曙光，由于怀疑到sbatch通讯的方向，他telnet了master上的sbatch通讯端口，发现是阻塞的，经查是由于防火墙限制阻塞了sbatch的通讯，造成openlava master机器上mbatch进程接收信息和处理信息受阻，从而导致执行openlava指令十分缓慢，且经常不能得到返回结果。然后W关掉了防火墙，再尝试bhosts指令，结果秒出，这个问题也被顺利解决。（防火墙应该本来就是关闭的，至少之前都不会对这个端口通讯造成阻塞，为何突然出现问题，仍然是个未解之谜）

    此时已经中午11:40，公司IC的同事因为等待openlava修复已经公司群里抱怨连连，赶快通知大家openlava能用了。

    从早上到单位开始修复问题，还没来得及吃早饭，连口水都没来得及喝。修复完问题，和同事W兴高采烈地去吃午饭。

 

 

    下午回到公司，想着既然修复了问题，需要把设置恢复原状，于是注销掉了MAX_JOBID=1200000这是设置，然后在master机器上重启了openlava服务，重启之后，openlava中所有有job的host都变味unreach的状态了（奇怪的是，没有job的host则都是ok的状态），这下傻眼了。

    由于只有两个操作，一是取消掉一个setting，二是重启服务，完全想不通这两个简单的常规操作为何能搞垮openlava。这时候公司大群里面又有人开始抱怨，为何刚刚好了的openlava又挂了，于是我又开始马不停蹄地debug。

   首先还原MAX_JOBID=1200000这个设置，重启openlava服务，不行。猜测应该跟这个设置无关。

    和上午的异常不一样的地方在于，现在执行openlava命令反应速度还是挺快的，但是openlava中host的机器状态不对，所以和上午是两个不一样的问题。unreach意味着slave机器上的sbatch进程通讯异常，既然防火墙的问题已经解决了，这个通讯异常应该是其它的网络问题，于是抱着电脑到W的工位那又拉着这个难兄难弟一起debug。

    我们先分析了一下问题所在。

    中午的时候openlava已经修复了，这个时候setting应该是没什么问题了。下午重启openlava服务之后就不行了，应该是服务被重置后出现了问题。（这个思路可是大大滴误导了我们）

    我们开始追踪sbatch服务。

    我们发现，当把一台slave机器上的openlava服务重启后，短暂时间内这台机器的状态是ok，但是过一会之后他就有变成了unreach状态。一定是有什么东西影响了sbatch进程。

    我们check了几台slave机器，发现同样是unreach的状态，有的机器上sbatch服务不在了，但是有的还在。我们觉得sbatch服务莫名其妙消失了肯定不对，于是去check openlava的sbatch log，只发现这个log有中断，但是没有任何错误或者警告信息。然后又check 系统日志，也没有发现谁把sbatch服务kill掉了。

    我和W又核对了一下上午debug的过程（此处是关键）。W问我改动过什么，我说我打开了debug设置，log中有了更多信息，并且中午的时候openlava是正常工作的，所以这个小的改动是无害的（此处有伏笔）。我问W上午做了什么让系统好了，W说关掉防火墙，给openlava的服务加上debug模式（就是加上参数 -d 2）。

    考虑到我中午重新启动openlava服务可能会冲掉这个debug模式，虽然我不认为这个debug模式有什么用，但是看着满屏的unreach，死马当活马医，我和W决定重新加上openlava的debug模式试试。我们重新开始了debug模式，可是没有，那些unreach仍然是unreach的样子。（虽然是同样的设置，但是不同的操作顺序会得到不同的结果，这点使我们当时没有想到的）

    公司大群里抗议的越来越多，我们都很着急，病急乱投医，我们开始各种尝试。

    登陆某些slave机器，手动重启openlava服务，可是过一会，无论上面的sbatch服务在不在，host的status一定会变成unreach。

    重启master上的openlava服务，无效，重启完看到还是一大片unreach状态的机器。

    重启master机器，然后重启服务，无效，仍然是一大片unreach状态机的机器。

    IT的领导提醒我们可能是master机器本身有问题，于是我们尝试换master机器，但是切换的时候出现了诡异的问题，lsf.clustor.openlava中将其它机器挪到第一位，重新启动服务，lim进程启动成功，res进程启动成功，sbatch进程启动卡住，然后程序崩溃了。

    我们又切换回原先的master，重启openlava服务，发现现在连bhosts都没有反应了。

    我看了看表，五点。我跟同事W说，我黔驴技穷了，我要回工位收拾东西去了。他问我还没下班呢你收拾什么东西，我说不是下班，你看全公司都在等我修复都等了一天了，我还没搞定就该引咎辞职了。我就抱着电脑回到了工位。

    同事Z也开始帮我debug，他重新拷贝了一份openlava，然后启动了这个精简版的openlava（只有两台机器），我们惊奇的发现这个精简的openlava竟然和我们大的openlava系统面临着一模一样的问题。我们绝望地怀疑是不是系统底层服务出问题了，如果网络或者系统底层的问题影响了openlava，是很难去debug的。

    同事W家的小孩已经高烧一天了，六点下班了，被我折磨了一天之后W火急火燎地坐上了班车要回家了，而我则打算要在单位通宵了。我给他发了条微信。

“告诉你个悲剧的消息，我们感觉还是通讯的问题，不是master的问题”

    W给我回了两条。

“我都要开车了”

“我去找你吧，班车不坐了”

    这妥妥的是中国好同事啊，完全是舍己为人，我很于心不安，他又被我拖下水了。我非常真诚地希望老板能给W同事一个年度优秀员工的奖状，虽然根据我了解，即便真的有这么个奖状也一定不可能有一毛钱奖金。

    我们挤在我的工位上，掏出笔记本，开始了新的一轮尝试。

    一个思路就是，为什么我换了master机器之后openlava连bhosts都执行不了了，我们怀疑在新的master机器上重新启动slave机器上的openlava进程时候遇到了阻碍，所以slave机器上的openlava进程保留了旧的设置，也就不能认识新的master了，于是W手动批量重启了所有slave机器上的openlava服务，bhosts命令work了。

    我们看到了曙光。

    但是令人失望的是，尽管刚刚启动的时候所有的机器都是ok的状态了，这很好，但是过了一会就有一大批机器变成了unreach的状态，说明sbatch-mbatch之间的通讯还是有问题，我们只不过是回到了一开始debug的道路上而已。

    我们登录到某些slave机器上查看进程，我突然发现有些sbatch进程的owenr竟然不是root（openlava的服务是用root启动的）。我们如获至宝，反复测试，发现用root启动sbatch服务，过一会它就自己消失了，或者sbatch的owenr自动变成了其它人。我们追踪这个进程变化的过程，发现一开始sbatch的owenr确实是root，但是一旦有任何job提交到这个机器上，这个job的owenr就会生成一个新的sbatch进程并踢掉root的sbatch进程，但是和master的mbatch通讯的应该是root账号的sbatch进程啊，root的sbatch进程被干掉了，通讯当然就不通了，可是这个异常又是怎么产生的呢？

    虽然离问题的答案又近了一步，但是如何解决这个问题我们仍然没有任何头绪。

    这个时候已经晚上七点多了。

    我们对这种异常行为的产生百思不得其解，W也困恼异常。W又逼问我到底做过什么改动，我糯糯地说就是打开了一些debug的setting，但是不可能影响sbatch进程啊，何况我是上午打开的这些setting，中午openlava都已经好好工作了，这些setting怎么可能有影响呢。不过既然你信不过，我还原回去，咱们再试试。

    于是我关掉了上午Y大神推荐我的debug设置，然后master上重启openlava服务，好多slave机器上的sbatch服务都重启失败。W手工帮我到slave机器上批量重启openlava服务，然后我们战战兢兢地等待了几分钟，openlava活过来了，bhosts的状态也都正常了，openlava完全好了。

    我们面面相觑。

    一下午的bug亡命追踪，就这么轻易地解决了，而且这个解决方案还跟其他乱七八糟的猜想都没有任何关系，它就是那么简单，“改动的东西改回去就好了”，而盲目地自信却偏偏让我忽略了这一点。

    我们分析了一下，这个阴错阳差的问题还是很有点技术含量的，也是很碰巧的。

    上午的时候我在openlava的lsf.conf配置文件中打开的debug setting应该是有一些问题的，这些setting除了在log中追加更加详细的信息之外，竟然还能影响sbatch服务的状态，这一点是谁都没有想到的。而特别巧的是，openlava服务的debug模式却恰恰能解决这个问题，因为openlava服务的debug模式应该会强制占住root启动的slave机器上的sbatch服务（我们猜测的），让它不被踢掉，这样从行为上看整个openlava就是正常的。但是下午我restart了所有机器上的openlava服务，服务由debug模式变味了normal模式，slave机器上root的sbatch服务不再被强占住，root启动的sbatch服务可以被踢掉了，这个问题就被触发了。而最开始我和W这两个不同的debug方式没有相互沟通，我们也没有想到两个debug方式还有相互牵制的功效（而且还必须遵守一定的顺序，就是机器正常，同时打开，相互不影响。下午的时候机器状态已经不正常了，相互打开，仍然相互不影响，但是不能弥补那些已经unreach机器的状态，所以当时我们就没有想到这一层），所以我们像没头苍蝇一样到处尝试，却只不过是在openlava的怪异行为面前处处碰壁，不明所以。

    尽管各种巧合和openlava神奇的行为造成了这惊魂的一天（对我而言，说它惊魂一点都不为过，上班以来我几乎没有一天过得这么焦虑，我司裁员那天都没有），但是它还是让我受益匪浅，对openalva的各种了解也深入了一层，也自远远不同于一年之前我在上一家公司所遇到的那个值得纪念的一天，几秒钟就把公司的openlava搞崩溃了。

 

    最后，特别感谢同事W，没有W的话可能我通宵也不能找到问题的所在，也许我第二天就真的因为对待openlava无能为力而引咎辞职了。所以说我又一次深刻地认识到，W是一名特别特别优秀的IT，欢迎有识之士出高薪来挖他，当然，我司也不见得舍得放他。

 

 

转载于:https://my.oschina.net/liyanqing/blog/2997172