Linux/Linux System Programming

Kill -9 Program ftrace (유저단)

Hans_S_92 2022. 12. 22. 16:44

ftrace 메세지로 프로세스 생성과 종료 과정 분석

  • 1단계 프로세스 생성
  • 2단계 raspbian_proc 프로세스 진행
  • 3단계 프로세스 종료
  • 4단계 부모 프로세스에게 시그널 전달
399             bash-12961 [002] .... 1060001.980092: sys_clone+0x14/0x38 <-ret_fast_syscall+0x0/0x28
  400             bash-12961 [002] .... 1060001.980119: <stack trace>
  401  => sys_clone+0x18/0x38
  402  => ret_fast_syscall+0x0/0x28
  403  => 0x7ef64190
  404             bash-12961 [002] .... 1060001.980122: _do_fork+0x14/0x464 <-sys_clone+0x30/0x38
  405             bash-12961 [002] .... 1060001.980133: <stack trace>
  406  => _do_fork+0x18/0x464
  407  => sys_clone+0x30/0x38
  408  => ret_fast_syscall+0x0/0x28
  409  => 0x7ef64190
  410             bash-12961 [002] .... 1060001.980136: copy_process.part.3+0x14/0x1af0 <-_do_fork+0xc0/0x464
  411             bash-12961 [002] .... 1060001.980148: <stack trace>
  412  => copy_process.part.3+0x18/0x1af0
  413  => _do_fork+0xc0/0x464
  414  => sys_clone+0x30/0x38
  415  => ret_fast_syscall+0x0/0x28
  416  => 0x7ef64190
  417             bash-12961 [002] .... 1060001.980824: sched_process_fork: comm=bash pid=12961 child_comm=bash child_pid=13030
  418           <idle>-0     [003] d... 1060001.980870: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=bash next_pid=13030 next_prio=120
  419             bash-12961 [002] d... 1060001.981378: sched_switch: prev_comm=bash prev_pid=12961 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
  420    raspbian_proc-13030 [003] dn.. 1060001.982333: sched_wakeup: comm=kworker/3:1H pid=87 prio=100 target_cpu=003
  421    raspbian_proc-13030 [003] d... 1060001.982355: sched_switch: prev_comm=bash prev_pid=13030 prev_prio=120 prev_state=D ==> next_comm=kworker/3:1H next_pid=87 next_prio=100
  422     kworker/3:1H-87    [003] d... 1060001.982411: sched_wakeup: comm=kworker/3:0 pid=9582 prio=120 target_cpu=003
  423     kworker/3:1H-87    [003] d... 1060001.982477: sched_switch: prev_comm=kworker/3:1H prev_pid=87 prev_prio=100 prev_state=I ==> next_comm=kworker/3:0 next_pid=9582 next_prio=120
  424      kworker/3:0-9582  [003] d... 1060001.982515: sched_switch: prev_comm=kworker/3:0 prev_pid=9582 prev_prio=120 prev_state=I ==> next_comm=swapper/3 next_pid=0 next_prio=120
  425           <idle>-0     [000] dns. 1060001.984210: sched_wakeup: comm=kworker/0:1 pid=12766 prio=120 target_cpu=000
  426           <idle>-0     [000] dns. 1060001.984243: sched_wakeup: comm=kworker/0:0H pid=13036 prio=100 target_cpu=000
  427           <idle>-0     [000] d... 1060001.984267: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=kworker/0:0H next_pid=13036 next_prio=100
  428            <...>-13036 [000] d... 1060001.984298: sched_switch: prev_comm=kworker/0:0H prev_pid=13036 prev_prio=100 prev_state=I ==> next_comm=kworker/0:1 next_pid=12766 next_prio=120
  429           <idle>-0     [003] dnh. 1060001.984305: sched_wakeup: comm=bash pid=13030 prio=120 target_cpu=003
