调查ovs-vswitch被随机stop的过程

ovs-vswitchd 进程随机被 kill

开始怀疑是进程被kill掉了，经过查看日志，应该是服务被正常stop了，并不是被异常kill了，所以后面主要是调研是谁主动stop该服务

是否有进程通过systemctl stop ovs-vswitchd关闭服务？

通过修改/usr/share/openvswitch/scripts/ovs-ctl脚本下面的内容，试图通过pstree来找到谁主动stop该服务 pstree -psa > /root/pstree.log

    stop)
        stop_forwarding
        stop_ovsdb
        pstree -psa > /root/pstree.log
        ;;

手动stop该服务，pstree.log的打印如下:

  |-sshd,1031                                                
  |   |-sshd,1099 
  |   |   `-bash,1296
  |   |       `-scl,1635 enable devtoolset-8 -- bash
  |   |           `-bash,1636 /var/tmp/scloXBYyN
  |   |               `-bash,1641
  |   |                   `-tailf,11680 /var/log/messages
  |   `-sshd,3234 
  |       `-bash,3265
  |           `-systemctl,11733 stop ovs-vswitchd
  |               |-pkttyagent,11735 --notify-fd 5 --fallback
  |               |   |-{pkttyagent},11736
  |               |   |-{pkttyagent},11737
  |               |   `-{pkttyagent},11738
  |               `-systemd-tty-ask,11734 --watch

可以看到是透过sshd登录到系统在bash里面执行了systemctl,11733 stop ovs-vswitchd，所以此方法是有机会抓到的，但遗憾的是在复现环境时没有抓到，但是systemctl的服务基本都是通过dbus来通信的，所以想是否可以通过监控dbus的通信看是否可以抓到谁发送的stop的信号来获知

监控dbus的通信看能否抓到是谁？

主要监控的对象是ovs的服务，我们使用dbus-monitor来监控，命令如下

dbus-monitor --system path='/org/freedesktop/systemd1/unit/ovs_2dvswitchd_2eservice' > dbus-monitor.log

可能会有人有疑问，path后面的如何获知的，可以通过busctl tree获取该路径，并监控与之所有的通信

    ├─/org/freedesktop/systemd1/unit/ovs_2ddelete_2dtransient_2dports_2eservice
    ├─/org/freedesktop/systemd1/unit/ovs_2dvswitchd_2eservice
    ├─/org/freedesktop/systemd1/unit/ovsdb_2dserver_2eservice

我们监控ovs-vswitch的服务所以选取该服务/org/freedesktop/systemd1/unit/ovs_2dvswitchd_2eservice
我们手动stop该服务看是否可以达到目的

