Linux神器之Strace的实践(Ubuntu上服务幽灵般的消失)

  不论是运维,还是开发,面对Linux系统,时常会因为配置参数或者系统的权限(iptables限制端口,selinux拦截,文件目录权限等)原因出现程序或者服务异常,无法启动等等。特别是在Linux的文件权限上,大型的程序或者服务依赖于大量的目录和相关文件,只要一个出现问题,就会发生连锁反应。

  strace常用来跟踪进程执行时的系统调用和所接收的信号。 在Linux世界,进程不能直接访问硬件设备,当进程需要访问硬件设备(比如读取磁盘文件,接收网络数据等等)时,必须由用户态模式切换至内核态模式,通 过系统调用访问硬件设备。strace可以跟踪到一个进程产生的系统调用,包括参数,返回值,执行消耗的时间。

  (strace的具体使用命令参考另外一位博主:http://www.cnblogs.com/ggjucheng/archive/2012/01/08/2316692.html

  鄙人前两天就遇到了一个很奇葩的问题:

  某个未上线服务器上的Ubuntu 12.04.5系统上运行的OpenStack组件Nova-compute服务执行启动之后,shell反馈有pid,/var/log/nova/nova-compute.log没有任何记录;执行ps -ef |grep nova-compute ,没有进程,服务处于stop状态。

      遇到问题的解决思路与过程是这样的:

      1.直接使用CLI交互下,使用root用户执行启动nova-compute服务,执行代码是:

   1 python /usr/bin/nova-compute --flagfile=/etc/nova/nova.conf 

  这样执行的结果是CLI下可以直接打印出本来应该写入到日志里面的东西,同时/var/log/nova/nova-compute.log日志中也是有了记录,其他session下也可以看到nova-compute进程,并且没有出现异常退出。发送到该节点的nova-compute任务也可以执行。基本证明:nova-compute的代码并没有被修改。root用户可以执行,是因为Linux系统上一般很难找到让root用户无法读写的情况。

  2.修改/etc/passwd 文件中nova用户使用bash,CLI下继续执行上面的命令。程序可以运行,日志可以记录,任务可以接受并执行,进程无异常退出。

    这里需要说明一下2步骤,理论上来说,先应该使用低权限用户来执行命令,避免root用户执行会修改日志文件或者某些目录的所属。

    但是此处的nova-compute服务通过ubuntu的init程序,也就是upstar启动,按照启动脚本的逻辑和方式最后的执行会是

   1 su -s /bin/sh -c exec nova-compute --flagfile=/etc/nova/nova.conf --flagfile=/etc/nova/nova-compute.conf nova  

   即表示使用nova用户,在sh交互下,执行nova-compute程序。也就是说,在nova用户下已经没有跑通,但是在nova用户使用cli的情况下又可以跑通。这样奇怪的问题也是极其罕见的。

  3.根据经验,Linux下这种问题,一般都是因为目录或者权限的原因导致的异常,但是nova-compute相关的目录与文件太多。此处可是使用find命令找出系统中所有与nova相关的位置,然后分别对它们执行stat命令,查看权限与所属。命令为 find / -name nova |grep -v /proc |xargs -i -t stat '{}' 这样的做法看起来有效,但可能相关的位置的名称中并没有包含nova这个关键字的话,那还是一样定位不到的。直接放弃。(后来发现,如果当初这么做,也是能解决的。。。)

  4.在经历了一整天的一筹莫展,周一上班之后,拿起了手边的书,看到了有strace的介绍。之前并不知道这个程序是做什么的,但是看过介绍之后,发现应该能够适用于此问题。就在这台服务器上安装了strace,之后执行了

   1 /etc/init.d/nova-compute restart |grep process |awk '{print $4}'|xargs strace -o debug_info.text -f -p

  大概说明一下这条命令:首先重新启动nova-compute服务,取关键字process行,筛选该行第四个位置的数字就是进程的pid,将PID交给strace程序,-o 参数是讲调试的内容输出到一个文件中,-f 是对fork的进程也调试,-p是指定进程的pid。

   这样执行下来之后会输出一个debug的文件,这个很长的debug信息中的末尾出现了如下的内容:

20641 write(2, "  File \"/usr/lib/python2.7/dist-"..., 102) = 102
20641 open("/usr/lib/python2.7/dist-packages/nova/compat/flagfile.py", O_RDONLY) = 3
20641 fstat(3, {st_mode=S_IFREG|0644, st_size=5884, ...}) = 0
20641 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f339e37a000
20641 read(3, "# vim: tabstop=4 shiftwidth=4 so"..., 4096) = 4096
20641 write(2, "    ", 4)               = 4
20641 write(2, "return open(path, 'r')\n", 23) = 23
20641 close(3)                          = 0
20641 munmap(0x7f339e37a000, 4096)      = 0
20641 write(2, "IOError", 7)            = 7
20641 write(2, ": ", 2)                 = 2
20641 write(2, "[Errno 13] Permission denied: '/"..., 59) = 59
20641 write(2, "\n", 1)              

  这里出现了提示权限被禁止,找到上面open的文件"/usr/lib/python2.7/dist-packages/nova/compat/flagfile.py",这个文件的权限和代码与其他节点也是相同的。

  那么根据之前的几步的判定,问题应该在某个文件的权限上。使用关键字“Permission denied”接着找,有了下面这一段:

  

20641 open("/etc/nova/nova-compute.conf", O_RDONLY) = -1 EACCES (Permission denied)
20641 lstat("/tmp/nova-conf-2mWZLQ", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
20641 openat(AT_FDCWD, "/tmp/nova-conf-2mWZLQ", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
20641 getdents(3, /* 3 entries */, 32768) = 88
20641 getdents(3, /* 0 entries */, 32768) = 0
20641 close(3)                          =

  这里提到了etc/nova/nova-compute.conf这个文件的权限错误,再检查,这个文件的所有者变成 root:root,修改配置文件的所属之后,使用service nova-compute restart之后,日志正常记录,服务没有异常丢失。 

posted on 2015-08-10 23:30  董小卓  阅读(553)  评论(0编辑  收藏  举报

导航