A script for profiling Android app by using adb to collect and constantly print CPU/memory/temperature/netstat information to the console.

profapp.pl

#!/usr/bin/env perl -w

use strict;
use warnings;
use Time::HiRes qw(usleep);
use Term::ANSIColor;

my $pkgName = $ARGV[0];
my $watch = $ARGV[1];
my @args = splice(@ARGV, 1);

if (!defined $pkgName) {
  print "Usage: profapp <pkg_name> [watch] [show_all_threads]\n";
  exit(1);
}

my $deviceUptimeKey = "Device Uptime";
my $cpuUsageStatKey = "__CpuUsage";
my $netStatKey = "__NetStat";
my $temperatureStatKey = "__Temperature";

my $cmd = qq{
    set `ps -ef | grep $pkgName | grep -v grep` &&
      grep -E "Name|State|VmRSS|VmSwap|VmSize|VmPeak|Threads" "/proc/\$2/status" 2> /dev/null
      cat /proc/cpuinfo | fgrep -c processor | xargs echo "CPU Cores:"
      cat /proc/\$2/task/*/stat 2> /dev/null | sed -e "s/.*/$cpuUsageStatKey: &/"
      cat /proc/uptime 2> /dev/null | sed -e "s/.*/$deviceUptimeKey: &/"
      cat /proc/\$2/net/dev 2> /dev/null | sed -e "s/.*/$netStatKey: &/"
      dumpsys meminfo "\$2" 2> /dev/null
      dumpsys thermalservice 2> /dev/null | sed -e "s/.*/$temperatureStatKey &/" 
      echo "\$2" | xargs echo "Pid:"
  };

my %infoDataMap;
my %accMemStatMap;
my %peakMemStatMap;
my $count = 0;
my $initialized = 0;
my $cpuHertz = 100;
my $startProcessUptime = 0;
my $curProcessUptime = 0;

my $maxTemperatureStatMap;
my %startCpuStatMap;
my %allTimeCpuTimeMap;
my %peakCpuTimeMap;
my $peakTotalCpuTime = 0;
my $allTimeTotalCpuTime = 0;

my $origNetStat = new NetStat(0, 0);
my $prevNetStat = new NetStat(0, 0);

my @infoKeyArr = ("CPU Cores", "Pid", $deviceUptimeKey);
$infoDataMap{"Package Name"} = $pkgName;

