From ca72ffc364da6686f44cb6eaab67eb02fde7f5d0 Mon Sep 17 00:00:00 2001 From: Joe Onorato Date: Sat, 1 Apr 2017 16:26:17 -0700 Subject: [PATCH] Add logblame and some log buffer tests. (cherry picked from commit 75f444e139793892c0b7d8d7df579624a6431d0c) A utility to read a logcat and print statistics about who is spamming the log. And tests that use it Signed-off-by: Joe Onorato Bug: 37252687 Test: ./test_analyze.py ; test_logs.py ; test_ps.py Change-Id: I811ba482b4be9779047f97c3f3b7ea5f996bd503 --- tools/logblame/analyze_logs.py | 262 +++ tools/logblame/app_switch_test | 72 + tools/logblame/connectivity_log_test | 58 + tools/logblame/logs.py | 162 ++ tools/logblame/medium_idle_test | 23 + tools/logblame/power_toggle_test | 35 + tools/logblame/ps.py | 142 ++ tools/logblame/sample.txt | 2947 ++++++++++++++++++++++++++ tools/logblame/short_idle_test | 23 + tools/logblame/test_analyze.py | 24 + tools/logblame/test_logs.py | 179 ++ tools/logblame/test_ps.py | 97 + 12 files changed, 4024 insertions(+) create mode 100755 tools/logblame/analyze_logs.py create mode 100755 tools/logblame/app_switch_test create mode 100755 tools/logblame/connectivity_log_test create mode 100644 tools/logblame/logs.py create mode 100755 tools/logblame/medium_idle_test create mode 100755 tools/logblame/power_toggle_test create mode 100644 tools/logblame/ps.py create mode 100644 tools/logblame/sample.txt create mode 100755 tools/logblame/short_idle_test create mode 100755 tools/logblame/test_analyze.py create mode 100755 tools/logblame/test_logs.py create mode 100755 tools/logblame/test_ps.py diff --git a/tools/logblame/analyze_logs.py b/tools/logblame/analyze_logs.py new file mode 100755 index 000000000..5d1090cd3 --- /dev/null +++ b/tools/logblame/analyze_logs.py @@ -0,0 +1,262 @@ +#!/usr/bin/env python2.7 + +import argparse +import datetime +import re +import subprocess +import sys + +import logs +import ps + +DURATION_RE = re.compile("((\\d+)w)?((\\d+)d)?((\\d+)h)?((\\d+)m)?((\\d+)s)?") + +class Bucket(object): + """Bucket of stats for a particular key managed by the Stats object.""" + def __init__(self): + self.count = 0 + self.memory = 0 + self.lines = [] + + def __str__(self): + return "(%s,%s)" % (self.count, self.memory) + + +class Stats(object): + """A group of stats with a particular key, where both memory and count are tracked.""" + def __init__(self): + self._data = dict() + + def add(self, key, logLine): + bucket = self._data.get(key) + if not bucket: + bucket = Bucket() + self._data[key] = bucket + bucket.count += 1 + bucket.memory += logLine.memory() + bucket.lines.append(logLine) + + def __iter__(self): + return self._data.iteritems() + + def data(self): + return [(key, bucket) for key, bucket in self._data.iteritems()] + + def byCount(self): + result = self.data() + result.sort(lambda a, b: -cmp(a[1].count, b[1].count)) + return result + + def byMemory(self): + result = self.data() + result.sort(lambda a, b: -cmp(a[1].memory, b[1].memory)) + return result + + +def ParseDuration(s): + """Parse a date of the format .w.d.h.m.s into the number of seconds.""" + def make_int(index): + val = m.group(index) + if val: + return int(val) + else: + return 0 + m = DURATION_RE.match(s) + if m: + weeks = make_int(2) + days = make_int(4) + hours = make_int(6) + minutes = make_int(8) + seconds = make_int(10) + return (weeks * 604800) + (days * 86400) + (hours * 3600) + (minutes * 60) + seconds + return 0 + +def FormatMemory(n): + """Prettify the number of bytes into gb, mb, etc.""" + if n >= 1024 * 1024 * 1024: + return "%10d gb" % (n / (1024 * 1024 * 1024)) + elif n >= 1024 * 1024: + return "%10d mb" % (n / (1024 * 1024)) + elif n >= 1024: + return "%10d kb" % (n / 1024) + else: + return "%10d b " % n + +def FormateTimeDelta(td): + """Format a time duration into the same format we accept on the commandline.""" + seconds = (td.days * 86400) + (td.seconds) + int(td.microseconds / 1000000) + if seconds == 0: + return "0s" + result = "" + if seconds >= 604800: + weeks = int(seconds / 604800) + seconds -= weeks * 604800 + result += "%dw" % weeks + if seconds >= 86400: + days = int(seconds / 86400) + seconds -= days * 86400 + result += "%dd" % days + if seconds >= 3600: + hours = int(seconds / 3600) + seconds -= hours * 3600 + result += "%dd" % hours + if seconds >= 60: + minutes = int(seconds / 60) + seconds -= minutes * 60 + result += "%dh" % minutes + if seconds > 0: + result += "%ds" % seconds + return result + + +def WriteResult(totalCount, totalMemory, bucket, text): + """Write a bucket in the normalized format.""" + print "%7d (%2d%%) %s (%2d%%) %s" % (bucket.count, (100 * bucket.count / totalCount), + FormatMemory(bucket.memory), (100 * bucket.memory / totalMemory), text) + + +def ParseArgs(argv): + parser = argparse.ArgumentParser(description="Process some integers.") + parser.add_argument("input", type=str, nargs="?", + help="the logs file to read") + parser.add_argument("--clear", action="store_true", + help="clear the log buffer before running logcat") + parser.add_argument("--duration", type=str, nargs=1, + help="how long to run for (XdXhXmXs)") + parser.add_argument("--rawlogs", type=str, nargs=1, + help="file to put the rawlogs into") + + args = parser.parse_args() + + args.durationSec = ParseDuration(args.duration[0]) if args.duration else 0 + + return args + + +def main(argv): + args = ParseArgs(argv) + + processes = ps.ProcessSet() + + if args.rawlogs: + rawlogs = file(args.rawlogs[0], "w") + else: + rawlogs = None + + # Choose the input + if args.input: + # From a file of raw logs + try: + infile = file(args.input, "r") + except IOError: + sys.stderr.write("Error opening file for read: %s\n" % args.input[0]) + sys.exit(1) + else: + # From running adb logcat on an attached device + if args.clear: + subprocess.check_call(["adb", "logcat", "-c"]) + cmd = ["adb", "logcat", "-v", "long", "-D", "-v", "uid"] + if not args.durationSec: + cmd.append("-d") + logcat = subprocess.Popen(cmd, stdout=subprocess.PIPE) + infile = logcat.stdout + + # Do one update because we know we'll need it, but then don't do it again + # if we're not streaming them. + processes.Update(True) + if args.durationSec: + processes.doUpdates = True + + totalCount = 0 + totalMemory = 0 + byTag = Stats() + byPid = Stats() + byText = Stats() + + startTime = datetime.datetime.now() + + # Read the log lines from the parser and build a big mapping of everything + for logLine in logs.ParseLogcat(infile, processes, args.durationSec): + if rawlogs: + rawlogs.write("%-10s %s %-6s %-6s %-6s %s/%s: %s\n" %(logLine.buf, logLine.timestamp, + logLine.uid, logLine.pid, logLine.tid, logLine.level, logLine.tag, logLine.text)) + + totalCount += 1 + totalMemory += logLine.memory() + byTag.add(logLine.tag, logLine) + byPid.add(logLine.pid, logLine) + byText.add(logLine.text, logLine) + + endTime = datetime.datetime.now() + + # Print the log analysis + + # At this point, everything is loaded, don't bother looking + # for new processes + processes.doUpdates = False + + print "Top tags by count" + print "-----------------" + i = 0 + for k,v in byTag.byCount(): + WriteResult(totalCount, totalMemory, v, k) + if i >= 10: + break + i += 1 + + print + print "Top tags by memory" + print "------------------" + i = 0 + for k,v in byTag.byMemory(): + WriteResult(totalCount, totalMemory, v, k) + if i >= 10: + break + i += 1 + + print + print "Top Processes by memory" + print "-----------------------" + i = 0 + for k,v in byPid.byMemory(): + WriteResult(totalCount, totalMemory, v, + "%-8s %s" % (k, processes.FindPid(k).DisplayName())) + if i >= 10: + break + i += 1 + + print + print "Top Duplicates by count" + print "-----------------------" + i = 0 + for k,v in byText.byCount(): + logLine = v.lines[0] + WriteResult(totalCount, totalMemory, v, + "%s/%s: %s" % (logLine.level, logLine.tag, logLine.text)) + if i >= 10: + break + i += 1 + + print + print "Top Duplicates by memory" + print "-----------------------" + i = 0 + for k,v in byText.byCount(): + logLine = v.lines[0] + WriteResult(totalCount, totalMemory, v, + "%s/%s: %s" % (logLine.level, logLine.tag, logLine.text)) + if i >= 10: + break + i += 1 + + print + print "Totals" + print "------" + print "%7d %s" % (totalCount, FormatMemory(totalMemory)) + + print "Actual duration: %s" % FormateTimeDelta(endTime-startTime) + +if __name__ == "__main__": + main(sys.argv) + +# vim: set ts=2 sw=2 sts=2 tw=100 nocindent autoindent smartindent expandtab: diff --git a/tools/logblame/app_switch_test b/tools/logblame/app_switch_test new file mode 100755 index 000000000..14c168af5 --- /dev/null +++ b/tools/logblame/app_switch_test @@ -0,0 +1,72 @@ +#!/bin/bash + +# The intents to launch +INTENTS="\ + com.google.android.googlequicksearchbox/.SearchActivity \ + com.android.settings/.Settings \ + com.google.android.apps.messaging/.ui.ConversationListActivity \ + com.google.android.calculator/com.android.calculator2.Calculator \ + com.google.android.deskclock/com.android.deskclock.DeskClock \ + com.google.android.contacts/com.android.contacts.activities.PeopleActivity \ + com.google.android.talk/.SigningInActivity \ + com.google.android.vr.home/com.google.android.apps.vr.home.app.MainActivity \ + com.android.documentsui/.Launcher \ + com.google.android.apps.nexuslauncher/.NexusLauncherActivity \ + " +# com.google.android.GoogleCamera/com.android.camera.CameraActivity \ + +# The files to save output to. +RAWLOGS_FILE=app-switch-rawlogs.txt +ANALYSIS_FILE=app-switch-analysis.txt + + +# Turn on the screen and unlock the device +# TODO: Power on +adb shell wm dismiss-keyguard +adb logcat -P "" + +# Turn on airplane mode (to reduce background noise caught by other tests) +airplane_mode_was_on=$(adb shell settings get global airplane_mode_on) +if [ $airplane_mode_was_on != 1 ] ; then + adb shell settings put global airplane_mode_on 1 > /dev/null + adb shell am broadcast -a android.intent.action.AIRPLANE_MODE > /dev/null + sleep 15 +fi + +# Start the analysis process +$TOP/development/tools/logblame/analyze_logs.py --duration=10m --clear --rawlogs $RAWLOGS_FILE \ + | tee $ANALYSIS_FILE & +analyze_pid=$! + +# Launch the intents with a 3s gap between them +for intent in $INTENTS +do + echo Starting: $intent + adb shell am start -a android.intent.action.MAIN $intent + sleep 4 +done + +# Turn the screen off and on +adb shell input keyevent 26 +adb shell input keyevent 26 +adb shell wm dismiss-keyguard + +echo +echo + +# Kill adb to disconnect logcat +adb kill-server + +# Wait for the pyton process to exit +wait $analyze_pid + +# Turn airplane mode back off +if [ $airplane_mode_was_on == 0 ] ; then + adb shell settings put global airplane_mode_on 0 > /dev/null + adb shell am broadcast -a android.intent.action.AIRPLANE_MODE > /dev/null +fi + +echo "Wrote raw logs to $RAWLOGS_FILE" +echo "Wrote analysis to $ANALYSIS_FILE" + + diff --git a/tools/logblame/connectivity_log_test b/tools/logblame/connectivity_log_test new file mode 100755 index 000000000..2afab61f4 --- /dev/null +++ b/tools/logblame/connectivity_log_test @@ -0,0 +1,58 @@ +#!/bin/bash + +# The files to save output to. +RAWLOGS_FILE=connectivity-rawlogs.txt +ANALYSIS_FILE=connectivity-analysis.txt + +# Turn on the screen and unlock the device +# TODO: Power on +adb shell wm dismiss-keyguard +adb logcat -P "" + +airplane_mode_was_on=$(adb shell settings get global airplane_mode_on) +if [ $airplane_mode_was_on == 1 ] ; then + adb shell settings put global airplane_mode_on 0 > /dev/null + adb shell am broadcast -a android.intent.action.AIRPLANE_MODE > /dev/null + sleep 30 +fi + +# Start the analysis process +$TOP/development/tools/logblame/analyze_logs.py --duration=10m --clear --rawlogs $RAWLOGS_FILE \ + | tee $ANALYSIS_FILE & +analyze_pid=$! + +# Turn on airplane mode and wait for it to settle +echo "Turning on airplane mode." +adb shell settings put global airplane_mode_on 1 > /dev/null +adb shell am broadcast -a android.intent.action.AIRPLANE_MODE > /dev/null +sleep 15 + +# Turn off airplane mode and wait for it to settle +echo "Turning off airplane mode." +adb shell settings put global airplane_mode_on 0 > /dev/null +adb shell am broadcast -a android.intent.action.AIRPLANE_MODE > /dev/null +sleep 45 + +# Turn off wifi and then back on +echo "Turning wifi off" +adb shell svc wifi disable +sleep 15 + +echo "Turning wifi on" +adb shell svc wifi enable +sleep 15 + + +echo +echo + +# Kill adb to disconnect logcat +adb kill-server + +# Wait for the pyton process to exit +wait $analyze_pid + +echo "Wrote raw logs to $RAWLOGS_FILE" +echo "Wrote analysis to $ANALYSIS_FILE" + + diff --git a/tools/logblame/logs.py b/tools/logblame/logs.py new file mode 100644 index 000000000..400a39b3e --- /dev/null +++ b/tools/logblame/logs.py @@ -0,0 +1,162 @@ + +import datetime +import re + +BUFFER_BEGIN = re.compile("^--------- beginning of (.*)$") +BUFFER_SWITCH = re.compile("^--------- switch to (.*)$") +HEADER = re.compile("^\\[ (\\d\\d-\\d\\d \\d\\d:\\d\\d:\\d\\d.\\d\\d\\d) +(.+?): *(\\d+): *(\\d+) *([EWIDV])/(.*?) *\\]$") +CHATTY_IDENTICAL = re.compile("^.* identical (\\d+) lines$") + +STATE_BEGIN = 0 +STATE_BUFFER = 1 +STATE_HEADER = 2 +STATE_TEXT = 3 +STATE_BLANK = 4 + +class LogLine(object): + """Represents a line of android logs.""" + def __init__(self, buf=None, timestamp=None, uid=None, pid=None, tid=None, level=None, + tag=None, text=""): + self.buf = buf + self.timestamp = timestamp + self.uid = uid + self.pid = pid + self.tid = tid + self.level = level + self.tag = tag + self.text = text + self.process = None + + def __str__(self): + return "{%s} {%s} {%s} {%s} {%s} {%s}/{%s}: {%s}" % (self.buf, self.timestamp, self.uid, + self.pid, self.tid, self.level, self.tag, self.text) + + def __eq__(self, other): + return ( + self.buf == other.buf + and self.timestamp == other.timestamp + and self.uid == other.uid + and self.pid == other.pid + and self.tid == other.tid + and self.level == other.level + and self.tag == other.tag + and self.text == other.text + ) + + def clone(self): + logLine = LogLine(self.buf, self.timestamp, self.uid, self.pid, self.tid, self.level, + self.tag, self.text) + logLine.process = self.process + return logLine + + def memory(self): + """Return an estimate of how much memory is used for the log. + 32 bytes of header + 8 bytes for the pointer + the length of the tag and the text. + This ignores the overhead of the list of log lines itself.""" + return 32 + 8 + len(self.tag) + 1 + len(self.text) + 1 + + +def ParseLogcat(f, processes, duration=None): + previous = None + for logLine in ParseLogcatInner(f, processes, duration): + if logLine.tag == "chatty" and logLine.level == "I": + m = CHATTY_IDENTICAL.match(logLine.text) + if m: + for i in range(int(m.group(1))): + clone = previous.clone() + clone.timestamp = logLine.timestamp + yield clone + continue + previous = logLine + yield logLine + + +def ParseLogcatInner(f, processes, duration=None): + """Parses a file object containing log text and returns a list of LogLine objects.""" + result = [] + + buf = None + timestamp = None + uid = None + pid = None + tid = None + level = None + tag = None + + state = STATE_BEGIN + logLine = None + previous = None + + if duration: + endTime = datetime.datetime.now() + datetime.timedelta(seconds=duration) + + # TODO: use a nonblocking / timeout read so we stop if there are + # no logs coming out (haha joke, right!) + for line in f: + if duration and endTime <= datetime.datetime.now(): + break + + if len(line) > 0 and line[-1] == '\n': + line = line[0:-1] + + m = BUFFER_BEGIN.match(line) + if m: + if logLine: + yield logLine + logLine = None + buf = m.group(1) + state = STATE_BUFFER + continue + + m = BUFFER_SWITCH.match(line) + if m: + if logLine: + yield logLine + logLine = None + buf = m.group(1) + state = STATE_BUFFER + continue + + m = HEADER.match(line) + if m: + if logLine: + yield logLine + logLine = LogLine( + buf=buf, + timestamp=m.group(1), + uid=m.group(2), + pid=m.group(3), + tid=m.group(4), + level=m.group(5), + tag=m.group(6) + ) + previous = logLine + logLine.process = processes.FindPid(logLine.pid, logLine.uid) + state = STATE_HEADER + continue + + if not len(line): + if state == STATE_BLANK: + if logLine: + logLine.text += "\n" + state = STATE_BLANK + continue + + if logLine: + if state == STATE_HEADER: + logLine.text += line + elif state == STATE_TEXT: + logLine.text += "\n" + logLine.text += line + elif state == STATE_BLANK: + if len(logLine.text): + logLine.text += "\n" + logLine.text += "\n" + logLine.text += line + state = STATE_TEXT + + if logLine: + yield logLine + + +# vim: set ts=2 sw=2 sts=2 tw=100 nocindent autoindent smartindent expandtab: diff --git a/tools/logblame/medium_idle_test b/tools/logblame/medium_idle_test new file mode 100755 index 000000000..c4813b118 --- /dev/null +++ b/tools/logblame/medium_idle_test @@ -0,0 +1,23 @@ +#!/bin/bash + +# The files to save output to. +RAWLOGS_FILE=medium-idle-rawlogs.txt +ANALYSIS_FILE=medium-idle-analysis.txt + +# Turn on the screen and unlock the device +# TODO: Power on +adb shell wm dismiss-keyguard + +# Start the analysis process +$TOP/development/tools/logblame/analyze_logs.py --duration=4h --clear --rawlogs $RAWLOGS_FILE \ + | tee $ANALYSIS_FILE & +analyze_pid=$! + +# Wait for the pyton process to exit +echo "waiting... analyze_pid" $analyze_pid +wait $analyze_pid + +echo "Wrote raw logs to $RAWLOGS_FILE" +echo "Wrote analysis to $ANALYSIS_FILE" + + diff --git a/tools/logblame/power_toggle_test b/tools/logblame/power_toggle_test new file mode 100755 index 000000000..e2630e481 --- /dev/null +++ b/tools/logblame/power_toggle_test @@ -0,0 +1,35 @@ +#!/bin/bash + +# The files to save output to. +RAWLOGS_FILE=power-toggle-rawlogs.txt +ANALYSIS_FILE=power-toggle-analysis.txt + + +# Turn on the screen and unlock the device +# TODO: Power on +adb shell wm dismiss-keyguard +adb logcat -P "" + +# Start the analysis process +$TOP/development/tools/logblame/analyze_logs.py --duration=10m --clear --rawlogs $RAWLOGS_FILE \ + | tee $ANALYSIS_FILE & +analyze_pid=$! + +sleep 5 +for i in {0..10..1}; do + adb shell input keyevent KEYCODE_POWER + sleep 5 + adb shell wm dismiss-keyguard + sleep 5 +done + +# Kill adb to disconnect logcat +adb kill-server + +# Wait for the pyton process to exit +wait $analyze_pid + +echo "Wrote raw logs to $RAWLOGS_FILE" +echo "Wrote analysis to $ANALYSIS_FILE" + + diff --git a/tools/logblame/ps.py b/tools/logblame/ps.py new file mode 100644 index 000000000..201601691 --- /dev/null +++ b/tools/logblame/ps.py @@ -0,0 +1,142 @@ +import csv +import re +import subprocess + +HEADER_RE = re.compile("USER\\s*PID\\s*PPID\\s*VSIZE\\s*RSS\\s*WCHAN\\s*PC\\s*NAME") +PROCESS_RE = re.compile("(\\S+)\\s+(\\d+)\\s+(\\d+)\\s+\\d+\\s+\\d+\\s+\\S+\\s+.\\S+\\s+\\S+\\s+(.*)") + +ANDROID_UID_RE = re.compile("u(\\d)+_([0-9a-fA-F]+)") +UID_RE = re.compile("(\\d)+") + +class Process(object): + def __init__(self, uid, pid, ppid, name): + self.uid = uid + self.pid = pid + self.ppid = ppid + self.name = name + + def DisplayName(self): + if self.name: + return self.name + if self.uid: + return self.uid.name + return self.pid + + def __str__(self): + return "Process(uid=%s, pid=%s, name=%s)" % (self.uid, self.pid, self.name) + +class Uid(object): + def __init__(self, uid, name): + self.uid = uid + self.name = name + + def __str__(self): + return "Uid(id=%s, name=%s)" % (self.uid, self.name) + +class ProcessSet(object): + def __init__(self): + self._processes = dict() + self._uids = dict() + self._pidUpdateCount = 0 + self._uidUpdateCount = 0 + self.doUpdates = False + + def Update(self, force=False): + self.UpdateUids(force) + self.UpdateProcesses(force) + + def UpdateProcesses(self, force=False): + if not (self.doUpdates or force): + return + self._pidUpdateCount += 1 + try: + text = subprocess.check_output(["adb", "shell", "ps"]) + except subprocess.CalledProcessError: + return # oh well. we won't get the pid + lines = ParsePs(text) + for line in lines: + if not self._processes.has_key(line[1]): + uid = self.FindUid(ParseUid(line[0])) + self._processes[line[1]] = Process(uid, line[1], line[2], line[3]) + + def UpdateUids(self, force=False): + if not (self.doUpdates or force): + return + self._uidUpdateCount += 1 + try: + text = subprocess.check_output(["adb", "shell", "dumpsys", "package", "--checkin"]) + except subprocess.CalledProcessError: + return # oh well. we won't get the pid + lines = ParseUids(text) + for line in lines: + if not self._uids.has_key(line[0]): + self._uids[line[1]] = Uid(*line) + + def FindPid(self, pid, uid=None): + """Try to find the Process object for the given pid. + If it can't be found, do an update. If it still can't be found after that, + create a syntheitc Process object, add that to the list, and return that. + That can only happen after the process has died, and we just missed our + chance to find it. The pid won't come back. + """ + result = self._processes.get(pid) + if not result: + self.UpdateProcesses() + result = self._processes.get(pid) + if not result: + if uid: + uid = self._uids.get(uid) + result = Process(uid, pid, None, None) + self._processes[pid] = result + return result + + def FindUid(self, uid): + result = self._uids.get(uid) + if not result: + self.UpdateUids() + result = self._uids.get(uid) + if not result: + result = Uid(uid, uid) + self._uids[uid] = result + return result + + def UpdateCount(self): + return (self._pidUpdateCount, self._uidUpdateCount) + + def Print(self): + for process in self._processes: + print process + for uid in self._uids: + print uid + +def ParsePs(text): + """Parses the output of ps, and returns it as a list of tuples of (user, pid, ppid, name)""" + result = [] + for line in text.splitlines(): + m = HEADER_RE.match(line) + if m: + continue + m = PROCESS_RE.match(line) + if m: + result.append((m.group(1), m.group(2), m.group(3), m.group(4))) + continue + return result + + +def ParseUids(text): + """Parses the output of dumpsys package --checkin and returns the uids as a list of + tuples of (uid, name)""" + return [(x[2], x[1]) for x in csv.reader(text.split("\n")) if len(x) and x[0] == "pkg"] + + +def ParseUid(text): + m = ANDROID_UID_RE.match(text) + if m: + result = int("0x" + m.group(2), 16) + return "(%s/%s/%s)" % (m.group(1), m.group(2), result) + m = UID_RE.match(text) + if m: + return "[%s]" % m.group(1) + return text + +# vim: set ts=2 sw=2 sts=2 tw=100 nocindent autoindent smartindent expandtab: diff --git a/tools/logblame/sample.txt b/tools/logblame/sample.txt new file mode 100644 index 000000000..725adb8dd --- /dev/null +++ b/tools/logblame/sample.txt @@ -0,0 +1,2947 @@ +--------- beginning of main +[ 01-01 15:12:06.640 root: 600: 600 I/chatty ] +uid=0(root) /system/bin/thermal-engine expire 3 lines + +[ 01-01 15:12:16.640 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1021): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:12:24.572 10081:20049:20054 I/zygote64 ] +Integer.valueOf will not be optimized + +--------- beginning of system +[ 01-01 15:12:24.863 1000: 2272: 3628 I/PowerManagerService ] +Going to sleep due to power button (uid 1000)... + +--------- switch to main +[ 01-01 15:12:24.572 10081:20049:20054 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:12:25.055 10081:20049:20054 I/zygote64 ] +Compiler allocated 6MB to compile void android.view.ViewRootImpl.performTraversals() + +--------- switch to system +[ 01-01 15:12:25.343 1000: 2272: 3592 D/BatteryStatsService ] +begin noteScreenState + +[ 01-01 15:12:25.344 1000: 2272: 3592 D/BatteryStatsService ] +end noteScreenState + +[ 01-01 15:12:25.347 1000: 2272: 3582 I/VrManagerService ] +VR mode is disallowed + +--------- switch to main +[ 01-01 15:12:25.431 1000: 2272: 3592 I/sensors ] +activate + +[ 01-01 15:12:25.436 1000: 2272: 3592 I/nanohub ] +queueActivate: sensor=28, handle=30, enable=0 + +[ 01-01 15:12:25.437 1000: 2272: 3592 V/KeyguardServiceDelegate ] +onScreenTurnedOff() + +[ 01-01 15:12:25.440 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=0, state=3 + + +[ 01-01 15:12:25.441 1000: 2272: 3592 I/sensors ] +activate + +[ 01-01 15:12:25.443 1000: 2272: 3592 I/nanohub ] +queueActivate: sensor=12, handle=7, enable=0 + +--------- switch to system +[ 01-01 15:12:25.448 1000: 2272: 3590 I/DisplayManagerService ] +Display device changed state: "Built-in Screen", OFF + +--------- switch to main +[ 01-01 15:12:25.453 1000: 398: 398 D/SurfaceFlinger ] +Set power mode=0, type=0 flinger=0x7542c6c000 + +--------- switch to system +[ 01-01 15:12:25.464 1000: 2272: 3614 W/LocalDisplayAdapter ] +Unable to find color mode 0, ignoring request. + +--------- switch to main +[ 01-01 15:12:25.466 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Setting mode 0 on display: 0 + +[ 01-01 15:12:25.595 1000: 398: 462 I/qdhwcomposer ] +handle_blank_event: dpy:0 panel power state: 0 + +[ 01-01 15:12:25.599 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Done setting mode 0 on display 0 + +[ 01-01 15:12:25.599 1000: 2272: 3787 D/SurfaceControl ] +Excessive delay in setPowerMode(): 146ms + +--------- switch to system +[ 01-01 15:12:25.604 1000: 2272: 3592 I/DreamManagerService ] +Entering dreamland. + +[ 01-01 15:12:25.605 1000: 2272: 3592 I/PowerManagerService ] +Dozing... + +[ 01-01 15:12:25.607 1000: 2272: 3588 I/DreamController ] +Starting dream: name=ComponentInfo{com.android.systemui/com.android.systemui.doze.DozeService}, isTest=false, canDoze=true, userId=0 + +--------- switch to main +[ 01-01 15:12:25.643 1000: 2272: 8012 I/sensors ] +batch + +[ 01-01 15:12:25.646 1000: 2272: 8012 I/nanohub ] +queueBatch: sensor=24, handle=20, period=1000000, latency=0 + +[ 01-01 15:12:25.646 1000: 2272: 8012 I/sensors ] +activate + +[ 01-01 15:12:25.648 1000: 2272: 8012 I/nanohub ] +queueActivate: sensor=24, handle=20, enable=1 + +[ 01-01 15:12:25.652 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] power: 1 + + +[ 01-01 15:12:25.654 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=1, state=4 + + +[ 01-01 15:12:25.656 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=1, state=3 + + +[ 01-01 15:12:25.658 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] activity activity powered on, new state 2 + + +--------- switch to system +[ 01-01 15:12:25.684 1000: 2272: 4217 I/ActivityManager ] +Setting hasTopUi=true for pid=3812 + +--------- switch to main +[ 01-01 15:12:25.694 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:12:25.723 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:12:25.730 nfc: 4175: 4351 E/NxpTml ] +_i2c_write() errno : 5 + +[ 01-01 15:12:25.731 nfc: 4175: 4351 E/NxpTml ] +PN54X - Error in I2C Write..... + + +[ 01-01 15:12:25.731 nfc: 4175: 4353 E/NxpHal ] +write error status = 0x1ff + +[ 01-01 15:12:25.731 nfc: 4175: 4346 E/NxpHal ] +write_unlocked failed - PN54X Maybe in Standby Mode - Retry + +[ 01-01 15:12:25.898 10036: 3812: 3812 D/StatusBar ] +disable: < expand icons alerts system_info back HOME* RECENT* clock search quick_settings > + +[ 01-01 15:12:26.644 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1022): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:12:26.694 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:12:27.695 1041: 541: 678 I/chatty ] +uid=1041(audioserver) MediaLogNotifie identical 1 line + +[ 01-01 15:12:28.696 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:12:36.647 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1023): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:12:36.858 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] detected still, confidence: 92, votes: 3, motionConfidence: 2 + + +[ 01-01 15:12:46.650 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1024): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:12:56.654 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1025): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:12:56.898 1000: 2272: 5402 D/WificondControl ] +Scan result ready event + +[ 01-01 15:12:56.951 1000: 2272: 3755 W/WifiConfigManager ] +Looking up network with invalid networkId -1 + +[ 01-01 15:13:06.657 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1026): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:13:26.664 root: 600: 600 I/chatty ] +uid=0(root) /system/bin/thermal-engine identical 2 lines + +[ 01-01 15:13:36.667 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1029): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:13:40.125 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] detected still, confidence: 92, votes: 3, motionConfidence: 7 + + +[ 01-01 15:13:46.670 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1030): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:13:56.674 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1031): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:13:56.996 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] sending event 0x00000001 + +[ 01-01 15:13:57.005 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] activity activity powered off, new state 0 + + +[ 01-01 15:13:57.007 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] power: 0 + + +[ 01-01 15:13:57.011 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=0, state=5 + + +[ 01-01 15:13:57.014 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=0, state=3 + + +[ 01-01 15:13:57.029 1000: 2272: 5447 I/sensors ] +batch + +[ 01-01 15:13:57.032 1000: 2272: 5447 I/nanohub ] +queueBatch: sensor=24, handle=20, period=1000000, latency=0 + +[ 01-01 15:13:57.032 1000: 2272: 5447 I/sensors ] +activate + +[ 01-01 15:13:57.035 1000: 2272: 5447 I/nanohub ] +queueActivate: sensor=24, handle=20, enable=1 + +[ 01-01 15:13:57.037 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] power: 1 + + +--------- switch to system +[ 01-01 15:13:57.038 1000: 2272: 3592 D/BatteryStatsService ] +begin noteScreenState + +--------- switch to main +[ 01-01 15:13:57.038 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=1, state=4 + + +--------- switch to system +[ 01-01 15:13:57.039 1000: 2272: 3592 D/BatteryStatsService ] +end noteScreenState + +[ 01-01 15:13:57.039 1000: 2272: 3592 I/DisplayPowerController ] +Blocking screen on until initial contents have been drawn. + +--------- switch to main +[ 01-01 15:13:57.040 1000: 2272: 3592 V/KeyguardServiceDelegate ] +onScreenTurnedOn(showListener = com.android.server.policy.PhoneWindowManager$2@cb6ff88) + +[ 01-01 15:13:57.043 1000: 398: 398 D/SurfaceFlinger ] +Set power mode=1, type=0 flinger=0x7542c6c000 + +--------- switch to system +[ 01-01 15:13:57.043 1000: 2272: 3590 I/DisplayManagerService ] +Display device changed state: "Built-in Screen", DOZE + +--------- switch to main +[ 01-01 15:13:57.043 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Setting mode 1 on display: 0 + +[ 01-01 15:13:57.047 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=1, state=3 + + +[ 01-01 15:13:57.050 1000: 2272: 4464 I/sensors ] +batch + +[ 01-01 15:13:57.050 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] activity activity powered on, new state 2 + + +--------- switch to system +[ 01-01 15:13:57.058 1000: 2272: 3614 W/LocalDisplayAdapter ] +Unable to find color mode 0, ignoring request. + +--------- switch to main +[ 01-01 15:13:57.059 1000: 2272: 4464 I/nanohub ] +queueBatch: sensor=13, handle=6, period=200000000, latency=0 + +[ 01-01 15:13:57.059 1000: 2272: 4464 I/sensors ] +activate + +[ 01-01 15:13:57.074 1000: 2272: 4464 I/nanohub ] +queueActivate: sensor=13, handle=6, enable=1 + +[ 01-01 15:13:57.084 1000: 2272: 4088 V/KeyguardServiceDelegate ] +**** SHOWN CALLED **** + +[ 01-01 15:13:57.095 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +--------- switch to system +[ 01-01 15:13:57.166 1000: 2272: 3592 I/DisplayPowerController ] +Unblocked screen on after 127 ms + +--------- switch to main +[ 01-01 15:13:57.167 1000: 2272: 3592 V/KeyguardServiceDelegate ] +onScreenTurnedOn() + +[ 01-01 15:13:57.298 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Done setting mode 1 on display 0 + +[ 01-01 15:13:57.298 1000: 398: 462 I/qdhwcomposer ] +handle_blank_event: dpy:0 panel power state: 2 + +[ 01-01 15:13:57.305 1000: 2272: 3787 D/SurfaceControl ] +Excessive delay in setPowerMode(): 262ms + +--------- switch to system +[ 01-01 15:13:57.395 1000: 2272: 3628 I/PowerManagerService ] +Waking up from dozing (uid 1000)... + +--------- switch to main +[ 01-01 15:13:57.400 1000: 2272: 2272 I/sensors ] +batch + +[ 01-01 15:13:57.403 1000: 2272: 2272 I/nanohub ] +queueBatch: sensor=28, handle=30, period=66667000, latency=0 + +[ 01-01 15:13:57.403 1000: 2272: 2272 I/sensors ] +activate + +--------- switch to system +[ 01-01 15:13:57.404 1000: 2272: 3592 D/BatteryStatsService ] +begin noteScreenState + +[ 01-01 15:13:57.405 1000: 2272: 3592 D/BatteryStatsService ] +end noteScreenState + +--------- switch to main +[ 01-01 15:13:57.406 1000: 2272: 2272 I/nanohub ] +queueActivate: sensor=28, handle=30, enable=1 + +[ 01-01 15:13:57.406 1000: 2272: 2272 V/KeyguardServiceDelegate ] +onStartedWakingUp() + +[ 01-01 15:13:57.409 1000: 2272: 3592 I/sensors ] +batch + +[ 01-01 15:13:57.412 1000: 2272: 3592 I/nanohub ] +queueBatch: sensor=12, handle=7, period=250000000, latency=0 + +[ 01-01 15:13:57.412 1000: 2272: 3592 I/sensors ] +activate + +[ 01-01 15:13:57.414 1000: 2272: 3592 I/nanohub ] +queueActivate: sensor=12, handle=7, enable=1 + +[ 01-01 15:13:57.418 1000: 398: 398 D/SurfaceFlinger ] +Set power mode=2, type=0 flinger=0x7542c6c000 + +[ 01-01 15:13:57.418 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Setting mode 2 on display: 0 + +--------- switch to system +[ 01-01 15:13:57.418 1000: 2272: 3590 I/DisplayManagerService ] +Display device changed state: "Built-in Screen", ON + +[ 01-01 15:13:57.419 1000: 2272: 3582 I/ActivityManager ] +Killing 14363:com.google.android.ims/u0a94 (adj 902): empty for 1839s + +[ 01-01 15:13:57.420 1000: 2272: 3582 I/ActivityManager ] +Killing 14629:com.android.cellbroadcastreceiver/u0a5 (adj 904): empty for 1839s + +[ 01-01 15:13:57.421 1000: 2272: 3582 I/ActivityManager ] +Killing 14601:org.codeaurora.ims/1001 (adj 904): empty for 1839s + +[ 01-01 15:13:57.422 1000: 2272: 3582 I/ActivityManager ] +Killing 14575:com.verizon.omadm/u0a9 (adj 904): empty for 1839s + +[ 01-01 15:13:57.423 1000: 2272: 3582 I/ActivityManager ] +Killing 14301:com.google.android.carriersetup/u0a93 (adj 904): empty for 1839s + +--------- switch to main +[ 01-01 15:13:57.423 1000: 398: 462 I/qdhwcomposer ] +handle_blank_event: dpy:0 panel power state: 1 + +--------- switch to system +[ 01-01 15:13:57.423 1000: 2272: 3582 I/ActivityManager ] +Killing 14132:com.android.sdm.plugins.sprintdm/1001 (adj 904): empty for 1839s + +[ 01-01 15:13:57.424 1000: 2272: 3582 I/ActivityManager ] +Killing 14711:com.lge.HiddenMenu/1000 (adj 906): empty for 1841s + +[ 01-01 15:13:57.431 1000: 2272: 3592 I/DreamManagerService ] +Gently waking up from dream. + +[ 01-01 15:13:57.433 1000: 2272: 3614 W/LocalDisplayAdapter ] +Unable to find color mode 0, ignoring request. + +--------- switch to main +[ 01-01 15:13:57.450 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +--------- switch to system +[ 01-01 15:13:57.454 1000: 2272: 8012 I/DreamManagerService ] +Leaving dreamland. + +[ 01-01 15:13:57.455 1000: 2272: 3588 I/DreamController ] +Stopping dream: name=ComponentInfo{com.android.systemui/com.android.systemui.doze.DozeService}, isTest=false, canDoze=true, userId=0 + +--------- switch to main +[ 01-01 15:13:57.495 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Done setting mode 2 on display 0 + +[ 01-01 15:13:57.502 1000: 2272: 3578 I/sensors ] +activate + +[ 01-01 15:13:57.504 1000: 2272: 3578 I/nanohub ] +queueActivate: sensor=24, handle=20, enable=0 + +[ 01-01 15:13:57.506 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_SET_TECH_CFG_EVT; status=0x0 + +[ 01-01 15:13:57.509 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_SET_PROTO_CFG_EVT; status=0x0 + +[ 01-01 15:13:57.511 nfc: 4175:20146 D/BrcmNfcJni ] +RoutingManager::commitRouting + +[ 01-01 15:13:57.511 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] power: 0 + + +[ 01-01 15:13:57.512 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_UPDATED_EVT + +[ 01-01 15:13:57.514 nfc: 4175: 4351 E/NxpTml ] +_i2c_write() errno : 5 + +[ 01-01 15:13:57.514 nfc: 4175: 4351 E/NxpTml ] +PN54X - Error in I2C Write..... + + +[ 01-01 15:13:57.514 nfc: 4175: 4353 E/NxpHal ] +write error status = 0x1ff + +[ 01-01 15:13:57.515 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] activity activity powered off, new state 0 + + +[ 01-01 15:13:57.516 nfc: 4175: 4346 E/NxpHal ] +write_unlocked failed - PN54X Maybe in Standby Mode - Retry + +[ 01-01 15:13:57.552 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:13:57.561 10036: 3812: 3819 I/chatty ] +uid=10036(u0_a36) Jit thread pool identical 4 lines + +[ 01-01 15:13:57.568 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:13:58.164 1000: 2272: 3617 I/nanohub ] +osLog: [WO] rotation changed to: ******* 0 ******* + + +[ 01-01 15:13:58.194 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:13:58.450 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:13:58.730 10036: 3812: 3812 D/StatusBar ] +disable: < expand icons alerts system_info back HOME RECENT clock search quick_settings > + +--------- switch to system +[ 01-01 15:13:58.812 1000: 2272: 3582 I/VrManagerService ] +VR mode is allowed + +--------- switch to main +[ 01-01 15:13:58.813 10036: 3812: 3812 D/StatusBar ] +disable: < expand icons alerts system_info back HOME RECENT clock search quick_settings > + +[ 01-01 15:13:58.997 1000: 2272: 8012 I/sensors ] +activate + +[ 01-01 15:13:58.999 1000: 2272: 8012 I/nanohub ] +queueActivate: sensor=13, handle=6, enable=0 + +[ 01-01 15:13:59.042 nfc: 4175: 4351 E/NxpTml ] +_i2c_write() errno : 5 + +[ 01-01 15:13:59.043 nfc: 4175: 4351 E/NxpTml ] +PN54X - Error in I2C Write..... + + +[ 01-01 15:13:59.043 nfc: 4175: 4353 E/NxpHal ] +write error status = 0x1ff + +[ 01-01 15:13:59.043 nfc: 4175: 4346 E/NxpHal ] +write_unlocked failed - PN54X Maybe in Standby Mode - Retry + +[ 01-01 15:13:59.054 nfc: 4175: 4346 E/BrcmNfcJni ] +nfaConnectionCallback: unknown event ???? + +[ 01-01 15:13:59.054 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_SET_TECH_CFG_EVT; status=0x0 + +[ 01-01 15:13:59.057 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_SET_PROTO_CFG_EVT; status=0x0 + +[ 01-01 15:13:59.057 nfc: 4175:20160 D/BrcmNfcJni ] +RoutingManager::commitRouting + +[ 01-01 15:13:59.057 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_UPDATED_EVT + +[ 01-01 15:13:59.109 10036: 3812: 3812 D/StatusBar ] +disable: < expand icons alerts system_info back home* recent* clock search quick_settings > + +[ 01-01 15:13:59.156 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:13:59.308 10018: 4514: 4514 I/chatty ] +uid=10018(u0_a18) com.google.android.gms identical 18 lines + +[ 01-01 15:13:59.319 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:13:59.450 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +--------- switch to system +[ 01-01 15:13:59.462 1000: 2272: 5450 I/ActivityManager ] +Setting hasTopUi=false for pid=3812 + +--------- switch to main +[ 01-01 15:14:00.090 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +[ 01-01 15:14:00.097 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:00.098 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:00.098 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:00.098 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:00.123 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:00.123 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +--------- switch to system +[ 01-01 15:14:00.192 1000: 2272: 3627 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 + +--------- switch to main +[ 01-01 15:14:00.451 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:00.458 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:00.458 1000: 2272: 3635 I/OpenGLRenderer ] +Initialized EGL, version 1.4 + +[ 01-01 15:14:00.458 1000: 2272: 3635 D/OpenGLRenderer ] +Swap behavior 2 + +[ 01-01 15:14:00.564 10038:18491:18672 I/AttachedClient ] +Adding client event 2 to pending list. + +[ 01-01 15:14:00.565 1000: 2272: 2282 I/zygote64 ] +Background concurrent copying GC freed 16057(13MB) AllocSpace objects, 0(0B) LOS objects, 42% free, 15MB/27MB, paused 530us total 107.155ms + +[ 01-01 15:14:00.642 10038:18491:18491 I/OptInState ] +There is a new client and it does not support opt-in. Dropping request. + +[ 01-01 15:14:00.648 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:00.655 10038:18491:18491 I/MicroDetectionWorker ] +#updateMicroDetector [currentDetectionMode: [mDetectionMode: [1]]] + +[ 01-01 15:14:00.655 10038:18491:18491 I/MicroDetectionWorker ] +#startMicroDetector [speakerMode: 0] + +[ 01-01 15:14:00.657 10038:18491:18496 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:00.664 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:00.664 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +[ 01-01 15:14:00.666 10038:18491:19016 I/MicroRecognitionRunner ] +Starting detection. + +[ 01-01 15:14:00.680 10038:18491:19008 I/MicrophoneInputStream ] +mic_starting com.google.android.apps.gsa.speech.audio.ag@4fc0a + +[ 01-01 15:14:00.683 1041: 541: 5248 W/DeviceHAL ] +Device 0xf4fad000 open_input_stream: Invalid argument + +[ 01-01 15:14:00.685 1041: 541:20182 I/AudioFlinger ] +AudioFlinger's thread 0xf1220600 tid=20182 ready to run + +[ 01-01 15:14:00.699 10038:18491:19008 I/MicrophoneInputStream ] +mic_started com.google.android.apps.gsa.speech.audio.ag@4fc0a + +[ 01-01 15:14:00.699 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:00.702 1041: 541:20183 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 1, rx 0, concurrency session_allowed 0 + +[ 01-01 15:14:00.702 1041: 541:20183 D/audio_hw_primary ] +enable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:00.702 1041: 541:20183 D/audio_route ] +Apply path: voice-rec-mic + +[ 01-01 15:14:00.704 10038:18491:19015 W/LocationOracle ] +No location history returned by ContextManager + +[ 01-01 15:14:00.711 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:00.712 10038:18491:18496 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:00.720 1041: 541:20183 D/audio_hw_primary ] +enable_audio_route: usecase(9) apply and update mixer path: audio-record + +[ 01-01 15:14:00.720 1041: 541:20183 D/audio_route ] +Apply path: audio-record + +[ 01-01 15:14:00.733 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:00.737 10038:18491:18502 I/zygote64 ] +Background concurrent copying GC freed 3431(3MB) AllocSpace objects, 1(68KB) LOS objects, 49% free, 8MB/17MB, paused 6.968ms total 70.367ms + +[ 01-01 15:14:00.796 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:00.814 10018: 5497: 5537 W/GCoreFlp ] +No location to return for getLastLocation() + +[ 01-01 15:14:00.870 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:00.876 10038: 4245: 4483 W/OpenGLRenderer ] +Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer... + +[ 01-01 15:14:00.979 1000: 2272: 5401 D/WificondControl ] +Scan result ready event + +[ 01-01 15:14:01.029 1000: 2272: 3755 W/WifiConfigManager ] +Looking up network with invalid networkId -1 + +[ 01-01 15:14:01.119 10018: 5497:19840 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:01.341 10018: 5497:19650 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:01.347 10018: 5497:20187 I/PlaceInferenceEngine ] +[anon] Changed inference mode: 105 + +[ 01-01 15:14:01.348 10018: 5497:20188 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:01.352 10018: 5497: 5537 W/GCoreFlp ] +No location to return for getLastLocation() + +[ 01-01 15:14:01.378 10018: 5497:20032 W/ctxmgr ] +[AclManager]No 3 for (accnt=account#-517948760#, com.google.android.googlequicksearchbox(10038):com.google.android.googlequicksearchbox, vrsn=10298000, 1, 3pPkg = null , 3pMdlId = null). Was: 3 for 18, account#-517948760# + +[ 01-01 15:14:01.383 1000: 2272: 4464 I/sensors ] +batch + +[ 01-01 15:14:01.387 10038:18491:19015 W/zygote64 ] +Long monitor contention with owner NonUserFacing9 (19135) at boolean android.os.BinderProxy.transactNative(int, android.os.Parcel, android.os.Parcel, int)(Binder.java:-2) waiters=0 in boolean com.google.android.apps.gsa.staticplugins.q.g.aJV() for 606ms + +[ 01-01 15:14:01.395 10018: 5497:19840 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:01.395 1000: 2272: 4464 I/nanohub ] +queueBatch: sensor=1, handle=1, period=20000000, latency=0 + +[ 01-01 15:14:01.395 1000: 2272: 4464 I/sensors ] +activate + +[ 01-01 15:14:01.401 1000: 2272: 4464 I/nanohub ] +queueActivate: sensor=1, handle=1, enable=1 + +[ 01-01 15:14:01.454 10018: 5497:20032 E/ctxmgr ] +[ProducerStatusImpl]updateStateForNewContextData: inactive, contextName=7 + +[ 01-01 15:14:01.505 10018: 5497:19161 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:01.513 10018: 5497:19161 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:01.547 10018: 5497:20187 I/Places ] +?: PlacesBleScanner start() with priority 2 + +[ 01-01 15:14:01.548 10018: 5497:20187 I/PlaceInferenceEngine ] +[anon] Changed inference mode: 102 + +[ 01-01 15:14:01.570 10018: 5497: 5537 W/GCoreFlp ] +No location to return for getLastLocation() + +[ 01-01 15:14:01.631 10018: 5497:20187 W/Places ] +?: Failed to download inference model weights + + +[ 01-01 15:14:01.631 10018: 5497:20187 W/PlaceInferenceEngine ] +Failed to download model weights. Status code: 7 + +[ 01-01 15:14:01.639 10018: 5497:19161 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:02.091 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +[ 01-01 15:14:02.094 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:02.094 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:02.094 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:02.094 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +--------- switch to system +[ 01-01 15:14:02.097 1000: 2272: 5450 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.android.settings/.Settings bnds=[435,1254][646,1507] (has extras)} from uid 10038 + +--------- switch to main +[ 01-01 15:14:02.134 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:02.134 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +[ 01-01 15:14:02.214 1000:14206:14206 I/zygote64 ] +Starting a blocking GC Explicit + +[ 01-01 15:14:02.265 1000:14206:14206 I/zygote64 ] +Explicit concurrent copying GC freed 2205(1093KB) AllocSpace objects, 0(0B) LOS objects, 49% free, 3MB/7MB, paused 357us total 50.228ms + +[ 01-01 15:14:02.270 1000:14206:14206 I/zygote64 ] +Starting a blocking GC Explicit + +[ 01-01 15:14:02.300 1000:14206:14206 I/zygote64 ] +Explicit concurrent copying GC freed 217(778KB) AllocSpace objects, 0(0B) LOS objects, 49% free, 3MB/7MB, paused 163us total 29.425ms + +[ 01-01 15:14:02.306 1000:14206:14206 E/StrictMode ] +class com.android.settings.SubSettings; instances=2; limit=1 +android.os.StrictMode$InstanceCountViolation: class com.android.settings.SubSettings; instances=2; limit=1 + at android.os.StrictMode.setClassInstanceLimit(StrictMode.java:1) + + +--------- switch to system +[ 01-01 15:14:02.364 1000:14206:14206 E/ActivityThread ] +Activity com.android.settings.SubSettings has leaked ServiceConnection android.bluetooth.BluetoothA2dp$2@97ec6ff that was originally bound here +android.app.ServiceConnectionLeaked: Activity com.android.settings.SubSettings has leaked ServiceConnection android.bluetooth.BluetoothA2dp$2@97ec6ff that was originally bound here + at android.app.LoadedApk$ServiceDispatcher.(LoadedApk.java:1485) + at android.app.LoadedApk.getServiceDispatcher(LoadedApk.java:1377) + at android.app.ContextImpl.bindServiceCommon(ContextImpl.java:1592) + at android.app.ContextImpl.bindServiceAsUser(ContextImpl.java:1552) + at android.content.ContextWrapper.bindServiceAsUser(ContextWrapper.java:699) + at android.bluetooth.BluetoothA2dp.doBind(BluetoothA2dp.java:200) + at android.bluetooth.BluetoothA2dp.(BluetoothA2dp.java:193) + at android.bluetooth.BluetoothAdapter.getProfileProxy(BluetoothAdapter.java:2044) + at com.android.settings.development.DevelopmentSettings.onCreateView(DevelopmentSettings.java:712) + at android.app.Fragment.performCreateView(Fragment.java:2554) + at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1262) + at android.app.FragmentManagerImpl.moveFragmentToExpectedState(FragmentManager.java:1516) + at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1578) + at android.app.FragmentManagerImpl.dispatchMoveToState(FragmentManager.java:2999) + at android.app.FragmentManagerImpl.dispatchActivityCreated(FragmentManager.java:2951) + at android.app.FragmentController.dispatchActivityCreated(FragmentController.java:178) + at android.app.Activity.performCreateCommon(Activity.java:6899) + at android.app.Activity.performCreate(Activity.java:6907) + at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1212) + at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2768) + at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2890) + at android.app.ActivityThread.-wrap11(Unknown Source:0) + at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1591) + at android.os.Handler.dispatchMessage(Handler.java:105) + at android.os.Looper.loop(Looper.java:164) + at android.app.ActivityThread.main(ActivityThread.java:6537) + at java.lang.reflect.Method.invoke(Native Method) + at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240) + at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767) + + +--------- switch to main +[ 01-01 15:14:02.366 1000:14206:14206 E/StrictMode ] +null +android.app.ServiceConnectionLeaked: Activity com.android.settings.SubSettings has leaked ServiceConnection android.bluetooth.BluetoothA2dp$2@97ec6ff that was originally bound here + at android.app.LoadedApk$ServiceDispatcher.(LoadedApk.java:1485) + at android.app.LoadedApk.getServiceDispatcher(LoadedApk.java:1377) + at android.app.ContextImpl.bindServiceCommon(ContextImpl.java:1592) + at android.app.ContextImpl.bindServiceAsUser(ContextImpl.java:1552) + at android.content.ContextWrapper.bindServiceAsUser(ContextWrapper.java:699) + at android.bluetooth.BluetoothA2dp.doBind(BluetoothA2dp.java:200) + at android.bluetooth.BluetoothA2dp.(BluetoothA2dp.java:193) + at android.bluetooth.BluetoothAdapter.getProfileProxy(BluetoothAdapter.java:2044) + at com.android.settings.development.DevelopmentSettings.onCreateView(DevelopmentSettings.java:712) + at android.app.Fragment.performCreateView(Fragment.java:2554) + at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1262) + at android.app.FragmentManagerImpl.moveFragmentToExpectedState(FragmentManager.java:1516) + at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1578) + at android.app.FragmentManagerImpl.dispatchMoveToState(FragmentManager.java:2999) + at android.app.FragmentManagerImpl.dispatchActivityCreated(FragmentManager.java:2951) + at android.app.FragmentController.dispatchActivityCreated(FragmentController.java:178) + at android.app.Activity.performCreateCommon(Activity.java:6899) + at android.app.Activity.performCreate(Activity.java:6907) + at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1212) + at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2768) + at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2890) + at android.app.ActivityThread.-wrap11(Unknown Source:0) + at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1591) + at android.os.Handler.dispatchMessage(Handler.java:105) + at android.os.Looper.loop(Looper.java:164) + at android.app.ActivityThread.main(ActivityThread.java:6537) + at java.lang.reflect.Method.invoke(Native Method) + at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240) + at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767) + + +--------- switch to system +[ 01-01 15:14:02.367 1000: 2272: 5402 W/ActivityManager ] +Unbind failed: could not find connection for android.os.BinderProxy@d2a6c1d + +--------- switch to main +[ 01-01 15:14:02.397 1000:14206:14206 D/DashboardSummary ] +Listening for condition changes + +[ 01-01 15:14:02.397 1000:14206:14206 D/DashboardSummary ] +onConditionsChanged + +[ 01-01 15:14:02.398 1000:14206:14206 D/DashboardAdapter ] +adapter setConditions called + +[ 01-01 15:14:02.398 1000:14206:14206 D/DashboardSummary ] +conditions refreshed + +[ 01-01 15:14:02.398 1000:14206:14206 D/APM_Condition ] +APM condition refreshed + +[ 01-01 15:14:02.399 1000:14206:14206 D/APM_Condition ] +setActive was called with false + +[ 01-01 15:14:02.456 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:02.507 1000:14206:20201 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 17 millis + +[ 01-01 15:14:02.537 1000:14206:20202 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 10 millis + +[ 01-01 15:14:02.644 1000:14206:20203 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:02.660 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:02.672 1000:14206:20203 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:02.673 1000:14206:20203 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +[ 01-01 15:14:02.677 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:02.677 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +--------- switch to system +[ 01-01 15:14:02.699 1000: 2272: 4464 D/BatteryStatsService ] +begin updateExternalStatsSync reason=get-stats + +[ 01-01 15:14:02.801 1000: 2272: 4464 E/BatteryStatsService ] +no controller energy info supplied + +[ 01-01 15:14:02.854 1000: 2272: 4464 D/BatteryStatsImpl ] +Reading cpu stats took 34 ms + +[ 01-01 15:14:02.881 1000: 2272: 4464 E/KernelMemoryBandwidthStats ] +Failed to read memory bandwidth: /sys/kernel/memory_state_time/show_stat (No such file or directory) + +[ 01-01 15:14:02.881 1000: 2272: 4464 D/BatteryStatsService ] +end updateExternalStatsSync + +--------- switch to main +[ 01-01 15:14:02.891 10038:18491:18491 I/MicroDetector ] +Keeping mic open: false + +[ 01-01 15:14:02.892 10038:18491:18549 I/MicroRecognitionRunner ] +Stopping hotword detection. + +[ 01-01 15:14:02.896 10038:18491:19006 I/DeviceStateChecker ] +DeviceStateChecker cancelled + +[ 01-01 15:14:02.897 10038:18491:19016 I/MicroRecognitionRunner ] +Detection finished + +[ 01-01 15:14:02.899 10038:18491:19007 I/AudioController ] +internalShutdown + +[ 01-01 15:14:02.900 10038:18491:19007 I/MicrophoneInputStream ] +mic_close com.google.android.apps.gsa.speech.audio.ag@4fc0a + +[ 01-01 15:14:02.997 1000: 2272: 3590 W/zygote64 ] +Long monitor contention with owner ActivityManager (3582) at void com.android.server.am.ActivityStackSupervisor$ActivityStackSupervisorHandler.activityIdleInternal(com.android.server.am.ActivityRecord, boolean)(ActivityStackSupervisor.java:4228) waiters=0 in void com.android.server.am.ActivityManagerService.notifyActivityDrawn(android.os.IBinder) for 178ms + +[ 01-01 15:14:02.997 1000: 2272: 3579 W/zygote64 ] +Long monitor contention with owner ActivityManager (3582) at void com.android.server.am.ActivityStackSupervisor$ActivityStackSupervisorHandler.activityIdleInternal(com.android.server.am.ActivityRecord, boolean)(ActivityStackSupervisor.java:4228) waiters=1 in boolean com.android.server.am.ActivityManagerService.unbindService(android.app.IServiceConnection) for 122ms + +[ 01-01 15:14:03.041 1041: 541:20182 D/audio_hw_primary ] +disable_audio_route: usecase(9) reset and update mixer path: audio-record + +[ 01-01 15:14:03.042 1041: 541:20182 D/audio_hw_primary ] +disable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:03.049 1041: 541:20182 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 0, rx 0, concurrency session_allowed 1 + +[ 01-01 15:14:03.054 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:03.240 1000:14206:20198 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:03.267 1000:14206:20198 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:03.269 1000:14206:20198 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +[ 01-01 15:14:03.456 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:03.495 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +[ 01-01 15:14:03.497 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:03.497 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:03.497 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:03.497 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:03.522 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:03.522 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +--------- switch to system +[ 01-01 15:14:03.529 1000: 2272: 3627 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 + +--------- switch to main +[ 01-01 15:14:03.581 10038: 4245: 4251 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:03.581 10038: 4245: 4251 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:03.585 1000:14206:14206 D/DashboardSummary ] +Stopped listening for condition changes + +[ 01-01 15:14:03.669 10038:18491:18672 I/AttachedClient ] +Adding client event 2 to pending list. + +[ 01-01 15:14:03.715 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:03.785 10038:18491:18491 I/MicroDetectionWorker ] +#updateMicroDetector [currentDetectionMode: [mDetectionMode: [1]]] + +[ 01-01 15:14:03.785 10038:18491:18491 I/MicroDetectionWorker ] +#startMicroDetector [speakerMode: 0] + +[ 01-01 15:14:03.805 10038:18491:19006 I/MicroRecognitionRunner ] +Starting detection. + +[ 01-01 15:14:03.806 10038:18491:18496 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:03.806 10038:18491:19008 I/MicrophoneInputStream ] +mic_starting com.google.android.apps.gsa.speech.audio.ag@85dd117 + +[ 01-01 15:14:03.813 1041: 541: 5248 W/DeviceHAL ] +Device 0xf4fad000 open_input_stream: Invalid argument + +[ 01-01 15:14:03.819 1041: 541:20213 I/AudioFlinger ] +AudioFlinger's thread 0xf1220e40 tid=20213 ready to run + +[ 01-01 15:14:03.836 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:03.837 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:03.837 10038:18491:19008 I/MicrophoneInputStream ] +mic_started com.google.android.apps.gsa.speech.audio.ag@85dd117 + +[ 01-01 15:14:03.841 1041: 541:20214 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 1, rx 0, concurrency session_allowed 0 + +[ 01-01 15:14:03.841 1041: 541:20214 D/audio_hw_primary ] +enable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:03.841 1041: 541:20214 D/audio_route ] +Apply path: voice-rec-mic + +[ 01-01 15:14:03.849 1041: 541:20214 D/audio_hw_primary ] +enable_audio_route: usecase(9) apply and update mixer path: audio-record + +[ 01-01 15:14:03.850 1041: 541:20214 D/audio_route ] +Apply path: audio-record + +[ 01-01 15:14:03.901 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:03.922 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:04.032 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:04.044 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:04.044 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +[ 01-01 15:14:04.045 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:04.159 10038: 4245: 4483 W/OpenGLRenderer ] +Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer... + +[ 01-01 15:14:04.446 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +--------- switch to system +[ 01-01 15:14:04.448 1000: 2272: 5447 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.android.settings/.Settings bnds=[435,1254][646,1507] (has extras)} from uid 10038 + +--------- switch to main +[ 01-01 15:14:04.448 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:04.449 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:04.449 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:04.449 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:04.457 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:04.480 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:04.480 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +[ 01-01 15:14:04.623 1000:14206:14206 D/DashboardSummary ] +Listening for condition changes + +[ 01-01 15:14:04.623 1000:14206:14206 D/DashboardSummary ] +onConditionsChanged + +[ 01-01 15:14:04.623 1000:14206:14206 D/DashboardAdapter ] +adapter setConditions called + +[ 01-01 15:14:04.624 1000:14206:14206 D/DashboardSummary ] +conditions refreshed + +[ 01-01 15:14:04.624 1000:14206:14206 D/APM_Condition ] +APM condition refreshed + +[ 01-01 15:14:04.624 1000:14206:14206 D/APM_Condition ] +setActive was called with false + +[ 01-01 15:14:04.712 1000:14206:20202 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 35 millis + +[ 01-01 15:14:04.738 1000:14206:20202 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 10 millis + +[ 01-01 15:14:04.837 1000:14206:20202 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:04.869 1000:14206:20202 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:04.870 1000:14206:20202 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +--------- switch to system +[ 01-01 15:14:04.898 1000: 2272: 3579 D/BatteryStatsService ] +begin updateExternalStatsSync reason=get-stats + +--------- switch to main +[ 01-01 15:14:04.908 1000: 2272: 5444 I/sensors ] +activate + +[ 01-01 15:14:04.916 1000: 2272: 5444 I/nanohub ] +queueActivate: sensor=1, handle=1, enable=0 + +[ 01-01 15:14:04.998 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:05.010 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:05.010 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +--------- switch to system +[ 01-01 15:14:05.022 1000: 2272: 3579 E/BatteryStatsService ] +no controller energy info supplied + +--------- switch to main +[ 01-01 15:14:05.040 1000: 2272: 3626 E/hw-IPCThreadState ] +binder thread pool (1 threads) starved for 116 ms + +--------- switch to system +[ 01-01 15:14:05.072 1000: 2272: 3579 D/BatteryStatsImpl ] +Reading cpu stats took 34 ms + +[ 01-01 15:14:05.098 1000: 2272: 3579 E/KernelMemoryBandwidthStats ] +Failed to read memory bandwidth: /sys/kernel/memory_state_time/show_stat (No such file or directory) + +[ 01-01 15:14:05.098 1000: 2272: 3579 D/BatteryStatsService ] +end updateExternalStatsSync + +--------- switch to main +[ 01-01 15:14:05.112 10038:18491:18491 I/MicroDetector ] +Keeping mic open: false + +[ 01-01 15:14:05.113 10038:18491:19016 I/DeviceStateChecker ] +DeviceStateChecker cancelled + +[ 01-01 15:14:05.119 10038:18491:19007 I/AudioController ] +internalShutdown + +[ 01-01 15:14:05.120 10038:18491:19007 I/MicrophoneInputStream ] +mic_close com.google.android.apps.gsa.speech.audio.ag@85dd117 + +[ 01-01 15:14:05.124 10038:18491:18549 I/MicroRecognitionRunner ] +Stopping hotword detection. + +[ 01-01 15:14:05.252 1041: 541:20213 D/audio_hw_primary ] +disable_audio_route: usecase(9) reset and update mixer path: audio-record + +[ 01-01 15:14:05.253 1041: 541:20213 D/audio_hw_primary ] +disable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:05.258 1041: 541:20213 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 0, rx 0, concurrency session_allowed 1 + +[ 01-01 15:14:05.263 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:05.267 10038:18491:19006 W/zygote64 ] +Long monitor contention with owner UserFacing4 (19007) at void android.media.AudioRecord.native_stop()(AudioRecord.java:-2) waiters=1 in void com.google.android.apps.gsa.speech.audio.an.reset(int) for 141ms + +[ 01-01 15:14:05.267 10038:18491:19006 I/MicroRecognitionRunner ] +Detection finished + +[ 01-01 15:14:05.457 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:05.465 1000:14206:20201 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:05.499 1000:14206:20201 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:05.500 1000:14206:20201 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +[ 01-01 15:14:05.564 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +[ 01-01 15:14:05.568 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:05.568 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:05.568 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:05.568 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:05.589 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:05.593 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:05.593 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +[ 01-01 15:14:05.598 1000:14206:14212 I/zygote64 ] +Integer.valueOf will not be optimized + +--------- switch to system +[ 01-01 15:14:05.603 1000: 2272: 3627 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 + +--------- switch to main +[ 01-01 15:14:05.658 1000:14206:14206 D/DashboardSummary ] +Stopped listening for condition changes + +[ 01-01 15:14:05.750 10038:18491:18504 I/AttachedClient ] +Adding client event 2 to pending list. + +[ 01-01 15:14:05.796 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:05.854 10038:18491:18491 I/MicroDetectionWorker ] +#updateMicroDetector [currentDetectionMode: [mDetectionMode: [1]]] + +[ 01-01 15:14:05.855 10038:18491:18491 I/MicroDetectionWorker ] +#startMicroDetector [speakerMode: 0] + +[ 01-01 15:14:05.883 10038:18491:19006 I/MicroRecognitionRunner ] +Starting detection. + +[ 01-01 15:14:05.884 10038:18491:19007 I/MicrophoneInputStream ] +mic_starting com.google.android.apps.gsa.speech.audio.ag@987bb93 + +[ 01-01 15:14:05.896 1041: 541: 5248 W/DeviceHAL ] +Device 0xf4fad000 open_input_stream: Invalid argument + +[ 01-01 15:14:05.906 1041: 541:20227 I/AudioFlinger ] +AudioFlinger's thread 0xf1220e80 tid=20227 ready to run + +[ 01-01 15:14:05.916 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:05.917 10038:18491:19007 I/MicrophoneInputStream ] +mic_started com.google.android.apps.gsa.speech.audio.ag@987bb93 + +[ 01-01 15:14:05.919 1041: 541:20228 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 1, rx 0, concurrency session_allowed 0 + +[ 01-01 15:14:05.919 1041: 541:20228 D/audio_hw_primary ] +enable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:05.919 1041: 541:20228 D/audio_route ] +Apply path: voice-rec-mic + +[ 01-01 15:14:05.927 1041: 541:20228 D/audio_hw_primary ] +enable_audio_route: usecase(9) apply and update mixer path: audio-record + +[ 01-01 15:14:05.927 1041: 541:20228 D/audio_route ] +Apply path: audio-record + +[ 01-01 15:14:05.936 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:05.981 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:06.029 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:06.112 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:06.123 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:06.123 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +[ 01-01 15:14:06.157 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:06.239 10038: 4245: 4483 W/OpenGLRenderer ] +Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer... + +[ 01-01 15:14:06.674 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1032): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +--------- switch to system +[ 01-01 15:14:06.931 1000: 2272: 3628 I/PowerManagerService ] +Going to sleep due to power button (uid 1000)... + +[ 01-01 15:14:07.432 1000: 2272: 3592 D/BatteryStatsService ] +begin noteScreenState + +[ 01-01 15:14:07.433 1000: 2272: 3592 D/BatteryStatsService ] +end noteScreenState + +[ 01-01 15:14:07.444 1000: 2272: 3582 I/VrManagerService ] +VR mode is disallowed + +--------- switch to main +[ 01-01 15:14:07.535 1000: 2272: 3592 I/sensors ] +activate + +[ 01-01 15:14:07.544 1000: 2272: 3592 I/nanohub ] +queueActivate: sensor=28, handle=30, enable=0 + +[ 01-01 15:14:07.545 1000: 2272: 3592 V/KeyguardServiceDelegate ] +onScreenTurnedOff() + +[ 01-01 15:14:07.547 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=0, state=3 + + +[ 01-01 15:14:07.548 1000: 2272: 3592 I/sensors ] +activate + +[ 01-01 15:14:07.550 1000: 2272: 3592 I/nanohub ] +queueActivate: sensor=12, handle=7, enable=0 + +--------- switch to system +[ 01-01 15:14:07.551 1000: 2272: 3590 I/DisplayManagerService ] +Display device changed state: "Built-in Screen", OFF + +--------- switch to main +[ 01-01 15:14:07.552 1000: 398: 398 D/SurfaceFlinger ] +Set power mode=0, type=0 flinger=0x7542c6c000 + +[ 01-01 15:14:07.555 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Setting mode 0 on display: 0 + +--------- switch to system +[ 01-01 15:14:07.565 1000: 2272: 3614 W/LocalDisplayAdapter ] +Unable to find color mode 0, ignoring request. + +--------- switch to main +[ 01-01 15:14:07.664 10038:18491:18491 I/MicroDetector ] +Keeping mic open: false + +[ 01-01 15:14:07.665 1000: 398: 462 I/qdhwcomposer ] +handle_blank_event: dpy:0 panel power state: 0 + +[ 01-01 15:14:07.665 10038:18491:19012 I/AudioController ] +internalShutdown + +[ 01-01 15:14:07.666 10038:18491:19012 I/MicrophoneInputStream ] +mic_close com.google.android.apps.gsa.speech.audio.ag@987bb93 + +[ 01-01 15:14:07.666 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Done setting mode 0 on display 0 + +[ 01-01 15:14:07.666 10038:18491:19016 I/DeviceStateChecker ] +DeviceStateChecker cancelled + +[ 01-01 15:14:07.666 1000: 2272: 3787 D/SurfaceControl ] +Excessive delay in setPowerMode(): 115ms + +--------- switch to system +[ 01-01 15:14:07.670 1000: 2272: 3592 I/DreamManagerService ] +Entering dreamland. + +--------- switch to main +[ 01-01 15:14:07.671 10038:18491:18549 I/MicroRecognitionRunner ] +Stopping hotword detection. + +--------- switch to system +[ 01-01 15:14:07.671 1000: 2272: 3592 I/PowerManagerService ] +Dozing... + +[ 01-01 15:14:07.673 1000: 2272: 3588 I/DreamController ] +Starting dream: name=ComponentInfo{com.android.systemui/com.android.systemui.doze.DozeService}, isTest=false, canDoze=true, userId=0 + +--------- switch to main +[ 01-01 15:14:07.710 1000: 2272: 5447 I/sensors ] +batch + +[ 01-01 15:14:07.711 1000: 2272: 5447 I/nanohub ] +queueBatch: sensor=24, handle=20, period=1000000, latency=0 + +[ 01-01 15:14:07.712 1000: 2272: 5447 I/sensors ] +activate + +[ 01-01 15:14:07.713 1000: 2272: 5447 I/nanohub ] +queueActivate: sensor=24, handle=20, enable=1 + +[ 01-01 15:14:07.717 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] power: 1 + + +[ 01-01 15:14:07.719 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=1, state=4 + + +[ 01-01 15:14:07.721 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=1, state=3 + + +[ 01-01 15:14:07.722 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] activity activity powered on, new state 2 + + +[ 01-01 15:14:07.730 1041: 541:20227 D/audio_hw_primary ] +disable_audio_route: usecase(9) reset and update mixer path: audio-record + +[ 01-01 15:14:07.731 1041: 541:20227 D/audio_hw_primary ] +disable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:07.735 1041: 541:20227 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 0, rx 0, concurrency session_allowed 1 + +[ 01-01 15:14:07.738 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:07.742 10038:18491:19006 I/MicroRecognitionRunner ] +Detection finished + +--------- switch to system +[ 01-01 15:14:07.769 1000: 2272: 4084 I/ActivityManager ] +Setting hasTopUi=true for pid=3812 + +--------- switch to main +[ 01-01 15:14:07.776 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:07.827 nfc: 4175: 4192 I/zygote64 ] +Background concurrent copying GC freed 96(1791KB) AllocSpace objects, 0(0B) LOS objects, 53% free, 1330KB/2MB, paused 6.135ms total 19.615ms + +[ 01-01 15:14:07.829 nfc: 4175: 4351 E/NxpTml ] +_i2c_write() errno : 5 + +[ 01-01 15:14:07.829 nfc: 4175: 4351 E/NxpTml ] +PN54X - Error in I2C Write..... + + +[ 01-01 15:14:07.829 nfc: 4175: 4353 E/NxpHal ] +write error status = 0x1ff + +[ 01-01 15:14:07.830 nfc: 4175: 4346 E/NxpHal ] +write_unlocked failed - PN54X Maybe in Standby Mode - Retry + +[ 01-01 15:14:07.831 nfc: 4175: 4351 E/NxpTml ] +_i2c_write() errno : 5 + +[ 01-01 15:14:07.831 nfc: 4175: 4351 E/NxpTml ] +PN54X - Error in I2C Write..... + + +[ 01-01 15:14:07.831 nfc: 4175: 4353 E/NxpHal ] +write error status = 0x1ff + +[ 01-01 15:14:07.831 nfc: 4175: 4346 E/NxpHal ] +write_unlocked failed - PN54X Maybe in Standby Mode - Retry + +[ 01-01 15:14:07.886 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:08.003 10036: 3812: 3812 D/StatusBar ] +disable: < expand icons alerts system_info back HOME* RECENT* clock search quick_settings > + +[ 01-01 15:14:08.108 10018: 5497:20188 E/ctxmgr ] +[WorkManager]Ongoing task not found: PlacesProducer_receive + +[ 01-01 15:14:08.776 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:09.777 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:10.001 1000: 2272: 4088 I/sensors ] +batch + +[ 01-01 15:14:10.007 1000: 2272: 4088 I/nanohub ] +queueBatch: sensor=1, handle=1, period=20000000, latency=0 + +[ 01-01 15:14:10.007 1000: 2272: 4088 I/sensors ] +activate + +[ 01-01 15:14:10.010 1000: 2272: 4088 I/nanohub ] +queueActivate: sensor=1, handle=1, enable=1 + +[ 01-01 15:14:10.778 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:12.776 10018: 5497:20188 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:12.842 1000: 2272: 5430 I/sensors ] +activate + +[ 01-01 15:14:12.845 10018: 5497:20187 I/PlaceInferenceEngine ] +[anon] Changed inference mode: 105 + +[ 01-01 15:14:12.851 10018: 5497: 5537 W/GCoreFlp ] +No location to return for getLastLocation() + +[ 01-01 15:14:12.857 1000: 2272: 5430 I/nanohub ] +queueActivate: sensor=1, handle=1, enable=0 + +[ 01-01 15:14:12.889 10018: 5497:20188 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:12.890 10018: 5497:19161 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:13.008 10018: 5497: 5502 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:14.351 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] sending event 0x00000001 + +[ 01-01 15:14:14.358 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] activity activity powered off, new state 0 + + +[ 01-01 15:14:14.361 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] power: 0 + + +[ 01-01 15:14:14.362 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=0, state=5 + + +[ 01-01 15:14:14.366 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=0, state=3 + + +[ 01-01 15:14:14.380 1000: 2272: 4219 I/sensors ] +batch + +[ 01-01 15:14:14.382 1000: 2272: 4219 I/nanohub ] +queueBatch: sensor=24, handle=20, period=1000000, latency=0 + +[ 01-01 15:14:14.383 1000: 2272: 4219 I/sensors ] +activate + +[ 01-01 15:14:14.385 1000: 2272: 4219 I/nanohub ] +queueActivate: sensor=24, handle=20, enable=1 + +[ 01-01 15:14:14.388 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] power: 1 + + +--------- switch to system +[ 01-01 15:14:14.389 1000: 2272: 3592 D/BatteryStatsService ] +begin noteScreenState + +[ 01-01 15:14:14.389 1000: 2272: 3592 D/BatteryStatsService ] +end noteScreenState + +[ 01-01 15:14:14.390 1000: 2272: 3592 I/DisplayPowerController ] +Blocking screen on until initial contents have been drawn. + +--------- switch to main +[ 01-01 15:14:14.391 1000: 2272: 3592 V/KeyguardServiceDelegate ] +onScreenTurnedOn(showListener = com.android.server.policy.PhoneWindowManager$2@cb6ff88) + +[ 01-01 15:14:14.393 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=1, state=4 + + +--------- switch to system +[ 01-01 15:14:14.394 1000: 2272: 3590 I/DisplayManagerService ] +Display device changed state: "Built-in Screen", DOZE + +--------- switch to main +[ 01-01 15:14:14.394 1000: 398: 398 D/SurfaceFlinger ] +Set power mode=1, type=0 flinger=0x7542c6c000 + +[ 01-01 15:14:14.395 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Setting mode 1 on display: 0 + +[ 01-01 15:14:14.396 1000: 2272: 3617 I/nanohub ] +osLog: [BMI160] accPower: on=1, state=3 + + +[ 01-01 15:14:14.398 1000: 2272: 4217 I/sensors ] +batch + +[ 01-01 15:14:14.400 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] activity activity powered on, new state 2 + + +[ 01-01 15:14:14.403 1000: 2272: 4217 I/nanohub ] +queueBatch: sensor=13, handle=6, period=200000000, latency=0 + +[ 01-01 15:14:14.404 1000: 2272: 4217 I/sensors ] +activate + +--------- switch to system +[ 01-01 15:14:14.405 1000: 2272: 3614 W/LocalDisplayAdapter ] +Unable to find color mode 0, ignoring request. + +--------- switch to main +[ 01-01 15:14:14.408 1000: 2272: 4217 I/nanohub ] +queueActivate: sensor=13, handle=6, enable=1 + +[ 01-01 15:14:14.421 1000: 2272: 5450 V/KeyguardServiceDelegate ] +**** SHOWN CALLED **** + +--------- switch to system +[ 01-01 15:14:14.514 1000: 2272: 3592 I/DisplayPowerController ] +Unblocked screen on after 124 ms + +--------- switch to main +[ 01-01 15:14:14.517 1000: 2272: 3592 V/KeyguardServiceDelegate ] +onScreenTurnedOn() + +[ 01-01 15:14:14.629 1000: 398: 462 I/qdhwcomposer ] +handle_blank_event: dpy:0 panel power state: 2 + +[ 01-01 15:14:14.629 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Done setting mode 1 on display 0 + +[ 01-01 15:14:14.650 1000: 2272: 3787 D/SurfaceControl ] +Excessive delay in setPowerMode(): 255ms + +--------- switch to system +[ 01-01 15:14:14.943 1000: 2272: 3628 I/PowerManagerService ] +Waking up from dozing (uid 1000)... + +--------- switch to main +[ 01-01 15:14:14.949 1000: 2272: 2272 I/sensors ] +batch + +--------- switch to system +[ 01-01 15:14:14.952 1000: 2272: 3592 D/BatteryStatsService ] +begin noteScreenState + +--------- switch to main +[ 01-01 15:14:14.953 1000: 2272: 2272 I/nanohub ] +queueBatch: sensor=28, handle=30, period=66667000, latency=0 + +[ 01-01 15:14:14.953 1000: 2272: 2272 I/sensors ] +activate + +--------- switch to system +[ 01-01 15:14:14.954 1000: 2272: 3592 D/BatteryStatsService ] +end noteScreenState + +--------- switch to main +[ 01-01 15:14:14.955 1000: 2272: 2272 I/nanohub ] +queueActivate: sensor=28, handle=30, enable=1 + +[ 01-01 15:14:14.955 1000: 2272: 2272 V/KeyguardServiceDelegate ] +onStartedWakingUp() + +[ 01-01 15:14:14.959 1000: 2272: 3592 I/sensors ] +batch + +[ 01-01 15:14:14.961 1000: 2272: 3592 I/nanohub ] +queueBatch: sensor=12, handle=7, period=250000000, latency=0 + +[ 01-01 15:14:14.961 1000: 2272: 3592 I/sensors ] +activate + +[ 01-01 15:14:14.962 1000: 2272: 3592 I/nanohub ] +queueActivate: sensor=12, handle=7, enable=1 + +--------- switch to system +[ 01-01 15:14:14.965 1000: 2272: 3590 I/DisplayManagerService ] +Display device changed state: "Built-in Screen", ON + +--------- switch to main +[ 01-01 15:14:14.966 1000: 398: 398 D/SurfaceFlinger ] +Set power mode=2, type=0 flinger=0x7542c6c000 + +[ 01-01 15:14:14.966 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Setting mode 2 on display: 0 + +[ 01-01 15:14:14.966 1000: 398: 462 I/qdhwcomposer ] +handle_blank_event: dpy:0 panel power state: 1 + +[ 01-01 15:14:14.966 1000: 398: 398 D/qdhwcomposer ] +hwc_setPowerMode: Done setting mode 2 on display 0 + +--------- switch to system +[ 01-01 15:14:14.970 1000: 2272: 3592 I/DreamManagerService ] +Gently waking up from dream. + +[ 01-01 15:14:14.975 1000: 2272: 3614 W/LocalDisplayAdapter ] +Unable to find color mode 0, ignoring request. + +--------- switch to main +[ 01-01 15:14:14.978 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +--------- switch to system +[ 01-01 15:14:14.998 1000: 2272: 5401 I/DreamManagerService ] +Leaving dreamland. + +[ 01-01 15:14:15.000 1000: 2272: 3588 I/DreamController ] +Stopping dream: name=ComponentInfo{com.android.systemui/com.android.systemui.doze.DozeService}, isTest=false, canDoze=true, userId=0 + +--------- switch to main +[ 01-01 15:14:15.007 1000: 2272: 5430 I/sensors ] +activate + +[ 01-01 15:14:15.008 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_SET_TECH_CFG_EVT; status=0x0 + +[ 01-01 15:14:15.008 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_SET_PROTO_CFG_EVT; status=0x0 + +[ 01-01 15:14:15.008 nfc: 4175:20249 D/BrcmNfcJni ] +RoutingManager::commitRouting + +[ 01-01 15:14:15.009 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_UPDATED_EVT + +[ 01-01 15:14:15.010 1000: 2272: 5430 I/nanohub ] +queueActivate: sensor=24, handle=20, enable=0 + +[ 01-01 15:14:15.011 nfc: 4175: 4351 E/NxpTml ] +_i2c_write() errno : 5 + +[ 01-01 15:14:15.011 nfc: 4175: 4351 E/NxpTml ] +PN54X - Error in I2C Write..... + + +[ 01-01 15:14:15.011 nfc: 4175: 4353 E/NxpHal ] +write error status = 0x1ff + +[ 01-01 15:14:15.011 nfc: 4175: 4346 E/NxpHal ] +write_unlocked failed - PN54X Maybe in Standby Mode - Retry + +[ 01-01 15:14:15.014 1000: 2272: 3617 I/nanohub ] +osLog: [PickupGesture] power: 0 + + +[ 01-01 15:14:15.019 1000: 2272: 3617 I/nanohub ] +osLog: [Activity] activity activity powered off, new state 0 + + +[ 01-01 15:14:15.045 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:15.069 10036: 3812: 3819 I/chatty ] +uid=10036(u0_a36) Jit thread pool identical 2 lines + +[ 01-01 15:14:15.070 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:15.098 10018: 5497: 5502 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:15.098 10018: 5497: 5502 I/chatty ] +uid=10018(u0_a18) Jit thread pool identical 1 line + +[ 01-01 15:14:15.098 10018: 5497: 5502 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:15.306 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:15.324 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:15.393 1000: 2272: 3617 I/nanohub ] +osLog: [WO] rotation changed to: ******* 0 ******* + + +[ 01-01 15:14:15.978 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:16.106 10036: 3812: 3812 D/StatusBar ] +disable: < expand icons alerts system_info back HOME RECENT clock search quick_settings > + +--------- switch to system +[ 01-01 15:14:16.196 1000: 2272: 3582 I/VrManagerService ] +VR mode is allowed + +--------- switch to main +[ 01-01 15:14:16.197 10036: 3812: 3812 D/StatusBar ] +disable: < expand icons alerts system_info back HOME RECENT clock search quick_settings > + +[ 01-01 15:14:16.382 1000: 2272: 4465 I/sensors ] +activate + +[ 01-01 15:14:16.384 1000: 2272: 4465 I/nanohub ] +queueActivate: sensor=13, handle=6, enable=0 + +[ 01-01 15:14:16.423 nfc: 4175: 4351 E/NxpTml ] +_i2c_write() errno : 5 + +[ 01-01 15:14:16.423 nfc: 4175: 4351 E/NxpTml ] +PN54X - Error in I2C Write..... + + +[ 01-01 15:14:16.423 nfc: 4175: 4353 E/NxpHal ] +write error status = 0x1ff + +[ 01-01 15:14:16.423 nfc: 4175: 4346 E/NxpHal ] +write_unlocked failed - PN54X Maybe in Standby Mode - Retry + +[ 01-01 15:14:16.428 nfc: 4175: 4346 E/BrcmNfcJni ] +nfaConnectionCallback: unknown event ???? + +[ 01-01 15:14:16.428 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_SET_TECH_CFG_EVT; status=0x0 + +[ 01-01 15:14:16.430 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_SET_PROTO_CFG_EVT; status=0x0 + +[ 01-01 15:14:16.430 nfc: 4175:20146 D/BrcmNfcJni ] +RoutingManager::commitRouting + +[ 01-01 15:14:16.430 nfc: 4175: 4346 D/BrcmNfcJni ] +RoutingManager::nfaEeCallback: NFA_EE_UPDATED_EVT + +[ 01-01 15:14:16.484 10038:18491:18504 I/AttachedClient ] +Adding client event 2 to pending list. + +[ 01-01 15:14:16.486 10038:18491:18504 I/AttachedClient ] +Adding client event 2 to pending list. + +[ 01-01 15:14:16.520 10038:18491:19642 W/LocationOracle ] +No location history returned by ContextManager + +[ 01-01 15:14:16.525 10036: 3812: 3812 D/StatusBar ] +disable: < expand icons alerts system_info back home* recent* clock search quick_settings > + +[ 01-01 15:14:16.537 10038:18491:18491 I/MicroDetectionWorker ] +#updateMicroDetector [currentDetectionMode: [mDetectionMode: [1]]] + +[ 01-01 15:14:16.538 10038:18491:18491 I/MicroDetectionWorker ] +#startMicroDetector [speakerMode: 0] + +[ 01-01 15:14:16.563 10038:18491:20275 I/MicroRecognitionRunner ] +Starting detection. + +[ 01-01 15:14:16.564 10038:18491:19007 I/MicrophoneInputStream ] +mic_starting com.google.android.apps.gsa.speech.audio.ag@bde1866 + +[ 01-01 15:14:16.565 10038:18491:18496 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:16.565 10038:18491:18496 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:16.567 1041: 541: 5248 W/DeviceHAL ] +Device 0xf4fad000 open_input_stream: Invalid argument + +[ 01-01 15:14:16.578 1041: 541:20278 I/AudioFlinger ] +AudioFlinger's thread 0xf12208c0 tid=20278 ready to run + +[ 01-01 15:14:16.584 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:16.585 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.590 10038:18491:19007 I/MicrophoneInputStream ] +mic_started com.google.android.apps.gsa.speech.audio.ag@bde1866 + +[ 01-01 15:14:16.591 1041: 541:20279 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 1, rx 0, concurrency session_allowed 0 + +[ 01-01 15:14:16.591 1041: 541:20279 D/audio_hw_primary ] +enable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:16.591 1041: 541:20279 D/audio_route ] +Apply path: voice-rec-mic + +[ 01-01 15:14:16.591 10018: 5497: 5537 W/GCoreFlp ] +No location to return for getLastLocation() + +[ 01-01 15:14:16.604 10038: 4245: 4251 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:16.610 1041: 541:20279 D/audio_hw_primary ] +enable_audio_route: usecase(9) apply and update mixer path: audio-record + +[ 01-01 15:14:16.611 1041: 541:20279 D/audio_route ] +Apply path: audio-record + +[ 01-01 15:14:16.613 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.616 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:16.617 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.636 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.638 10038:18491:18502 I/zygote64 ] +Background concurrent copying GC freed 1017(3MB) AllocSpace objects, 1(68KB) LOS objects, 50% free, 8MB/16MB, paused 2.320ms total 118.207ms + +[ 01-01 15:14:16.648 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.665 10018: 4514: 4514 I/chatty ] +uid=10018(u0_a18) com.google.android.gms identical 2 lines + +[ 01-01 15:14:16.670 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.677 root: 600: 600 W/thermal-engine ] +type=1400 audit(0.0:1033): avc: denied { search } for name="leds" dev="sysfs" ino=7453 scontext=u:r:thermal-engine:s0 tcontext=u:object_r:sysfs_leds:s0 tclass=dir permissive=0 + +[ 01-01 15:14:16.681 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:16.709 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.728 10018: 4514: 4514 I/chatty ] +uid=10018(u0_a18) com.google.android.gms identical 2 lines + +[ 01-01 15:14:16.735 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.743 10018: 5497:19161 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:16.747 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.796 10018: 4514: 4514 I/chatty ] +uid=10018(u0_a18) com.google.android.gms identical 6 lines + +[ 01-01 15:14:16.801 10018: 4514: 4514 I/DeviceCache ] +Unable to convert the the network interface's MAC Address to string. MAC address cannot be null. + +[ 01-01 15:14:16.803 10038: 4245: 4483 W/OpenGLRenderer ] +Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer... + +--------- switch to system +[ 01-01 15:14:16.937 1000: 2272: 3579 I/ActivityManager ] +Setting hasTopUi=false for pid=3812 + +--------- switch to main +[ 01-01 15:14:16.980 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:16.988 10018: 5497:19840 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:16.990 10018: 5497:20283 I/PlaceInferenceEngine ] +[anon] Changed inference mode: 105 + +[ 01-01 15:14:16.993 10018: 5497:19161 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:17.009 10018: 5497: 5537 W/GCoreFlp ] +No location to return for getLastLocation() + +[ 01-01 15:14:17.041 10018: 5497:19161 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:17.107 10018: 5497:20188 W/ctxmgr ] +[AclManager]No 3 for (accnt=account#-517948760#, com.google.android.googlequicksearchbox(10038):com.google.android.googlequicksearchbox, vrsn=10298000, 1, 3pPkg = null , 3pMdlId = null). Was: 3 for 18, account#-517948760# + +[ 01-01 15:14:17.108 1000: 2272: 3832 I/sensors ] +batch + +[ 01-01 15:14:17.110 1000: 2272: 3832 I/nanohub ] +queueBatch: sensor=1, handle=1, period=20000000, latency=0 + +[ 01-01 15:14:17.110 1000: 2272: 3832 I/sensors ] +activate + +[ 01-01 15:14:17.111 1000: 2272: 3832 I/nanohub ] +queueActivate: sensor=1, handle=1, enable=1 + +[ 01-01 15:14:17.139 10018: 5497:20188 E/ctxmgr ] +[ProducerStatusImpl]updateStateForNewContextData: inactive, contextName=7 + +[ 01-01 15:14:17.165 10018: 5497:20284 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:17.187 10018: 5497:19161 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:17.224 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +[ 01-01 15:14:17.227 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +--------- switch to system +[ 01-01 15:14:17.227 1000: 2272: 5431 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.android.settings/.Settings bnds=[435,1254][646,1507] (has extras)} from uid 10038 + +--------- switch to main +[ 01-01 15:14:17.227 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:17.227 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:17.227 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:17.250 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:17.250 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +[ 01-01 15:14:17.251 10018: 5497: 5506 E/StrictMode ] +A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks. +java.lang.Throwable: Explicit termination method 'close' not called + at dalvik.system.CloseGuard.open(CloseGuard.java:223) + at java.io.FileOutputStream.(FileOutputStream.java:224) + at android.app.ContextImpl.openFileOutput(ContextImpl.java:513) + at android.content.ContextWrapper.openFileOutput(ContextWrapper.java:195) + at android.content.ContextWrapper.openFileOutput(ContextWrapper.java:195) + at android.content.ContextWrapper.openFileOutput(ContextWrapper.java:195) + at android.content.ContextWrapper.openFileOutput(ContextWrapper.java:195) + at lts.c(:com.google.android.gms:96) + at lts.a(:com.google.android.gms:55) + at com.google.android.gms.icing.proxy.ApplicationLauncherIntentOperation.onHandleIntent(:com.google.android.gms:5192) + at com.google.android.chimera.IntentOperation.onHandleIntent(:com.google.android.gms:118) + at caz.run(:com.google.android.gms:10864) + at caw.run(:com.google.android.gms:1143) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +[ 01-01 15:14:17.252 10018: 5497:20283 I/Places ] +?: PlacesBleScanner start() with priority 2 + +[ 01-01 15:14:17.252 10018: 5497:20283 I/PlaceInferenceEngine ] +[anon] Changed inference mode: 102 + +[ 01-01 15:14:17.253 10018: 5497:20283 W/Places ] +?: Failed to download inference model weights + + +[ 01-01 15:14:17.253 10018: 5497:20283 W/PlaceInferenceEngine ] +Failed to download model weights. Status code: 7 + +[ 01-01 15:14:17.264 10018: 5497:20188 I/Places ] +?: Couldn't find platform key file. + +[ 01-01 15:14:17.352 10018: 5497: 5537 W/GCoreFlp ] +No location to return for getLastLocation() + +[ 01-01 15:14:17.458 1000:14206:14206 D/DashboardSummary ] +Listening for condition changes + +[ 01-01 15:14:17.458 1000:14206:14206 D/DashboardSummary ] +onConditionsChanged + +[ 01-01 15:14:17.458 1000:14206:14206 D/DashboardAdapter ] +adapter setConditions called + +[ 01-01 15:14:17.459 1000:14206:14206 D/DashboardSummary ] +conditions refreshed + +[ 01-01 15:14:17.459 1000:14206:14206 D/APM_Condition ] +APM condition refreshed + +[ 01-01 15:14:17.459 1000:14206:14206 D/APM_Condition ] +setActive was called with false + +[ 01-01 15:14:17.559 1000:14206:20203 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 60 millis + +[ 01-01 15:14:17.596 1000:14206:20203 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 22 millis + +[ 01-01 15:14:17.699 1000:14206:20203 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:17.727 1000:14206:20203 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:17.728 1000:14206:20203 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +--------- switch to system +[ 01-01 15:14:17.745 1000: 2272: 5448 D/BatteryStatsService ] +begin updateExternalStatsSync reason=get-stats + +--------- switch to main +[ 01-01 15:14:17.748 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:17.760 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:17.760 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +--------- switch to system +[ 01-01 15:14:17.764 1000: 2272: 5448 E/BatteryStatsService ] +no controller energy info supplied + +[ 01-01 15:14:17.817 1000: 2272: 5448 D/BatteryStatsImpl ] +Reading cpu stats took 34 ms + +[ 01-01 15:14:17.843 1000: 2272: 5448 E/KernelMemoryBandwidthStats ] +Failed to read memory bandwidth: /sys/kernel/memory_state_time/show_stat (No such file or directory) + +[ 01-01 15:14:17.843 1000: 2272: 5448 D/BatteryStatsService ] +end updateExternalStatsSync + +--------- switch to main +[ 01-01 15:14:17.894 10038:18491:18491 I/MicroDetector ] +Keeping mic open: false + +[ 01-01 15:14:17.895 10038:18491:19006 I/DeviceStateChecker ] +DeviceStateChecker cancelled + +[ 01-01 15:14:17.896 10038:18491:19012 I/AudioController ] +internalShutdown + +[ 01-01 15:14:17.896 10038:18491:19012 I/MicrophoneInputStream ] +mic_close com.google.android.apps.gsa.speech.audio.ag@bde1866 + +[ 01-01 15:14:17.899 10038:18491:18549 I/MicroRecognitionRunner ] +Stopping hotword detection. + +[ 01-01 15:14:17.964 1000:14206:14212 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:17.982 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:18.003 1041: 541:20278 D/audio_hw_primary ] +disable_audio_route: usecase(9) reset and update mixer path: audio-record + +[ 01-01 15:14:18.004 1041: 541:20278 D/audio_hw_primary ] +disable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:18.008 1041: 541:20278 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 0, rx 0, concurrency session_allowed 1 + +[ 01-01 15:14:18.010 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:18.013 10038:18491:20275 I/MicroRecognitionRunner ] +Detection finished + +[ 01-01 15:14:18.203 1000:14206:20198 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:18.230 1000:14206:20198 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:18.231 1000:14206:20198 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +[ 01-01 15:14:18.311 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +[ 01-01 15:14:18.313 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:18.313 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:18.313 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:18.313 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:18.339 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:18.339 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +--------- switch to system +[ 01-01 15:14:18.417 1000: 2272: 3627 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 + +--------- switch to main +[ 01-01 15:14:18.467 1000:14206:14206 D/DashboardSummary ] +Stopped listening for condition changes + +[ 01-01 15:14:18.539 10038:18491:18504 I/AttachedClient ] +Adding client event 2 to pending list. + +[ 01-01 15:14:18.582 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:18.630 10038:18491:18491 I/MicroDetectionWorker ] +#updateMicroDetector [currentDetectionMode: [mDetectionMode: [1]]] + +[ 01-01 15:14:18.630 10038:18491:18491 I/MicroDetectionWorker ] +#startMicroDetector [speakerMode: 0] + +[ 01-01 15:14:18.647 10038:18491:20275 I/MicroRecognitionRunner ] +Starting detection. + +[ 01-01 15:14:18.650 10038:18491:19012 I/MicrophoneInputStream ] +mic_starting com.google.android.apps.gsa.speech.audio.ag@e61439e + +[ 01-01 15:14:18.652 1041: 541:18637 W/DeviceHAL ] +Device 0xf4fad000 open_input_stream: Invalid argument + +[ 01-01 15:14:18.654 1041: 541:20301 I/AudioFlinger ] +AudioFlinger's thread 0xf19aa340 tid=20301 ready to run + +[ 01-01 15:14:18.661 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:18.662 10038:18491:18496 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:18.675 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:18.676 10038:18491:19012 I/MicrophoneInputStream ] +mic_started com.google.android.apps.gsa.speech.audio.ag@e61439e + +[ 01-01 15:14:18.681 1041: 541:20302 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 1, rx 0, concurrency session_allowed 0 + +[ 01-01 15:14:18.681 1041: 541:20302 D/audio_hw_primary ] +enable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:18.681 1041: 541:20302 D/audio_route ] +Apply path: voice-rec-mic + +[ 01-01 15:14:18.687 1041: 541:20302 D/audio_hw_primary ] +enable_audio_route: usecase(9) apply and update mixer path: audio-record + +[ 01-01 15:14:18.687 1041: 541:20302 D/audio_route ] +Apply path: audio-record + +[ 01-01 15:14:18.689 1000: 2272: 2282 I/zygote64 ] +Background concurrent copying GC freed 31100(11MB) AllocSpace objects, 6(240KB) LOS objects, 42% free, 16MB/28MB, paused 299us total 106.777ms + +[ 01-01 15:14:18.745 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:18.780 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:18.859 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:18.874 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:18.874 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +[ 01-01 15:14:18.911 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:19.034 10038: 4245: 4483 W/OpenGLRenderer ] +Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer... + +[ 01-01 15:14:19.215 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +--------- switch to system +[ 01-01 15:14:19.216 1000: 2272: 3832 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.android.settings/.Settings bnds=[435,1254][646,1507] (has extras)} from uid 10038 + +--------- switch to main +[ 01-01 15:14:19.219 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:19.220 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:19.220 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:19.220 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:19.245 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:19.245 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +[ 01-01 15:14:19.384 1000:14206:14206 D/DashboardSummary ] +Listening for condition changes + +[ 01-01 15:14:19.384 1000:14206:14206 D/DashboardSummary ] +onConditionsChanged + +[ 01-01 15:14:19.385 1000:14206:14206 D/DashboardAdapter ] +adapter setConditions called + +[ 01-01 15:14:19.385 1000:14206:14206 D/DashboardSummary ] +conditions refreshed + +[ 01-01 15:14:19.385 1000:14206:14206 D/APM_Condition ] +APM condition refreshed + +[ 01-01 15:14:19.385 1000:14206:14206 D/APM_Condition ] +setActive was called with false + +[ 01-01 15:14:19.455 1000:14206:20201 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 22 millis + +[ 01-01 15:14:19.497 1000:14206:20201 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 23 millis + +[ 01-01 15:14:19.600 1000:14206:20201 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:19.636 1000:14206:20201 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:19.638 1000:14206:20201 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +--------- switch to system +[ 01-01 15:14:19.660 1000: 2272: 5448 D/BatteryStatsService ] +begin updateExternalStatsSync reason=get-stats + +[ 01-01 15:14:19.681 1000: 2272: 5448 E/BatteryStatsService ] +no controller energy info supplied + +[ 01-01 15:14:19.737 1000: 2272: 5448 D/BatteryStatsImpl ] +Reading cpu stats took 34 ms + +--------- switch to main +[ 01-01 15:14:19.759 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +--------- switch to system +[ 01-01 15:14:19.764 1000: 2272: 5448 E/KernelMemoryBandwidthStats ] +Failed to read memory bandwidth: /sys/kernel/memory_state_time/show_stat (No such file or directory) + +[ 01-01 15:14:19.764 1000: 2272: 5448 D/BatteryStatsService ] +end updateExternalStatsSync + +--------- switch to main +[ 01-01 15:14:19.772 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:19.772 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +[ 01-01 15:14:19.981 10038:18491:18491 I/MicroDetector ] +Keeping mic open: false + +[ 01-01 15:14:19.982 10038:18491:19007 I/AudioController ] +internalShutdown + +[ 01-01 15:14:19.983 10038:18491:18549 I/MicroRecognitionRunner ] +Stopping hotword detection. + +[ 01-01 15:14:19.987 10038:18491:20275 I/MicroRecognitionRunner ] +Detection finished + +[ 01-01 15:14:19.989 10038:18491:19006 I/DeviceStateChecker ] +DeviceStateChecker cancelled + +[ 01-01 15:14:19.990 10038:18491:19007 I/MicrophoneInputStream ] +mic_close com.google.android.apps.gsa.speech.audio.ag@e61439e + +[ 01-01 15:14:20.045 1041: 541:20301 D/audio_hw_primary ] +disable_audio_route: usecase(9) reset and update mixer path: audio-record + +[ 01-01 15:14:20.046 1041: 541:20301 D/audio_hw_primary ] +disable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:20.051 1041: 541:20301 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 0, rx 0, concurrency session_allowed 1 + +[ 01-01 15:14:20.053 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:20.153 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:20.153 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +[ 01-01 15:14:20.156 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:20.156 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:20.156 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:20.157 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:20.165 1000:14206:20202 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:20.180 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:20.181 10036: 3812: 3819 I/chatty ] +uid=10036(u0_a36) Jit thread pool identical 3 lines + +[ 01-01 15:14:20.181 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:20.185 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:20.185 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +[ 01-01 15:14:20.199 1000:14206:20202 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:20.200 1000:14206:20202 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +--------- switch to system +[ 01-01 15:14:20.204 1000: 2272: 3627 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 + +--------- switch to main +[ 01-01 15:14:20.346 1000:14206:14206 D/DashboardSummary ] +Stopped listening for condition changes + +[ 01-01 15:14:20.352 10038:18491:18672 I/AttachedClient ] +Adding client event 2 to pending list. + +[ 01-01 15:14:20.392 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:20.466 1000: 2272: 4217 W/zygote64 ] +Long monitor contention with owner Binder:2272_4 (3832) at void com.android.server.am.ActivityManagerService.activityIdle(android.os.IBinder, android.content.res.Configuration, boolean)(ActivityManagerService.java:6920) waiters=2 in int com.android.server.am.ActivityManagerService.getLastResumedActivityUserId() for 103ms + +[ 01-01 15:14:20.492 10038:18491:18491 I/MicroDetectionWorker ] +#updateMicroDetector [currentDetectionMode: [mDetectionMode: [1]]] + +[ 01-01 15:14:20.492 10038:18491:18491 I/MicroDetectionWorker ] +#startMicroDetector [speakerMode: 0] + +[ 01-01 15:14:20.511 10038:18491:19006 I/MicroRecognitionRunner ] +Starting detection. + +[ 01-01 15:14:20.512 10038:18491:19007 I/MicrophoneInputStream ] +mic_starting com.google.android.apps.gsa.speech.audio.ag@cdae8fe + +[ 01-01 15:14:20.513 1041: 541:18637 W/DeviceHAL ] +Device 0xf4fad000 open_input_stream: Invalid argument + +[ 01-01 15:14:20.515 1041: 541:20313 I/AudioFlinger ] +AudioFlinger's thread 0xf19a7500 tid=20313 ready to run + +[ 01-01 15:14:20.542 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:20.543 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:20.544 10038:18491:19007 I/MicrophoneInputStream ] +mic_started com.google.android.apps.gsa.speech.audio.ag@cdae8fe + +[ 01-01 15:14:20.545 1041: 541:20314 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 1, rx 0, concurrency session_allowed 0 + +[ 01-01 15:14:20.545 1041: 541:20314 D/audio_hw_primary ] +enable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:20.545 1041: 541:20314 D/audio_route ] +Apply path: voice-rec-mic + +[ 01-01 15:14:20.552 1041: 541:20314 D/audio_hw_primary ] +enable_audio_route: usecase(9) apply and update mixer path: audio-record + +[ 01-01 15:14:20.552 1041: 541:20314 D/audio_route ] +Apply path: audio-record + +[ 01-01 15:14:20.613 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:20.618 1000: 2272: 4088 I/sensors ] +activate + +[ 01-01 15:14:20.621 1000: 2272: 4088 I/nanohub ] +queueActivate: sensor=1, handle=1, enable=0 + +[ 01-01 15:14:20.638 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:20.705 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:20.716 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:20.716 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +[ 01-01 15:14:20.755 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:20.843 10038: 4245: 4483 W/OpenGLRenderer ] +Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer... + +[ 01-01 15:14:21.055 1000: 2272: 4464 D/WificondControl ] +Scan result ready event + +[ 01-01 15:14:21.096 1000: 2272: 3755 W/WifiConfigManager ] +Looking up network with invalid networkId -1 + +[ 01-01 15:14:21.153 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:21.980 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +--------- switch to system +[ 01-01 15:14:21.982 1000: 2272: 5450 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.android.settings/.Settings bnds=[435,1254][646,1507] (has extras)} from uid 10038 + +--------- switch to main +[ 01-01 15:14:21.983 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:21.983 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:21.983 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:21.983 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:22.016 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:22.016 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +[ 01-01 15:14:22.154 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:22.182 1000:14206:14206 D/DashboardSummary ] +Listening for condition changes + +[ 01-01 15:14:22.183 1000:14206:14206 D/DashboardSummary ] +onConditionsChanged + +[ 01-01 15:14:22.183 1000:14206:14206 D/DashboardAdapter ] +adapter setConditions called + +[ 01-01 15:14:22.183 1000:14206:14206 D/DashboardSummary ] +conditions refreshed + +[ 01-01 15:14:22.183 1000:14206:14206 D/APM_Condition ] +APM condition refreshed + +[ 01-01 15:14:22.183 1000:14206:14206 D/APM_Condition ] +setActive was called with false + +[ 01-01 15:14:22.258 1000:14206:20201 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 42 millis + +[ 01-01 15:14:22.292 1000:14206:20201 D/DatabaseIndexingManager ] +Indexing locale 'en_US' took 19 millis + +[ 01-01 15:14:22.397 1000:14206:20201 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:22.429 1000:14206:20201 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:22.430 1000:14206:20201 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +--------- switch to system +[ 01-01 15:14:22.448 1000: 2272: 4217 D/BatteryStatsService ] +begin updateExternalStatsSync reason=get-stats + +--------- switch to main +[ 01-01 15:14:22.525 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:22.541 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:22.541 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +--------- switch to system +[ 01-01 15:14:22.551 1000: 2272: 4217 E/BatteryStatsService ] +no controller energy info supplied + +[ 01-01 15:14:22.601 1000: 2272: 4217 D/BatteryStatsImpl ] +Reading cpu stats took 35 ms + +[ 01-01 15:14:22.627 1000: 2272: 4217 E/KernelMemoryBandwidthStats ] +Failed to read memory bandwidth: /sys/kernel/memory_state_time/show_stat (No such file or directory) + +[ 01-01 15:14:22.628 1000: 2272: 4217 D/BatteryStatsService ] +end updateExternalStatsSync + +--------- switch to main +[ 01-01 15:14:22.642 10038:18491:18491 I/MicroDetector ] +Keeping mic open: false + +[ 01-01 15:14:22.642 10038:18491:19012 I/AudioController ] +internalShutdown + +[ 01-01 15:14:22.643 10038:18491:19012 I/MicrophoneInputStream ] +mic_close com.google.android.apps.gsa.speech.audio.ag@cdae8fe + +[ 01-01 15:14:22.644 10038:18491:18549 I/MicroRecognitionRunner ] +Stopping hotword detection. + +[ 01-01 15:14:22.649 10038:18491:20275 I/DeviceStateChecker ] +DeviceStateChecker cancelled + +[ 01-01 15:14:22.736 1000: 2272: 3582 W/zygote64 ] +Long monitor contention with owner Binder:2272_7 (4217) at android.os.ParcelFileDescriptor com.android.server.am.BatteryStatsService.getStatisticsStream()(BatteryStatsService.java:378) waiters=0 in boolean com.android.server.am.ActivityManagerService.applyOomAdjLocked(com.android.server.am.ProcessRecord, boolean, long, long) for 108ms + +[ 01-01 15:14:22.790 1041: 541:20313 D/audio_hw_primary ] +disable_audio_route: usecase(9) reset and update mixer path: audio-record + +[ 01-01 15:14:22.791 1041: 541:20313 D/audio_hw_primary ] +disable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:22.798 1041: 541:20313 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 0, rx 0, concurrency session_allowed 1 + +[ 01-01 15:14:22.799 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:22.804 10038:18491:18549 W/zygote64 ] +Long monitor contention with owner UserFacing6 (19012) at void android.media.AudioRecord.native_stop()(AudioRecord.java:-2) waiters=0 in void com.google.android.apps.gsa.speech.audio.an.reset(int) for 154ms + +[ 01-01 15:14:22.805 10038:18491:19006 I/MicroRecognitionRunner ] +Detection finished + +[ 01-01 15:14:22.936 1041: 541: 5252 D/audio_route ] +Apply path: speaker-protected + +[ 01-01 15:14:22.938 1041: 541: 5252 D/audio_hw_primary ] +enable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:22.938 1041: 541: 5252 D/audio_route ] +Apply path: vi-feedback + +[ 01-01 15:14:22.938 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(23) apply and update mixer path: spkr-vi-record + +[ 01-01 15:14:22.938 1041: 541: 5252 D/audio_route ] +Apply path: spkr-vi-record + +[ 01-01 15:14:22.969 1041: 541: 5252 D/audio_hw_primary ] +enable_audio_route: usecase(1) apply and update mixer path: low-latency-playback + +[ 01-01 15:14:22.969 1041: 541: 5252 D/audio_route ] +Apply path: low-latency-playback + +[ 01-01 15:14:23.024 1000:14206:20198 I/SuggestionParser ] +Use your voice requires unavailable account type com.google + +[ 01-01 15:14:23.062 1000:14206:20198 W/Bundle ] +Key com.android.settings.dismiss expected String but value was a java.lang.Integer. The default value was returned. + +[ 01-01 15:14:23.063 1000:14206:20198 W/Bundle ] +Attempt to cast generated internal exception: +java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String + at android.os.BaseBundle.getString(BaseBundle.java:1072) + at com.android.settingslib.SuggestionParser.getDismissControl(SuggestionParser.java:377) + at com.android.settingslib.SuggestionParser.isDismissed(SuggestionParser.java:330) + at com.android.settingslib.SuggestionParser.filterSuggestions(SuggestionParser.java:187) + at com.android.settingslib.SuggestionParser.readSuggestions(SuggestionParser.java:204) + at com.android.settingslib.SuggestionParser.getSuggestions(SuggestionParser.java:151) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:260) + at com.android.settings.dashboard.DashboardSummary$SuggestionLoader.doInBackground(DashboardSummary.java:255) + at android.os.AsyncTask$2.call(AsyncTask.java:305) + at java.util.concurrent.FutureTask.run(FutureTask.java:266) + at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243) + at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) + at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) + at java.lang.Thread.run(Thread.java:764) + + +--------- switch to system +[ 01-01 15:14:23.066 1000: 2272: 3627 I/ActivityManager ] +START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 + +--------- switch to main +[ 01-01 15:14:23.120 1000:14206:14206 D/DashboardSummary ] +Stopped listening for condition changes + +[ 01-01 15:14:23.156 1041: 541: 678 I/ServiceManager ] +Waiting for service media.log... + +[ 01-01 15:14:23.242 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:23.249 10038:18491:18504 I/AttachedClient ] +Adding client event 2 to pending list. + +[ 01-01 15:14:23.317 10036: 3812: 3819 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:23.320 10038:18491:18491 I/MicroDetectionWorker ] +#updateMicroDetector [currentDetectionMode: [mDetectionMode: [1]]] + +[ 01-01 15:14:23.321 10038:18491:18491 I/MicroDetectionWorker ] +#startMicroDetector [speakerMode: 0] + +[ 01-01 15:14:23.331 10038:18491:18496 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:23.337 10038:18491:20275 I/MicroRecognitionRunner ] +Starting detection. + +[ 01-01 15:14:23.339 10038:18491:19012 I/MicrophoneInputStream ] +mic_starting com.google.android.apps.gsa.speech.audio.ag@681da37 + +[ 01-01 15:14:23.341 1041: 541: 742 W/DeviceHAL ] +Device 0xf4fad000 open_input_stream: Invalid argument + +[ 01-01 15:14:23.352 1041: 541:20329 I/AudioFlinger ] +AudioFlinger's thread 0xf19a7f40 tid=20329 ready to run + +[ 01-01 15:14:23.361 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:23.364 1041: 541: 741 I/SoundTriggerHwService::Module ] +onCallbackEvent no clients + +[ 01-01 15:14:23.364 10038:18491:19012 I/MicrophoneInputStream ] +mic_started com.google.android.apps.gsa.speech.audio.ag@681da37 + +[ 01-01 15:14:23.374 1041: 541:20330 D/sound_trigger_platform ] +platform_stdev_check_and_update_concurrency: concurrency active 0, tx 1, rx 0, concurrency session_allowed 0 + +[ 01-01 15:14:23.375 1041: 541:20330 D/audio_hw_primary ] +enable_snd_device: snd_device(72: voice-rec-mic) + +[ 01-01 15:14:23.375 1041: 541:20330 D/audio_route ] +Apply path: voice-rec-mic + +[ 01-01 15:14:23.377 10038:18491:18496 I/zygote64 ] +Integer.valueOf will not be optimized + +[ 01-01 15:14:23.378 1041: 541:20330 D/audio_hw_primary ] +enable_audio_route: usecase(9) apply and update mixer path: audio-record + +[ 01-01 15:14:23.378 1041: 541:20330 D/audio_route ] +Apply path: audio-record + +[ 01-01 15:14:23.431 10038:18491:18491 I/MicroDetectionWorker ] +onReady + +[ 01-01 15:14:23.473 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:23.491 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback + +[ 01-01 15:14:23.503 1041: 541: 717 D/audio_hw_primary ] +disable_snd_device: snd_device(88: vi-feedback) + +[ 01-01 15:14:23.503 1041: 541: 717 D/audio_hw_primary ] +disable_audio_route: usecase(23) reset and update mixer path: spkr-vi-record + +[ 01-01 15:14:23.593 1000: 2272: 3783 W/OpenGLRenderer ] +Warning: attempt to read pixels from hardware bitmap, which is very slow operation + +[ 01-01 15:14:23.698 10038: 4245: 4483 W/OpenGLRenderer ] +Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer... + +--------- switch to system +[ 01-01 15:14:24.210 1000: 2272: 3628 I/PowerManagerService ] +Going to sleep due to power button (uid 1000)... + +[ 01-01 15:14:24.708 1000: 2272: 3592 D/BatteryStatsService ] +begin noteScreenState + +[ 01-01 15:14:24.710 1000: 2272: 3592 D/BatteryStatsService ] +end noteScreenState + +[ 01-01 15:14:24.719 1000: 2272: 3582 I/VrManagerService ] +VR mode is disallowed + diff --git a/tools/logblame/short_idle_test b/tools/logblame/short_idle_test new file mode 100755 index 000000000..c4ff43630 --- /dev/null +++ b/tools/logblame/short_idle_test @@ -0,0 +1,23 @@ +#!/bin/bash + +# The files to save output to. +RAWLOGS_FILE=short-idle-rawlogs.txt +ANALYSIS_FILE=short-idle-analysis.txt + +# Turn on the screen and unlock the device +# TODO: Power on +adb shell wm dismiss-keyguard + +# Start the analysis process +$TOP/development/tools/logblame/analyze_logs.py --duration=5m --clear --rawlogs $RAWLOGS_FILE \ + | tee $ANALYSIS_FILE & +analyze_pid=$! + +# Wait for the pyton process to exit +echo "waiting... analyze_pid" $analyze_pid +wait $analyze_pid + +echo "Wrote raw logs to $RAWLOGS_FILE" +echo "Wrote analysis to $ANALYSIS_FILE" + + diff --git a/tools/logblame/test_analyze.py b/tools/logblame/test_analyze.py new file mode 100755 index 000000000..4bd752f51 --- /dev/null +++ b/tools/logblame/test_analyze.py @@ -0,0 +1,24 @@ +#!/usr/bin/env python2.7 -B + +import analyze_logs + + +def test_ParseDuration(s, expected): + actual = analyze_logs.ParseDuration(s) + if actual != expected: + raise Exception("expected %s, actual %s" % (expected, actual)) + +def main(): + test_ParseDuration("1w", 604800) + test_ParseDuration("1d", 86400) + test_ParseDuration("1h", 3600) + test_ParseDuration("1m", 60) + test_ParseDuration("1s", 1) + test_ParseDuration("1w1d1h1m1s", 694861) + + +if __name__ == "__main__": + main() + + +# vim: set ts=2 sw=2 sts=2 tw=100 nocindent autoindent smartindent expandtab : diff --git a/tools/logblame/test_logs.py b/tools/logblame/test_logs.py new file mode 100755 index 000000000..122ecf316 --- /dev/null +++ b/tools/logblame/test_logs.py @@ -0,0 +1,179 @@ +#!/usr/bin/env python2.7 -B + +import logs +import ps + +import datetime +import StringIO + +def test_empty(): + """Test parsing no tag and no text, not well formed.""" + expected = [ logs.LogLine(None, "03-29 00:46:58.872", "1000", "1815", "1816", "I", "", + "") ] + text = """[ 03-29 00:46:58.872 1000: 1815: 1816 I/ ] + +""" + check_parsing(expected, text) + + +def test_none(): + """Test parsing no tag and no text.""" + expected = [ logs.LogLine(None, "03-29 00:46:58.872", "1000", "1815", "1816", "I", "", + "") ] + text = """[ 03-29 00:46:58.872 1000: 1815: 1816 I/ ] +""" + check_parsing(expected, text) + + + +def test_trailing_blank(): + """Test parsing text containing an extra intended newline at the end.""" + expected = [ logs.LogLine(None, "03-29 00:46:58.872", "1000", "1815", "1816", "I", "abcd", + "Newline after\n") ] + text = """[ 03-29 00:46:58.872 1000: 1815: 1816 I/abcd ] +Newline after + + +""" + check_parsing(expected, text) + + +def test_blank_between(): + """Test parsing text containing a newline in the middle.""" + expected = [ logs.LogLine(None, "03-29 00:46:58.872", "1000", "1815", "1816", "I", "abcd", + "Message\n\nNewline between") ] + text = """[ 03-29 00:46:58.872 1000: 1815: 1816 I/abcd ] +Message + +Newline between + +""" + check_parsing(expected, text) + + +def test_preceeding_blank(): + """Test parsing text containing a newline then text.""" + expected = [ logs.LogLine(None, "03-29 00:46:58.872", "1000", "1815", "1816", "I", "abcd", + "\nNewline before") ] + text = """[ 03-29 00:46:58.872 1000: 1815: 1816 I/abcd ] + +Newline before + +""" + check_parsing(expected, text) + + +def test_one_blank(): + """Test parsing text one blank line.""" + expected = [ logs.LogLine(None, "03-29 00:46:58.872", "1000", "1815", "1816", "I", "abcd", + "\n") ] + text = """[ 03-29 00:46:58.872 1000: 1815: 1816 I/abcd ] + + +""" + check_parsing(expected, text) + + +def test_two_blanks(): + """Test parsing text two blank lines.""" + expected = [ logs.LogLine(None, "03-29 00:46:58.872", "1000", "1815", "1816", "I", "abcd", + "\n\n") ] + text = """[ 03-29 00:46:58.872 1000: 1815: 1816 I/abcd ] + + + +""" + check_parsing(expected, text) + + +def test_two_lines_noblanks(): + """Test parsing two lines of text with no blank lines.""" + expected = [ logs.LogLine(None, "03-29 00:46:58.872", "1000", "1815", "1816", "I", "abcd", + "One\nTwo") ] + text = """[ 03-29 00:46:58.872 1000: 1815: 1816 I/abcd ] +One +Two + +""" + check_parsing(expected, text) + + +def test_chatty(): + """Test a log with chatty identical messages.""" + + expected = [ + logs.LogLine("system", "03-29 00:46:58.857", "1000", "1815", "1816", "I", "Noisy", "Message"), + logs.LogLine("system", "03-29 00:46:58.858", "1000", "1815", "1816", "I", "Noisy", "Message"), + logs.LogLine("system", "03-29 00:46:58.858", "1000", "1815", "1816", "I", "Noisy", "Message"), + logs.LogLine("system", "03-29 00:46:58.858", "1000", "1815", "1816", "I", "Noisy", "Message"), + logs.LogLine("system", "03-29 00:46:58.859", "1000", "1815", "1816", "I", "Noisy", "Message"), + ] + text = """--------- beginning of system +[ 03-29 00:46:58.857 1000: 1815: 1816 I/Noisy ] +Message + +[ 03-29 00:46:58.858 1000: 1815: 1816 I/chatty ] +uid=1000(system) Thread-6 identical 3 lines + +[ 03-29 00:46:58.859 1000: 1815: 1816 I/Noisy ] +Message + +""" + check_parsing(expected, text) + + + +def test_normal(): + """Test a realistic (albeit short) log.""" + expected = [ + logs.LogLine("system", "03-29 00:46:58.857", "1000", "1815", "1816", "I", "Package: ]Manager", + "/system/app/KeyChain changed; collecting certs"), + logs.LogLine("system", "03-29 00:46:58.872", "1000", "1815", "1816", "I", "PackageManager", + "/system/app/HiddenMenu changed; collecting certs"), + logs.LogLine("main", "03-29 00:46:58.872", "1000", "1815", "1816", "I", "PackageManager", + "/system/app/HiddenMenu changed; collecting certs"), + ] + + text = """--------- beginning of system +[ 03-29 00:46:58.857 1000: 1815: 1816 I/Package: ]Manager ] +/system/app/KeyChain changed; collecting certs + +[ 03-29 00:46:58.872 1000: 1815: 1816 I/PackageManager ] +/system/app/HiddenMenu changed; collecting certs + +--------- switch to main +[ 03-29 00:46:58.872 1000: 1815: 1816 I/PackageManager ] +/system/app/HiddenMenu changed; collecting certs + +""" + check_parsing(expected, text) + + + +def check_parsing(expected, text): + """Parse the text and see if it parsed as expected.""" + processes = ps.ProcessSet() + result = [x for x in logs.ParseLogcat(StringIO.StringIO(text), processes)] + if result != expected: + raise Exception("test failed.\nexpected:\n[%s]\nactual\n[%s]" % ( + ", ".join([str(r) for r in expected]), + ", ".join([str(r) for r in result]))) + + +def main(): + test_empty() + test_none() + test_trailing_blank() + test_blank_between() + test_preceeding_blank() + test_one_blank() + test_two_blanks() + test_chatty() + test_normal() + + +if __name__ == "__main__": + main() + + +# vim: set ts=2 sw=2 sts=2 tw=100 nocindent autoindent smartindent expandtab: diff --git a/tools/logblame/test_ps.py b/tools/logblame/test_ps.py new file mode 100755 index 000000000..a0d73cb22 --- /dev/null +++ b/tools/logblame/test_ps.py @@ -0,0 +1,97 @@ +#!/usr/bin/env python2.7 -B + +import ps + + +def test_pids(): + text = """USER PID PPID VSIZE RSS WCHAN PC NAME +root 1 0 10632 776 SyS_epoll_ 0000000000 S /init +root 2 0 0 0 kthreadd 0000000000 S kthreadd +u0_a22 7308 633 1808572 79760 SyS_epoll_ 0000000000 S com.google.android.dialer +u0_a19 7370 633 1841228 37828 SyS_epoll_ 0000000000 S com.google.android.gms.feedback +u0_a136 7846 634 1320656 119964 SyS_epoll_ 0000000000 S com.sonos.acr +""" + + actual = ps.ParsePs(text) + + expected = [ + ('root', '1', '0', '/init'), + ('root', '2', '0', 'kthreadd'), + ('u0_a22', '7308', '633', 'com.google.android.dialer'), + ('u0_a19', '7370', '633', 'com.google.android.gms.feedback'), + ('u0_a136', '7846', '634', 'com.sonos.acr') + ] + + if actual != expected: + print "Expected:" + print expected + print + print "Actual:" + print actual + raise Exception("test failed") + + +def test_uids(): + text = """vers,1 +vrfy,com.android.vending,10035 +ifv,com.google.android.gms,10019 +lib,com.vzw.apnlib,jar,/system/app/VZWAPNLib/VZWAPNLib.apk +lib,com.google.android.media.effects,jar,/system/framework/com.google.android.media.effects.jar +pkg,com.amazon.mShop.android.shopping,10118,116434610,1486361139496,1491403362196,com.android.vending +pkg-splt,base,0 +pkg-usr,0,IbsusL,0,com.android.vending +pkg,com.getgoodcode.bart,10129,21,1486361637815,1486361637815,com.android.vending +pkg-splt,base,0 +pkg-usr,0,IbsuSl,0,? +pkg,com.flightaware.android.liveFlightTracker,10115,138,1486361042695,1486361042695,com.android.vending +pkg-splt,base,0 +pkg-usr,0,IbsuSl,0,? +pkg,com.android.cts.priv.ctsshim,10010,24,1230796800000,1230796800000,? +pkg-splt,base,0 +pkg-usr,0,IbsusL,0,? +""" + actual = ps.ParseUids(text) + + expected = [ + ('10118', 'com.amazon.mShop.android.shopping'), + ('10129', 'com.getgoodcode.bart'), + ('10115', 'com.flightaware.android.liveFlightTracker'), + ('10010', 'com.android.cts.priv.ctsshim') + ] + + if actual != expected: + print "Expected:" + print expected + print + print "Actual:" + print actual + raise Exception("test failed") + + +def test_update(): + """Requires an attached device.""" + processes = ps.ProcessSet() + processes.Update() + processes.Update() + processes.Print() + process = processes.FindPid("0", "0") + print "process:", process + print "uid:", process.uid.uid + print "username:", process.uid.name + print "pid:", process.pid + print "ppid:", process.ppid + print "name:", process.name + print "displayName:", process.DisplayName() + + +def main(): + #test_uids() + #test_pids() + test_update() + + +if __name__ == "__main__": + main() + + +# vim: set ts=2 sw=2 sts=2 tw=100 nocindent autoindent smartindent expandtab: