1 /*
2  * Copyright (C) 2022 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.car.oem;
18 
19 import android.annotation.Nullable;
20 import android.car.builtin.util.Slogf;
21 import android.content.Context;
22 import android.content.res.Resources;
23 import android.os.Binder;
24 import android.os.Process;
25 import android.util.ArrayMap;
26 import android.util.Log;
27 
28 import com.android.car.CarLog;
29 import com.android.car.R;
30 import com.android.car.internal.util.IndentingPrintWriter;
31 import com.android.internal.annotations.GuardedBy;
32 import com.android.internal.annotations.VisibleForTesting;
33 
34 import java.util.Optional;
35 import java.util.concurrent.Callable;
36 import java.util.concurrent.ExecutionException;
37 import java.util.concurrent.ExecutorService;
38 import java.util.concurrent.Executors;
39 import java.util.concurrent.Future;
40 import java.util.concurrent.TimeUnit;
41 import java.util.concurrent.TimeoutException;
42 
43 // TODO(b/239698894):Enhance logging to keep track of timeout calls, and dump last 10 timeout calls.
44 
45 /**
46  * This class does following:
47  * <ul>
48  *   <li>Handles binder call to OEM Service and exposes multiple APIs to call OEM Service.
49  *   <li>Handles OEM service crash.
50  *   <li>Tracks circular call for OEM Service.
51  * </ul>
52  * <p>
53  * If there is more than {@link MAX_CIRCULAR_CALLS_PER_CALLER} circular calls per binder or more
54  * than {@link MAX_CIRCULAR_CALL_TOTAL} circular calls overall, Car Service and OEM service
55  * would be crashed.
56  */
57 public final class CarOemProxyServiceHelper {
58 
59     private static final String TAG = CarLog.tagFor(CarOemProxyServiceHelper.class);
60     private static final boolean DBG = Slogf.isLoggable(TAG, Log.DEBUG);
61 
62     private static final int EXIT_FLAG = 10;
63     private static final int MAX_THREAD_POOL_SIZE = 16;
64     private static final int MIN_THREAD_POOL_SIZE = 8;
65 
66     @VisibleForTesting
67     /*
68      * Max number of circular calls per caller. A circular is call between CarService and OEM
69      * Service where CarService calls OEM service and OEM services calls back to CarService.
70      */
71     static final int MAX_CIRCULAR_CALLS_PER_CALLER = 5;
72 
73     @VisibleForTesting
74     /*
75      * Max number of total circular calls. A circular is call between CarService and OEM
76      * Service where CarService calls OEM service and OEM services calls back to CarService.
77      *
78      * <p>MAX_CIRCULAR_CALL_TOTAL should be less than MIN_THREAD_POOL_SIZE
79      */
80     static final int MAX_CIRCULAR_CALL_TOTAL = 6;
81 
82     private final Object mLock = new Object();
83 
84     private final int mRegularCallTimeoutMs;
85     private final int mCrashCallTimeoutMs;
86     // Kept for dumping
87     private final int mThreadPoolSizeFromRRO;
88 
89     // Thread pool size will be read from resource overlay. The default value is 8. The maximum
90     // and minimum thread pool size can be MAX_THREAD_POOL_SIZE and MIN_THREAD_POOL_SIZE
91     // respectively. If resource overlay value is more than MAX_THREAD_POOL_SIZE, then thread
92     // pool size will be MAX_THREAD_POOL_SIZE. If resource overlay value is less than
93     // MIN_THREAD_POOL_SIZE, then thread pool size will be MIN_THREAD_POOL_SIZE.
94     private final int mBinderDispatchThreadPoolSize;
95 
96     /**
97      * This map would keep track of possible circular calls
98      * <p>
99      * Ideally there should not be any call from OEM service to Car Service but it may be required
100      * for some reason. In such situation, It is important that it doesn't create circular calls.
101      *
102      * For example:
103      * <ol>
104      *   <li>CarService calling OEM Service
105      *   <li>OEM Service calling car-lib
106      *   <li>Car-lib calling CarService
107      *   <li>CarService calling OEM Service again
108      * </ol>
109      * <p>
110      * This may create infinite loop. If something like this is detected, CarService and OEM Service
111      * would be crashed, and this map would keep track of such circular calls.
112      */
113     @GuardedBy("mLock")
114     private final ArrayMap<String, Integer> mCallerTracker = new ArrayMap<String, Integer>(2);
115 
116     private final ExecutorService mThreadPool;
117     @GuardedBy("mLock")
118     private Callable<String> mOemStackTracer;
119     @GuardedBy("mLock")
120     private int mTotalCircularCallsInProcess;
121     @GuardedBy("mLock")
122     private int mOemCarServicePid;
123 
CarOemProxyServiceHelper(Context context)124     public CarOemProxyServiceHelper(Context context) {
125         Resources res = context.getResources();
126         mRegularCallTimeoutMs = res
127                 .getInteger(R.integer.config_oemCarService_regularCall_timeout_ms);
128         mCrashCallTimeoutMs = res
129                 .getInteger(R.integer.config_oemCarService_crashCall_timeout_ms);
130         mThreadPoolSizeFromRRO = res
131                 .getInteger(R.integer.config_oemCarService_thread_pool_size);
132         if (mThreadPoolSizeFromRRO > MAX_THREAD_POOL_SIZE) {
133             mBinderDispatchThreadPoolSize = MAX_THREAD_POOL_SIZE;
134         } else if (mThreadPoolSizeFromRRO < MIN_THREAD_POOL_SIZE) {
135             mBinderDispatchThreadPoolSize = MIN_THREAD_POOL_SIZE;
136         } else {
137             mBinderDispatchThreadPoolSize = mThreadPoolSizeFromRRO;
138         }
139 
140         mThreadPool = Executors.newFixedThreadPool(mBinderDispatchThreadPoolSize);
141 
142         Slogf.i(TAG, "RegularCallTimeoutMs: %d, CrashCallTimeoutMs: %d, ThreadPoolSizeFromRRO: %d,"
143                 + " ThreadPoolSize: %d.", mRegularCallTimeoutMs,
144                 mCrashCallTimeoutMs, mThreadPoolSizeFromRRO, mBinderDispatchThreadPoolSize);
145     }
146 
147     /**
148      * Does timed call to the OEM service and returns default value if OEM service timed out or
149      * throws any other Exception.
150      *
151      * <p>Caller would not know if the call to OEM service timed out or returned a valid value which
152      * could be same as defaultValue. It is preferred way to call OEM service if the defaultValue is
153      * an acceptable result.
154      *
155      * @param <T> Type of the result.
156      * @param callerTag is tag from the caller. Used for tracking circular calls per binder.
157      * @param callable containing binder call.
158      * @param defaultValue to be returned if call timeout or any other exception is thrown.
159      *
160      * @return Result of the binder call. Result can be null.
161      */
162     @Nullable
doBinderTimedCallWithDefaultValue(String callerTag, Callable<T> callable, T defaultValue)163     public <T> T doBinderTimedCallWithDefaultValue(String callerTag, Callable<T> callable,
164             T defaultValue) {
165         if (DBG) {
166             Slogf.d(TAG, "Received doBinderTimedCallWithDefaultValue call for caller tag: %s.",
167                     callerTag);
168         }
169         startTracking(callerTag);
170         try {
171             Future<T> result = mThreadPool.submit(callable);
172             try {
173                 return result.get(mRegularCallTimeoutMs, TimeUnit.MILLISECONDS);
174             } catch (Exception e) {
175                 if (e instanceof InterruptedException) {
176                     Thread.currentThread().interrupt(); // Restore the interrupted status
177                 }
178                 Slogf.w(TAG, "Binder call threw an exception. Return default value %s for caller "
179                         + "tag: %s", defaultValue, callerTag);
180                 return defaultValue;
181             }
182         } finally {
183             stopTracking(callerTag);
184         }
185     }
186 
187     /**
188      * Does timed call to the OEM service and throws timeout exception.
189      *
190      * <p>Throws timeout exception if OEM service times out. If OEM service throw any other
191      * exception, it is wrapped in Timeout exception.
192      *
193      * @param <T> Type of the result.
194      * @param callerTag is tag from the caller. Used for tracking circular calls per binder.
195      * @param callable containing binder call.
196      * @param timeoutMs in milliseconds.
197      *
198      * @return result of the binder call. Result can be null.
199      *
200      * @throws TimeoutException if call times out or throws any other exception.
201      */
202     @Nullable
doBinderTimedCallWithTimeout(String callerTag, Callable<T> callable, long timeoutMs)203     public <T> T doBinderTimedCallWithTimeout(String callerTag, Callable<T> callable,
204             long timeoutMs) throws TimeoutException {
205         if (DBG) {
206             Slogf.d(TAG, "Received doBinderTimedCallWithTimeout call for caller tag: %s.",
207                     callerTag);
208         }
209         startTracking(callerTag);
210         try {
211             Future<T> result = mThreadPool.submit(callable);
212             try {
213                 return result.get(timeoutMs, TimeUnit.MILLISECONDS);
214             } catch (InterruptedException | ExecutionException e) {
215                 Slogf.w(TAG, "Binder call received Exception", e);
216                 if (e instanceof InterruptedException) {
217                     Thread.currentThread().interrupt(); // Restore the interrupted status
218                 }
219                 // Throw timeout exception even for other exception as caller knows how to handle
220                 // timeout exception in this case.
221                 TimeoutException exception = new TimeoutException();
222                 exception.initCause(e);
223                 throw exception;
224             }
225         } finally {
226             stopTracking(callerTag);
227         }
228     }
229 
230     /**
231      * Does timed call to OEM service with two different timeouts.
232      *
233      * <p>If OEM service returns before the {@code defaultTimeoutMs}, it would return OEM response.
234      * After {@code defaultTimeoutMs}, call will return {@link Optional#empty()} and queue a tracker
235      * for OEM service response asynchronously. Tracker would wait for {@code mCrashCallTimeoutMs}
236      * for OEM service to response. If OEM service respond before {code mCrashCallTimeoutMs},
237      * callback {@code CallbackForDelayedResult} will be used to post the OEM results on the
238      * original caller. If OEM service doesn't respond within {code mCrashCallTimeoutMs}, CarService
239      * and OEM service both will be crashed.
240      *
241      * <p>This call should be used if it is okay to quickly check for results from OEM Service, and
242      * it is possible to incorporate results from OEM service if delivered late.
243      *
244      * <p>If the binder to OEM service throw any exception during short timeout, it would be ignored
245      * and {@link Optional#empty()} is returned. If the binder to OEM service throw timeout
246      * exception after the longer timeout, it would rash the CarService and OEM Service. If the
247      * binder to OEM service throw any other exception during longer timeout, it would be ignored
248      * and {@link Optional#empty()} is returned.
249      *
250      * @param <T> Type of the result.
251      * @param callerTag is tag from the caller. Used for tracking circular calls per binder.
252      * @param callable containing binder call.
253      * @param defaultTimeoutMs in milliseconds.
254      * @param callback for the delayed results. Callback waits for {@code mCrashCallTimeoutMs}.
255      *
256      * @return Optional carrying result of the binder call. Optional can be empty.
257      */
doBinderCallWithDefaultValueAndDelayedWaitAndCrash(String callerTag, Callable<T> callable, long defaultTimeoutMs, CallbackForDelayedResult<T> callback)258     public <T> Optional<T> doBinderCallWithDefaultValueAndDelayedWaitAndCrash(String callerTag,
259             Callable<T> callable, long defaultTimeoutMs,
260             CallbackForDelayedResult<T> callback) {
261         if (DBG) {
262             Slogf.d(TAG, "Received doBinderCallWithDefaultValueAndDelayedWaitAndCrash call for"
263                     + " caller tag: %s.", callerTag);
264         }
265         startTracking(callerTag);
266         try {
267             Future<T> result = mThreadPool.submit(callable);
268             try {
269                 return Optional.ofNullable(result.get(defaultTimeoutMs, TimeUnit.MILLISECONDS));
270             } catch (Exception e) {
271                 if (e instanceof InterruptedException) {
272                     Thread.currentThread().interrupt(); // Restore the interrupted status
273                 }
274                 Slogf.e(TAG, "Binder call received Exception", e);
275             }
276 
277             // Queue for long wait time check
278             mThreadPool.execute(() -> {
279                 startTracking(callerTag);
280                 try {
281                     callback.onDelayedResults(
282                             Optional.ofNullable(
283                                     result.get(mCrashCallTimeoutMs, TimeUnit.MILLISECONDS)));
284                 } catch (TimeoutException e) {
285                     Slogf.e(TAG, "Binder call received TimeoutException", e);
286                     crashCarService("TimeoutException");
287                 } catch (InterruptedException | ExecutionException e) {
288                     if (e instanceof InterruptedException) {
289                         Thread.currentThread().interrupt(); // Restore the interrupted status
290                     }
291                     Slogf.e(TAG, "Binder call received Eexception", e);
292                     callback.onDelayedResults(Optional.empty());
293                 } finally {
294                     stopTracking(callerTag);
295                 }
296             });
297         } finally {
298             stopTracking(callerTag);
299         }
300 
301         return Optional.empty();
302     }
303 
304     /**
305      * Callback for getting OEM results after default timeout.
306      *
307      * @param <T> Type of the result.
308      */
309     public interface CallbackForDelayedResult<T> {
310         /**
311          * Invoked when OEM results are received after default timeout.
312          *
313          * @param result received from OEM service
314          */
onDelayedResults(Optional<T> result)315         void onDelayedResults(Optional<T> result);
316     }
317 
stopTracking(String callerTag)318     private void stopTracking(String callerTag) {
319         synchronized (mLock) {
320             if (Binder.getCallingPid() != mOemCarServicePid) return;
321         }
322         // update tracker
323         synchronized (mLock) {
324             int currentCircularCallForTag = mCallerTracker.getOrDefault(callerTag, 0);
325             if (currentCircularCallForTag <= 0 || mTotalCircularCallsInProcess <= 0) {
326                 Slogf.wtf(TAG, "Current Circular Calls for %s is %d which is unexpected.",
327                         callerTag, currentCircularCallForTag);
328             }
329             mCallerTracker.put(callerTag, currentCircularCallForTag - 1);
330             mTotalCircularCallsInProcess = mTotalCircularCallsInProcess - 1;
331         }
332     }
333 
startTracking(String callerTag)334     private void startTracking(String callerTag) {
335         synchronized (mLock) {
336             if (Binder.getCallingPid() != mOemCarServicePid) return;
337         }
338 
339         int currentCircularCallForTag;
340         int totalCircularCallsInProcess;
341 
342         synchronized (mLock) {
343             currentCircularCallForTag = mCallerTracker.getOrDefault(callerTag, 0) + 1;
344             mCallerTracker.put(callerTag, currentCircularCallForTag);
345             totalCircularCallsInProcess = mTotalCircularCallsInProcess + 1;
346             mTotalCircularCallsInProcess = totalCircularCallsInProcess;
347         }
348 
349         Slogf.w(TAG, "Possible circular call for %s. Current circular calls are %d."
350                 + " Total circular calls are %d.", callerTag, currentCircularCallForTag,
351                 totalCircularCallsInProcess);
352 
353         if (currentCircularCallForTag > MAX_CIRCULAR_CALLS_PER_CALLER) {
354             Slogf.e(TAG, "Current Circular Calls for %s is %d which is more than the limit %d."
355                     + " Calling to crash CarService", callerTag, currentCircularCallForTag,
356                     MAX_CIRCULAR_CALLS_PER_CALLER);
357             crashCarService("Max Circular call for " + callerTag);
358         }
359 
360         if (totalCircularCallsInProcess > MAX_CIRCULAR_CALL_TOTAL) {
361             Slogf.e(TAG, "Total Circular Calls is %d which is more than the limit %d."
362                     + " Calling to crash CarService", totalCircularCallsInProcess,
363                     MAX_CIRCULAR_CALL_TOTAL);
364             crashCarService("Max Circular calls overall");
365         }
366     }
367 
368     /**
369      * Does timed call to the OEM service and crashes the OEM and Car Service if call is not served
370      * within time.
371      *
372      * <p>If OEM service throw TimeoutException, it would crash the CarService and OEM service. If
373      * OemService throws any other exception, {@link Optional#empty()} is returned.
374      *
375      * @param <T> Type of the result.
376      * @param callerTag is tag from the caller. Used for tracking circular calls per binder.
377      * @param callable containing binder call.
378      *
379      * @return Optional carrying result of the binder call. Optional can be empty.
380      */
doBinderCallWithTimeoutCrash(String callerTag, Callable<T> callable)381     public <T> Optional<T> doBinderCallWithTimeoutCrash(String callerTag, Callable<T> callable) {
382         if (DBG) {
383             Slogf.d(TAG, "Received doBinderCallWithTimeoutCrash call for caller tag: %s.",
384                     callerTag);
385         }
386         startTracking(callerTag);
387         try {
388             Future<T> result = mThreadPool.submit(callable);
389             try {
390                 return Optional.ofNullable(result.get(mCrashCallTimeoutMs, TimeUnit.MILLISECONDS));
391             } catch (TimeoutException e) {
392                 Slogf.e(TAG, "Binder call received Exception", e);
393                 crashCarService("TimeoutException");
394             } catch (InterruptedException | ExecutionException e) {
395                 if (e instanceof InterruptedException) {
396                     Thread.currentThread().interrupt(); // Restore the interrupted status
397                 }
398                 Slogf.e(TAG, "Binder call received Exception", e);
399                 return Optional.empty();
400             }
401         } finally {
402             stopTracking(callerTag);
403         }
404 
405         throw new AssertionError("Should not return from crashCarService");
406     }
407 
408     /**
409      * Does one way call to OEM Service. Runnable will be queued to threadpool and not waited for
410      * completion.
411      *
412      * <p>It is recommended to use callable with some result if waiting for call to complete is
413      * required.
414      *
415      * @param callerTag is tag from the caller. Used for tracking circular calls per binder.
416      * @param runnable containing binder call
417      */
doBinderOneWayCall(String callerTag, Runnable runnable)418     public void doBinderOneWayCall(String callerTag, Runnable runnable) {
419         if (DBG) {
420             Slogf.d(TAG, "Received doBinderOneWayCall call for caller tag: %s.", callerTag);
421         }
422 
423         mThreadPool.execute(() -> {
424             startTracking(callerTag);
425             try {
426                 Future<?> result = mThreadPool.submit(runnable);
427                 try {
428                     result.get(mRegularCallTimeoutMs, TimeUnit.MILLISECONDS);
429                 } catch (Exception e) {
430                     if (e instanceof InterruptedException) {
431                         Thread.currentThread().interrupt(); // Restore the interrupted status
432                     }
433                     Slogf.e(TAG, "Exception while running a runnable for caller tag: " + callerTag,
434                             e);
435                 }
436             } finally {
437                 stopTracking(callerTag);
438             }
439         });
440     }
441 
442     /**
443      * Crashes CarService and OEM Service.
444      */
crashCarService(String reason)445     public void crashCarService(String reason) {
446         Slogf.e(TAG, "****Crashing CarService and OEM service because %s****", reason);
447         Slogf.e(TAG, "Car Service stack-");
448         Slogf.e(TAG, Log.getStackTraceString(new Exception()));
449 
450         Callable<String> oemStackTracer = null;
451         synchronized (mLock) {
452             oemStackTracer = mOemStackTracer;
453         }
454 
455         if (oemStackTracer != null) {
456             Slogf.e(TAG, "OEM Service stack-");
457             int timeoutMs = 2000;
458             String stack = "";
459             // Call OEM service directly. Calling any doBinderCallXXX here can lead to infinite loop
460             Future<String> result = mThreadPool.submit(oemStackTracer);
461             try {
462                 stack = result.get(timeoutMs, TimeUnit.MILLISECONDS);
463                 Slogf.e(TAG, stack);
464             } catch (Exception e) {
465                 Slogf.e(TAG, "Didn't received OEM stack within %d milliseconds.\n", timeoutMs);
466             }
467         }
468 
469         int carServicePid = Process.myPid();
470         int oemCarServicePid;
471         synchronized (mLock) {
472             oemCarServicePid = mOemCarServicePid;
473         }
474 
475         if (oemCarServicePid != 0) {
476             Slogf.e(TAG, "Killing OEM service process with PID %d.", oemCarServicePid);
477             Process.killProcess(oemCarServicePid);
478         }
479         Slogf.e(TAG, "Killing Car service process with PID %d.", carServicePid);
480         Process.killProcess(carServicePid);
481         System.exit(EXIT_FLAG);
482     }
483 
484     /**
485      * Updates PID of the OEM process.
486      */
updateOemPid(int pid)487     public void updateOemPid(int pid) {
488         synchronized (mLock) {
489             mOemCarServicePid = pid;
490         }
491     }
492 
493     /**
494      * Dumps
495      */
dump(IndentingPrintWriter writer)496     public void dump(IndentingPrintWriter writer) {
497         writer.println("***CarOemProxyServiceHelper dump***");
498         writer.increaseIndent();
499         synchronized (mLock) {
500             writer.printf("mOemCarServicePid: %d\n", mOemCarServicePid);
501             writer.printf("mCallerTracker.size: %d\n", mCallerTracker.size());
502             if (mCallerTracker.size() > 0) {
503                 writer.increaseIndent();
504                 for (int i = 0; i < mCallerTracker.size(); i++) {
505                     writer.printf("mCallerTracker entry: %d, CallerTag: %s, CircularCalls: %d\n", i,
506                             mCallerTracker.keyAt(i), mCallerTracker.valueAt(i));
507                 }
508                 writer.decreaseIndent();
509             }
510             writer.printf("mRegularCallTimeoutMs: %d\n", mRegularCallTimeoutMs);
511             writer.printf("mCrashCallTimeoutMs: %d\n", mCrashCallTimeoutMs);
512             writer.printf("mBinderDispatchThreadPoolSize: %d\n", mBinderDispatchThreadPoolSize);
513             writer.printf("ThreadPoolSizeFromRRO: %d\n", mThreadPoolSizeFromRRO);
514         }
515         writer.decreaseIndent();
516     }
517 
518     /**
519      * Updates call for getting OEM stack trace.
520      */
updateOemStackCall(Callable<String> oemStackTracer)521     public void updateOemStackCall(Callable<String> oemStackTracer) {
522         synchronized (mLock) {
523             mOemStackTracer = oemStackTracer;
524         }
525     }
526 }
527