Update CPU Monitor to report CPU frequency and battery level.

R=wzh@webrtc.org

Review URL: https://codereview.webrtc.org/1813053007 .

Cr-Commit-Position: refs/heads/master@{#12081}

webrtc/examples/androidapp/src/org/appspot/apprtc/CallActivity.java

@@ -134,8 +134,10 @@ public class CallActivity extends Activity
   private long callStartedTimeMs = 0;
 
   // Controls
-  CallFragment callFragment;
-  HudFragment hudFragment;
+  private CallFragment callFragment;
+  private HudFragment hudFragment;
+  private CpuMonitor cpuMonitor;
+
 
   @Override
   public void onCreate(Bundle savedInstanceState) {
@@ -242,6 +244,10 @@ public class CallActivity extends Activity
     roomConnectionParameters = new RoomConnectionParameters(
         roomUri.toString(), roomId, loopback);
 
+    // Create CPU monitor
+    cpuMonitor = new CpuMonitor(this);
+    hudFragment.setCpuMonitor(cpuMonitor);
+
     // Send intent arguments to fragments.
     callFragment.setArguments(intent.getExtras());
     hudFragment.setArguments(intent.getExtras());
@@ -280,6 +286,7 @@ public class CallActivity extends Activity
     if (peerConnectionClient != null) {
       peerConnectionClient.stopVideoSource();
     }
+    cpuMonitor.pause();
   }
 
   @Override
@@ -289,6 +296,7 @@ public class CallActivity extends Activity
     if (peerConnectionClient != null) {
       peerConnectionClient.startVideoSource();
     }
+    cpuMonitor.resume();
   }
 
   @Override
@@ -299,6 +307,7 @@ public class CallActivity extends Activity
     }
     activityRunning = false;
     rootEglBase.release();
+    cpuMonitor.release();
     super.onDestroy();
   }
 

webrtc/examples/androidapp/src/org/appspot/apprtc/CpuMonitor.java

@@ -10,15 +10,27 @@
 
 package org.appspot.apprtc;
 
+import android.content.Context;
+import android.content.Intent;
+import android.content.IntentFilter;
+import android.os.BatteryManager;
+import android.os.Environment;
+import android.os.SystemClock;
 import android.util.Log;
 
 import java.io.BufferedReader;
+import java.io.File;
 import java.io.FileNotFoundException;
+import java.io.FileOutputStream;
 import java.io.FileReader;
 import java.io.IOException;
-import java.util.InputMismatchException;
+import java.text.SimpleDateFormat;
+import java.util.Calendar;
+import java.util.Date;
 import java.util.Scanner;
 
