package android.telecom.Logging;
import android.annotation.NonNull;
import android.telecom.Log;
import android.text.TextUtils;
import android.util.Pair;
import com.android.internal.annotations.VisibleForTesting;
import com.android.internal.util.IndentingPrintWriter;
import java.time.Instant;
import java.time.ZoneId;
import java.time.ZonedDateTime;
import java.time.format.DateTimeFormatter;
import java.util.ArrayList;
import java.util.Collections;
import java.util.Comparator;
import java.util.HashMap;
import java.util.IllegalFormatException;
import java.util.LinkedList;
import java.util.List;
import java.util.Locale;
import java.util.Map;
import java.util.concurrent.LinkedBlockingQueue;
public class EventManager {
public static final String TAG = "Logging.Events";
@VisibleForTesting
public static final int DEFAULT_EVENTS_TO_CACHE = 10;
public static final DateTimeFormatter DATE_TIME_FORMATTER =
DateTimeFormatter.ofPattern("HH:mm:ss.SSS");
public interface Loggable {
String getId();
String getDescription();
}
private final Map<Loggable, EventRecord> mCallEventRecordMap = new HashMap<>();
private LinkedBlockingQueue<EventRecord> mEventRecords =
new LinkedBlockingQueue<>(DEFAULT_EVENTS_TO_CACHE);
private List<EventListener> mEventListeners = new ArrayList<>();
public interface EventListener {
void eventRecordAdded(EventRecord eventRecord);
}
private SessionManager.ISessionIdQueryHandler mSessionIdHandler;
private final Map<String, List<TimedEventPair>> requestResponsePairs = new HashMap<>();
private static final Object mSync = new Object();
public static class TimedEventPair {
private static final long DEFAULT_TIMEOUT = 3000L;
String mRequest;
String mResponse;
String mName;
long mTimeoutMillis = DEFAULT_TIMEOUT;
public TimedEventPair(String request, String response, String name) {
this.mRequest = request;
this.mResponse = response;
this.mName = name;
}
public TimedEventPair(String request, String response, String name, long timeoutMillis) {
this.mRequest = request;
this.mResponse = response;
this.mName = name;
this.mTimeoutMillis = timeoutMillis;
}
}
public void addRequestResponsePair(TimedEventPair p) {
if (requestResponsePairs.containsKey(p.mRequest)) {
requestResponsePairs.get(p.mRequest).add(p);
} else {
ArrayList<TimedEventPair> responses = new ArrayList<>();
responses.add(p);
requestResponsePairs.put(p.mRequest, responses);
}
}
public static class Event {
public String eventId;
public String sessionId;
public long time;
public Object data;
public final String timestampString;
public Event(String eventId, String sessionId, long time, Object data) {
this.eventId = eventId;
this.sessionId = sessionId;
this.time = time;
timestampString =
ZonedDateTime.ofInstant(Instant.ofEpochMilli(time), ZoneId.systemDefault())
.format(DATE_TIME_FORMATTER);
this.data = data;
}
}
public class EventRecord {
public class EventTiming extends TimedEvent<String> {
public String name;
public long time;
public EventTiming(String name, long time) {
this.name = name;
this.time = time;
}
public String getKey() {
return name;
}
public long getTime() {
return time;
}
}
private class PendingResponse {
String requestEventId;
long requestEventTimeMillis;
long timeoutMillis;
String name;
public PendingResponse(String requestEventId, long requestEventTimeMillis,
long timeoutMillis, String name) {
this.requestEventId = requestEventId;
this.requestEventTimeMillis = requestEventTimeMillis;
this.timeoutMillis = timeoutMillis;
this.name = name;
}
}
private final List<Event> mEvents = new LinkedList<>();
private final Loggable mRecordEntry;
public EventRecord(Loggable recordEntry) {
mRecordEntry = recordEntry;
}
public Loggable getRecordEntry() {
return mRecordEntry;
}
public void addEvent(String event, String sessionId, Object data) {
mEvents.add(new Event(event, sessionId, System.currentTimeMillis(), data));
Log.i("Event", "RecordEntry %s: %s, %s", mRecordEntry.getId(), event, data);
}
public List<Event> getEvents() {
return mEvents;
}
public List<EventTiming> extractEventTimings() {
if (mEvents == null) {
return Collections.emptyList();
}
LinkedList<EventTiming> result = new LinkedList<>();
Map<String, PendingResponse> pendingResponses = new HashMap<>();
for (Event event : mEvents) {
if (requestResponsePairs.containsKey(event.eventId)) {
for (EventManager.TimedEventPair p : requestResponsePairs.get(event.eventId)) {
pendingResponses.put(p.mResponse, new PendingResponse(event.eventId,
event.time, p.mTimeoutMillis, p.mName));
}
}
PendingResponse pendingResponse = pendingResponses.remove(event.eventId);
if (pendingResponse != null) {
long elapsedTime = event.time - pendingResponse.requestEventTimeMillis;
if (elapsedTime < pendingResponse.timeoutMillis) {
result.add(new EventTiming(pendingResponse.name, elapsedTime));
}
}
}
return result;
}
public void dump(IndentingPrintWriter pw) {
pw.print(mRecordEntry.getDescription());
pw.increaseIndent();
for (Event event : mEvents) {
pw.print(event.timestampString);
pw.print(" - ");
pw.print(event.eventId);
if (event.data != null) {
pw.print(" (");
Object data = event.data;
if (data instanceof Loggable) {
EventRecord record = mCallEventRecordMap.get(data);
if (record != null) {
data = "RecordEntry " + record.mRecordEntry.getId();
}
}
pw.print(data);
pw.print(")");
}
if (!TextUtils.isEmpty(event.sessionId)) {
pw.print(":");
pw.print(event.sessionId);
}
pw.println();
}
pw.println("Timings (average for this call, milliseconds):");
pw.increaseIndent();
Map<String, Double> avgEventTimings = EventTiming.averageTimings(extractEventTimings());
List<String> eventNames = new ArrayList<>(avgEventTimings.keySet());
Collections.sort(eventNames);
for (String eventName : eventNames) {
pw.printf("%s: %.2f\n", eventName, avgEventTimings.get(eventName));
}
pw.decreaseIndent();
pw.decreaseIndent();
}
}
public EventManager(@NonNull SessionManager.ISessionIdQueryHandler l) {
mSessionIdHandler = l;
}
public void event(Loggable recordEntry, String event, Object data) {
String currentSessionID = mSessionIdHandler.getSessionId();
if (recordEntry == null) {
Log.i(TAG, "Non-call EVENT: %s, %s", event, data);
return;
}
synchronized (mEventRecords) {
if (!mCallEventRecordMap.containsKey(recordEntry)) {
EventRecord newRecord = new EventRecord(recordEntry);
addEventRecord(newRecord);
}
EventRecord record = mCallEventRecordMap.get(recordEntry);
record.addEvent(event, currentSessionID, data);
}
}
public void event(Loggable recordEntry, String event, String format, Object... args) {
String msg;
try {
msg = (args == null || args.length == 0) ? format
: String.format(Locale.US, format, args);
} catch (IllegalFormatException ife) {
Log.e(this, ife, "IllegalFormatException: formatString='%s' numArgs=%d", format,
args.length);
msg = format + " (An error occurred while formatting the message.)";
}
event(recordEntry, event, msg);
}
public void dumpEvents(IndentingPrintWriter pw) {
pw.println("Historical Events:");
pw.increaseIndent();
for (EventRecord eventRecord : mEventRecords) {
eventRecord.dump(pw);
}
pw.decreaseIndent();
}
public void dumpEventsTimeline(IndentingPrintWriter pw) {
pw.println("Historical Events (sorted by time):");
List<Pair<Loggable, Event>> events = new ArrayList<>();
for (EventRecord er : mEventRecords) {
for (Event ev : er.getEvents()) {
events.add(new Pair<>(er.getRecordEntry(), ev));
}
}
Comparator<Pair<Loggable, Event>> byEventTime =
Comparator.comparingLong(e -> e.second.time);
events.sort(byEventTime);
pw.increaseIndent();
for (Pair<Loggable, Event> event : events) {
pw.print(event.second.timestampString);
pw.print(",");
pw.print(event.first.getId());
pw.print(",");
pw.print(event.second.eventId);
pw.print(",");
pw.println(event.second.data);
}
pw.decreaseIndent();
}
public void changeEventCacheSize(int newSize) {
LinkedBlockingQueue<EventRecord> oldEventLog = mEventRecords;
mEventRecords = new LinkedBlockingQueue<>(newSize);
mCallEventRecordMap.clear();
oldEventLog.forEach((newRecord -> {
Loggable recordEntry = newRecord.getRecordEntry();
if (mEventRecords.remainingCapacity() == 0) {
EventRecord record = mEventRecords.poll();
if (record != null) {
mCallEventRecordMap.remove(record.getRecordEntry());
}
}
mEventRecords.add(newRecord);
mCallEventRecordMap.put(recordEntry, newRecord);
}));
}
public void registerEventListener(EventListener e) {
if (e != null) {
synchronized (mSync) {
mEventListeners.add(e);
}
}
}
@VisibleForTesting
public LinkedBlockingQueue<EventRecord> getEventRecords() {
return mEventRecords;
}
@VisibleForTesting
public Map<Loggable, EventRecord> getCallEventRecordMap() {
return mCallEventRecordMap;
}
private void addEventRecord(EventRecord newRecord) {
Loggable recordEntry = newRecord.getRecordEntry();
if (mEventRecords.remainingCapacity() == 0) {
EventRecord record = mEventRecords.poll();
if (record != null) {
mCallEventRecordMap.remove(record.getRecordEntry());
}
}
mEventRecords.add(newRecord);
mCallEventRecordMap.put(recordEntry, newRecord);
synchronized (mSync) {
for (EventListener l : mEventListeners) {
l.eventRecordAdded(newRecord);
}
}
}
}