[Bug 681071] Re: init: PTRACE_EVENT_CLONE not handled in fork tracking

[Clint Byrum]

I recently took a second look at this, and it may actually be Invalid.
The original daemon that we were looking at doing this, corosync, was
actually misunderstood. Apparently, it does fork, but it also did spawn
threads explicitly, which may have confused my debugging efforts.

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to upstart in Ubuntu.
https://bugs.launchpad.net/bugs/681071

Title:
  init: PTRACE_EVENT_CLONE not handled in fork tracking

Status in Upstart:
  Triaged
Status in “upstart” package in Ubuntu:
  Triaged
Status in “upstart” source package in Precise:
  Triaged

Bug description:
  corosync seems to use 'clone' instead of 'fork' to daemonize. Here is
  its startup strace to demonstrate:

  10709 recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"0\0\0\0\24\0\2\0\274O\354L\325)\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 224
  10709 recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"@\0\0\0\24\0\2\0\274O\354L\325)\0\0\n\200\200\376\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 320
  10709 recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0\274O\354L\325)\0\0\0\0\0\0\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
  10709 close(3)                          = 0
  10709 socket(PF_NETLINK, SOCK_RAW, 0)   = 3
  10709 bind(3, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
  10709 getsockname(3, {sa_family=AF_NETLINK, pid=10709, groups=00000000}, [12]) = 0
  10709 sendto(3, "\24\0\0\0\26\0\1\3\274O\354L\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
  10709 recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"0\0\0\0\24\0\2\0\274O\354L\325)\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 224
  10709 recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"@\0\0\0\24\0\2\0\274O\354L\325)\0\0\n\200\200\376\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 320
  10709 recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0\274O\354L\325)\0\0\0\0\0\0\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
  10709 close(3)                          = 0
  10709 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fa2c17029d0) = 10710
  10710 setsid()                          = 10710
  10710 open("/dev/null", O_RDWR)         = 3
  10710 dup2(3, 0)                        = 0
  10710 dup2(3, 1)                        = 1
  10710 dup2(3, 2)                        = 2
  10710 close(3)                          = 0
  10710 mmap(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7fa2be6e8000
  10710 mprotect(0x7fa2be6e8000, 4096, PROT_NONE) = 0
  10710 clone(child_stack=0x7fa2beee7ff0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7fa2beee89e0, tls=0x7fa2beee8710, child_tidptr=0x7fa2beee89e0) = 10711
  10710 futex(0x7fa2c12c30c4, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
  10711 set_robust_list(0x7fa2beee89f0, 0x18 <unfinished ...>
  10709 exit_group(0)                     = ?

  In the above example, 10710 is the process that should be traced as
  the daemon.

  I think this may be ptrace getting outsmarted somehow. It normally
  will fire off a PTRACE_EVENT_FORK even if it shows as a clone syscall,
  but in this case, it doesn't. I'll attach this little hacky ptracing
  program that demonstraces where PTRACE_EVENT_CLONE gets fired before
  PTRACE_EVENT_FORK.

  # ./test /usr/sbin/corosync
  parent waiting for pid #29995 at line 74
  child running ptrace at line 89
  PTRACE_TRACEME successful
  TRAP received..0
  TRAP: caught, new pid=0
  TRAP: FIRST child...
  TRAP: 29995 did a (unknown)
  parent waiting for pid #29995 at line 74
  TRAP received..0
  TRAP: caught, new pid=29996
  TRAP: 29996 did a (unknown)
  parent waiting for pid #29995 at line 74
  TRAP received..3
  TRAP: caught, new pid=29996
  TRAP: 29996 did a clone
  parent waiting for pid #29995 at line 74
  TRAP received..1
  TRAP: caught, new pid=29996
  TRAP: cannot ptrace 29996: No such process
  TRAP: 29996 did a fork
  parent waiting for pid #29995 at line 74

  I think it might be worth working on a minimal patch that is back
  portable to previous versions of upstart so they can track daemons
  that do this.

  The end result of this, btw, is not that corosync is shown to have
  died, but that corosync's children are all tracked as the service
  itself, causing a 'stop corosync' to send SIGTERM to all of corosync's
  services, which is incorrect behavior quite obviously.

To manage notifications about this bug go to:
https://bugs.launchpad.net/upstart/+bug/681071/+subscriptions