2

I'm profiling a function within an app which is executed every 5 seconds. However, I only see half of the calls in the "Calls + Rec/Total" option in the trace view. I am using samplebased profiling with 1 microsecond as a sampling interval. I tried to play with this sampling rate but no visible improvements. For example, when I run the view for 236 seconds, I should get 47 calls in the "Call + Rec/Total" option, however, it shows only 20 as shown in the picture below. Can anyone comment what I am doing wrong ? 

Tested devices: 
Device 1: SmartWatch LG R (Android 6.0.1), observes this problem
Device 2: Samsung Galaxy S2 (Android 5.0.1 Custom ROM), observes this problem
Device 3: Samsung Galaxy S2 (Android 4.4, Custom ROM), works fine

enter image description here

UPDATE: I installed Android 4.4.4 on the second Samsung (originally with Android 5.1.1) based on my discussion with @kws and now the sampling-based method is working fine with it. However, the smartwatch with Android 6.0.1 is still behaving the old way with trace view.

Update 2: I think the sampling based method doesn't have the resolution to capture very lightweight functions because it could be that these functions are executed between two samples and it will be missed by this the profiler. Though it records data with microseconds as an sampling interval, I doubt that it can reach to such detailed granularity. The reasoning behind this argument is that when I tested a very lightweight function with it, and not every call was caught on all three devices.

utengr
  • 3,225
  • 3
  • 29
  • 68
  • Did you log each method call? What was the number of actual method calls? – kws Oct 28 '16 at 15:24
  • I expect the profiler to log each method call. The actual number of method calls in this case was 47. I repeated the experiment many times but same result which I have no idea why. My sampling interval is very low such that 1 microsecond so it should capture all method calls. Moreover, it behaves differently on different devices with different android versions. – utengr Oct 28 '16 at 15:40
  • Not sure if rooted status has any role to play in here. – utengr Oct 28 '16 at 19:29
  • Your Kitkat runs on dalvik? – kws Oct 28 '16 at 19:32
  • @kws the kitkat runs on Dalvik and the Samsung Galaxy (5.0.1) on ART. I assume the watch also runs on ART. Apparently the sampling based method trace should work fine with ART but it doesnt. I am not sure what I am doing wrong. – utengr Oct 28 '16 at 20:16
  • Could you go to the developer options of your Kitkat device, change the runtime to ART and profile your code again? – kws Oct 28 '16 at 20:35
  • @kws I tried but it doesn't allow me to change it to Art. As soon as I does it, it restarts and changes back to Dalvik. While changing I also get a warning the Custom rom I have doesn't support ART. Btw I have CynaongenMod Custom ROM for Android 4.4.4. – utengr Oct 28 '16 at 20:48
  • My Android 5.1.1 on the other phone is also from CynanogenMod Custom ROM. So I can understand if it doesn't work on it. However, the sampling method should work on the watch which isn't a custom rom. One problem I can think of is that the watch is connected to the phone with Android 5.1.1. Either I can replace this with 4.4.4 and see how it goes. – utengr Oct 28 '16 at 20:52
  • @kws I installed a custom rom (kitkat ) on second samsung phone and its working fine now. However, the smartwatch is't working fine with traceview. – utengr Oct 29 '16 at 00:40

1 Answers1

1

I did some tests and I noticed same behavior here (run on Kitkat and Marshmallow). It seems that if you use sample based profiling and set the sampling rate too low you get inaccurate results. If you increase the sampling rate it is likely to get more accurate results. On the other hand if you use trace based profiling the results are accurate.

I think those sample based profiling results are acceptable since profiler is supposed to return sample results and not the actual ones. As for the case of the 1 μs sampling interval, I think that its successful execution depends on the device also. Maybe a high-end device could produce better results.

Also an important point to be aware of is that according to docs, profiling should not used to generate absolute timings but rather is for checking the results of your code optimization.

Interpreted code runs more slowly when profiling is enabled. Don't try to generate absolute timings from the profiler results (such as, "function X takes 2.5 seconds to run"). The times are only useful in relation to other profile output, so you can see if changes have made the code faster or slower relative to a previous profiling run.

EDIT

If you want more precise results then you have either to go for trace based profiling or you have to use the more accurate Debug class. Using the latter you will be able to specify exactly where to start and stop logging trace data in your code. More info here.

kws
  • 926
  • 7
  • 11
  • you are right that these values are just an indication. I think, I will go with the trace-based method because atleast its more consistent across various devices in its results whereas the sampling-based method is a bit inconsistent. Lets see if someone else comes up with another explanation. – utengr Oct 29 '16 at 13:40
  • You are also right that its accuracy increases with increasing the sampling rate from 1 microsecond to 1000 microseconds. However, it starts going down if I increase it more than 1000 microseconds. Seems like its the optimal value. I'm just afraid, it won't catch functions with execution time less than the sampling interval. – utengr Oct 29 '16 at 13:45
  • thanks for that. It was on initially an option, however, I didn't go for it because my function is triggered by a timer every few milliseconds which means that I have to start and stop the trace every time its executed, leading to lots of trace files. If I don't stop it right after the function closes, then it will be the same as the trace based method. – utengr Oct 29 '16 at 14:13