signal sender=:1.23 -> dest=(null destination) serial=9214 path=/org/freedesktop/systemd1/unit/ovs_2dvswitchd_2eservice; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged               
   string "org.freedesktop.systemd1.Unit"                                           
   array [                                                                          
      dict entry(                                                                   
         string "ActiveState"                                                       
         variant             string "deactivating"                                  
      )                                                                             
      dict entry(                                                                   
         string "SubState"                                                          
         variant             string "stop"                                          
      )                                                                             
      dict entry(                                                                   
         string "InactiveExitTimestamp"                                             
         variant             uint64 1600742635574238                                
      )                                                                             
      dict entry(                                                                   
         string "InactiveExitTimestampMonotonic"                                    
         variant             uint64 53596580921                                     
      )                                                                             
      dict entry( 
         string "ActiveEnterTimestamp"                                              
         variant             uint64 1600742635635951                                
      )

可以看到确实会抓到通信内容，以我自测可以看到systemd会发送一个stop信号
ps:时间戳计算方法：

[root@localhost ~]# echo $((1600742635635951/1000/1000))
1600742635

使用在线转换软件 https://www.dunplab.it/timestamp-to-datetime

Your date time converted value
"mm-dd-yyyy hh:mm:ss": 09-22-2020 10:43:55

通过dbus或许可以抓到，但是我们知道在service基本都是通过systemd来管理的，在服务被关闭的时候会调用如下函数static void service_enter_stop(Service *s, ServiceResult f)，所以我们在这里插入probe点或许也可以查询到谁来stop的该服务

使用systemtap来插入probe点

查阅systemd的代码可以看到service一般的代码流程

static int service_stop(Unit *u)
    ---> service_enter_stop(s, SERVICE_SUCCESS);

但我们不确定是否走该代码路径，因为service_enter_stop有很多调用路径，所以我们的prode选择service_enter_stop

service_enter_stop 1491 src/core/service.c                 service_enter_stop(s, SERVICE_SUCCESS);
service_enter_stop 1525 src/core/service.c         service_enter_stop(s, SERVICE_FAILURE_RESOURCES);
service_enter_stop 1788 src/core/service.c                 service_enter_stop(s, SERVICE_FAILURE_RESOURCES);
service_enter_stop 1821 src/core/service.c         service_enter_stop(s, SERVICE_FAILURE_RESOURCES);
service_enter_stop 1930 src/core/service.c         service_enter_stop(s, SERVICE_SUCCESS);
service_enter_stop 2353 src/core/service.c                                 service_enter_stop(s, SERVICE_FAILURE_RESOURCES);
service_enter_stop 2597 src/core/service.c                                         service_enter_stop(s, f);
service_enter_stop 2608 src/core/service.c                                                         service_enter_stop(s, SERVICE_FAILURE_RESOURCES);
service_enter_stop 2687 src/core/service.c                 service_enter_stop(s, SERVICE_FAILURE_TIMEOUT);

使用systemtap，测试是否可以抓取相关的callstrace，在住用使用systemctl stop ovs-vswitchd的callstrace

the meta_id="ovs-vswitchd.service" 
the main_pid=0, control_pid=0
 0x5556363b11d0 : service_enter_stop+0x0/0x170 [/usr/lib/systemd/systemd]
 0x5556363b1386 : service_stop+0x46/0xd0 [/usr/lib/systemd/systemd]
 0x55563644c920 : job_perform_on_unit+0x40/0xd0 [/usr/lib/systemd/systemd]
 0x55563644e6c2 : job_run_and_invalidate+0x272/0x460 [/usr/lib/systemd/systemd]
 0x5556363971fc : manager_dispatch_run_queue+0x3c/0x1b0 [/usr/lib/systemd/systemd]
 0x55563643ee92 : source_dispatch+0x112/0x320 [/usr/lib/systemd/systemd]
 0x55563643ffda : sd_event_dispatch+0x6a/0x1b0 [/usr/lib/systemd/systemd]
 0x55563639f607 : manager_loop+0x637/0x7a0 [/usr/lib/systemd/systemd]
 0x55563639375b : main+0x1e7b/0x3e00 [/usr/lib/systemd/systemd]
 0x7f665bbdc545 [/usr/lib64/libc-2.17.so+0x22545/0x3c9000]
Tue Sep 22 09:15:28 2020: systemd (1), 1, 0

ovs-vswitchd进程被kill掉或者崩溃是如下的callstrace，可以看到是收到signal到进程被stop

the meta_id="ovs-vswitchd.service"
the main_pid=0, control_pid=0                                                   
 0x5556363b11d0 : service_enter_stop+0x0/0x170 [/usr/lib/systemd/systemd]          
 0x5556363b59e7 : service_sigchld_event+0xf7/0xd20 [/usr/lib/systemd/systemd]      
 0x55563639746e : invoke_sigchld_event+0xfe/0x230 [/usr/lib/systemd/systemd]       
 0x5556363977c6 : manager_dispatch_sigchld+0x226/0x2a0 [/usr/lib/systemd/systemd]  
 0x55563639e6ff : manager_dispatch_signal_fd+0x55f/0x8b0 [/usr/lib/systemd/systemd]
 0x55563643ef40 : source_dispatch+0x1c0/0x320 [/usr/lib/systemd/systemd] 
 0x55563643ffda : sd_event_dispatch+0x6a/0x1b0 [/usr/lib/systemd/systemd]
 0x55563639f607 : manager_loop+0x637/0x7a0 [/usr/lib/systemd/systemd]
 0x55563639375b : main+0x1e7b/0x3e00 [/usr/lib/systemd/systemd]
 0x7f665bbdc545 [/usr/lib64/libc-2.17.so+0x22545/0x3c9000]
Tue Sep 22 09:17:58 2020: systemd (1), 1, 0

经过上面三方面的在环境部署等待复现时：

发现方式1没有的到任何信息;
方式2有抓到相关信息;
方式3也抓到了callstrace;

方式2的信息如下：

signal sender=:1.1 -> dest=(null destination) serial=1350 path=/org/freedesktop/systemd1/unit/ovs_2dvswitchd_2eservice; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
   string "org.freedesktop.systemd1.Unit"
   array [
      dict entry(
         string "ActiveState"
         variant             string "deactivating"
      )
      dict entry(
         string "SubState"
         variant             string "stop"
      )
      dict entry(
         string "InactiveExitTimestamp"
         variant             uint64 1600772154190238
      )
      dict entry(
         string "InactiveExitTimestampMonotonic"
         variant             uint64 14204303952
      )
      dict entry(

可以看到是systemd发送了stop消息给ovs的service
方式3的信息如下：

0x556101cf01a0 : service_enter_stop+0x0/0x170 [/usr/lib/systemd/systemd]
0x556101d1caa7 : manager_notify_cgroup_empty+0x77/0x100 [/usr/lib/systemd/systemd]
0x556101cd7ee6 : manager_dispatch_cgroups_agent_fd+0x166/0x180 [/usr/lib/systemd/systemd]
0x556101d7df00 : source_dispatch+0x1c0/0x320 [/usr/lib/systemd/systemd]
0x556101d7ef9a : sd_event_dispatch+0x6a/0x1b0 [/usr/lib/systemd/systemd]
0x556101cde5d7 : manager_loop+0x637/0x7a0 [/usr/lib/systemd/systemd]
0x556101cd272b : main+0x1e7b/0x3e00 [/usr/lib/systemd/systemd]
0x7fba2d7e1545 : __libc_start_main+0xf5/0x1c0 [/usr/lib64/libc-2.17.so]
0x556101cd46ec : _start+0x29/0x2d [/usr/lib/systemd/systemd]

发现这个call strace和上面测试的完全不同，但是看到manager_notify_cgroup_empty这个函数

1046 int manager_notify_cgroup_empty(Manager *m, const char *cgroup) {
     /* [previous][next][first][last][top][bottom][index][help]  */
1047         Unit *u;
1048         int r;
1049 
1050         assert(m);
1051         assert(cgroup);
1052 
1053         log_debug("Got cgroup empty notification for: %s", cgroup);
1054 
1055         u = manager_get_unit_by_cgroup(m, cgroup);
1056         if (u) {
1057                 r = cg_is_empty_recursive(SYSTEMD_CGROUP_CONTROLLER, u->cgroup_path, true);
1058                 if (r > 0) {
1059                         if (UNIT_VTABLE(u)->notify_cgroup_empty)
1060                                 UNIT_VTABLE(u)->notify_cgroup_empty(u);
1061 
1062                         unit_add_to_gc_queue(u);
1063                 }
1064         }
1065 
1066         return 0;
1067 }

在执行UNIT_VTABLE(u)->notify_cgroup_empty(u)会调用到service_enter_stop函数关闭service
通过上面的两个debug信息可以看出推测应该是systemd检测到ovs-vswitchd的cgroup消失了，发送stop信号，主动关闭ovs-vswithd进程,那我们可能会有疑问，为什么cgroup会消失变更empty呢，下一篇我们继续调查

Q&A：

如何获取ovs-vswitchd的serive路径(/org/freedesktop/systemd1/unit/ovs_2dvswitchd_2eservice)？

通过命令busctl tree可以获知

如何接的dbus的sender是谁(signal sender=:1.1 -> dest=(null destination))？

通过dbusctl --list可以获得

[root@localhost ]# busctl --list
NAME                                   PID PROCESS         USER             CONNECTION    UNIT                      SESSION    DESCRIPTION        
:1.0                                   730 systemd-logind  root             :1.0          systemd-logind.service    -          -                  
:1.1                                     1 systemd         root             :1.1          -                         -          -                  
:1.19                                  993 systemd-resolve systemd-resolve  :1.19         systemd-resolved.service  -          -                  
:1.20                                  994 tuned           root             :1.20         tuned.service             -          -                  
:1.3                                   747 NetworkManager  root             :1.3          NetworkManager.service    -          -                  
:1.4                                   748 polkitd         polkitd          :1.4          polkit.service            -          -                  
:1.7                                   747 NetworkManager  root             :1.7          NetworkManager.service    -          -                  
:1.76                                19402 dbus-monitor    root             :1.76         session-2.scope           2          -                  
:1.97                                20293 busctl          root             :1.97         session-2.scope           2          -

可以看到sender=:1.1是systemd

附件：
debug.sh

#/bin/bash
dbus-monitor --system path='/org/freedesktop/systemd1/unit/ovs_2dvswitchd_2eservice' > dbus-monitor.log &
stap -vg debug.stp > debug.log

debug.stp

function process_tree() {                         
        cur_proc = task_current();                
        parent_pid = task_pid(task_parent (cur_proc));                                               
        while (parent_pid != 0) {                 
                printf("%s: %s (%d), %d, %d -> ", ctime(), task_execname(cur_proc), task_pid(cur_proc), task_pid(cur_proc), task_gid(cur_proc));                                                           
                cur_proc = task_parent(cur_proc);                                                    
                parent_pid = task_pid(task_parent(cur_proc));                                        
        }                                         
        if (task_pid(cur_proc) == 1) {            
                printf("%s: %s (%d), %d, %d\n", ctime(), task_execname(cur_proc), task_pid(cur_proc), task_pid(cur_proc), task_gid(cur_proc));                                                             
        }                                         
} 

probe process("/usr/lib/systemd/systemd").function("service_enter_stop")
{
        printf("the meta_id=%s\n", $s->meta->id$)
        if(user_string($s->meta->id) == "ovs-vswitchd.service")
        {
                printf("the main_pid=%d, control_pid=%d\n", $s->main_pid, $s->control_pid)
                print_ubacktrace()
                process_tree()
        }
}

文章归档

近期文章

ovs-vswitchd 进程随机被 kill

是否有进程通过systemctl stop ovs-vswitchd关闭服务？

监控dbus的通信看能否抓到是谁？

使用systemtap来插入probe点

Q&A：

发送评论编辑评论

ovs-vswitchd 进程随机被 kill

是否有进程通过systemctl stop ovs-vswitchd关闭服务？

监控dbus的通信看能否抓到是谁？

使用systemtap来插入probe点

Q&A：

发送评论 编辑评论

推荐文章

发送评论编辑评论