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.devicepolicy;
18 
19 import static java.util.concurrent.TimeUnit.NANOSECONDS;
20 
21 import android.app.AlarmManager;
22 import android.app.AlarmManager.OnAlarmListener;
23 import android.app.admin.DeviceAdminReceiver;
24 import android.app.admin.NetworkEvent;
25 import android.os.Bundle;
26 import android.os.Handler;
27 import android.os.Looper;
28 import android.os.Message;
29 import android.os.SystemClock;
30 import android.util.LongSparseArray;
31 import android.util.Slog;
32 
33 import com.android.internal.annotations.GuardedBy;
34 import com.android.internal.annotations.VisibleForTesting;
35 
36 import java.util.ArrayList;
37 import java.util.List;
38 import java.util.concurrent.TimeUnit;
39 
40 /**
41  * A Handler class for managing network logging on a background thread.
42  */
43 final class NetworkLoggingHandler extends Handler {
44 
45     private static final String TAG = NetworkLoggingHandler.class.getSimpleName();
46 
47     static final String NETWORK_EVENT_KEY = "network_event";
48 
49     // If this value changes, update DevicePolicyManager#retrieveNetworkLogs() javadoc
50     private static final int MAX_EVENTS_PER_BATCH = 1200;
51 
52     /**
53      * Maximum number of batches to store in memory. If more batches are generated and the DO
54      * doesn't fetch them, we will discard the oldest one.
55      */
56     private static final int MAX_BATCHES = 5;
57 
58     private static final long BATCH_FINALIZATION_TIMEOUT_MS = 90 * 60 * 1000; // 1.5h
59     private static final long BATCH_FINALIZATION_TIMEOUT_ALARM_INTERVAL_MS = 30 * 60 * 1000; // 30m
60 
61     private static final String NETWORK_LOGGING_TIMEOUT_ALARM_TAG = "NetworkLogging.batchTimeout";
62 
63     /** Delay after which older batches get discarded after a retrieval. */
64     private static final long RETRIEVED_BATCH_DISCARD_DELAY_MS = 5 * 60 * 1000; // 5m
65 
66     /** Throttle batch finalization to 10 seconds.*/
67     private static final long FORCE_FETCH_THROTTLE_NS = TimeUnit.SECONDS.toNanos(10);
68     /** Timestamp of the last call to finalise a batch. Used for throttling forced finalization.*/
69     @GuardedBy("this")
70     private long mLastFinalizationNanos = -1;
71 
72     /** Do not call into mDpm with locks held */
73     private final DevicePolicyManagerService mDpm;
74     private final AlarmManager mAlarmManager;
75 
76     private long mId;
77 
78     private final OnAlarmListener mBatchTimeoutAlarmListener = new OnAlarmListener() {
79         @Override
80         public void onAlarm() {
81             Slog.d(TAG, "Received a batch finalization timeout alarm, finalizing "
82                     + mNetworkEvents.size() + " pending events.");
83             Bundle notificationExtras = null;
84             synchronized (NetworkLoggingHandler.this) {
85                 notificationExtras = finalizeBatchAndBuildDeviceOwnerMessageLocked();
86             }
87             if (notificationExtras != null) {
88                 notifyDeviceOwner(notificationExtras);
89             }
90         }
91     };
92 
93     @VisibleForTesting
94     static final int LOG_NETWORK_EVENT_MSG = 1;
95 
96     /** Network events accumulated so far to be finalized into a batch at some point. */
97     @GuardedBy("this")
98     private ArrayList<NetworkEvent> mNetworkEvents = new ArrayList<>();
99 
100     /**
101      * Up to {@code MAX_BATCHES} finalized batches of logs ready to be retrieved by the DO. Already
102      * retrieved batches are discarded after {@code RETRIEVED_BATCH_DISCARD_DELAY_MS}.
103      */
104     @GuardedBy("this")
105     private final LongSparseArray<ArrayList<NetworkEvent>> mBatches =
106             new LongSparseArray<>(MAX_BATCHES);
107 
108     @GuardedBy("this")
109     private boolean mPaused = false;
110 
111     // each full batch is represented by its token, which the DPC has to provide back to retrieve it
112     @GuardedBy("this")
113     private long mCurrentBatchToken;
114 
115     @GuardedBy("this")
116     private long mLastRetrievedBatchToken;
117 
NetworkLoggingHandler(Looper looper, DevicePolicyManagerService dpm)118     NetworkLoggingHandler(Looper looper, DevicePolicyManagerService dpm) {
119         this(looper, dpm, 0 /* event id */);
120     }
121 
122     @VisibleForTesting
NetworkLoggingHandler(Looper looper, DevicePolicyManagerService dpm, long id)123     NetworkLoggingHandler(Looper looper, DevicePolicyManagerService dpm, long id) {
124         super(looper);
125         this.mDpm = dpm;
126         this.mAlarmManager = mDpm.mInjector.getAlarmManager();
127         this.mId = id;
128     }
129 
130     @Override
handleMessage(Message msg)131     public void handleMessage(Message msg) {
132         switch (msg.what) {
133             case LOG_NETWORK_EVENT_MSG: {
134                 final NetworkEvent networkEvent = msg.getData().getParcelable(NETWORK_EVENT_KEY);
135                 if (networkEvent != null) {
136                     Bundle notificationExtras = null;
137                     synchronized (NetworkLoggingHandler.this) {
138                         mNetworkEvents.add(networkEvent);
139                         if (mNetworkEvents.size() >= MAX_EVENTS_PER_BATCH) {
140                             notificationExtras = finalizeBatchAndBuildDeviceOwnerMessageLocked();
141                         }
142                     }
143                     if (notificationExtras != null) {
144                         notifyDeviceOwner(notificationExtras);
145                     }
146                 }
147                 break;
148             }
149             default: {
150                 Slog.d(TAG, "NetworkLoggingHandler received an unknown of message.");
151                 break;
152             }
153         }
154     }
155 
scheduleBatchFinalization()156     void scheduleBatchFinalization() {
157         final long when = SystemClock.elapsedRealtime() + BATCH_FINALIZATION_TIMEOUT_MS;
158         // We use alarm manager and not just postDelayed here to ensure the batch gets finalized
159         // even if the device goes to sleep.
160         mAlarmManager.setWindow(AlarmManager.ELAPSED_REALTIME_WAKEUP, when,
161                 BATCH_FINALIZATION_TIMEOUT_ALARM_INTERVAL_MS, NETWORK_LOGGING_TIMEOUT_ALARM_TAG,
162                 mBatchTimeoutAlarmListener, this);
163         Slog.d(TAG, "Scheduled a new batch finalization alarm " + BATCH_FINALIZATION_TIMEOUT_MS
164                 + "ms from now.");
165     }
166 
167     /**
168      * Forces batch finalisation. Throttled to 10 seconds per batch finalisation.
169      * @return the number of milliseconds to wait until batch finalisation can be forced.
170      */
forceBatchFinalization()171     long forceBatchFinalization() {
172         Bundle notificationExtras;
173         synchronized (this) {
174             final long toWaitNanos =
175                 mLastFinalizationNanos + FORCE_FETCH_THROTTLE_NS - System.nanoTime();
176             if (toWaitNanos > 0) {
177                 return NANOSECONDS.toMillis(toWaitNanos) + 1; // Round up.
178             }
179             notificationExtras = finalizeBatchAndBuildDeviceOwnerMessageLocked();
180         }
181         if (notificationExtras != null) {
182             notifyDeviceOwner(notificationExtras);
183         }
184         return 0;
185     }
186 
pause()187     synchronized void pause() {
188         Slog.d(TAG, "Paused network logging");
189         mPaused = true;
190     }
191 
resume()192     void resume() {
193         Bundle notificationExtras = null;
194         synchronized (this) {
195             if (!mPaused) {
196                 Slog.d(TAG, "Attempted to resume network logging, but logging is not paused.");
197                 return;
198             }
199 
200             Slog.d(TAG, "Resumed network logging. Current batch=" + mCurrentBatchToken
201                     + ", LastRetrievedBatch=" + mLastRetrievedBatchToken);
202             mPaused = false;
203 
204             // If there is a batch ready that the device owner hasn't been notified about, do it now.
205             if (mBatches.size() > 0 && mLastRetrievedBatchToken != mCurrentBatchToken) {
206                 scheduleBatchFinalization();
207                 notificationExtras = buildDeviceOwnerMessageLocked();
208             }
209         }
210         if (notificationExtras != null) {
211             notifyDeviceOwner(notificationExtras);
212         }
213     }
214 
discardLogs()215     synchronized void discardLogs() {
216         mBatches.clear();
217         mNetworkEvents = new ArrayList<>();
218         Slog.d(TAG, "Discarded all network logs");
219     }
220 
221     @GuardedBy("this")
222     /** @returns extras if a message should be sent to the device owner */
finalizeBatchAndBuildDeviceOwnerMessageLocked()223     private Bundle finalizeBatchAndBuildDeviceOwnerMessageLocked() {
224         mLastFinalizationNanos = System.nanoTime();
225         Bundle notificationExtras = null;
226         if (mNetworkEvents.size() > 0) {
227             // Assign ids to the events.
228             for (NetworkEvent event : mNetworkEvents) {
229                 event.setId(mId);
230                 if (mId == Long.MAX_VALUE) {
231                     Slog.i(TAG, "Reached maximum id value; wrapping around ." + mCurrentBatchToken);
232                     mId = 0;
233                 } else {
234                     mId++;
235                 }
236             }
237             // Finalize the batch and start a new one from scratch.
238             if (mBatches.size() >= MAX_BATCHES) {
239                 // Remove the oldest batch if we hit the limit.
240                 mBatches.removeAt(0);
241             }
242             mCurrentBatchToken++;
243             mBatches.append(mCurrentBatchToken, mNetworkEvents);
244             mNetworkEvents = new ArrayList<>();
245             if (!mPaused) {
246                 notificationExtras = buildDeviceOwnerMessageLocked();
247             }
248         } else {
249             // Don't notify the DO, since there are no events; DPC can still retrieve
250             // the last full batch if not paused.
251             Slog.d(TAG, "Was about to finalize the batch, but there were no events to send to"
252                     + " the DPC, the batchToken of last available batch: " + mCurrentBatchToken);
253         }
254         // Regardless of whether the batch was non-empty schedule a new finalization after timeout.
255         scheduleBatchFinalization();
256         return notificationExtras;
257     }
258 
259     @GuardedBy("this")
260     /** Build extras notification to the DO. Should only be called when there
261         is a batch available. */
buildDeviceOwnerMessageLocked()262     private Bundle buildDeviceOwnerMessageLocked() {
263         final Bundle extras = new Bundle();
264         final int lastBatchSize = mBatches.valueAt(mBatches.size() - 1).size();
265         extras.putLong(DeviceAdminReceiver.EXTRA_NETWORK_LOGS_TOKEN, mCurrentBatchToken);
266         extras.putInt(DeviceAdminReceiver.EXTRA_NETWORK_LOGS_COUNT, lastBatchSize);
267         return extras;
268     }
269 
270     /** Sends a notification to the DO. Should not hold locks as DevicePolicyManagerService may
271         call into NetworkLoggingHandler. */
notifyDeviceOwner(Bundle extras)272     private void notifyDeviceOwner(Bundle extras) {
273         Slog.d(TAG, "Sending network logging batch broadcast to device owner, batchToken: "
274                 + extras.getLong(DeviceAdminReceiver.EXTRA_NETWORK_LOGS_TOKEN, -1));
275         if (Thread.holdsLock(this)) {
276             Slog.wtfStack(TAG, "Shouldn't be called with NetworkLoggingHandler lock held");
277             return;
278         }
279         mDpm.sendDeviceOwnerCommand(DeviceAdminReceiver.ACTION_NETWORK_LOGS_AVAILABLE, extras);
280     }
281 
retrieveFullLogBatch(final long batchToken)282     synchronized List<NetworkEvent> retrieveFullLogBatch(final long batchToken) {
283         final int index = mBatches.indexOfKey(batchToken);
284         if (index < 0) {
285             // Invalid token or batch has already been discarded.
286             return null;
287         }
288 
289         // Schedule this and older batches to be discarded after a delay to lessen memory load
290         // without interfering with the admin's ability to collect logs out-of-order.
291         // It isn't critical and we allow it to be delayed further if the phone sleeps, so we don't
292         // use the alarm manager here.
293         postDelayed(() -> {
294             synchronized(this) {
295                 while (mBatches.size() > 0 && mBatches.keyAt(0) <= batchToken) {
296                     mBatches.removeAt(0);
297                 }
298             }
299         }, RETRIEVED_BATCH_DISCARD_DELAY_MS);
300 
301         mLastRetrievedBatchToken = batchToken;
302         return mBatches.valueAt(index);
303     }
304 }
305 
306