Android - Problems with logging the start up latency

Question

I am trying to log the start up latency of my app. They way I am doing it is setting the start time of the app on Application.onCreate and provide a public method that returns the time.

MyApplication extends Application {
    Date startUpTime;
    //Declare variables
    @Override
    public void onCreate() {
        super.onCreate();
        setStartupTime();
        //other initializations
    }

    private void setStartUpTime() {
        startUpTime = new Date();
    }

    public Date getStartUpTime() {
        return startUpTime;
    }
}

MyActivity extends Activity {
.
.
.
    @Override
    public void onStart(){
        logStartUpLatency();
        //other onStart stuff
    }

    private void logStartUpLatency() {
        Date currentTime = new Date();
        Date startTime = (MyApplication)getApplicationContext().getStartUpTime();
        long latency = currentTime.getTime() - startTIme.getTime();
        Log.d("Start up Latency is ", Long.toString(latency)):

    }

This is how I am testing my start up latency:

• adb install myapk
• run the app to get the first start up latency. I can see the latency logged is correct for the first start
• run the app again to test the start latency. The latency logged is correct for the start(or any number of subsequent starts)
• Now I increase my app's version code and name by 1. To simulate an upgrade, I used the command adb install -r myapk.
• Now I run the app again to test the first start latency after upgrade, even though it takes 3 seconds, the latency logged is off the charts.

Does any one know why that might happen?

Update

So if I install the apk using "adb install -r myapk", the app isn't going through the Myapplication.onCreate().

Answer 1

I suggest the use of the TimingLogger class. As per the documentation, you can easily track the elapsed time and even add splits in the process.

This

TimingLogger timings = new TimingLogger(TAG, "methodA");
// ... do some work A ...
timings.addSplit("work A");
// ... do some work B ...
timings.addSplit("work B");
// ... do some work C ...
timings.addSplit("work C");
timings.dumpToLog();

produces

D/TAG (3459): methodA: begin
D/TAG (3459): methodA:      9 ms, work A
D/TAG (3459): methodA:      1 ms, work B
D/TAG (3459): methodA:      6 ms, work C
D/TAG (3459): methodA: end, 16 ms