1 /* 2 * Copyright (C) 2015 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 package org.chromium.latency.walt; 18 19 import android.content.BroadcastReceiver; 20 import android.content.Context; 21 import android.content.Intent; 22 import android.os.Bundle; 23 import android.support.v4.app.Fragment; 24 import android.text.method.ScrollingMovementMethod; 25 import android.view.LayoutInflater; 26 import android.view.MotionEvent; 27 import android.view.View; 28 import android.view.ViewGroup; 29 import android.widget.ImageButton; 30 import android.widget.TextView; 31 32 import java.io.IOException; 33 import java.util.ArrayList; 34 import java.util.Locale; 35 36 import static org.chromium.latency.walt.Utils.getBooleanPreference; 37 38 public class TapLatencyFragment extends Fragment 39 implements View.OnClickListener, RobotAutomationListener { 40 41 private static final int ACTION_DOWN_INDEX = 0; 42 private static final int ACTION_UP_INDEX = 1; 43 private SimpleLogger logger; 44 private TraceLogger traceLogger; 45 private WaltDevice waltDevice; 46 private TextView logTextView; 47 private TextView tapCatcherView; 48 private TextView tapCountsView; 49 private TextView moveCountsView; 50 private ImageButton finishButton; 51 private ImageButton restartButton; 52 private HistogramChart latencyChart; 53 private int moveCount = 0; 54 private int allDownCount = 0; 55 private int allUpCount = 0; 56 private int okDownCount = 0; 57 private int okUpCount = 0; 58 private boolean shouldShowLatencyChart = false; 59 60 ArrayList<UsMotionEvent> eventList = new ArrayList<>(); 61 ArrayList<Double> p2kDown = new ArrayList<>(); 62 ArrayList<Double> p2kUp = new ArrayList<>(); 63 ArrayList<Double> k2cDown = new ArrayList<>(); 64 ArrayList<Double> k2cUp = new ArrayList<>(); 65 66 private BroadcastReceiver logReceiver = new BroadcastReceiver() { 67 @Override 68 public void onReceive(Context context, Intent intent) { 69 String msg = intent.getStringExtra("message"); 70 TapLatencyFragment.this.appendLogText(msg); 71 } 72 }; 73 74 private View.OnTouchListener touchListener = new View.OnTouchListener() { 75 @Override 76 public boolean onTouch(View v, MotionEvent event) { 77 UsMotionEvent tapEvent = new UsMotionEvent(event, waltDevice.clock.baseTime); 78 79 if(tapEvent.action != MotionEvent.ACTION_UP && tapEvent.action != MotionEvent.ACTION_DOWN) { 80 moveCount++; 81 updateCountsDisplay(); 82 return true; 83 } 84 85 // Debug: logger.log("\n"+ action + " event received: " + tapEvent.toStringLong()); 86 tapEvent.physicalTime = waltDevice.readLastShockTime(); 87 88 tapEvent.isOk = checkTapSanity(tapEvent); 89 // Save it in any case so we can do stats on bad events later 90 eventList.add(tapEvent); 91 92 final double physicalToKernelTime = (tapEvent.kernelTime - tapEvent.physicalTime) / 1000.; 93 final double kernelToCallbackTime = (tapEvent.createTime - tapEvent.kernelTime) / 1000.; 94 if (tapEvent.action == MotionEvent.ACTION_DOWN) { 95 allDownCount++; 96 if (tapEvent.isOk) { 97 okDownCount++; 98 p2kDown.add(physicalToKernelTime); 99 k2cDown.add(kernelToCallbackTime); 100 if (shouldShowLatencyChart) latencyChart.addEntry(ACTION_DOWN_INDEX, physicalToKernelTime); 101 logger.log(String.format(Locale.US, 102 "ACTION_DOWN:\ntouch2kernel: %.1f ms\nkernel2java: %.1f ms", 103 physicalToKernelTime, kernelToCallbackTime)); 104 } 105 } else if (tapEvent.action == MotionEvent.ACTION_UP) { 106 allUpCount++; 107 if (tapEvent.isOk) { 108 okUpCount++; 109 p2kUp.add(physicalToKernelTime); 110 k2cUp.add(kernelToCallbackTime); 111 if (shouldShowLatencyChart) latencyChart.addEntry(ACTION_UP_INDEX, physicalToKernelTime); 112 logger.log(String.format(Locale.US, 113 "ACTION_UP:\ntouch2kernel: %.1f ms\nkernel2java: %.1f ms", 114 physicalToKernelTime, kernelToCallbackTime)); 115 } 116 } 117 traceLogEvent(tapEvent); 118 119 updateCountsDisplay(); 120 return true; 121 } 122 }; 123 traceLogEvent(UsMotionEvent tapEvent)124 private void traceLogEvent(UsMotionEvent tapEvent) { 125 if (!tapEvent.isOk) return; 126 if (traceLogger == null) return; 127 if (tapEvent.action != MotionEvent.ACTION_DOWN && tapEvent.action != MotionEvent.ACTION_UP) return; 128 final String title = tapEvent.action == MotionEvent.ACTION_UP ? "Tap-Up" : "Tap-Down"; 129 traceLogger.log(tapEvent.physicalTime + waltDevice.clock.baseTime, 130 tapEvent.kernelTime + waltDevice.clock.baseTime, title + " Physical", 131 "Bar starts at accelerometer shock and ends at kernel time of tap event"); 132 traceLogger.log(tapEvent.kernelTime + waltDevice.clock.baseTime, 133 tapEvent.createTime + waltDevice.clock.baseTime, title + " App Callback", 134 "Bar starts at kernel time of tap event and ends at app callback time"); 135 } 136 TapLatencyFragment()137 public TapLatencyFragment() { 138 // Required empty public constructor 139 } 140 141 @Override onCreateView(LayoutInflater inflater, ViewGroup container, Bundle savedInstanceState)142 public View onCreateView(LayoutInflater inflater, ViewGroup container, 143 Bundle savedInstanceState) { 144 shouldShowLatencyChart = getBooleanPreference(getContext(), R.string.preference_show_tap_histogram, true); 145 if (getBooleanPreference(getContext(), R.string.preference_systrace, true)) { 146 traceLogger = TraceLogger.getInstance(); 147 } 148 waltDevice = WaltDevice.getInstance(getContext()); 149 logger = SimpleLogger.getInstance(getContext()); 150 // Inflate the layout for this fragment 151 final View view = inflater.inflate(R.layout.fragment_tap_latency, container, false); 152 restartButton = (ImageButton) view.findViewById(R.id.button_restart_tap); 153 finishButton = (ImageButton) view.findViewById(R.id.button_finish_tap); 154 tapCatcherView = (TextView) view.findViewById(R.id.tap_catcher); 155 logTextView = (TextView) view.findViewById(R.id.txt_log_tap_latency); 156 tapCountsView = (TextView) view.findViewById(R.id.txt_tap_counts); 157 moveCountsView = (TextView) view.findViewById(R.id.txt_move_count); 158 latencyChart = (HistogramChart) view.findViewById(R.id.latency_chart); 159 logTextView.setMovementMethod(new ScrollingMovementMethod()); 160 finishButton.setEnabled(false); 161 return view; 162 } 163 164 @Override onResume()165 public void onResume() { 166 super.onResume(); 167 168 logTextView.setText(logger.getLogText()); 169 logger.registerReceiver(logReceiver); 170 171 // Register this fragment class as the listener for some button clicks 172 restartButton.setOnClickListener(this); 173 finishButton.setOnClickListener(this); 174 } 175 176 @Override onPause()177 public void onPause() { 178 logger.unregisterReceiver(logReceiver); 179 super.onPause(); 180 } 181 appendLogText(String msg)182 public void appendLogText(String msg) { 183 logTextView.append(msg + "\n"); 184 } 185 checkTapSanity(UsMotionEvent e)186 public boolean checkTapSanity(UsMotionEvent e) { 187 String action = e.getActionString(); 188 double dt = (e.kernelTime - e.physicalTime) / 1000.0; 189 190 if (e.physicalTime == 0) { 191 logger.log(action + " no shock found"); 192 return false; 193 } 194 195 if (dt < 0 || dt > 200) { 196 logger.log(action + " bogus kernelTime=" + e.kernelTime + ", ignored, dt=" + dt); 197 return false; 198 } 199 return true; 200 } 201 updateCountsDisplay()202 void updateCountsDisplay() { 203 String tpl = "N ↓%d (%d) ↑%d (%d)"; 204 tapCountsView.setText(String.format(Locale.US, 205 tpl, 206 okDownCount, 207 allDownCount, 208 okUpCount, 209 allUpCount 210 )); 211 212 moveCountsView.setText(String.format(Locale.US, "⇄ %d", moveCount)); 213 } 214 restartMeasurement()215 void restartMeasurement() { 216 logger.log("\n## Restarting tap latency measurement. Re-sync clocks ..."); 217 try { 218 waltDevice.softReset(); 219 waltDevice.syncClock(); 220 } catch (IOException e) { 221 logger.log("Error syncing clocks: " + e.getMessage()); 222 restartButton.setImageResource(R.drawable.ic_play_arrow_black_24dp); 223 finishButton.setEnabled(false); 224 latencyChart.setVisibility(View.GONE); 225 return; 226 } 227 228 eventList.clear(); 229 p2kDown.clear(); 230 p2kUp.clear(); 231 k2cDown.clear(); 232 k2cUp.clear(); 233 234 moveCount = 0; 235 allDownCount = 0; 236 allUpCount = 0; 237 okDownCount = 0; 238 okUpCount = 0; 239 240 updateCountsDisplay(); 241 tapCatcherView.setOnTouchListener(touchListener); 242 } 243 finishAndShowStats()244 void finishAndShowStats() { 245 tapCatcherView.setOnTouchListener(null); 246 waltDevice.checkDrift(); 247 logger.log("\n-------------------------------"); 248 logger.log(String.format(Locale.US, 249 "Tap latency results:\n" + 250 "Number of events recorded:\n" + 251 " ACTION_DOWN %d (bad %d)\n" + 252 " ACTION_UP %d (bad %d)\n" + 253 " ACTION_MOVE %d", 254 okDownCount, 255 allDownCount - okDownCount, 256 okUpCount, 257 allUpCount - okUpCount, 258 moveCount 259 )); 260 261 logger.log("ACTION_DOWN median times:"); 262 logger.log(String.format(Locale.US, 263 " Touch to kernel: %.1f ms\n Kernel to Java: %.1f ms", 264 Utils.median(p2kDown), 265 Utils.median(k2cDown) 266 )); 267 logger.log("ACTION_UP median times:"); 268 logger.log(String.format(Locale.US, 269 " Touch to kernel: %.1f ms\n Kernel to Java: %.1f ms", 270 Utils.median(p2kUp), 271 Utils.median(k2cUp) 272 )); 273 logger.log("-------------------------------"); 274 if (traceLogger != null) traceLogger.flush(getContext()); 275 276 if (shouldShowLatencyChart) { 277 latencyChart.setLabel(ACTION_DOWN_INDEX, String.format(Locale.US, "ACTION_DOWN median=%.1f ms", Utils.median(p2kDown))); 278 latencyChart.setLabel(ACTION_UP_INDEX, String.format(Locale.US, "ACTION_UP median=%.1f ms", Utils.median(p2kUp))); 279 } 280 LogUploader.uploadIfAutoEnabled(getContext()); 281 } 282 283 @Override onClick(View v)284 public void onClick(View v) { 285 if (v.getId() == R.id.button_restart_tap) { 286 restartButton.setImageResource(R.drawable.ic_refresh_black_24dp); 287 finishButton.setEnabled(true); 288 if (shouldShowLatencyChart) { 289 latencyChart.setVisibility(View.VISIBLE); 290 latencyChart.clearData(); 291 latencyChart.setLabel(ACTION_DOWN_INDEX, "ACTION_DOWN"); 292 latencyChart.setLabel(ACTION_UP_INDEX, "ACTION_UP"); 293 } 294 restartMeasurement(); 295 return; 296 } 297 298 if (v.getId() == R.id.button_finish_tap) { 299 finishButton.setEnabled(false); 300 finishAndShowStats(); 301 restartButton.setImageResource(R.drawable.ic_play_arrow_black_24dp); 302 return; 303 } 304 305 } 306 onRobotAutomationEvent(String event)307 public void onRobotAutomationEvent(String event) { 308 // Never show the latency chart during automated runs. 309 shouldShowLatencyChart = false; 310 if (event.equals(RobotAutomationListener.RESTART_EVENT) || 311 event.equals(RobotAutomationListener.START_EVENT)) { 312 restartMeasurement(); 313 } else if (event.equals(RobotAutomationListener.FINISH_EVENT)) { 314 finishAndShowStats(); 315 } 316 } 317 } 318