1 /*
2  * Copyright (C) 2016 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License
15  */
16 
17 package com.android.server.telecom;
18 
19 import android.content.Context;
20 import android.os.SystemClock;
21 import android.telecom.Logging.EventManager;
22 import android.telecom.Logging.EventManager.TimedEventPair;
23 
24 import com.android.internal.annotations.VisibleForTesting;
25 
26 import java.util.HashMap;
27 import java.util.Map;
28 
29 /**
30  * Temporary location of new Logging class
31  */
32 
33 public class LogUtils {
34 
35     private static final String TAG = "Telecom";
36     private static final String LOGUTILS_TAG = "LogUtils";
37 
38     public static final boolean SYSTRACE_DEBUG = false; /* STOP SHIP if true */
39     private static boolean sInitializedLoggerListeners = false; // used to gate re-init of listeners
40     private static int sInitializedCounter = 0; /* For testing purposes only */
41     private static final Object sLock = new Object(); // Coarse lock for all of LogUtils
42 
43     public static class EventTimer {
44         private long mLastElapsedMillis;
45         private Map<String, Long> mTimings = new HashMap<>();
46 
EventTimer()47         public EventTimer() {
48             mLastElapsedMillis = SystemClock.elapsedRealtime();
49         }
50 
record(String label)51         public void record(String label) {
52             long newElapsedMillis = SystemClock.elapsedRealtime();
53             mTimings.put(label, newElapsedMillis - mLastElapsedMillis);
54             mLastElapsedMillis = newElapsedMillis;
55         }
56 
57         @Override
toString()58         public String toString() {
59             StringBuilder sb = new StringBuilder();
60             for (Map.Entry<String, Long> entry : mTimings.entrySet()) {
61                 sb.append(entry.getKey()).append(": ").append(entry.getValue()).append(", ");
62             }
63             return sb.toString();
64         }
65     }
66 
67     public static final class Sessions {
68         public static final String ICA_ANSWER_CALL = "ICA.aC";
69         public static final String ICA_DEFLECT_CALL = "ICA.defC";
70         public static final String ICA_REJECT_CALL = "ICA.rC";
71         public static final String ICA_TRANSFER_CALL = "ICA.tC";
72         public static final String ICA_CONSULTATIVE_TRANSFER = "ICA.cT";
73         public static final String ICA_DISCONNECT_CALL = "ICA.dC";
74         public static final String ICA_HOLD_CALL = "ICA.hC";
75         public static final String ICA_UNHOLD_CALL = "ICA.uC";
76         public static final String ICA_MUTE = "ICA.m";
77         public static final String ICA_SET_AUDIO_ROUTE = "ICA.sAR";
78         public static final String ICA_ENTER_AUDIO_PROCESSING = "ICA.enBAP";
79         public static final String ICA_EXIT_AUDIO_PROCESSING = "ICA.exBAP";
80         public static final String ICA_CONFERENCE = "ICA.c";
81         public static final String CSW_HANDLE_CREATE_CONNECTION_COMPLETE = "CSW.hCCC";
82         public static final String CSW_SET_ACTIVE = "CSW.sA";
83         public static final String CSW_SET_RINGING = "CSW.sR";
84         public static final String CSW_SET_DIALING = "CSW.sD";
85         public static final String CSW_SET_PULLING = "CSW.sP";
86         public static final String CSW_SET_DISCONNECTED = "CSW.sDc";
87         public static final String CSW_SET_ON_HOLD = "CSW.sOH";
88         public static final String CSW_REMOVE_CALL = "CSW.rC";
89         public static final String CSW_SET_IS_CONFERENCED = "CSW.sIC";
90         public static final String CSW_ADD_CONFERENCE_CALL = "CSW.aCC";
91         public static final String CSA_SET_STATE = "CSA.sSS";
92     }
93 
94     public final static class Events {
95         public static final String CREATED = "CREATED";
96         public static final String USER_CONFIRMATION = "USER_CONFIRMATION";
97         public static final String USER_CONFIRMED = "USER_CONFIRMED";
98         public static final String USER_CANCELLED = "USER_CANCELLED";
99         public static final String DESTROYED = "DESTROYED";
100         public static final String SET_CONNECTING = "SET_CONNECTING";
101         public static final String SET_DIALING = "SET_DIALING";
102         public static final String SET_PULLING = "SET_PULLING";
103         public static final String SET_ACTIVE = "SET_ACTIVE";
104         public static final String SET_HOLD = "SET_HOLD";
105         public static final String SET_RINGING = "SET_RINGING";
106         public static final String SET_ANSWERED = "SET_ANSWERED";
107         public static final String SET_DISCONNECTED = "SET_DISCONNECTED";
108         public static final String SKIP_CALL_LOG = "SKIP_CALL_LOG";
109         public static final String LOG_CALL = "LOG_CALL";
110         public static final String SET_DISCONNECTING = "SET_DISCONNECTING";
111         public static final String SET_SELECT_PHONE_ACCOUNT = "SET_SELECT_PHONE_ACCOUNT";
112         public static final String SET_AUDIO_PROCESSING = "SET_AUDIO_PROCESSING";
113         public static final String SET_SIMULATED_RINGING = "SET_SIMULATED_RINGING";
114         public static final String REQUEST_RTT = "REQUEST_RTT";
115         public static final String RESPOND_TO_RTT_REQUEST = "RESPOND_TO_RTT_REQUEST";
116         public static final String SET_RRT_MODE = "SET_RTT_MODE";
117         public static final String ON_RTT_FAILED = "ON_RTT_FAILED";
118         public static final String ON_RTT_REQUEST = "ON_RTT_REQUEST";
119         public static final String REQUEST_HOLD = "REQUEST_HOLD";
120         public static final String REQUEST_UNHOLD = "REQUEST_UNHOLD";
121         public static final String REQUEST_DISCONNECT = "REQUEST_DISCONNECT";
122         public static final String REQUEST_ACCEPT = "REQUEST_ACCEPT";
123         public static final String REQUEST_SIMULATED_ACCEPT = "REQUEST_SIMULATED_ACCEPT";
124         public static final String REQUEST_PICKUP_FOR_AUDIO_PROCESSING =
125                 "REQUEST_PICKUP_FOR_AUDIO_PROCESSING";
126         public static final String REQUEST_DEFLECT = "REQUEST_DEFLECT";
127         public static final String REQUEST_REJECT = "REQUEST_REJECT";
128         public static final String REQUEST_TRANSFER = "REQUEST_TRANSFER";
129         public static final String REQUEST_CONSULTATIVE_TRANSFER = "REQUEST_CONSULTATIVE_TRANSFER";
130         public static final String START_DTMF = "START_DTMF";
131         public static final String STOP_DTMF = "STOP_DTMF";
132         public static final String START_RINGER = "START_RINGER";
133         public static final String STOP_RINGER = "STOP_RINGER";
134         public static final String START_VIBRATOR = "START_VIBRATOR";
135         public static final String STOP_VIBRATOR = "STOP_VIBRATOR";
136         public static final String SKIP_VIBRATION = "SKIP_VIBRATION";
137         public static final String SKIP_RINGING = "SKIP_RINGING";
138         public static final String START_CALL_WAITING_TONE = "START_CALL_WAITING_TONE";
139         public static final String STOP_CALL_WAITING_TONE = "STOP_CALL_WAITING_TONE";
140         public static final String START_CONNECTION = "START_CONNECTION";
141         public static final String CREATE_CONNECTION_FAILED = "CREATE_CONNECTION_FAILED";
142         public static final String CREATE_CONNECTION_TIMEOUT = "CREATE_CONNECTION_TIMEOUT";
143         public static final String START_CONFERENCE = "START_CONFERENCE";
144         public static final String CREATE_CONFERENCE_FAILED = "CREATE_CONFERENCE_FAILED";
145         public static final String CREATE_CONFERENCE_TIMEOUT = "CREATE_CONFERENCE_TIMEOUT";
146         public static final String BIND_CS = "BIND_CS";
147         public static final String CS_BOUND = "CS_BOUND";
148         public static final String CONFERENCE_WITH = "CONF_WITH";
149         public static final String SPLIT_FROM_CONFERENCE = "CONF_SPLIT";
150         public static final String SWAP = "SWAP";
151         public static final String ADD_PARTICIPANT = "ADD_PARTICIPANT";
152         public static final String ADD_CHILD = "ADD_CHILD";
153         public static final String REMOVE_CHILD = "REMOVE_CHILD";
154         public static final String SET_PARENT = "SET_PARENT";
155         public static final String CONF_STATE_CHANGED = "CONF_STATE_CHANGED";
156         public static final String CONF_CALLS_CHANGED = "CONF_CALLS_CHANGED";
157         public static final String CALL_DIRECTION_CHANGED = "CALL_DIRECTION_CHANGED";
158         public static final String MUTE = "MUTE";
159         public static final String UNMUTE = "UNMUTE";
160         public static final String AUDIO_ROUTE = "AUDIO_ROUTE";
161         public static final String AUDIO_ROUTE_EARPIECE = "AUDIO_ROUTE_EARPIECE";
162         public static final String AUDIO_ROUTE_HEADSET = "AUDIO_ROUTE_HEADSET";
163         public static final String AUDIO_ROUTE_BT = "AUDIO_ROUTE_BT";
164         public static final String AUDIO_ROUTE_SPEAKER = "AUDIO_ROUTE_SPEAKER";
165         public static final String ERROR_LOG = "ERROR";
166         public static final String USER_LOG_MARK = "USER_LOG_MARK";
167         public static final String SILENCE = "SILENCE";
168         public static final String BIND_SCREENING = "BIND_SCREENING";
169         public static final String SCREENING_BOUND = "SCREENING_BOUND";
170         public static final String SCREENING_SENT = "SCREENING_SENT";
171         public static final String SCREENING_SKIPPED = "SCREENING_SKIPPED";
172         public static final String CONTROLLER_SCREENING_COMPLETED =
173                 "CONTROLLER_SCREENING_COMPLETED";
174         public static final String SCREENING_COMPLETED = "SCREENING_COMPLETED";
175         public static final String CALL_IDENTIFICATION_SET = "CALL_IDENTIFICATION_SET";
176         public static final String BLOCK_CHECK_INITIATED = "BLOCK_CHECK_INITIATED";
177         public static final String BLOCK_CHECK_FINISHED = "BLOCK_CHECK_FINISHED";
178         public static final String DIRECT_TO_VM_INITIATED = "DIRECT_TO_VM_INITIATED";
179         public static final String DIRECT_TO_VM_FINISHED = "DIRECT_TO_VM_FINISHED";
180         public static final String FILTERING_INITIATED = "FILTERING_INITIATED";
181         public static final String DND_PRE_CHECK_INITIATED = "DND_PRE_CHECK_INITIATED";
182         public static final String DND_PRE_CHECK_COMPLETED = "DND_PRE_CHECK_COMPLETED";
183         public static final String FILTERING_COMPLETED = "FILTERING_COMPLETED";
184         public static final String FILTERING_TIMED_OUT = "FILTERING_TIMED_OUT";
185         public static final String REMOTELY_HELD = "REMOTELY_HELD";
186         public static final String REMOTELY_UNHELD = "REMOTELY_UNHELD";
187         public static final String REQUEST_PULL = "PULL";
188         public static final String INFO = "INFO";
189         public static final String VIDEO_STATE_CHANGED = "VIDEO_STATE_CHANGED";
190         public static final String RECEIVE_VIDEO_REQUEST = "RECEIVE_VIDEO_REQUEST";
191         public static final String RECEIVE_VIDEO_RESPONSE = "RECEIVE_VIDEO_RESPONSE";
192         public static final String SEND_VIDEO_REQUEST = "SEND_VIDEO_REQUEST";
193         public static final String SEND_VIDEO_RESPONSE = "SEND_VIDEO_RESPONSE";
194         public static final String IS_EXTERNAL = "IS_EXTERNAL";
195         public static final String PROPERTY_CHANGE = "PROPERTY_CHANGE";
196         public static final String CAPABILITY_CHANGE = "CAPABILITY_CHANGE";
197         public static final String CONNECTION_EVENT = "CONNECTION_EVENT";
198         public static final String CALL_EVENT = "CALL_EVENT";
199         public static final String HANDOVER_REQUEST = "HANDOVER_REQUEST";
200         public static final String START_HANDOVER = "START_HANDOVER";
201         public static final String ACCEPT_HANDOVER = "ACCEPT_HANDOVER";
202         public static final String HANDOVER_COMPLETE = "HANDOVER_COMPLETE";
203         public static final String HANDOVER_FAILED = "HANDOVER_FAILED";
204         public static final String START_RINBACK = "START_RINGBACK";
205         public static final String STOP_RINGBACK = "STOP_RINGBACK";
206         public static final String REDIRECTION_BOUND_USER = "REDIRECTION_BOUND_USER";
207         public static final String REDIRECTION_BOUND_CARRIER = "REDIRECTION_BOUND_CARRIER";
208         public static final String REDIRECTION_SENT_USER = "REDIRECTION_SENT_USER";
209         public static final String REDIRECTION_SENT_CARRIER = "REDIRECTION_SENT_CARRIER";
210         public static final String REDIRECTION_COMPLETED_USER = "REDIRECTION_COMPLETED_USER";
211         public static final String REDIRECTION_COMPLETED_CARRIER = "REDIRECTION_COMPLETED_CARRIER";
212         public static final String REDIRECTION_TIMED_OUT_USER = "REDIRECTION_TIMED_OUT_USER";
213         public static final String REDIRECTION_TIMED_OUT_CARRIER = "REDIRECTION_TIMED_OUT_CARRIER";
214         public static final String REDIRECTION_USER_CONFIRMATION = "REDIRECTION_USER_CONFIRMATION";
215         public static final String REDIRECTION_USER_CONFIRMED = "REDIRECTION_USER_CONFIRMED";
216         public static final String REDIRECTION_USER_CANCELLED = "REDIRECTION_USER_CANCELLED";
217         public static final String BT_QUALITY_REPORT = "BT_QUALITY_REPORT";
218         public static final String SET_DISCONNECTED_ORIG = "SET_DISCONNECTED_ORIG";
219         public static final String OVERRIDE_DISCONNECT_MESSAGE = "OVERRIDE_DISCONNECT_MSG";
220         public static final String CALL_DIAGNOSTIC_SERVICE_TIMEOUT =
221                 "CALL_DIAGNOSTIC_SERVICE_TIMEOUT";
222         public static final String VERSTAT_CHANGED = "VERSTAT_CHANGED";
223         public static final String SET_VOIP_MODE = "SET_VOIP_MODE";
224         public static final String STATE_TIMEOUT = "STATE_TIMEOUT";
225         public static final String ICS_EXTRAS_CHANGED = "ICS_EXTRAS_CHANGED";
226         public static final String FLASH_NOTIFICATION_START = "FLASH_NOTIFICATION_START";
227         public static final String FLASH_NOTIFICATION_STOP = "FLASH_NOTIFICATION_STOP";
228         public static final String GAINED_FGS_DELEGATION = "GAINED_FGS_DELEGATION";
229         public static final String GAIN_FGS_DELEGATION_FAILED = "GAIN_FGS_DELEGATION_FAILED";
230         public static final String LOST_FGS_DELEGATION = "LOST_FGS_DELEGATION";
231         public static final String START_STREAMING = "START_STREAMING";
232         public static final String STOP_STREAMING = "STOP_STREAMING";
233 
234         public static class Timings {
235             public static final String ACCEPT_TIMING = "accept";
236             public static final String REJECT_TIMING = "reject";
237             public static final String DISCONNECT_TIMING = "disconnect";
238             public static final String HOLD_TIMING = "hold";
239             public static final String UNHOLD_TIMING = "unhold";
240             public static final String OUTGOING_TIME_TO_DIALING_TIMING = "outgoing_time_to_dialing";
241             public static final String BIND_CS_TIMING = "bind_cs";
242             public static final String SCREENING_COMPLETED_TIMING = "screening_completed";
243             public static final String DIRECT_TO_VM_FINISHED_TIMING = "direct_to_vm_finished";
244             public static final String BLOCK_CHECK_FINISHED_TIMING = "block_check_finished";
245             public static final String FILTERING_COMPLETED_TIMING = "filtering_completed";
246             public static final String DND_PRE_CHECK_COMPLETED_TIMING = "dnd_pre_check_completed";
247             public static final String FILTERING_TIMED_OUT_TIMING = "filtering_timed_out";
248             public static final String START_CONNECTION_TO_REQUEST_DISCONNECT_TIMING =
249                     "start_connection_to_request_disconnect";
250 
251             private static final TimedEventPair[] sTimedEvents = {
252                     new TimedEventPair(REQUEST_ACCEPT, SET_ACTIVE, ACCEPT_TIMING),
253                     new TimedEventPair(REQUEST_REJECT, SET_DISCONNECTED, REJECT_TIMING),
254                     new TimedEventPair(REQUEST_DISCONNECT, SET_DISCONNECTED, DISCONNECT_TIMING),
255                     new TimedEventPair(REQUEST_HOLD, SET_HOLD, HOLD_TIMING),
256                     new TimedEventPair(REQUEST_UNHOLD, SET_ACTIVE, UNHOLD_TIMING),
257                     new TimedEventPair(START_CONNECTION, SET_DIALING,
258                             OUTGOING_TIME_TO_DIALING_TIMING),
259                     new TimedEventPair(BIND_CS, CS_BOUND, BIND_CS_TIMING),
260                     new TimedEventPair(SCREENING_SENT, SCREENING_COMPLETED,
261                             SCREENING_COMPLETED_TIMING),
262                     new TimedEventPair(DIRECT_TO_VM_INITIATED, DIRECT_TO_VM_FINISHED,
263                             DIRECT_TO_VM_FINISHED_TIMING),
264                     new TimedEventPair(BLOCK_CHECK_INITIATED, BLOCK_CHECK_FINISHED,
265                             BLOCK_CHECK_FINISHED_TIMING),
266                     new TimedEventPair(FILTERING_INITIATED, FILTERING_COMPLETED,
267                             FILTERING_COMPLETED_TIMING),
268                     new TimedEventPair(DND_PRE_CHECK_INITIATED, DND_PRE_CHECK_COMPLETED,
269                             DND_PRE_CHECK_COMPLETED_TIMING),
270                     new TimedEventPair(FILTERING_INITIATED, FILTERING_TIMED_OUT,
271                             FILTERING_TIMED_OUT_TIMING, 6000L),
272                     new TimedEventPair(START_CONNECTION, REQUEST_DISCONNECT,
273                             START_CONNECTION_TO_REQUEST_DISCONNECT_TIMING),
274             };
275         }
276     }
277 
eventRecordAdded(EventManager.EventRecord eventRecord)278     private static void eventRecordAdded(EventManager.EventRecord eventRecord) {
279         // Only Calls will be added as event records in this case
280         EventManager.Loggable recordEntry = eventRecord.getRecordEntry();
281         if (recordEntry instanceof Call) {
282             Call callRecordEntry = (Call) recordEntry;
283             Analytics.CallInfo callInfo = callRecordEntry.getAnalytics();
284             if(callInfo != null) {
285                 callInfo.setCallEvents(eventRecord);
286             } else {
287                 if(!android.telecom.Log.isUnitTestingEnabled()) {
288                     android.telecom.Log.w(LOGUTILS_TAG, "Could not get Analytics CallInfo.");
289                 }
290             }
291         } else {
292             android.telecom.Log.w(LOGUTILS_TAG, "Non-Call EventRecord Added.");
293         }
294     }
295 
initLogging(Context context)296     public static void initLogging(Context context) {
297         android.telecom.Log.d(LOGUTILS_TAG, "initLogging: attempting to acquire LogUtils sLock");
298         synchronized (sLock) {
299             android.telecom.Log.d(LOGUTILS_TAG, "initLogging: grabbed LogUtils sLock");
300             if (!sInitializedLoggerListeners) {
301                 android.telecom.Log.d(LOGUTILS_TAG,
302                         "initLogging: called for first time. Registering the EventListener &"
303                                 + " SessionListener.");
304 
305                 android.telecom.Log.setTag(TAG);
306                 android.telecom.Log.setSessionContext(context);
307                 for (EventManager.TimedEventPair p : Events.Timings.sTimedEvents) {
308                     android.telecom.Log.addRequestResponsePair(p);
309                 }
310                 android.telecom.Log.registerEventListener(LogUtils::eventRecordAdded);
311                 // Store analytics about recently completed Sessions.
312                 android.telecom.Log.registerSessionListener(Analytics::addSessionTiming);
313 
314                 // Ensure LogUtils#initLogging(Context) is called once throughout the entire
315                 // lifecycle of not only TelecomSystem, but the Testing Framework.
316                 sInitializedLoggerListeners = true;
317                 sInitializedCounter++; /* For testing purposes only */
318             } else {
319                 android.telecom.Log.d(LOGUTILS_TAG, "initLogging: called again. Doing nothing.");
320             }
321         }
322     }
323 
324     /**
325      * Needed in order to test if the registerEventListener & registerSessionListener are ever
326      * re-initialized in the entire process of the Testing Framework or TelecomSystem.
327      *
328      * @return the number of times initLogging(Context) listeners have been initialized
329      */
330     @VisibleForTesting
getInitializedCounter()331     public static int getInitializedCounter() {
332         return sInitializedCounter;
333     }
334 }
335