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