Using strace on Android

Question

I've been trying to use strace in order to track system calls executed when running a native application written in c/c++. After several tries on a "real world" app I realized that things are not as straightforward as on Linux. Firstly because there were a lot more system calls (which is fine) but the real problem is that I can even see the system calls that I know that should be pop up in strace.

So I decided to create the simplest possible ndk application and use strace there. But then I am seeing the same things.

Here's the code of the simple app:

#include <jni.h>
#include <string>

#include <android/log.h>
#include <signal.h>
#include <sys/mman.h>
#include <unistd.h>

#define  LOGE(...)  __android_log_print(ANDROID_LOG_ERROR, "LOG_TAG", __VA_ARGS__)

const size_t size = 4 * 1024;

static void sigsegv_handler(int id, siginfo_t *info, void *data)
{
    LOGE("%s()\n", __func__);
    LOGE("fault address: %p\n", info->si_addr);

    mprotect(info->si_addr, size, PROT_READ | PROT_WRITE);
}

extern "C" JNIEXPORT jstring JNICALL
Java_com_example_myapplication_MainActivity_stringFromJNI(
        JNIEnv* env,
        jobject /* this */) {
    // sleep(2);

    LOGE("%s()\n", __func__);
    LOGE("sigsegv_handler: %p\n", sigsegv_handler);

    struct sigaction sa = {};
    sa.sa_flags = SA_SIGINFO;
    sigemptyset(&sa.sa_mask);
    sigaddset(&sa.sa_mask, SIGSEGV);
    sa.sa_sigaction = sigsegv_handler;
    int result = sigaction(SIGSEGV, &sa, NULL);
    if (result == -1)
        LOGE("sigaction failed\n");

    void *addr = mmap(NULL, size, PROT_READ | PROT_WRITE, MAP_PRIVATE | MAP_ANONYMOUS, -1, 0);
    if (addr == MAP_FAILED)
        LOGE("mmap failed\n");

    mprotect(addr, size, PROT_NONE);
    int *segfault = (int *)addr;
    *segfault = 0;

    const std::string hello = "Hello from C++";
    return env->NewStringUTF(hello.c_str());
}

My first question is which is the correct way to attach strace to the application? I have tried two methods but neither seem to give correct results.

1.

am start -n com.example.myapplication/com.example.myapplication.MainActivity && set `ps -A | grep myapplication` && strace -p $2 &> /storage/emulated/0/Download/strace.txt

This produces something but it definitely is not complete because for example I cannot see neither rt_sigaction that installs the handler nor --- SIGSEGV when the segmentation fault triggers.

A workaround is to un-commend the // sleep(2);. which will give time to strace to attach the process. This is will yield the same results as with the the second method but it is not something you can reliably do with a real world app.

2. The second method is based on https://stackoverflow.com/a/26610905/5969257 Looks more complete but still something is missing.

set `ps -A | grep -w zygote64` ; strace -p $2 -ff -tt -T -s 500 -o /storage/emulated/0/Download/strace.txt

The idea here is to attach strace to zygote64 which will effectively fork the new process.

For example with this I can see in the logcat

08-12 09:23:48.844  8945  8945 E LOG_TAG : Java_com_example_myapplication_MainActivity_stringFromJNI()
08-12 09:23:48.845  8945  8945 E LOG_TAG : sigsegv_handler()
08-12 09:23:48.845  8945  8945 E LOG_TAG : fault address: 0x75588af000

and in strace.txt.8945 there's

09:23:48.844871 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x75588af000 <0.000023>
09:23:48.844928 mprotect(0x75588af000, 4096, PROT_NONE) = 0 <0.000016>
09:23:48.844975 --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_ACCERR, si_addr=0x75588af000} ---

which is very nice but the call to rt_sigaction that installs the handler is missing!

So my question is. Am I doing something wrong? Do I have the wrong expectations? Or there is something wrong with strace on Android?

Answer 1

You want a wrap shell script. These are somewhat annoying to use, but you can follow https://github.com/DanAlbert/strace-example as an example.

(if you want the debugger to keep working, you should also copy the jdwp section of $NDK/wrap.sh/asan.sh from the latest NDK into your wrap.sh)

strace output should then show up in logcat.

You'll immediately notice that strace output for an Android app is extremely noisy. ART is doing a ton of stuff in the background. You'll need to use -e to filter for the syscalls you want to monitor. If ART is also using those syscalls, strace is basically useless and you're better off with plain old logging. That was the problem I ran into, because I was trying to spot deadlocks, but because ART is constantly profiling the Java side of the app to find hot methods to JIT, the strace output was uselessly noisy.