.....
14205             sshd-12938 [000] d... 1060112.279601: sched_wakeup: comm=kworker/u8:0 pid=12411 prio=120 target_cpu=000
14206             sshd-12938 [000] d... 1060112.279643: sched_switch: prev_comm=sshd prev_pid=12938 prev_prio=120 prev_state=S ==> next_comm=kworker/u8:0 next_pid=12411 next_prio=120
14207     kworker/u8:0-12411 [000] d... 1060112.279675: signal_generate: sig=2 errno=0 code=128 comm=raspbian_proc pid=13030 grp=1 res=0
14208           <idle>-0     [003] dnh. 1060112.279682: sched_wakeup: comm=raspbian_proc pid=13030 prio=120 target_cpu=003
14209           <idle>-0     [003] d... 1060112.279696: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=raspbian_proc next_pid=13030 next_prio=120
14210           <idle>-0     [002] dnh. 1060112.279697: sched_wakeup: comm=kworker/u8:1 pid=9851 prio=120 target_cpu=002
14211     kworker/u8:0-12411 [000] d... 1060112.279705: sched_wakeup: comm=sshd pid=12938 prio=120 target_cpu=000
14212    raspbian_proc-13030 [003] d... 1060112.279707: signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
14213           <idle>-0     [002] d... 1060112.279711: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=kworker/u8:1 next_pid=9851 next_prio=120
14214    raspbian_proc-13030 [003] .... 1060112.279712: do_exit+0x14/0xbe8 <-do_group_exit+0x50/0xe8
14215     kworker/u8:0-12411 [000] d... 1060112.279716: sched_switch: prev_comm=kworker/u8:0 prev_pid=12411 prev_prio=120 prev_state=I ==> next_comm=sshd next_pid=12938 next_prio=120
14216     kworker/u8:1-9851  [002] d... 1060112.279741: sched_switch: prev_comm=kworker/u8:1 prev_pid=9851 prev_prio=120 prev_state=I ==> next_comm=swapper/2 next_pid=0 next_prio=120
14217    raspbian_proc-13030 [003] .... 1060112.279747: <stack trace>
14218  => do_exit+0x18/0xbe8
14219  => do_group_exit+0x50/0xe8
14220  => get_signal+0x1a4/0x8fc
14221  => do_signal+0x318/0x498
14222  => do_work_pending+0xec/0x104
14223  => slow_work_pending+0xc/0x20
14224  => 0x76ecc2ec
14225             sshd-12938 [000] d... 1060112.279921: sched_switch: prev_comm=sshd prev_pid=12938 prev_prio=120 prev_state=S ==> next_comm=kworker/0:1 next_pid=12766 next_prio=120
14226      kworker/0:1-12766 [000] d... 1060112.279951: sched_switch: prev_comm=kworker/0:1 prev_pid=12766 prev_prio=120 prev_state=I ==> next_comm=swapper/0 next_pid=0 next_prio=120
14227    raspbian_proc-13030 [003] .... 1060112.280075: sched_process_exit: comm=raspbian_proc pid=13030 prio=120
14228    raspbian_proc-13030 [003] d... 1060112.280155: signal_generate: sig=17 errno=0 code=2 comm=bash pid=12961 grp=1 res=0
14229           <idle>-0     [002] dnh. 1060112.280175: sched_wakeup: comm=bash pid=12961 prio=120 target_cpu=002
14230    raspbian_proc-13030 [003] d... 1060112.280176: sched_switch: prev_comm=raspbian_proc prev_pid=13030 prev_prio=120 prev_state=Z ==> next_comm=swapper/3 next_pid=0 next_prio=120
14231           <idle>-0     [002] d... 1060112.280186: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=bash next_pid=12961 next_prio=120
14232             bash-12961 [002] d... 1060112.280455: signal_deliver: sig=17 errno=0 code=2 sa_handler=55a6c sa_flags=14000000
14233             bash-12961 [002] d... 1060112.280560: sched_wakeup: comm=kworker/u8:1 pid=9851 prio=120 target_cpu=002
14234             bash-12961 [002] d... 1060112.281343: sched_switch: prev_comm=bash prev_pid=12961 prev_prio=120 prev_state=S ==> next

410번 라인에 _do_fork()가 보입니다. 해당 라인의 앞부분을 보면 "bash-12961"이 적혀있습니다. 즉 bash가 _do_fork를 호출한 것입니다. 417번 라인을 확인하면 pid가 13030인 프로세스를 생성한다. “child_comm=bash” 메시지로 자식 프로세스 이름도 bash인것 같다.

프로세스 종료에 대한 흐름도는 다음과 같다.

Kill 명령어를 사용하면 위와 같은 흐름이 진행된다. 이것을 ftracbe를 통해 확인해보자.

14217번 라인을 보면 커널 공간에서 Kill을 사용햇을 때의 흐름도가 보인다. 그럼 이 시점 전에 Kill 시그널을 받았다는 것이다. 14212 번 라인을 확인하면 SIGKIL을 받은 것을 알 수 있다. (sig=9가 SIGKIL)

14227 번 라인은 paspbian_proc 프로세스가 종료하는 동작을 보여준다.

14228 번 라인은 pid가 13030 인 raspbian_proc 프로세서가 자신이 소멸될 것이라는 것을 부모 프로세스 ( pid: 12961 ) 로 signal 17번을 전달한다. signal 17는 SIGCHLD이다.