while (1) {
  my $statData = `adb shell '$cmd' 2> /dev/null`;

  my $output;
  my %curMemStatMap;
  my %curCpuStatMap;
  my $curTotalCpuUsage = 0;
  my $threadCount = 0;

  if ($statData !~ /VmRSS/) {
    print("Process [$pkgName] is not running.\n");
    sleep(1);
    $count = 0;
    $initialized = 0;
    undef %accMemStatMap;
    undef %peakMemStatMap;
    undef $peakTotalCpuTime;
    undef %allTimeCpuTimeMap;
    undef %peakCpuTimeMap;
    $allTimeTotalCpuTime = 0;
    next;
  }

  foreach my $key (@infoKeyArr) {
    if ($statData =~ /$key:\s*(\d[^ \n]*)/) {
      $infoDataMap{$key} = $1;
    }
  }

  my $pid = $infoDataMap{"Pid"};
  my $deviceUptime = $infoDataMap{$deviceUptimeKey};
  if (!$initialized) {
    $initialized = 1;

    collectCpuStat($statData, $deviceUptime, sub {
        my ($key, $cpuTime, $tid) = @_;
        $startCpuStatMap{$key} = $cpuTime;
        if ($tid == $pid) {
          $startProcessUptime = $curProcessUptime = $cpuTime->{totalTime};
        }
      });

    $origNetStat = collectNetStat($statData);
  }

  my $prevProcessUptime = $curProcessUptime;
  my %periodCpuTimeMap;
  my $periodTotalCpuTime = 0;

  collectCpuStat($statData, $deviceUptime, sub {
      my ($key, $cpuTime, $tid) = @_;

      ++$threadCount;

      if ($tid == $pid) {
        $curProcessUptime = $cpuTime->{totalTime};
      }

      if (exists $startCpuStatMap{$key}) {
        $cpuTime->subtract($startCpuStatMap{$key});
      }

      my $periodCpuTime = $cpuTime->clone();
      my $prevCpuTime = $allTimeCpuTimeMap{$key};

      # this is for 'Average' cpu time for each thread
      $allTimeCpuTimeMap{$key} = $cpuTime;

      if ($prevCpuTime) {
        $periodCpuTime->subtract($prevCpuTime);
      }

      # this is for 'Current' cpu time for each thread
      $periodCpuTimeMap{$key} = $periodCpuTime;

      my $prevPeakCpuTime = $peakCpuTimeMap{$key};
      my $peakCpuTime;
      if ($periodCpuTime->compareUsage($prevPeakCpuTime) > 0) {
        $peakCpuTime = $periodCpuTime;
      } else {
        $peakCpuTime = $prevPeakCpuTime;
      }

      # this is for 'Peak' cpu time for each thread
      $peakCpuTimeMap{$key} = $peakCpuTime;
    });

  my $samplingInterval = $curProcessUptime - $prevProcessUptime;
  if ($samplingInterval <= 0) {
    usleep(1000 * 5);
    next;
  }

  my $prevPeakTotalCpuTime = $peakTotalCpuTime;
  $peakTotalCpuTime = 0;

  map { 
    my $usedTime = $_->{usedTime} * 100;
    $allTimeTotalCpuTime += $usedTime;
    $periodTotalCpuTime += $usedTime;
    $peakTotalCpuTime += $usedTime;
  } values %periodCpuTimeMap;

  $periodTotalCpuTime /= $samplingInterval;
  $peakTotalCpuTime /= $samplingInterval;
  $peakTotalCpuTime = $prevPeakTotalCpuTime if $peakTotalCpuTime < $prevPeakTotalCpuTime;
  my $avgAllTimeTotalCpuTime = $allTimeTotalCpuTime / ($curProcessUptime - $startProcessUptime);

  # delete stat data of threads that were destroyed
  map { delete $peakCpuTimeMap{$_} if not exists $periodCpuTimeMap{$_} } keys %peakCpuTimeMap;

  ++$count;


  # collecting mem stat
  my @memStatKeyArr = (
    "VmPeak", "VmSize", "VmRSS", "Native Heap",
    "Java Heap", "Graphics", "Code", "Stack", "System");
  foreach my $key (@memStatKeyArr) {
    $peakMemStatMap{$key} = 0 if !defined $peakMemStatMap{$key};

    if ($statData =~ /$key:\s*(\d+)/) {
      $accMemStatMap{$key} += $1;
      $curMemStatMap{$key} = $1;
      $peakMemStatMap{$key} = $1 if $peakMemStatMap{$key} < $1;
    }
  }
  if ($statData =~ /TOTAL:\s*(\d+)/) {
    $accMemStatMap{"PSS"} += $1;
    $curMemStatMap{"PSS"} = $1;
    $peakMemStatMap{"PSS"} = $1 if !$peakMemStatMap{"PSS"} || $peakMemStatMap{"PSS"} < $1;
  }


  # collecting net stat
  my $netStat = collectNetStat($statData);
  $netStat->subtract($origNetStat);
  my $netSpeedStat = $netStat->clone();
  $netSpeedStat->subtract($prevNetStat);
  $prevNetStat = $netStat->clone();
  my $txSpeedStr = 0;
  my $rxSpeedStr = 0;
  if ($samplingInterval > 0) {
    $txSpeedStr = sprintf("%.1fKb/s", $netSpeedStat->{txBytes} / $samplingInterval / 1024);
    $rxSpeedStr = sprintf("%.1fKb/s", $netSpeedStat->{rxBytes} / $samplingInterval / 1024);
  }


  my $curTemperatureStatMap = collectTemperatureStat($statData);
  foreach my $key (keys %$curTemperatureStatMap) {
    $maxTemperatureStatMap->{$key} = max($curTemperatureStatMap->{$key}, $maxTemperatureStatMap->{$key});
  }

  if (grep(/^watch$/, @args)) {
    # see https://askubuntu.com/questions/25077/how-to-really-clear-the-terminal
    # clear the screen
    print("\033c");
  }

  $output .= sprintf("┌──────────────────────────────────────────────────────────────────────────────┐\n");

  $output .= sprintf("│%24s: %-52s│\n", "Times", $count);
  foreach my $key (sort keys %infoDataMap) {
    $output .= sprintf("│%24s: %-52s│\n", $key, $infoDataMap{$key});
  }
  $output .= sprintf("│%24s: %-52d│\n", "Threads", $threadCount);
  $output .= sprintf("│%24s: %-52.2f│\n", "Process Uptime", $curProcessUptime);

  if (%$curTemperatureStatMap) {
    $output .= sprintf("├─ TEMPERATURES ───────────────────────────────────────────────────────────────┤\n");
    $output .= concatTemperatureStr($curTemperatureStatMap, $maxTemperatureStatMap);
  }

  $output .= sprintf("├─ NET ────────────────────────────────────────────────────────────────────────┤\n");
  my $rxStr = sprintf("%sKb", int($netStat->{rxBytes} / 1024));
  my $txStr = sprintf("%sKb", int($netStat->{txBytes} / 1024));
  $output .= sprintf("│ %s: %-12s %s: %-12s %s: %-12s %s: %-12s│\n",
    "Tx", $txStr, "Rx", $rxStr, "TxSpeed", $txSpeedStr, "RxSpeed", $rxSpeedStr);
  #$output .= sprintf("│%24s: %-52s│\n", "Transmitted", $txStr);

  $output .= sprintf("├─ MEM ─────────────────── Current ────── Average ────── Peak ─────────────────┤\n");

  foreach my $key (sort keys %curMemStatMap) {
    my $value = sprintf("%-14s %-14s %s",
      $curMemStatMap{$key} . " Kb",
      int($accMemStatMap{$key} / $count) . " Kb",
      $peakMemStatMap{$key} . " Kb");
    if ($key =~ /PSS|Native Heap|VmRSS/) {
      $output .= sprintf("│%24s: %s%-52s%s│\n", $key, color("red"), $value, color("reset"));
    } else {
      $output .= sprintf("│%24s: %-52s│\n", $key, $value);
    }
  }

  $output .= sprintf("├─ CPU ─────────────────── Current ────── Average ────── Peak ─────────────────┤\n");

  my $cpuCores = $infoDataMap{"CPU Cores"};
  my $curCpuPercent = sprintf("%.2f%%", $periodTotalCpuTime / $cpuCores);
  my $avgCpuPercent = sprintf("%.2f%%", $avgAllTimeTotalCpuTime / $cpuCores);
  my $peakCpuPercent = sprintf("%.2f%%", $peakTotalCpuTime / $cpuCores);
  $output .= sprintf("│%24s: %s%-15s%-15s%-22s%s│\n", "[Overall]",
    color("cyan"), $curCpuPercent, $avgCpuPercent, $peakCpuPercent, color("reset"));

  foreach my $key (sort {
      $allTimeCpuTimeMap{$b}->asPercentage() <=> $allTimeCpuTimeMap{$a}->asPercentage()
    } keys %allTimeCpuTimeMap) {

    if (!$periodCpuTimeMap{$key} ||
      ($periodCpuTimeMap{$key}->{usedTime} <= 0 && !grep(/^show_all_threads$/, @args))) {
      next;
    }

    my $curCpuPercent = sprintf("%.2f%%", $periodCpuTimeMap{$key}->asPercentage() / $cpuCores);
    my $avgCpuPercent = sprintf("%.2f%%", $allTimeCpuTimeMap{$key}->asPercentage() / $cpuCores);
    my $peakCpuPercent = sprintf("%.2f%%", $peakCpuTimeMap{$key}->asPercentage() / $cpuCores);
    $output .= sprintf("│%24s: %-15s%-15s%-22s│\n", $key, $curCpuPercent, $avgCpuPercent, $peakCpuPercent);
  }

  $output .= sprintf("└──────────────────────────────────────────────────────────────────────────────┘\n");
  print($output);
  #print("$statData\n");
  usleep(1000*900);
}

