ProviderPerfActivity.java revision bb4addaaf281db7cc7e666536b694e323e7bf19c
1/*
2 * Copyright (C) 2010 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 *      http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17
18// TODO: find AIDL for ContentResolver.  add queryExtensible() returning struct{Cursor?,String? singleRow}
19//    -- would have to lazily do real requery(), registerContentObserver(), etc
20
21package com.android.rpc_performance;
22
23import android.app.Activity;
24import android.content.ComponentName;
25import android.content.ContentQueryMap;
26import android.content.ContentResolver;
27import android.content.ContentValues;
28import android.content.IContentProvider;
29import android.content.Context;
30import android.content.Intent;
31import android.content.ServiceConnection;
32import android.content.pm.PackageManager;
33import android.content.pm.ResolveInfo;
34import android.content.res.Configuration;
35import android.content.res.Resources;
36import android.database.Cursor;
37import android.database.SQLException;
38import android.net.LocalSocket;
39import android.net.LocalSocketAddress;
40import android.net.Uri;
41import android.os.Bundle;
42import android.os.Handler;
43import android.os.IBinder;
44import android.os.RemoteException;
45import android.os.SystemClock;
46import android.telephony.TelephonyManager;
47import android.text.TextUtils;
48import android.util.AndroidException;
49import android.util.Config;
50import android.util.Log;
51import android.view.View;
52import android.widget.Button;
53import android.widget.TextView;
54
55import java.io.File;
56import java.io.FileInputStream;
57import java.io.IOException;
58import java.io.InputStream;
59import java.io.OutputStream;
60
61public class ProviderPerfActivity extends Activity {
62
63    private static final String TAG = "ProviderPerfActivity";
64    private static final Uri SYSTEM_SETTINGS_URI = Uri.parse("content://settings/system");
65
66    // No-op provider URLs:
67    private static final Uri CROSS_PROC_PROVIDER_URI = Uri.parse("content://com.android.rpc_performance/");
68    private static final Uri IN_PROC_PROVIDER_URI = Uri.parse("content://com.android.rpc_performance.local/");
69
70    private final Handler mHandler = new Handler();
71    private final static int LOOP_TIME_MILLIS = 2000;
72    private final static long LOOP_TIME_NANOS = (long) LOOP_TIME_MILLIS * 1000000L;
73
74    private IService mServiceStub = null;
75    private ServiceConnection serviceConnection = new ServiceConnection() {
76        public void onServiceConnected(ComponentName name, IBinder service) {
77            mServiceStub = IService.Stub.asInterface(service);
78            Log.v(TAG, "Service bound");
79        }
80
81        public void onServiceDisconnected(ComponentName name) {
82            mServiceStub = null;
83            Log.v(TAG, "Service unbound");
84        };
85    };
86
87
88    ContentResolver cr;
89
90    /** Called when the activity is first created. */
91    @Override
92    public void onCreate(Bundle savedInstanceState) {
93        super.onCreate(savedInstanceState);
94        setContentView(R.layout.main);
95
96        cr = getContentResolver();
97
98        setButtonAction(R.id.lookup_button, new Runnable() {
99                public void run() {
100                    final float avgTime = settingsProviderLoop(100, MODE_READ, 0);
101                    endAsyncOp(R.id.lookup_button, R.id.lookup_text, avgTime);
102                }});
103
104        setButtonAction(R.id.bg_read_button, new Runnable() {
105                public void run() {
106                    final float avgTime =
107                        settingsProviderLoop(50, MODE_READ, 100);
108                    endAsyncOp(R.id.bg_read_button, R.id.bg_read_text, avgTime);
109                }});
110
111        setButtonAction(R.id.bg_write_button, new Runnable() {
112                public void run() {
113                    final float avgTime =
114                        settingsProviderLoop(20, MODE_WRITE, 0);
115                    endAsyncOp(R.id.bg_write_button, R.id.bg_write_text, avgTime);
116                }});
117
118        setButtonAction(R.id.bg_writedup_button, new Runnable() {
119                public void run() {
120                    final float avgTime =
121                        settingsProviderLoop(20, MODE_WRITE_DUP, 0);
122                    endAsyncOp(R.id.bg_writedup_button, R.id.bg_writedup_text, avgTime);
123                }});
124
125        setButtonAction(R.id.dummy_lookup_button, new Runnable() {
126                public void run() {
127                    final float avgTime = noOpProviderLoop(CROSS_PROC_PROVIDER_URI);
128                    endAsyncOp(R.id.dummy_lookup_button, R.id.dummy_lookup_text, avgTime);
129                }});
130
131        setButtonAction(R.id.dummy_local_lookup_button, new Runnable() {
132                public void run() {
133                    final float avgTime = noOpProviderLoop(IN_PROC_PROVIDER_URI);
134                    endAsyncOp(R.id.dummy_local_lookup_button,
135                               R.id.dummy_local_lookup_text, avgTime);
136                }});
137
138        setButtonAction(R.id.localsocket_button, new Runnable() {
139                public void run() {
140                    final float avgTime = localSocketLoop();
141                    endAsyncOp(R.id.localsocket_button, R.id.localsocket_text, avgTime);
142                }});
143
144        setButtonAction(R.id.service_button, new Runnable() {
145                public void run() {
146                    final float avgTime = serviceLoop(0);
147                    endAsyncOp(R.id.service_button, R.id.service_text, avgTime);
148                }});
149
150        setButtonAction(R.id.service2_button, new Runnable() {
151                public void run() {
152                    final float avgTime = serviceLoop(1);
153                    endAsyncOp(R.id.service2_button, R.id.service2_text, avgTime);
154                }});
155
156        setButtonAction(R.id.proc_button, new Runnable() {
157                public void run() {
158                    final float avgTime = procLoop();
159                    endAsyncOp(R.id.proc_button, R.id.proc_text, avgTime);
160                }});
161
162        setButtonAction(R.id.call_button, new Runnable() {
163                public void run() {
164                    final float avgTime = callLoop("ringtone");
165                    endAsyncOp(R.id.call_button, R.id.call_text, avgTime);
166                }});
167
168        setButtonAction(R.id.call2_button, new Runnable() {
169                public void run() {
170                    final float avgTime = callLoop("XXXXXXXX");  // non-existent
171                    endAsyncOp(R.id.call2_button, R.id.call2_text, avgTime);
172                }});
173    }
174
175    @Override public void onResume() {
176        super.onResume();
177
178        bindService(new Intent(this, MiscService.class),
179                    serviceConnection, Context.BIND_AUTO_CREATE);
180    }
181
182    @Override public void onPause() {
183        super.onPause();
184        if (serviceConnection != null) {
185            unbindService(serviceConnection);
186        }
187    }
188
189    private void setButtonAction(int button_id, final Runnable r) {
190        final Button button = (Button) findViewById(button_id);
191        if (button == null) {
192            Log.w(TAG, "Bogus button ID: " + button_id);
193            return;
194        }
195        button.setOnClickListener(new View.OnClickListener() {
196                public void onClick(View v) {
197                    button.setEnabled(false);
198                    new Thread(r).start();
199                }
200            });
201    }
202
203    private void endAsyncOp(final int button_id, final int text_id, final float avgTime) {
204        mHandler.post(new Runnable() {
205                public void run() {
206                    Button button = (Button) findViewById(button_id);
207                    button.setEnabled(true);
208                    setTextTime(text_id, avgTime);
209                }});
210    }
211
212    private void setTextTime(int id, float avgTime) {
213        TextView tv = (TextView) findViewById(id);
214        if (tv == null) return;
215        String text = tv.getText().toString();
216        text = text.substring(0, text.indexOf(':') + 1) + "\n" + avgTime + " ms avg";
217        tv.setText(text);
218    }
219
220    // Returns average cross-process dummy query time in milliseconds.
221    private float noOpProviderLoop(Uri uri) {
222        long sumNanos = 0;
223        int failures = 0;
224        int total = 0;
225        long startTime = System.nanoTime();
226        long endTime = startTime + LOOP_TIME_NANOS;
227        while (System.nanoTime() < endTime) {
228            long duration = doNoOpLookup(uri);
229            if (duration < 0) {
230                failures++;
231            } else {
232                total++;
233                sumNanos += duration;
234            }
235        }
236        float averageMillis = (float) sumNanos /
237            (float) (total != 0 ? total : 1) /
238            1000000.0f;
239        Log.v(TAG, "dummy loop: fails=" + failures + "; total=" + total + "; goodavg ms=" + averageMillis);
240        return averageMillis;
241    }
242
243    // Returns average cross-process dummy query time in milliseconds.
244    private float callLoop(String key) {
245        IContentProvider cp = cr.acquireProvider(SYSTEM_SETTINGS_URI.getAuthority());
246
247        long sumNanos = 0;
248        int total = 0;
249
250        long lastTime = System.nanoTime();
251        long endTime = lastTime + LOOP_TIME_NANOS;
252        try {
253            while (lastTime < endTime) {
254                Bundle b = cp.call("GET_system", key, null);
255                long nowTime = System.nanoTime();
256                total++;
257                sumNanos += (nowTime - lastTime);
258                lastTime = nowTime;
259            }
260        } catch (RemoteException e) {
261            return -999.0f;
262        }
263        float averageMillis = (float) sumNanos /
264            (float) (total != 0 ? total : 1) /
265            1000000.0f;
266        Log.v(TAG, "call loop: avg_ms=" + averageMillis + "; calls=" + total);
267        return averageMillis;
268    }
269
270    // Returns average cross-process dummy query time in milliseconds.
271    private float procLoop() {
272        long sumNanos = 0;
273        int total = 0;
274        long lastTime = System.nanoTime();
275        long endTime = lastTime + LOOP_TIME_NANOS;
276        File f = new File("/proc/self/cmdline");
277        byte[] buf = new byte[100];
278        String value = null;
279        try {
280            while (lastTime < endTime) {
281                FileInputStream is = new FileInputStream(f);
282                int readBytes = is.read(buf, 0, 100);
283                is.close();
284                //value = new String(buf, 0, readBytes);
285                long nowTime = System.nanoTime();
286                total++;
287                sumNanos += (nowTime - lastTime);
288                lastTime = nowTime;
289            }
290        } catch (IOException e) {
291            return -999.0f;
292        }
293        float averageMillis = (float) sumNanos /
294            (float) (total != 0 ? total : 1) /
295            1000000.0f;
296        Log.v(TAG, "proc loop: total: " + total + "; avg_ms=" + averageMillis + "; value=" + value);
297        return averageMillis;
298    }
299
300    private static final String[] IGNORED_COLUMN = {"ignored"};
301
302    // Returns nanoseconds.
303    private long doNoOpLookup(Uri uri) {
304        Cursor c = null;
305        try {
306            long startTime = System.nanoTime();
307            c = cr.query(uri,
308                         IGNORED_COLUMN,  //new String[]{"ignored"},  // but allocate it for apples-to-apples
309                         "name=?",
310                         IGNORED_COLUMN,  // new String[]{"also_ignored"},  // also for equality in benchmarking
311                         null /* sort order */);
312            if (c == null) {
313                Log.w(TAG, "cursor null");
314                return -1;
315            }
316            String value = c.moveToNext() ? c.getString(0) : null;
317            long duration = System.nanoTime() - startTime;
318            //Log.v(TAG, "got value: " + value + " in " + duration);
319            return duration;
320        } catch (SQLException e) {
321            Log.w(TAG, "sqlite exception: " + e);
322            return -1;
323        } finally {
324            if (c != null) c.close();
325        }
326    }
327
328    // Returns average cross-process dummy query time in milliseconds.
329    private float serviceLoop(int amtEncoding) {
330        if (mServiceStub == null) {
331            Log.v(TAG, "No service stub.");
332            return -999;
333        }
334        String dummy = null;
335        try {
336            long sumNanos = 0;
337            int count = 0;
338            long lastTime = System.nanoTime();
339            long endTime = lastTime + LOOP_TIME_NANOS;
340            while (lastTime < endTime) {
341                if (amtEncoding == 0) {
342                    mServiceStub.pingVoid();
343                } else {
344                    dummy = mServiceStub.pingString(dummy);
345                }
346                long curTime = System.nanoTime();
347                long duration = curTime - lastTime;
348                lastTime = curTime;
349                count++;
350                sumNanos += duration;
351            }
352            float averageMillis = (float) sumNanos / (float) (count != 0 ? count : 1) / 1000000.0f;
353            Log.v(TAG, "service loop: total: " + count + "; avg_ms=" + averageMillis);
354            return averageMillis;
355        } catch (RemoteException e) {
356            Log.e(TAG, "error in service loop: " + e);
357            return -999.0f;
358        }
359    }
360
361    // Returns average milliseconds.
362    private float localSocketLoop() {
363        LocalSocket socket = null;
364        try {
365            socket = new LocalSocket();
366            Log.v(TAG, "Connecting to socket...");
367            socket.connect(new LocalSocketAddress(MiscService.SOCKET_NAME));
368            Log.v(TAG, "Connected to socket.");
369            InputStream is = socket.getInputStream();
370            OutputStream os = socket.getOutputStream();
371
372            long nowTime = System.nanoTime();
373            long endTime = nowTime + LOOP_TIME_NANOS;
374            int count = 0;
375            long sumNanos = 0;
376            while (nowTime < endTime) {
377                int expectByte = count & 0xff;
378                os.write(expectByte);
379                int gotBackByte = is.read();
380
381                long afterTime = System.nanoTime();
382                sumNanos += (afterTime - nowTime);
383                nowTime = afterTime;
384
385                if (gotBackByte != expectByte) {
386                    Log.w(TAG, "Got wrong byte back.  Got: " + gotBackByte
387                          + "; wanted=" + expectByte);
388                    return -999.00f;
389                }
390                count++;
391            }
392            return count == 0 ? 0.0f : ((float) sumNanos / (float) count / 1000000.0f);
393        } catch (IOException e) {
394            Log.v(TAG, "error in localSocketLoop: " + e);
395            return -1.0f;
396        } finally {
397            if (socket != null) {
398                try { socket.close(); } catch (IOException e) {}
399            }
400        }
401    }
402
403    // Returns average milliseconds.
404    private static final int MODE_READ = 0;
405    private static final int MODE_WRITE = 1;
406    private static final int MODE_WRITE_DUP = 2;
407
408    private float settingsProviderLoop(int iters, int mode, long innerSleep) {
409        long sumMillis = 0;
410        int total = 0;
411        long startTime = System.nanoTime();
412        long endTime = startTime + LOOP_TIME_NANOS;
413        while (System.nanoTime() < endTime) {
414            long duration = mode == MODE_READ ? doRead(innerSleep) : doWrite(mode);
415            if (duration < 0) {
416                return -999.0f;
417            }
418            total++;
419            sumMillis += duration;
420        }
421        float averageMillis = ((float) sumMillis / (float) (total != 0 ? total : 1));
422        Log.v(TAG, "settings provider; mode=" + mode + "; total=" + total +
423              "; goodavg_ms=" + averageMillis);
424        return averageMillis;
425    }
426
427    // Returns milliseconds taken, or -1 on failure.
428    private long doRead(long innerSleep) {
429        Cursor c = null;
430        try {
431            long startTime = SystemClock.uptimeMillis();
432            c = cr.query(SYSTEM_SETTINGS_URI,
433                         new String[]{"value"},
434                         "name=?",
435                         new String[]{"airplane_mode_on"},
436                         null /* sort order */);
437            if (c == null) {
438                Log.w(TAG, "cursor null");
439                return -1;
440            }
441            String value = c.moveToNext() ? c.getString(0) : null;
442            long duration = SystemClock.uptimeMillis() - startTime;
443            if (innerSleep > 0) {
444                try {
445                    Thread.sleep(innerSleep);
446                } catch (InterruptedException e) {}
447            }
448            return duration;
449        } catch (SQLException e) {
450            Log.w(TAG, "sqlite exception: " + e);
451            return -1;
452        } finally {
453            if (c != null) c.close();
454        }
455    }
456
457    // Returns milliseconds taken, or -1 on failure.
458    private long doWrite(int mode) {
459        Cursor c = null;
460        long startTime = SystemClock.uptimeMillis();
461        // The database will take care of replacing duplicates.
462        try {
463            ContentValues values = new ContentValues();
464            values.put("name", "dummy_for_testing");
465            values.put("value", (mode == MODE_WRITE ? (""+startTime) : "foo"));
466            Uri uri = cr.insert(SYSTEM_SETTINGS_URI, values);
467            Log.v(TAG, "inserted uri: " + uri);
468        } catch (SQLException e) {
469            Log.w(TAG, "sqliteexception during write: " + e);
470            return -1;
471        }
472        long duration = SystemClock.uptimeMillis() - startTime;
473        return duration;
474    }
475}
476