本文能学到
1. 背景
无意中瞟一眼出厂产品的日志文件 /app/recode 大小居然有9MB,按照设计每10min执行任务检查/app/recode文件大小,该文件不会超过4MB,超过此大小则压缩处理,仅保留最近的日志内容。立马着手检查linux定时任务cron运行情况。
2. 初步排查
执 crontab -e 查看定时任务配置情况,其实是以root权限打开 var/spool/cron/crontabs/root 文件,第二行是本背景该执行的脚本,乍看一下没有任何问题。检查 /var/log/message 看是否有被执行的记录,“cat /var/log/message | grep cron”,干干净净!!!的确没被执行。
本来事情到此为止只算工程师一个平常无奇的日常,不过10min后再查看 /app/recode 居然从9MB变成4KB,/var/log/message也有执行记录,发生了什么?
3. 分析
为了分析具体原因,准备一新烧录的板卡作为排查对象。怀疑方向有三个,这三方面都是引起任务计划不被执行的诱因:
3.1. x11 crontab file 格式不正确
crontab file文件位于 var/spool/cron/crontabs/root,当使用crontab -e命令打开该文件,不做任何修改并退出,cron任务计划能被运行。
怀疑var/spool/cron/crontabs/root文件里可能包含不合法字符或语法不正确,如:文件末尾有\r、\n、一行里有多个空格会影响cron解析该文件。
-
cp var/spool/cron/crontabs/root var/spool/cron/crontabs/root.bak;
-
-
watch -n 1 cat /var/log/message。
-
md5sum var/spool/cron/crontabs/root var/spool/cron/crontabs/root.bak;
结果:文件一致。
证明:“crontab file 格式不正确”不是诱因。
3.2. x12 文件系统被改写
crontab -e虽然没有修改var/spool/cron/crontabs/root,但无法证明它有没有改写文件系统其他文件。于是在一块重新烧录镜像的板卡执行如下步骤排查:
-
获取文件系统所有文件的MD5保存为/tmp/a.txt;
find arch bin etc home lib media opt \
root sbin tmp usr var -name "*" | \
xargs md5sum > /unuse/a.txt
-
-
获取文件系统所有文件的MD5保存为/tmp/b.txt;
find arch bin etc home lib media opt \
root sbin tmp usr var -name "*" | \
xargs md5sum > /unuse/b.txt
-
比较a.txt和b.txt是否一致,从而证明crontab -e是否修改文件系统内容
结果:a.txt,b.txt文件一致。
证明:“x12 文件系统被改写”不是诱因。
3.3. x13 crontab file所属用户不合法
产品的cron是busybox的组件,源码面前无秘密。开始跟踪crond执行过程。
在busybox源码的miscutils/crond.c添加若干 “printf(”LINE %d", __ LINE __);"跟踪程序运行。
cron在前台运行,执行crond -f var/spool/cron/crontabs/root; 发现947行没有被执行,且文件指针是0;
推断:var/spool/cron/crontabs/root没有被读取。
跟踪文件读取函数load_crontab发现438行的if第二个条件不满足,DEAMON_UID是0,只有当sbuf.st_uid也等于0时才能执行文件读取,实际返回1000。变量sbuf.st_uid表示文件所属用户的UID。
-
•修改crontab file文件的UID和GID都是0,chown 0:0 /var/spool/cron/crontabs/root;
-
•重新启动crond:crond -f var/spool/cron/crontabs/
-
•10min后在/var/log/message里看到任务计划执行痕迹
Jan 10 12:00:00 (none) cron.info crond[854]: USER root pid 3506 cmd /usr/bin/compresslog.sh
Jan 10 12:00:00 (none) cron.info crond[854]: USER root pid 3508 cmd /usr/local/bin/recode_check.sh
Jan 10 12:10:00 (none) cron.info crond[854]: USER root pid 5007 cmd /usr/local/bin/recode_check.sh
Jan 10 12:20:00 (none) cron.info crond[854]: USER root pid 6506 cmd /usr/local/bin/recode_check.sh
结果:修改“crontab file所属用户”有效,任务计划可以正常运行。
证明:“crontab file所属用户不合法”是诱因
4. 推断过程
看到这个1000我已经觉察到问题根本原因,看我娓娓道来。
/etc/passwd记录linux用户所属UID、GID。UID=0、GID=0属于root用户。passwd有若干ID号,普通预设的用户的UID、GID在1~999,adduser创建的用户ID从1000开始,启动crond守护进程时会根据当前用名去
/var/spool/cron/crontabs/
目录下寻找与用户名同名的文件,顺带检查该文件的所属用户UID,只有文件存在、UID相同才读取该文件。
按照设想,那么crontab -e执行后应该会修改用户所属ID,下面是实验步骤。
-
再修改用户组为 1000 “chown 1000:root /var/spool/cron/crontabs/root”
-
观察crontab -e执行前后文件所属用户是否改变
-
实践和设想一致:crontab会修改文件所属用户。
5. 为什么测试阶段没发现问题
我的Linux系统开发环境普通用户编码从1000开始,为避免使用root用户误操作危害开发环境,一切文件均在普通用户环境下编辑,为有编辑权限,曾执行过 chown up /var/spool/cron/crontabs/root(不理解cron设计者为什么要去检查文件所属UID,即使当前已经是root权限),这个up就是我的用户名,up的UID=1000。
之所以在软件测试阶段未发现问题,原因在于任务计划默认10min才执行一次,为缩短测试时间而修改任务计划执行频率,提高测试效率,修改方法就是crontab -e编辑
/var/spool/cron/crontabs/root。
当初只注重recode_check.sh执行的正确性。