=begin comment
funIter = sub { my ($key, $cpuTime) }
=cut
sub collectCpuStat {
  my ($statData, $deviceUptime, $funIter) = @_;

  while ($statData =~ /^$cpuUsageStatKey: *(.+)$/mg) {
    my $line = $1 =~ s/(\([^)]*\))/$1 =~ s| |_|gr/re;
    my @fields = split(" ", $line);

    my $tid = $fields[0];
    my $tname = $fields[1];
    my $totalTimeSec = $deviceUptime - ($fields[21] / $cpuHertz);
    my $usedTimeSec = ($fields[13] + $fields[14]) / $cpuHertz;

    $funIter->("$tname\@$tid", new CpuTime($totalTimeSec, $usedTimeSec), $tid);
  }
}

sub collectNetStat {
  my $statData = shift;

  my $totalRxBytes = 0;
  my $totalTxBytes = 0;
  while ($statData =~ /^$netStatKey: *(.+)$/mg) {
    my @fields = split(" ", $1);

    my $rxBytes = $fields[1];
    my $txBytes = $fields[9];
    if ((!$rxBytes || grep(/[a-z]/, $rxBytes)) &&
      (!$txBytes || grep(/[a-z]/, $txBytes))) {
      next;
    }
    $totalRxBytes += $rxBytes;
    $totalTxBytes += $txBytes;
  }

  return new NetStat($totalRxBytes, $totalTxBytes);
}