+import org.appspot.apprtc.util.LooperExecutor;
+
 /**
  * Simple CPU monitor.  The caller creates a CpuMonitor object which can then
  * be used via sampleCpuUtilization() to collect the percentual use of the
@@ -62,29 +74,142 @@ import java.util.Scanner;
  */
 
 class CpuMonitor {
-  private static final int SAMPLE_SAVE_NUMBER = 10;  // Assumed to be >= 3.
-  private int[] percentVec = new int[SAMPLE_SAVE_NUMBER];
-  private int sum3 = 0;
-  private int sum10 = 0;
   private static final String TAG = "CpuMonitor";
-  private long[] cpuFreq;
+  private static final String DUMP_FILE = "cpu_log.txt";
+  private static final int CPU_STAT_SAMPLE_PERIOD = 2000;
+  private static final int CPU_STAT_LOG_PERIOD = 6000;
+
+  private final Context appContext;
+  private LooperExecutor executor;
+  private long lastStatLogTimeMs;
+  private int iterations;
+  private double currentUserCpuUsage;
+  private double currentSystemCpuUsage;
+  private double currentTotalCpuUsage;
+  private double currentFrequencyScale = -1;
+  private double sumUserCpuUsage;
+  private double sumSystemCpuUsage;
+  private double sumFrequencyScale;
+  private double sumTotalCpuUsage;
+  private long[] cpuFreqMax;
   private int cpusPresent;
-  private double lastPercentFreq = -1;
-  private int cpuCurrent;
-  private int cpuAvg3;
-  private int cpuAvgAll;
+  private int actualCpusPresent;
   private boolean initialized = false;
   private String[] maxPath;
   private String[] curPath;
-  ProcStat lastProcStat;
+  private double[] curFreqScales;
+  private ProcStat lastProcStat;
+
+  private static boolean dumpEnabled = false;
+  private static FileOutputStream fileWriter;
 
   private class ProcStat {
-    final long runTime;
+    final long userTime;
+    final long systemTime;
     final long idleTime;
 
-    ProcStat(long aRunTime, long aIdleTime) {
-      runTime = aRunTime;
-      idleTime = aIdleTime;
+    ProcStat(long userTime, long systemTime, long idleTime) {
+      this.userTime = userTime;
+      this.systemTime = systemTime;
+      this.idleTime = idleTime;
+    }
+  }
+
+  public CpuMonitor(Context context) {
+    Log.d(TAG, "CpuMonitor ctor.");
+    appContext = context.getApplicationContext();
+    lastStatLogTimeMs = 0;
+
+    executor = new LooperExecutor();
+    executor.requestStart();
+    scheduleCpuUtilizationTask();
+  }
+
+  public void release() {
+    if (executor != null) {
+      Log.d(TAG, "release");
+      executor.cancelScheduledTasks();
+      executor.requestStop();
+      executor = null;
+    }
+  }
+
+  public void pause() {
+    if (executor != null) {
+      Log.d(TAG, "pause");
+      executor.cancelScheduledTasks();
+    }
+  }
+
+  public void resume() {
+    if (executor != null) {
+      Log.d(TAG, "resume");
+      resetStat();
+      scheduleCpuUtilizationTask();
+    }
+  }
+
+  public synchronized int getCpuUsageCurrent() {
+    return doubleToPercent(currentTotalCpuUsage);
+  }
+
+  public synchronized int getCpuUsageAverage() {
+    return sumDoubleToPercent(sumTotalCpuUsage, iterations);
+  }
+
+  public synchronized int getCpuFrequencyScaleCurrent() {
+    return doubleToPercent(currentFrequencyScale);
+  }
+
+  private void scheduleCpuUtilizationTask() {
+    executor.scheduleAtFixedRate(new Runnable() {
+      @Override
+      public void run() {
+        logCpuUtilization();
+      }
+    }, CPU_STAT_SAMPLE_PERIOD);
+  }
+
+  private void checkDump(String statString) {
+    if (!dumpEnabled) {
+      return;
+    }
+    if (fileWriter == null) {
+      Log.d(TAG, "Start log dump");
+      String fileName = Environment.getExternalStorageDirectory().getAbsolutePath()
+          + File.separator + DUMP_FILE;
+      try {
+        fileWriter = new FileOutputStream(fileName, false /* append */);
+      } catch (FileNotFoundException e) {
+        Log.e(TAG, "Can not open file.", e);
+        dumpEnabled = false;
+        return;
+      }
+    }
+
+    Date date = Calendar.getInstance().getTime();
+    SimpleDateFormat df = new SimpleDateFormat("MM-dd HH:mm:ss.SSS");
+    String msg = df.format(date) + " " + TAG + ":" + statString + "\n";
+    try {
+      fileWriter.write(msg.getBytes());
+    } catch (IOException e) {
+      Log.e(TAG, "Can not write to file.", e);
+      dumpEnabled = false;
+    }
+  }
+
+  private void logCpuUtilization() {
+    boolean logStatistics = false;
+    if (SystemClock.elapsedRealtime() - lastStatLogTimeMs >= CPU_STAT_LOG_PERIOD) {
+      lastStatLogTimeMs = SystemClock.elapsedRealtime();
+      logStatistics = true;
+    }
+    boolean cpuMonitorAvailable = sampleCpuUtilization();
+    if (logStatistics && cpuMonitorAvailable) {
+      String statString = getStatString();
+      checkDump(statString);
+      Log.d(TAG, statString);
+      resetStat();
     }
   }
 
@@ -92,8 +217,8 @@ class CpuMonitor {
     try {
       FileReader fin = new FileReader("/sys/devices/system/cpu/present");
       try {
-        BufferedReader rdr = new BufferedReader(fin);
-        Scanner scanner = new Scanner(rdr).useDelimiter("[-\n]");
+        BufferedReader reader = new BufferedReader(fin);
+        Scanner scanner = new Scanner(reader).useDelimiter("[-\n]");
         scanner.nextInt();  // Skip leading number 0.
         cpusPresent = 1 + scanner.nextInt();
         scanner.close();
@@ -108,20 +233,45 @@ class CpuMonitor {
       Log.e(TAG, "Error closing file");
     }
 
-    cpuFreq = new long [cpusPresent];
-    maxPath = new String [cpusPresent];
-    curPath = new String [cpusPresent];
+    cpuFreqMax = new long[cpusPresent];
+    maxPath = new String[cpusPresent];
+    curPath = new String[cpusPresent];
+    curFreqScales = new double[cpusPresent];
     for (int i = 0; i < cpusPresent; i++) {
-      cpuFreq[i] = 0;  // Frequency "not yet determined".
+      cpuFreqMax[i] = 0;  // Frequency "not yet determined".
+      curFreqScales[i] = 0;
       maxPath[i] = "/sys/devices/system/cpu/cpu" + i + "/cpufreq/cpuinfo_max_freq";
       curPath[i] = "/sys/devices/system/cpu/cpu" + i + "/cpufreq/scaling_cur_freq";
     }
 
-    lastProcStat = new ProcStat(0, 0);
+    lastProcStat = new ProcStat(0, 0, 0);
+    resetStat();
 
     initialized = true;
   }
 
+  private synchronized void resetStat() {
+    sumUserCpuUsage = 0;
+    sumSystemCpuUsage = 0;
+    sumFrequencyScale = 0;
+    sumTotalCpuUsage = 0;
+    iterations = 0;
+  }
+
+  private int getBatteryLevel() {
+    // Use sticky broadcast with null receiver to read battery level once only.
+    Intent intent = appContext.registerReceiver(
+        null /* receiver */, new IntentFilter(Intent.ACTION_BATTERY_CHANGED));
+
+    int batteryLevel = 0;
+    int batteryScale = intent.getIntExtra(BatteryManager.EXTRA_SCALE, 100);
+    if (batteryScale > 0) {
+      batteryLevel = (int) (
+          100f * intent.getIntExtra(BatteryManager.EXTRA_LEVEL, 0) / batteryScale);
+    }
+    return batteryLevel;
+  }
+
   /**
    * Re-measure CPU use.  Call this method at an interval of around 1/s.
    * This method returns true on success.  The fields
@@ -130,36 +280,48 @@ class CpuMonitor {
    * cpuAvg3: The average CPU over the last 3 calls.
    * cpuAvgAll: The average CPU over the last SAMPLE_SAVE_NUMBER calls.
    */
-  public boolean sampleCpuUtilization() {
+  private synchronized boolean sampleCpuUtilization() {
     long lastSeenMaxFreq = 0;
-    long cpufreqCurSum = 0;
-    long cpufreqMaxSum = 0;
+    long cpuFreqCurSum = 0;
+    long cpuFreqMaxSum = 0;
 
     if (!initialized) {
       init();
     }
+    if (cpusPresent == 0) {
+      return false;
+    }
 
+    actualCpusPresent = 0;
     for (int i = 0; i < cpusPresent; i++) {
       /*
        * For each CPU, attempt to first read its max frequency, then its
        * current frequency.  Once as the max frequency for a CPU is found,
-       * save it in cpuFreq[].
+       * save it in cpuFreqMax[].
        */
 
-      if (cpuFreq[i] == 0) {
+      curFreqScales[i] = 0;
+      if (cpuFreqMax[i] == 0) {
         // We have never found this CPU's max frequency.  Attempt to read it.
         long cpufreqMax = readFreqFromFile(maxPath[i]);
         if (cpufreqMax > 0) {
           lastSeenMaxFreq = cpufreqMax;
-          cpuFreq[i] = cpufreqMax;
+          cpuFreqMax[i] = cpufreqMax;
           maxPath[i] = null;  // Kill path to free its memory.
         }
       } else {
-        lastSeenMaxFreq = cpuFreq[i];  // A valid, previously read value.
+        lastSeenMaxFreq = cpuFreqMax[i];  // A valid, previously read value.
       }
 
-      long cpufreqCur = readFreqFromFile(curPath[i]);
-      cpufreqCurSum += cpufreqCur;
+      long cpuFreqCur = readFreqFromFile(curPath[i]);
+      if (cpuFreqCur == 0 && lastSeenMaxFreq == 0) {
+        // No current frequency information for this CPU core - ignore it.
+        continue;
+      }
+      if (cpuFreqCur > 0) {
+        actualCpusPresent++;
+      }
+      cpuFreqCurSum += cpuFreqCur;
 
       /* Here, lastSeenMaxFreq might come from
        * 1. cpuFreq[i], or
@@ -167,11 +329,14 @@ class CpuMonitor {
        * 3. a newly read value, or
        * 4. hypothetically from the pre-loop dummy.
        */
-      cpufreqMaxSum += lastSeenMaxFreq;
+      cpuFreqMaxSum += lastSeenMaxFreq;
+      if (lastSeenMaxFreq > 0) {
+        curFreqScales[i] = (double) cpuFreqCur / lastSeenMaxFreq;
+      }
     }
 
-    if (cpufreqMaxSum == 0) {
-      Log.e(TAG, "Could not read max frequency for any CPU");
+    if (cpuFreqCurSum == 0 || cpuFreqMaxSum == 0) {
+      Log.e(TAG, "Could not read max or current frequency for any CPU");
       return false;
     }
 
@@ -182,58 +347,85 @@ class CpuMonitor {
      * incorrect only if the frequencies have peeked or dropped in between the
      * invocations.
      */
-    double newPercentFreq = 100.0 * cpufreqCurSum / cpufreqMaxSum;
-    double percentFreq;
-    if (lastPercentFreq > 0) {
-      percentFreq = (lastPercentFreq + newPercentFreq) * 0.5;
+    double newFrequencyScale = (double) cpuFreqCurSum / cpuFreqMaxSum;
+    double frequencyScale;
+    if (currentFrequencyScale > 0) {
+      frequencyScale = (currentFrequencyScale + newFrequencyScale) * 0.5;
     } else {
-      percentFreq = newPercentFreq;
+      frequencyScale = newFrequencyScale;
     }
-    lastPercentFreq = newPercentFreq;
 
-    ProcStat procStat = readIdleAndRunTime();
+    ProcStat procStat = readProcStat();
     if (procStat == null) {
       return false;
     }
 
-    long diffRunTime = procStat.runTime - lastProcStat.runTime;
+    long diffUserTime = procStat.userTime - lastProcStat.userTime;
+    long diffSystemTime = procStat.systemTime - lastProcStat.systemTime;
     long diffIdleTime = procStat.idleTime - lastProcStat.idleTime;
+    long allTime = diffUserTime + diffSystemTime + diffIdleTime;
 
+    if (frequencyScale == 0 || allTime == 0) {
+      return false;
+    }
+
+    // Update statistics.
+    currentFrequencyScale = frequencyScale;
+    sumFrequencyScale += frequencyScale;
+
+    currentUserCpuUsage = (double) diffUserTime / allTime;
+    sumUserCpuUsage += currentUserCpuUsage;
+
+    currentSystemCpuUsage = (double) diffSystemTime / allTime;
+    sumSystemCpuUsage += currentSystemCpuUsage;
+
+    currentTotalCpuUsage = (currentUserCpuUsage + currentSystemCpuUsage) * currentFrequencyScale;
+    sumTotalCpuUsage += currentTotalCpuUsage;
+
+    iterations++;
     // Save new measurements for next round's deltas.
     lastProcStat = procStat;
 
-    long allTime = diffRunTime + diffIdleTime;
-    int percent = allTime == 0 ? 0 : (int) Math.round(percentFreq * diffRunTime / allTime);
-    percent = Math.max(0, Math.min(percent, 100));
-
-    // Subtract old relevant measurement, add newest.
-    sum3 += percent - percentVec[2];
-    // Subtract oldest measurement, add newest.
-    sum10 += percent - percentVec[SAMPLE_SAVE_NUMBER - 1];
-
-    // Rotate saved percent values, save new measurement in vacated spot.
-    for (int i = SAMPLE_SAVE_NUMBER - 1; i > 0; i--) {
-      percentVec[i] = percentVec[i - 1];
-    }
-    percentVec[0] = percent;
-
-    cpuCurrent = percent;
-    cpuAvg3 = sum3 / 3;
-    cpuAvgAll = sum10 / SAMPLE_SAVE_NUMBER;
-
     return true;
   }
 
-  public int getCpuCurrent() {
-    return cpuCurrent;
+  private int doubleToPercent(double d) {
+    return (int) (d * 100 + 0.5);
   }
 
-  public int getCpuAvg3() {
-    return cpuAvg3;
+  private int sumDoubleToPercent(double d, int iterations) {
+    if (iterations > 0) {
+      return (int) (d * 100.0 / (double) iterations + 0.5);
+    } else {
+      return 0;
+    }
   }
 
-  public int getCpuAvgAll() {
-    return cpuAvgAll;
+  private String getStatString() {
+    StringBuilder stat = new StringBuilder();
+    stat.append("CPU User: ")
+        .append(doubleToPercent(currentUserCpuUsage)).append("/")
+        .append(sumDoubleToPercent(sumUserCpuUsage, iterations)).append(" (")
+        .append(doubleToPercent(currentUserCpuUsage * currentFrequencyScale)).append(")")
+        .append(". System: ")
+        .append(doubleToPercent(currentSystemCpuUsage)).append("/")
+        .append(sumDoubleToPercent(sumSystemCpuUsage, iterations)).append(" (")
+        .append(doubleToPercent(currentSystemCpuUsage * currentFrequencyScale)).append(")")
+        .append(". CPU freq %: ")
+        .append(doubleToPercent(currentFrequencyScale)).append("/")
+        .append(sumDoubleToPercent(sumFrequencyScale, iterations))
+        .append(". Total CPU usage: ")
+        .append(doubleToPercent(currentTotalCpuUsage)).append("/")
+        .append(sumDoubleToPercent(sumTotalCpuUsage, iterations))
+        .append(". Cores: ")
+        .append(actualCpusPresent);
+    stat.append("( ");
+    for (int i = 0; i < cpusPresent; i++) {
+      stat.append(doubleToPercent(curFreqScales[i])).append(" ");
+    }
+    stat.append("). Battery %: ")
+        .append(getBatteryLevel());
+    return stat.toString();
   }
 
   /**
@@ -266,8 +458,9 @@ class CpuMonitor {
    * Read the current utilization of all CPUs using the cumulative first line
    * of /proc/stat.
    */
-  private ProcStat readIdleAndRunTime() {
-    long runTime = 0;
+  private ProcStat readProcStat() {
+    long userTime = 0;
+    long systemTime = 0;
     long idleTime = 0;
     try {
       FileReader fin = new FileReader("/proc/stat");
@@ -275,11 +468,13 @@ class CpuMonitor {
         BufferedReader rdr = new BufferedReader(fin);
         Scanner scanner = new Scanner(rdr);
         scanner.next();
-        long user = scanner.nextLong();
+        userTime = scanner.nextLong();
         long nice = scanner.nextLong();
-        long sys = scanner.nextLong();
-        runTime = user + nice + sys;
+        userTime += nice;
+        systemTime = scanner.nextLong();
         idleTime = scanner.nextLong();
+        long ioWaitTime = scanner.nextLong();
+        userTime += ioWaitTime;
         scanner.close();
       } catch (Exception e) {
         Log.e(TAG, "Problems parsing /proc/stat");
@@ -294,6 +489,6 @@ class CpuMonitor {
       Log.e(TAG, "Problems reading /proc/stat");
       return null;
     }
-    return new ProcStat(runTime, idleTime);
+    return new ProcStat(userTime, systemTime, idleTime);
   }
 }

webrtc/examples/androidapp/src/org/appspot/apprtc/HudFragment.java

@@ -38,7 +38,7 @@ public class HudFragment extends Fragment {
   private boolean videoCallEnabled;
   private boolean displayHud;
   private volatile boolean isRunning;
-  private final CpuMonitor cpuMonitor = new CpuMonitor();
+  private CpuMonitor cpuMonitor;
 
   @Override
   public View onCreateView(LayoutInflater inflater, ViewGroup container,
@@ -89,6 +89,10 @@ public class HudFragment extends Fragment {
     super.onStop();
   }
 
+  public void setCpuMonitor(CpuMonitor cpuMonitor) {
+    this.cpuMonitor = cpuMonitor;
+  }
+
   private void hudViewsSetProperties(int visibility) {
     hudViewBwe.setVisibility(visibility);
     hudViewConnection.setVisibility(visibility);
@@ -189,11 +193,9 @@ public class HudFragment extends Fragment {
       }
     }
 
-    if (cpuMonitor.sampleCpuUtilization()) {
-      encoderStat.append("CPU%: ")
-          .append(cpuMonitor.getCpuCurrent()).append("/")
-          .append(cpuMonitor.getCpuAvg3()).append("/")
-          .append(cpuMonitor.getCpuAvgAll());
+    if (cpuMonitor != null) {
+      encoderStat.append("CPU%: ").append(cpuMonitor.getCpuUsageCurrent())
+        .append(". Freq: ").append(cpuMonitor.getCpuFrequencyScaleCurrent());
     }
     encoderStatView.setText(encoderStat.toString());
   }

webrtc/examples/androidapp/src/org/appspot/apprtc/PeerConnectionClient.java

@@ -929,6 +929,7 @@ public class PeerConnectionClient {
           + isError);
       return;
     }
+    Log.d(TAG, "changeCaptureFormat: " + width + "x" + height + "@" + framerate);
     videoCapturer.onOutputFormatRequest(width, height, framerate);
   }
 

webrtc/examples/androidapp/src/org/appspot/apprtc/util/LooperExecutor.java

@@ -14,6 +14,8 @@ import android.os.Handler;
 import android.os.Looper;
 import android.util.Log;
 
+import java.util.LinkedList;
+import java.util.List;
 import java.util.concurrent.Executor;
 
 /**
@@ -24,6 +26,7 @@ public class LooperExecutor extends Thread implements Executor {
   // Object used to signal that looper thread has started and Handler instance
   // associated with looper thread has been allocated.
   private final Object looperStartedEvent = new Object();
+  private final List<Runnable> scheduledPeriodicRunnables = new LinkedList<Runnable>();
   private Handler handler = null;
   private boolean running = false;
   private long threadId;
@@ -79,6 +82,41 @@ public class LooperExecutor extends Thread implements Executor {
     return (Thread.currentThread().getId() == threadId);
   }
 
+  public synchronized void scheduleAtFixedRate(final Runnable command, final long periodMillis) {
+    if (!running) {
+      Log.w(TAG, "Trying to schedule task for non running executor");
+      return;
+    }
+    Runnable runnable = new Runnable() {
+      @Override
+      public void run() {
+        if (running) {
+          command.run();
+          if (!handler.postDelayed(this, periodMillis)) {
+            Log.e(TAG, "Failed to post a delayed runnable in the chain.");
+          }
+        }
+      }
+    };
+    scheduledPeriodicRunnables.add(runnable);
+    if (!handler.postDelayed(runnable, periodMillis)) {
+      Log.e(TAG, "Failed to post a delayed runnable.");
+    }
+  }
+
+  public synchronized void cancelScheduledTasks() {
+    if (!running) {
+      Log.w(TAG, "Trying to cancel schedule tasks for non running executor");
+      return;
+    }
+
+    // Stop scheduled periodic tasks.
+    for (Runnable r : scheduledPeriodicRunnables) {
+      handler.removeCallbacks(r);
+    }
+    scheduledPeriodicRunnables.clear();
+  }
+
   @Override
   public synchronized void execute(final Runnable runnable) {
     if (!running) {