The capability of aprof is similar to what gprof does, it provides call graph and time sampling profiling, but it's incompatible with gprof since the gprof can't profile shared library, it's limited by its representation.
Usage for aprof
If you want to profile an executable or static library, you can turn on aprof by inserting the following line to Android.mk:
LOCAL_ENABLE_APROF := true
There are two modes for profile shared library. The first one is specify for Non-JNI used shared library, it's just used like executable, but it only triggers aprof when the executable is being profiled.
The second mode is designed for JNI, it's called JNI mode, it's life-cycle-sensitive for Activity : active when onStart, stop and dump profiling when onStop; but here is one exception in JNI mode, it will trade as Non-JNI mode if the shared library are opened by the executable which is already turn on the aprof, So you can turn-on JNI mode aprof for shared library by adding the follow line to Android.mk:
LOCAL_ENABLE_APROF_JNI := true
In addition, regarding JNI-mode is you should make sure your application have the permission to write external storage. Here is the setting example in the AndroidManifest.xml.
AndroidManifest.xml:
<manifest xmlns:android="http://schemas.android.com/apk/res/android"
package="com.example.android.simplejni">
<application android:label="Simple JNI">
<activity android:name="SimpleJNI">
<intent-filter>
<action android:name="android.intent.action.MAIN" />
<category android:name="android.intent.category.LAUNCHER" />
</intent-filter>
</activity>
</application>
<uses-permission android:name="android.permission.WRITE_EXTERNAL_STORAGE" />
</manifest>
You can start profiling your program after recompiling executables with aprof and execute on the Android device, After the profiling has been accomplished, the result will be put in the /mnt/sdcard/ (according `EXTERNAL_STORAGE` environment variable), the default file name is executable name with .aprof suffix : $(progname).aprof And the next step is grabbing the data to the host, you can grab by adb
adb pull /mnt/sdcard/$(progname).aprof # For example, you are profiling `foo` adb pull /mnt/sdcard/foo.aprofNote: You can also set environment variables `APROF_OUTPUT` and `APROF_OUTPUT_FILENAME` to change the default output folder and file name
And then interpret the data by aprof, the usage is as follow:
# aprof $(prog_file) $(prof_file) aprof foo foo.aprof
And here is the example output:
% cumulative self self total time time time calls ms/call ms/call name 99.52 2170 2140 2178309 0 0 fib 0.00 2170 0 1 0 217 main 0.48 0 30 0 0 0 <libc.so>
Call graph (explanation follows)
-------------------------------------------------------------
Image : foo
Cumulative time : 2170 ms
Self time : 2140 ms
Function % time cumulative self Count Call by
fib 2170 2140
100.00 2170 0 1 main
100.00 2170 2140 2178308 fib
main 2170 0
100.00 2170 0 1 <libc.so>
Upper half part shows how many time spent in which function,
- cumulative time : the execution time with the child function.
- self time : the execution time for this function alone.
- calls : the number of times this function was invoked.
- self ms/call : the average number of milliseconds spent in this function per call.
- total ms/call :the average number of milliseconds spent in function and its descendants per call
And the lower part shows the detail for each function.
We can see a unusual symbol
# aprof $(prog_file) $(prof_file) -L$(lib_path)aprof foo foo.aprof -L out/target/product/panda/symbols/system/lib We will get more details of profiling data after loading symbol, but it still imprecise info in the output since the shared libraries building without aprof, so the part of `calls` and `cumulative time` may be incorrect; however the `Self time` can show after we load the symbol info.
% cumulative self self total time time time calls ms/call ms/call name 99.52 2170 2140 2178309 0 0 fib 0.00 2170 0 1 0 217 main 0.32 0 20 0 0 0 write 0.16 0 10 0 0 0 memcpy
Call graph (explanation follows)
-------------------------------------------------------------
Image : foo
Cumulative time : 2170 ms
Self time : 2140 ms
Function % time cumulative self Count Call by
fib 2170 2140
100.00 2170 0 1 main
100.00 2170 2140 2178308 fib
main 2170 0
100.00 2170 0 1 __libc_init
-------------------------------------------------------------
Image : foo
Cumulative time : 2170 ms
Self time : 30 ms
write 0 20
memcpy 0 10
And the last part is about visualization part of aprof, aprof supports the `dot` format by `-d` option, so we can use the `dot`(usually in graphviz package) program to output the call graph with timing info by the pipeline, you can reference the following command :
# aprof $(prog_file) $(prof_file) -L$(lib_path) aprof foo foo.aprof -L out/target/product/panda/symbols/system/lib -d | dot -Tpng -o foo.aprof.png
And here is an example output generated by md5sum of busybox.
Current State
Aprof still under review on gerrit, however you can checkout it from gerrit. Aprof support ICS, JB and Gingerbread, however if you are using Linaro, CyanogenMod (and it's derives) or Gingerbread, you may need also checkout the bellow patch-set:- bionic: add clean kernel header ucontext.h
- Profiling use aprof, enable by LOCAL_ENABLE_APROF or LOCAL_ENABLE_APROF_JNI
- Update build rule for executable with PRIVATE_ALL_WHOLE_STATIC_LIBRARIES
Feel free to report any problem