sub collectTemperatureStat {
  my $statData = shift;

  my $result = {};
  my $isCurrent = 0;
  while ($statData =~ /^$temperatureStatKey *(.+)$/mg) {
    my $line = $1;
    if (!$isCurrent) {
      if ($line =~ /Current temperatures from HAL/mg) {
        $isCurrent = 1;
      }
      next;
    }

    if ($line =~ /mValue=([^,]*).*mName=([^,]*)/mg) {
      $result->{$2} = $1;
    }
  }

  return $result;
}

sub concatTemperatureStr {
  my ($curMap, $maxMap) = @_;

  my $output;
  my $index = 0;
  foreach my $key (sort keys %$curMap) {
    if ($index % 4 == 0) {
      $output .= sprintf("│%8s: %-4.1f/%-4.1f", $key, $curMap->{$key}, $maxMap->{$key});
    } elsif ($index % 4 == 3) {
      $output .= sprintf("%8s: %-4.1f/%-4.1f  │\n", $key, $curMap->{$key}, $maxMap->{$key});
    } else {
      $output .= sprintf("%8s: %-4.1f/%-4.1f", $key, $curMap->{$key}, $maxMap->{$key});
    }
    ++$index;
  }
  if ($index > 0 && $index % 4 > 0) {
    my $c = 4 - ($index % 4);
    $c = $c * 18 + ($c - 1) + 2;
    $output .= sprintf("%-${c}s │\n", "");
  }

  return $output;
}

sub max {
  my ($a, $b) = @_;
  if (!$a) {
    return $b;
  }
  if (!$b) {
    return $a;
  }
  return $a > $b ? $a : $b;
}

package BaseObject;

sub new {
  my ($class, $args) = @_;
  return bless $args, $class;
}

sub clone {
  my $self = shift;
  my $copy = bless { %$self }, ref $self;
  return $copy;
}


package NetStat;
use parent -norequire, qw(BaseObject);

sub new {
  my ($class, $rxBytes, $txBytes) = @_;
  return $class->SUPER::new({
      rxBytes => $rxBytes,
      txBytes => $txBytes
    });
}

sub subtract {
  my ($self, $other) = @_;
  foreach my $k (keys %$self) {
    $self->{$k} -= $other->{$k};
  }
}


