Home | History | Annotate | Download | only in walt 
      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 
    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 
    137     public TapLatencyFragment() {
    138         // Required empty public constructor
    139     }
    140 
    141     @Override
    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
    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
    177     public void onPause() {
    178         logger.unregisterReceiver(logReceiver);
    179         super.onPause();
    180     }
    181 
    182     public void appendLogText(String msg) {
    183         logTextView.append(msg + "\n");
    184     }
    185 
    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 
    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 
    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 
    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
    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 
    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