Android - strace runtime

Sun, 18 Nov 2007 16:22:37 +0000
tech android article

Last time I looked at the processes involved with initialising the Android Java framework. This wasn't able to give us much information on what was happening. To get some more data we are going to be using the strace tool. I've compiled a version of strace for Android, which you can download and use.

This time we start runtime using strace: ./strace -ff -F -tt -s 200 -o /tmp/strace runtime. -ff makes strace follow fork() and output each forked files trace to a different file. -F means we try and follow any vfork()s. -tt prints out the time of system calls in microseconds. -s 200 so that we can see a bit more detail in any strings that are used. After doing this we also start up zygote.

After start-up we can get a little bit more information about the running process. When we dig into the /proc/ directory of our runtime task we find a bit more information. In particular we see that as well as the main process, there are two extra threads. Now we are in a good position to start examining the trace files. We copy these across to the host using adb pull to make analysis a little easier.

We start by looking at the main process. Below is the annotate trace of the main thread.

The first part is just standard process initialisation:

05:30:51.171267 execve("/system/bin/runtime", ["runtime"], [/* 8 vars */]) = 0
05:30:51.179335 getpid()                = 493
05:30:51.180403 syscall_983045(0xb0016b68, 0xb0013780, 0x3e4, 0, 0xbef86e58, 0x1, 0, 0xf0005, 0xb0013780, 0, 0, 0xbef86e54, 0, 0xbef86e08, 0xb0000d89, 0xb00016ec, 0x10, 0xb0016b68, 0, 0, 0xc764, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) = 0
05:30:51.181639 gettid()                = 493
05:30:51.182628 sigaction(SIGILL, {0xb0001469, [], SA_RESTART}, {SIG_DFL}, 0) = 0
05:30:51.184487 sigaction(SIGABRT, {0xb0001469, [], SA_RESTART}, {SIG_DFL}, 0) = 0
05:30:51.186137 sigaction(SIGBUS, {0xb0001469, [], SA_RESTART}, {SIG_DFL}, 0) = 0
05:30:51.187460 sigaction(SIGFPE, {0xb0001469, [], SA_RESTART}, {SIG_DFL}, 0) = 0
05:30:51.188726 sigaction(SIGSEGV, {0xb0001469, [], SA_RESTART}, {SIG_DFL}, 0) = 0
05:30:51.189968 sigaction(SIGSTKFLT, {0xb0001469, [], SA_RESTART}, {SIG_DFL}, 0) = 0

Next up is the loading of shared libraries. I've stripped this down after the first one, as it is just the same blocks of code with different actual libraries. It doesn't quite load all the libraries on the system, but it goes pretty close:

05:30:51.191422 open("libandroid_runtime.so", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
05:30:51.193687 open("/system/lib/libandroid_runtime.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.195163 lseek(4, -8, SEEK_END)  = 313648
05:30:51.196653 read(4, "\0\0000\255PRE ", 8) = 8
05:30:51.198031 mmap2(0xad300000, 315392, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE, 4, 0) = 0xad300000
05:30:51.199144 close(4)                = 0
05:30:51.202026 mmap2(0xad34d000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, 0, 0) = 0xad34d000
...
...
05:30:51.205846 open("/system/lib/libexpat.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.212147 open("/system/lib/libc.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.222236 open("/system/lib/libstdc++.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.228944 open("/system/lib/libm.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.237093 open("/system/lib/libnativehelper.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.246900 open("/system/lib/libcutils.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.257238 open("/system/lib/libssl.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.266356 open("/system/lib/libcrypto.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.285991 open("/system/lib/libutils.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.292459 open("/system/lib/libz.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.314445 open("/system/lib/libicudata.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.323224 open("/system/lib/libicuuc.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.339731 open("/system/lib/libicui18n.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.366170 open("/system/lib/libsqlite.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.384451 open("/system/lib/libui.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.394162 open("/system/lib/libcorecg.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.403491 open("/system/lib/libpixelflinger.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.411948 open("/system/lib/libhardware.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.419561 open("/system/lib/libmedia.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.491956 open("/system/lib/libsgl.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.517146 open("/system/lib/libdvm.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.534603 open("/system/lib/libpim.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.542365 open("/system/lib/libopengles_cm.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.554764 open("/system/lib/libsonivox.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.566665 open("/system/lib/libdbus.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.602983 open("/system/lib/libsystem_server.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.610384 open("/system/lib/libsurfaceflinger.so", O_RDONLY|O_LARGEFILE) = 4
05:30:51.652278 open("/system/lib/libaudioflinger.so", O_RDONLY|O_LARGEFILE) = 4

Not quite sure what this stuff does. Nothing too important though.

05:30:51.698931 gettid()                = 493
05:30:51.699882 syscall_983045(0xbef86d5c, 0, 0x20, 0, 0xbef67000, 0xbef86e10, 0xbef86e50, 0xf0005, 0xbef86e50, 0, 0xd9e8, 0xd9e4, 0, 0xbef86d50, 0xafe20a4b, 0xafe0949c, 0x60000010, 0xbef86d5c, 0, 0, 0xc764, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) = 0

This next bit is interesting. We open a socket, but the path is a little interesting. Definitely needs some more investigation.

05:30:51.701110 socket(PF_FILE, SOCK_STREAM, 0) = 4
05:30:51.702175 connect(4, {sa_family=AF_FILE, path=@property_service}, 19) = 0
05:30:51.703602 recvmsg(4, {msg_name(0)=NULL, msg_iov(1)=[{"\0\200\0\0", 4}], msg_controllen=16, {cmsg_len=16, cmsg_level=SOL_SOCKET, cmsg_type=SCM_RIGHTS, {5}}, msg_flags=0}, 0) = 4
05:30:51.704618 mmap2(NULL, 32768, PROT_READ, MAP_SHARED, 5, 0) = 0x40000000
05:30:51.705794 close(5)                = 0
05:30:51.706714 close(4)                = 0

Try to open a file for malloc debug. It might be interesting to actually create this file and seem what happens.

05:30:51.708084 open("/data/malloc_debug", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)

Something did a malloc presumably, causing the brk.

05:30:51.709572 brk(0x15000)            = 0x15000

Scan the /tmp directory for some reason.

05:30:51.710607 open("/tmp", O_RDONLY|O_LARGEFILE|O_DIRECTORY) = 4
05:30:51.711709 getdents64(4, /* 6 entries */, 4200) = 192
05:30:51.714895 getdents64(4, /* 0 entries */, 4200) = 0
05:30:51.716089 close(4)                = 0

It opens up a bunch of log files.

05:30:51.717808 open("/dev/log/main", O_WRONLY|O_LARGEFILE) = 4
05:30:51.719025 open("/dev/log/radio", O_WRONLY|O_LARGEFILE) = 5
05:30:51.720213 open("/dev/log/events", O_WRONLY|O_LARGEFILE) = 6

Write out a startup message

05:30:51.721375 writev(4, [{"\4", 1}, {"runtime\0", 8}, {"*** Startup: root=\'/system\' asset=\'/system/app\' data=\'/data\' ***\n\0", 66}], 3) = 75

Check the input device is available, but don't open it.

05:30:51.723733 access("/dev/input/event0", R_OK) = 0
05:30:51.725407 writev(4, [{"\4", 1}, {"runtime\0", 8}, {"Key input device: 1 1 \'/dev/input/event0\'\n\0", 43}], 3) = 52
05:30:51.727398 getpid()                = 493
05:30:51.728306 setpgid(0, 493)         = 0
05:30:51.729234 chdir("/system/app")    = 0

05:30:51.730480 open("/dev/alarm", O_RDWR|O_LARGEFILE) = 7
05:30:51.731637 ioctl(7, 0x40086104, 0xbef86ce0) = 0
05:30:51.732909 close(7)                = 0

This bit here is pretty important. /dev/binder is the character device for OpenBinder, which is something that you see in the kernel source. This appears to be an IPC sub-system for the Linux kernel. It was at some stage donated by Palm, and there was an OpenBinder.org website for sometime, although that site is now dead. Finding more information on this will be essential.

05:30:51.733954 open("/dev/binder", O_RDWR|O_LARGEFILE) = 7
05:30:51.735488 fcntl64(7, F_SETFD, FD_CLOEXEC) = 0
05:30:51.736483 ioctl(7, 0xc0046209, 0xbef86cbc) = 0
05:30:51.737443 ioctl(7, 0x40046205, 0xbef86cb8) = 0
05:30:51.738385 mmap2(NULL, 8388608, PROT_READ, MAP_PRIVATE|MAP_NORESERVE, 7, 0) = 0x40008000
05:30:51.739478 writev(4, [{"\4", 1}, {"runtime\0", 8}, {"Entered boot_init()!\n\0", 22}], 3) = 31
05:30:51.741301 writev(4, [{"\3", 1}, {"runtime\0", 8}, {"ProcessState: 0x13420\n\0", 23}], 3) = 32


05:30:51.743109 ioctl(7, 0x40046207, 0xbef86c9c) = 0
05:30:51.744223 writev(4, [{"\4", 1}, {"runtime\0", 8}, {"Binder driver opened.  Multiprocess enabled.\n\0", 46}], 3) = 55
05:30:51.746874 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(ui_hardware, 0x1357c)\n\0", 50}], 3) = 66

A loop trying to communicate with zygote.

05:30:51.749204 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:30:51.750298 socket(PF_FILE, SOCK_STREAM, 0) = 8
05:30:51.751305 connect(8, {sa_family=AF_FILE, path=@android.zygote}, 17) = -1 ECONNREFUSED (Connection refused)
05:30:51.752442 close(8)                = 0
...
05:30:51.753446 nanosleep({0, 500000000}, {0, 500000000}) = 0
05:30:52.266564 socket(PF_FILE, SOCK_STREAM, 0) = 8
05:30:52.268061 connect(8, {sa_family=AF_FILE, path=@android.zygote}, 17) = -1 ECONNREFUSED (Connection refused)
05:30:52.269456 close(8)                = 0
...
05:31:04.230401 nanosleep({0, 500000000}, {0, 500000000}) = 0
05:31:04.746608 socket(PF_FILE, SOCK_STREAM, 0) = 8
05:31:04.748192 connect(8, {sa_family=AF_FILE, path=@android.zygote}, 17) = 0

Once a connection with zygote is obtained it appears to send a message: 5
--allow-disconnect
--nice-name=system_server
--setuid=0
--setgid=0
android.server.SystemServer
. It then seems to receive back a 4 byte message, which seems to be 498, but it's not clear what that is. My guess would be a pid, but it doesn't seem to be true. It seems that zygote acts as a process manager, and runtime can communicate with it to start new processes, in particular it starts up the system_server process.

05:31:04.749657 fcntl64(8, F_GETFL)     = 0x2 (flags O_RDWR)
05:31:04.751247 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40808000
05:31:04.752834 mprotect(0x40808000, 4096, PROT_READ) = 0
05:31:04.754234 fstat64(8, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
05:31:04.757578 mprotect(0x40808000, 4096, PROT_READ|PROT_WRITE) = 0
05:31:04.758739 mprotect(0x40808000, 4096, PROT_READ) = 0
05:31:04.759853 write(8, "5\n--allow-disconnect\n--nice-name=system_server\n--setuid=0\n--setgid=0\nandroid.server.SystemServer\n", 97) = 97
05:31:04.762081 read(8, "\0", 1024)     = 1
05:31:05.818220 read(8, "\0", 1024)     = 1
05:31:05.820120 read(8, "\1", 1024)     = 1
05:31:05.821236 read(8, "\362", 1024)   = 1
05:31:05.822320 close(8)                = 0

Initialise and print out messages on the console.

05:31:05.823445 fstat64(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 0), ...}) = 0
05:31:05.825556 mprotect(0x40808000, 4096, PROT_READ|PROT_WRITE) = 0
05:31:05.826475 mprotect(0x40808000, 4096, PROT_READ) = 0
05:31:05.827278 ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
05:31:05.828818 write(1, "+++ post-zygote\n", 16) = 16

Create a new thread -- we find out what this does in a little bit.

05:31:05.832934 mmap2(0x10000000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x10000000
05:31:05.833889 mprotect(0x10000000, 4096, PROT_NONE) = 0
05:31:05.834890 clone(child_stack=0x100fff80, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_DETACHED) = 484

Not quite sure what is going on here. There appears to be communication with another thread (the SurfaceFlinger) via the futex 0x134a8, it then prints a message once it has found the SurfaceFlinger.

05:31:05.837944 writev(4, [{"\3", 1}, {"runtime\0", 8}, {"DisplayDevice::detach\n\0", 23}], 3) = 32
05:31:05.839713 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: waiting for service SurfaceFlinger\n\0", 52}], 3) = 68
05:31:05.841621 clock_gettime(CLOCK_MONOTONIC, {127, 101400000}) = 0
05:31:05.842936 clock_gettime(CLOCK_MONOTONIC, {127, 103070000}) = 0
05:31:05.844238 clock_gettime(CLOCK_MONOTONIC, {127, 104026000}) = 0
05:31:05.845441 futex(0x134ac, FUTEX_WAIT, -1, {4, 997000000}) = 0
05:31:06.118721 futex(0x134a8, FUTEX_WAIT, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
05:31:06.122382 futex(0x134a8, FUTEX_WAKE, 1) = 0
05:31:06.126330 writev(4, [{"\4", 1}, {"runtime\0", 8}, {"Display startup: 1 devices\n\0", 28}], 3) = 37

No time like the present to get your PID and UID. No idea why this is required (twice!).

05:31:06.133210 getpid() = 493
05:31:06.154288 getuid32() = 0
05:31:06.160787 getpid() = 493
05:31:06.165845 getuid32() = 0

This block appears to be an IPC using the OpenBinder interface. This is a common block of code that we see throughout. Not quite sure why the getpriority is required every-time. It would be extremely useful to see the contents of the ioctl buffer, but this isn't really available easily in strace. It might mean either extensions to strace, or putting some hacks in the kernel.

05:31:06.168510 getpriority(PRIO_PROCESS, 0) = 20
05:31:06.171049 ioctl(7, 0xc0186201, 0xbef86b08) = 0
05:31:06.187776 ioctl(7, 0xc0186201, 0xbef86b08) = 0

More log file activity. Here we seem to have detached from the display device, presumably that was what the previous IPC was all about.

05:31:06.189902 writev(4, [{"\3", 1}, {"runtime\0", 8}, {"DisplayDevice::shutDown\n\0", 25}], 3) = 34
05:31:06.191663 writev(4, [{"\3", 1}, {"runtime\0", 8}, {"DisplayDevice::detach\n\0", 23}], 3) = 32

This next section seems to be waiting for service activity to occur.

05:31:06.193425 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: waiting for service activity\n\0", 46}], 3) = 62
05:31:06.271693 clock_gettime(CLOCK_MONOTONIC, {127, 531615000}) = 0
05:31:06.272800 clock_gettime(CLOCK_MONOTONIC, {127, 532606000}) = 0
05:31:06.273769 clock_gettime(CLOCK_MONOTONIC, {127, 533559000}) = 0
05:31:06.274735 futex(0x134ac, FUTEX_WAIT, -3, {4, 998000000}) = 0
05:31:06.800315 futex(0x134a8, FUTEX_WAIT, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
05:31:06.802159 clock_gettime(CLOCK_MONOTONIC, {128, 61969000}) = 0
05:31:06.804065 clock_gettime(CLOCK_MONOTONIC, {128, 63928000}) = 0
05:31:06.879426 futex(0x134a8, FUTEX_WAKE, 1) = 0
05:31:06.882042 futex(0x134ac, FUTEX_WAIT, -4, {4, 467000000}) = 0
05:31:06.891935 futex(0x134a8, FUTEX_WAIT, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
05:31:06.893777 futex(0x134a8, FUTEX_WAKE, 1) = 0
05:31:06.898754 getpid() = 493
05:31:06.904418 getuid32() = 0
05:31:06.907269 getpriority(PRIO_PROCESS, 0) = 20
05:31:06.909036 ioctl(7, 0xc0186201, 0xbef86b58) = 0
05:31:06.914561 ioctl(7, 0xc0186201, 0xbef86b58) = 0
05:31:06.920828 futex(0xafe40c00, FUTEX_WAIT, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
05:31:06.923679 futex(0xafe40c00, FUTEX_WAKE, 1) = 0
05:31:06.928106 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Now that service activity is ready to happen, we go through a series of adding services.

05:31:06.933366 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(activity.services, 0x150d0)\n\0", 56}], 3)    = 72
05:31:06.939660 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:06.940605 getpriority(PRIO_PROCESS, 0) = 25
05:31:06.941485 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:06.946561 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Unknown IPC

05:31:08.201642 getpriority(PRIO_PROCESS, 0) = 35
05:31:08.202648 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.205743 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add the window service

05:31:08.223890 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(window, 0x15418)\n\0", 45}], 3) = 61
05:31:08.226533 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:08.227542 getpriority(PRIO_PROCESS, 0) = 25
05:31:08.228462 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.231366 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add the USB service

05:31:08.339061 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(USB, 0x151f8)\n\0", 42}], 3)    = 58
05:31:08.341890 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:08.342755 getpriority(PRIO_PROCESS, 0) = 25
05:31:08.343562 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.366177 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Unknown IPC

05:31:08.470072 getpriority(PRIO_PROCESS, 0) = 25
05:31:08.471010 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.471990 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add the statusbar service.

05:31:08.481632 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(statusbar, 0x15660)\n\0", 48}], 3) = 64
05:31:08.483719 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:08.484601 getpriority(PRIO_PROCESS, 0) = 25
05:31:08.485720 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.491172 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Unknown IPCs

05:31:08.499888 getpriority(PRIO_PROCESS, 0)    = 25
05:31:08.501478 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.505934 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:08.514132 getpriority(PRIO_PROCESS, 0)    = 25
05:31:08.518759 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.523850 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add the statusbar service.

05:31:08.530638 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(statistics, 0x15890)\n\0", 49}], 3)    = 65
05:31:08.533406 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:08.534278 getpriority(PRIO_PROCESS, 0) = 25
05:31:08.535099 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.626083 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Unknown IPCs

05:31:08.868326 getpriority(PRIO_PROCESS, 0) = 20
05:31:08.869383 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.870513 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:08.874043 getpriority(PRIO_PROCESS, 0) = 20
05:31:08.875021 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.877895 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:08.930930 getpriority(PRIO_PROCESS, 0) = 20
05:31:08.931941 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.932985 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:08.949753 getpriority(PRIO_PROCESS, 0) = 20
05:31:08.950735 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:08.951764 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:09.065015 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.066231 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.067293 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:09.122422 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.123511 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.124627 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:09.165747 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.166886 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.167966 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:09.206344 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.207418 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.208536 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add the PhoneNotifier service

05:31:09.428385 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(android.telephony.PhoneNotifier, 0x15928)\n\0", 70}], 3) = 86
05:31:09.431266 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:09.432328 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.433284 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.434453 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Unknown IPC

05:31:09.449402 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.450514 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.451817 ioctl(7, 0xc0186201, 0xbef86c10) = 0
05:31:09.524328 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(SMS, 0x15988)\n\0", 42}], 3) = 58
05:31:09.526862 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:09.527847 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.528758 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.529847 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add the SimPhoneBook service

05:31:09.549454 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(android.telephony.SimPhoneBook, 0x154c0)\n\0", 69}], 3) = 85
05:31:09.552176 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:09.553202 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.554154 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.556977 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Unknown IPC

05:31:09.704285 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.705523 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.706634 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:09.867287 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.868394 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.869523 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add the volume service.

05:31:09.886578 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(volume, 0x15540)\n\0", 45}], 3) = 61
05:31:09.888998 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:09.890025 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.890977 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.892075 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add the phone service.

05:31:09.910618 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(phone, 0x155b8)\n\0", 44}], 3) = 60
05:31:09.912975 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:09.913996 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.914986 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.917974 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Unknown IPCs

05:31:09.941316 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.942419 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.943557 ioctl(7, 0xc0186201, 0xbef86c10) = 0

05:31:09.948824 getpriority(PRIO_PROCESS, 0) = 20
05:31:09.949879 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:09.950985 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Bluetooth service

05:31:10.141405 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(org.bluez.bluetooth, 0x15ca8)\n\0", 58}], 3) = 74
05:31:10.144074 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:10.145156 getpriority(PRIO_PROCESS, 0) = 20
05:31:10.146278 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:10.147366 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Add bluetooth mailbox service

05:31:10.150666 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(org.bluez.bluetooth_mailbox, 0x15d50)\n\0", 66}], 3) = 82
05:31:10.153207 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
05:31:10.154173 getpriority(PRIO_PROCESS, 0) = 20
05:31:10.155077 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:10.158028 ioctl(7, 0xc0186201, 0xbef86c10) = 0

Many more unknown IPCs

.....
05:31:12.209289 getpriority(PRIO_PROCESS, 0) = 20
05:31:12.210336 ioctl(7, 0xc0186201, 0xbef86ac0) = 0
05:31:12.213804 ioctl(7, 0xc0186201

At the end of time, the runtime sits waiting for more IPCs to occur. That ends the analysis of the main runtime thread. In summary it seems to hang around as the ServiceManager, adding services. Presumably the other IPCs relate to other threads requesting services and the like. Before doing this it seems to help kick things off by spawning android.server.SystemServer.

Along the way you may remember that a new thread was spawned (thread id 484). We now take a look at what happens in that thread. It seems to do not very much. It has some interaction with the binder, and then seems to just spawn off a new thread of its own before exiting.

06:38:07.140035 syscall_983045(0x100fff80, 0, 0x20, 0, 0x100fff80, 0x139f0, 0xa9d25ef9, 0xf0005, 0xbeaacc38, 0xafe36e70, 0xa9d25ef9, 0x1, 0, 0x100fff68, 0xafe0b238, 0xafe0949c, 0x60000010, 0x100fff80, 0xc1000, 0, 0xc764, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) = 0
06:38:07.141657 getpid()                = 479
06:38:07.142520 getuid32()              = 0
06:38:07.143438 ioctl(7, 0xc0186201, 0x100ffef8) = 0
06:38:07.305190 mmap2(0x10100000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x10100000
06:38:07.306160 mprotect(0x10100000, 4096, PROT_NONE) = 0
06:38:07.307099 clone(child_stack=0x101fff80, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_DETACHED) = 488
06:38:07.308664 getpriority(PRIO_PROCESS, 0) = 20
06:38:07.309560 ioctl(7, 0xc0186201, 0x100ffda8) = 0
06:38:07.310866 ioctl(7, 0xc0186201, 0x100ffef8) = 0
06:38:15.193301 ioctl(7, 0xc0186201, 0x100ffef8) = 0
06:38:15.194829 futex(0x13a00, FUTEX_WAKE, 1) = 0
06:38:15.196296 munmap(0x10000000, 1048576) = 0
06:38:15.198228 exit(0)                 = ?

The next thread is 488. Like the last thread, it seems to just create a new thread (499), and then exit. (Not quite sure why we have these threads that start, do not much and then exit, maybe implementing some asynchronous style IPC(?).

06:38:07.311899 syscall_983045(0x101fff80, 0, 0x20, 0, 0x101fff80, 0x13d50, 0xa9d25ef9, 0xf0005, 0x100ffd90, 0xafe36e70, 0xa9d25ef9, 0x1, 0, 0x101fff68, 0xafe0b238, 0xafe0949c, 0x60000010, 0x101fff80, 0xc10f0, 0, 0xc764, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) = 0
06:38:07.313122 getpid()                = 479
06:38:07.313959 getuid32()              = 0
06:38:07.314808 ioctl(7, 0xc0186201, 0x101ffef8) = 0
06:38:07.370653 mmap2(0x10200000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x10200000
06:38:07.371719 mprotect(0x10200000, 4096, PROT_NONE) = 0
06:38:07.372785 clone(child_stack=0x102fff80, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_DETACHED) = 499
06:38:07.374282 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: waiting for service SurfaceFlinger\n\0", 52}], 3) = 68
06:38:07.377988 clock_gettime(CLOCK_MONOTONIC, {41, 594807000}) = 0
06:38:07.379786 clock_gettime(CLOCK_MONOTONIC, {41, 596593000}) = 0
06:38:07.381511 clock_gettime(CLOCK_MONOTONIC, {41, 598312000}) = 0
06:38:07.383379 futex(0x134ac, FUTEX_WAIT, -1, {4, 996000000}) = 0
06:38:07.401561 futex(0x134a8, FUTEX_WAIT, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
06:38:07.405316 futex(0x134a8, FUTEX_WAKE, 1) = 0
06:38:07.409904 getpriority(PRIO_PROCESS, 0) = 30
06:38:07.416223 ioctl(7, 0xc0186201, 0x101ffda8) = 0
06:38:07.440719 ioctl(7, 0xc0186201, 0x101ffef8) = 0
06:38:25.193171 ioctl(7, 0xc0186201, 0x101ffef8) = 0
06:38:25.194719 futex(0x13d60, FUTEX_WAKE, 1) = 0
06:38:25.196134 munmap(0x10100000, 1048576) = 0
06:38:25.198048 exit(0)                 = ?

And now thread 499. This seems to spawn another thread (TID 500), adds the SurfaceFlinger service, and then exit.

06:38:07.376978 syscall_983045(0x102fff80, 0, 0x20, 0, 0x102fff80, 0x14060, 0xa9d25ef9, 0xf0005, 0x101ffd90, 0xafe36e70, 0xa9d25ef9, 0x1, 0, 0x102fff68, 0xafe0b238, 0xafe0949c, 0x60000010, 0x102fff80, 0, 0, 0xc764, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) = 0
06:38:07.379192 getpid() = 479
06:38:07.380922 getuid32() = 0
06:38:07.382691 ioctl(7, 0xc0186201, 0x102ffef8) = 0
06:38:07.385026 mmap2(0x10300000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x10300000
06:38:07.392408 mprotect(0x10300000, 4096, PROT_NONE) = 0
06:38:07.393447 clone(child_stack=0x103fff80, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_DETACHED) = 500
06:38:07.395459 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(SurfaceFlinger, 0x144a0)\n\0", 53}], 3) = 69
06:38:07.398890 futex(0x134ac, FUTEX_WAKE, 2147483647)                = 2
06:38:07.402396 futex(0x134a8, FUTEX_WAKE, 1)              = 0
06:38:07.406189 getpriority(PRIO_PROCESS, 0)    = 20
06:38:07.410508 ioctl(7, 0xc0186201, 0x102ffda8) = 0
06:38:07.433790 ioctl(7, 0xc0186201, 0x102ffef8) = 0
06:38:20.193223 ioctl(7, 0xc0186201, 0x102ffef8) = 0
06:38:20.194793 futex(0x14070, FUTEX_WAKE, 1) = 0
06:38:20.196186 munmap(0x10200000, 1048576) = 0
06:38:20.198087 exit(0)                 = ?

Thread 500 actually seems to do something useful. This seems to create yet another thread (502), and then seems to do something very similar to the main thread, sitting in a loop adding new services, and responding IPC messages. It is not clear why we need two different threads. Possibly there is a different thread for each possible client.

06:38:07.397343 syscall_983045(0x103fff80, 0, 0x20, 0, 0x103fff80, 0x143b8, 0xa9d25ef9, 0xf0005, 0x102ffd90, 0xafe36e70, 0xa9d25ef9, 0x1, 0, 0x103fff68, 0xafe0b238, 0xafe0949c, 0x60000010, 0x103fff80, 0xc12d0, 0, 0xc764, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) = 0
06:38:07.400080 getpid() = 479
06:38:07.403663 getuid32() = 0
06:38:07.407513 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:07.414539 mmap2(0x10400000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0)    = 0x10400000
06:38:07.439311 mprotect(0x10400000, 4096, PROT_NONE)    = 0
06:38:07.442042 clone(child_stack=0x104fff80, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_DETACHED) = 502
06:38:07.444609 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(AudioFlinger, 0x14b40)\n\0", 51}], 3)              = 67
06:38:07.449432 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:07.452182 getpriority(PRIO_PROCESS, 0)    = 20
06:38:07.459755 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:07.473981 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:08.076657 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(power, 0x14830)\n\0", 44}], 3) = 60
06:38:08.078875 futex(0x134ac, FUTEX_WAKE, 2147483647) = 1
06:38:08.080710 futex(0x134a8, FUTEX_WAKE, 1) = 0
06:38:08.082566 getpriority(PRIO_PROCESS, 0) = 25
06:38:08.084402 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:08.099967 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:08.165531 getpriority(PRIO_PROCESS, 0) = 25
06:38:08.166646 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:08.167758 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:08.171184 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(activity, 0x14e88)\n\0", 47}], 3) = 63
06:38:08.173533 futex(0x134ac, FUTEX_WAKE, 2147483647) = 1
06:38:08.177313 futex(0x134a8, FUTEX_WAKE, 1) = 1
06:38:08.185288 getpriority(PRIO_PROCESS, 0) = 25
06:38:08.186450 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:08.187727 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:08.206589 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(activity.receivers, 0x15028)\n\0", 57}], 3)    = 73
06:38:08.209646 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:08.210606 getpriority(PRIO_PROCESS, 0) = 25
06:38:08.211485 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:08.219706 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:08.225865 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(activity.providers, 0x14e30)\n\0", 57}], 3)    = 73
06:38:08.228957 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:08.229950 getpriority(PRIO_PROCESS, 0) = 25
06:38:08.230829 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:08.258759 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.049151 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(package, 0x15260)\n\0", 46}], 3) = 62
06:38:09.051523 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:09.052531 getpriority(PRIO_PROCESS, 0) = 25
06:38:09.053477 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.054570 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.059698 getpriority(PRIO_PROCESS, 0) = 25
06:38:09.060763 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.061861 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.083975 getpriority(PRIO_PROCESS, 0) = 25
06:38:09.085589 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.086949 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.104476 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(content, 0x152a0)\n\0", 46}], 3) = 62
06:38:09.107125 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:09.108104 getpriority(PRIO_PROCESS, 0) = 25
06:38:09.109013 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.118773 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.183888 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(battery, 0x15320)\n\0", 46}], 3) = 62
06:38:09.186582 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:09.187569 getpriority(PRIO_PROCESS, 0) = 25
06:38:09.188464 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.225874 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.487155 getpriority(PRIO_PROCESS, 0) = 35
06:38:09.488238 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.489328 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.521681 getpriority(PRIO_PROCESS, 0) = 25
06:38:09.522675 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.544021 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.601845 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(org.bluez.bluetooth_service, 0x15150)\n\0", 66}], 3) = 82
06:38:09.604465 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:09.606401 getpriority(PRIO_PROCESS, 0) = 25
06:38:09.607262 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.639998 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.803186 getpriority(PRIO_PROCESS, 0)    = 25
06:38:09.804803 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.810019 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:09.819942 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(statistics, 0x15888)\n\0", 49}], 3)    = 65
06:38:09.822767 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:09.823646 getpriority(PRIO_PROCESS, 0) = 25
06:38:09.824478 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:09.865728 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.154474 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.157321 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.158537 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.163674 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.164666 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.165885 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.251413 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.252438 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.253512 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.274076 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.276875 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.278112 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.282103 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.283091 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.284126 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.318757 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.319829 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.320913 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.527902 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.529000 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.530108 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.553191 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.554366 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.557334 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.785261 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(android.telephony.PhoneNotifier, 0x15938)\n\0", 70}], 3) = 86
06:38:10.787969 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:10.788952 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.789867 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.790925 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.825487 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.826620 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.827751 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.864624 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(SMS, 0x15998)\n\0", 42}], 3) = 58
06:38:10.867192 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:10.868174 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.869088 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.870161 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.902914 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(android.telephony.SimPhoneBook, 0x154c0)\n\0", 69}], 3) = 85
06:38:10.905863 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:10.906910 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.908018 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.909213 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:10.964689 getpriority(PRIO_PROCESS, 0) = 20
06:38:10.965983 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:10.967082 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:11.034374 getpriority(PRIO_PROCESS, 0) = 20
06:38:11.038891 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:11.040226 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:11.067389 getpriority(PRIO_PROCESS, 0) = 20
06:38:11.068514 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:11.078629 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:11.253134 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(volume, 0x15540)\n\0", 45}], 3) = 61
06:38:11.258928 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:11.260032 getpriority(PRIO_PROCESS, 0) = 20
06:38:11.260964 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:11.270195 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:11.284493 getpriority(PRIO_PROCESS, 0)    = 20
06:38:11.288630 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:11.298964 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:11.432430 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(org.bluez.bluetooth, 0x15cb8)\n\0", 58}], 3) = 74
06:38:11.434972 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:11.441544 getpriority(PRIO_PROCESS, 0) = 20
06:38:11.445408 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:11.452511 ioctl(7, 0xc0186201, 0x103ffef8) = 0
06:38:11.460171 getpriority(PRIO_PROCESS, 0) = 20
06:38:11.464099 ioctl(7, 0xc0186201, 0x103ffda8) = 0
06:38:11.478595 ioctl(7, 0xc0186201

This thread doesn't do much, it seems similar to the previous, where it is simply sitting waiting for IPC messages and adding services.

06:38:07.446832 syscall_983045(0x104fff80, 0, 0x20, 0, 0x104fff80, 0x140d8, 0xa9d25ef9, 0xf0005, 0x103ffd90, 0xafe36e70, 0xa9d25ef9, 0x1, 0, 0x104fff68, 0xafe0b238, 0xafe0949c, 0x60000010, 0x104fff80, 0xc13c0, 0, 0xc764, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) = 0
06:38:07.450234 getpid() = 479
06:38:07.452799 getuid32() = 0
06:38:07.471704 ioctl(7, 0xc0186201, 0x104ffef8) = 0
06:38:11.449551 writev(4, [{"\4", 1}, {"ServiceManager\0", 15}, {"ServiceManager: addService(org.bluez.bluetooth_mailbox, 0x15db0)\n\0", 66}], 3)    = 82
06:38:11.453639 futex(0x134ac, FUTEX_WAKE, 2147483647) = 0
06:38:11.454617 getpriority(PRIO_PROCESS, 0) = 20
06:38:11.460965 ioctl(7, 0xc0186201, 0x104ffda8) = 0
06:38:11.470727 ioctl(7, 0xc0186201

So there it is. A fairly detailed breakdown of what the runtime process does. Next up is to find out what zygote does. It looks like it is basically something like a CORBA ORB. It would definitely be nice to understand a lot more about the IPC.

blog comments powered by Disqus