浅谈CI脚本异常退出问题定位

背景

在CI脚本中，使用类似如下脚本进行项目编译的计时，但在执行过程中，有时会出现CI脚本(命名为ci.sh)未完全执行的情况：

#!/bin/bash -e

sleep_time=$1

start_time=`date "+%s"`
# do sth, this sleep would simulate project compilation
sleep $sleep_time
end_time=`date "+%s"`

process_time=`expr \( end_time - start_time \)`
echo "---- process time(sec) are: " $process_time "seconds"

# ...

这个脚本，只是模拟我们在CI中的程序，项目编译前计时，项目编译后再次计时，通过sleep休眠来模拟CI中项目编译锁消耗的时间，然后计算出消耗的时间。这个简化的脚本逻辑很简单，我们通过以下命令来调用：

# ./ci.sh
---- process time(sec) are: 2 seconds

这样执行好像并不会出错，那实际CI中为什么会出错呢？

分析

首先，我们发现，当出现脚本未完全执行完成时，不会打印“process time(sec) are”这一句，也就是说错误是这句之前引起的。

另外，细心的朋友还会发现，在脚本的首行，我们给bash使用了-e参数，这个参数的作用就是，一旦shell脚本中任何一行出现了错误，shell脚本就停止运行。所谓的出现错误，也就是这行语句的返回值为非零。那么，CI脚本未完全执行的原因，很可能就是因为某一行语句出现了错误，导致脚本直接退出。

通过增加打印“echo $?”来打印上一行语句的执行结果，很快定位到报错的语句在计算处理时间的这一行：

process_time=`expr \( end_time - start_time \)`　

这一行看起来十分普通，只是简单的用终止时间减去开始时间，然后赋值给process_time。为什么会返回非0值呢？

原来，expr命令有一个小小的trick，当expr表达式中的计算结果为0时，expr命令就会返回1，而不是通常的0。在我们实际的CI任务中，一旦某个项目编译时间非常短，在1秒钟内完成，那么起止时间系统，其差值也就为0，因此，expr就会返回非零值，而CI脚本也会因此而退出。