package CpuTime;
use parent -norequire, qw(BaseObject);

sub new {
  my ($class, $totalTime, $usedTime) = @_;
  return $class->SUPER::new({
      totalTime => $totalTime,
      usedTime => $usedTime
    });
}

sub subtract {
  my ($self, $other) = @_;
  foreach my $k (keys %$self) {
    $self->{$k} -= $other->{$k};
  }
}

sub compareUsage {
  my ($self, $cpuTime) = @_;
  if (!$cpuTime) {
    return 1;
  }
  my $totalTime = $self->{totalTime};
  my $otherTotalTime = $cpuTime->{totalTime};
  if ($totalTime <= 0) {
    $totalTime = 1;
  }
  if ($otherTotalTime <= 0) {
    $otherTotalTime = 1;
  }
  my $usage = $self->{usedTime} / $totalTime;
  my $otherUsage = $cpuTime->{usedTime} / $otherTotalTime;
  if ($usage < $otherUsage) {
    return -1;
  }
  if ($usage == $otherUsage) {
    return 0;
  }
  return 1;
}

sub asPercentage() {
  my $self = shift;
  if (!$self->{totalTime}) {
    return 0;
  }
  return 100 * $self->{usedTime} / $self->{totalTime};
}

sub debug {
  my $self = shift;
  printf("DEBUG: totalTime:%f, usedTime:%f\n", $self->{totalTime}, $self->{usedTime});
}

output of the script:

┌──────────────────────────────────────────────────────────────────────────────┐
│                   Times: 3                                                   │
│               CPU Cores: 8                                                   │
│           Device Uptime: 2062635.07                                          │
│            Package Name: com.example.demo                                    │
│                     Pid: 14821                                               │
│                 Threads: 44                                                  │
│          Process Uptime: 6514.35                                             │
├─ NET ────────────────────────────────────────────────────────────────────────┤
│ Tx: 0Kb          Rx: 0Kb          TxSpeed: 0.0Kb/s      RxSpeed: 0.0Kb/s     │
├─ MEM ─────────────────── Current ────── Average ────── Peak ─────────────────┤
│                    Code: 37912 Kb       37912 Kb       37912 Kb              │
│                Graphics: 222308 Kb      222308 Kb      222308 Kb             │
│               Java Heap: 10396 Kb       10388 Kb       10396 Kb              │
│             Native Heap: 22800 Kb       23418 Kb       23968 Kb              │
│                   Stack: 1008 Kb        1008 Kb        1008 Kb               │
│                  System: 8818 Kb        8818 Kb        8818 Kb               │
│                  VmPeak: 2248424 Kb     2248424 Kb     2248424 Kb            │
│                   VmRSS: 116540 Kb      117142 Kb      117868 Kb             │
│                  VmSize: 2192176 Kb     2192176 Kb     2192176 Kb            │
├─ CPU ─────────────────── Current ────── Average ────── Peak ─────────────────┤
│               [Overall]: 5.25%          5.34%          7.29%                 │
│     (RenderThread)@8734: 1.00%          0.87%          1.00%                 │
│   (Binder:14821_2)@8718: 0.45%          0.78%          1.87%                 │
│        (Thread-16)@9604: 0.78%          0.69%          0.78%                 │
│        (Thread-15)@9602: 0.67%          0.56%          0.67%                 │
│  (JNISurfaceTextu)@9593: 0.56%          0.52%          0.62%                 │
│ (com.example.demo)@4821: 0.45%          0.43%          0.45%                 │
│  (MediaCodec_loop)@9592: 0.33%          0.35%          0.42%                 │
│  (unknown________)@9601: 0.33%          0.35%          0.42%                 │
│       (AudioTrack)@9526: 0.22%          0.22%          0.22%                 │
│  (unknown________)@9600: 0.22%          0.22%          0.42%                 │
│  (HwBinder:14821_)@9519: 0.11%          0.17%          0.22%                 │
│         (Thread-5)@8741: 0.11%          0.09%          0.21%                 │
└──────────────────────────────────────────────────────────────────────────────┘