1 /*
2  * Copyright (C) 2015 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.content;
18 
19 import android.app.job.JobParameters;
20 import android.app.job.JobService;
21 import android.content.Intent;
22 import android.os.Message;
23 import android.os.Messenger;
24 import android.os.RemoteException;
25 import android.os.SystemClock;
26 import android.util.Log;
27 import android.util.Slog;
28 import android.util.SparseArray;
29 import android.util.SparseBooleanArray;
30 import android.util.SparseLongArray;
31 
32 import com.android.internal.annotations.GuardedBy;
33 
34 public class SyncJobService extends JobService {
35     private static final String TAG = "SyncManager";
36 
37     public static final String EXTRA_MESSENGER = "messenger";
38 
39     private Messenger mMessenger;
40 
41     private final Object mLock = new Object();
42 
43     @GuardedBy("mLock")
44     private final SparseArray<JobParameters> mJobParamsMap = new SparseArray<>();
45 
46     @GuardedBy("mLock")
47     private final SparseBooleanArray mStartedSyncs = new SparseBooleanArray();
48 
49     @GuardedBy("mLock")
50     private final SparseLongArray mJobStartUptimes = new SparseLongArray();
51 
52     private final SyncLogger mLogger = SyncLogger.getInstance();
53 
54     /**
55      * This service is started by the SyncManager which passes a messenger object to
56      * communicate back with it. It never stops while the device is running.
57      */
58     @Override
onStartCommand(Intent intent, int flags, int startId)59     public int onStartCommand(Intent intent, int flags, int startId) {
60         mMessenger = intent.getParcelableExtra(EXTRA_MESSENGER);
61         Message m = Message.obtain();
62         m.what = SyncManager.SyncHandler.MESSAGE_JOBSERVICE_OBJECT;
63         m.obj = this;
64         sendMessage(m);
65 
66         return START_NOT_STICKY;
67     }
68 
sendMessage(Message message)69     private void sendMessage(Message message) {
70         if (mMessenger == null) {
71             Slog.e(TAG, "Messenger not initialized.");
72             return;
73         }
74         try {
75             mMessenger.send(message);
76         } catch (RemoteException e) {
77             Slog.e(TAG, e.toString());
78         }
79     }
80 
81     @Override
onStartJob(JobParameters params)82     public boolean onStartJob(JobParameters params) {
83 
84         mLogger.purgeOldLogs();
85 
86         boolean isLoggable = Log.isLoggable(TAG, Log.VERBOSE);
87         synchronized (mLock) {
88             final int jobId = params.getJobId();
89             mJobParamsMap.put(jobId, params);
90 
91             mStartedSyncs.delete(jobId);
92             mJobStartUptimes.put(jobId, SystemClock.uptimeMillis());
93         }
94         Message m = Message.obtain();
95         m.what = SyncManager.SyncHandler.MESSAGE_START_SYNC;
96         SyncOperation op = SyncOperation.maybeCreateFromJobExtras(params.getExtras());
97 
98         mLogger.log("onStartJob() jobid=", params.getJobId(), " op=", op);
99 
100         if (op == null) {
101             Slog.e(TAG, "Got invalid job " + params.getJobId());
102             return false;
103         }
104         if (isLoggable) {
105             Slog.v(TAG, "Got start job message " + op.target);
106         }
107         m.obj = op;
108         sendMessage(m);
109         return true;
110     }
111 
112     @Override
onStopJob(JobParameters params)113     public boolean onStopJob(JobParameters params) {
114         if (Log.isLoggable(TAG, Log.VERBOSE)) {
115             Slog.v(TAG, "onStopJob called " + params.getJobId() + ", reason: "
116                     + params.getStopReason());
117         }
118         final boolean readyToSync = SyncManager.readyToSync();
119 
120         mLogger.log("onStopJob() ", mLogger.jobParametersToString(params),
121                 " readyToSync=", readyToSync);
122         synchronized (mLock) {
123             final int jobId = params.getJobId();
124             mJobParamsMap.remove(jobId);
125 
126             final long startUptime = mJobStartUptimes.get(jobId);
127             final long nowUptime = SystemClock.uptimeMillis();
128             final long runtime = nowUptime - startUptime;
129 
130 
131             if (startUptime == 0) {
132                 wtf("Job " + jobId + " start uptime not found: "
133                         + " params=" + jobParametersToString(params));
134             } else if (runtime > 60 * 1000) {
135                 // WTF if startSyncH() hasn't happened, *unless* onStopJob() was called too soon.
136                 // (1 minute threshold.)
137                 // Also don't wtf when it's not ready to sync.
138                 if (readyToSync && !mStartedSyncs.get(jobId)) {
139                     wtf("Job " + jobId + " didn't start: "
140                             + " startUptime=" + startUptime
141                             + " nowUptime=" + nowUptime
142                             + " params=" + jobParametersToString(params));
143                 }
144             } else if (runtime < 10 * 1000) {
145                 // This happens too in a normal case too, and it's rather too often.
146                 // Disable it for now.
147 //                // Job stopped too soon. WTF.
148 //                wtf("Job " + jobId + " stopped in " + runtime + " ms: "
149 //                        + " startUptime=" + startUptime
150 //                        + " nowUptime=" + nowUptime
151 //                        + " params=" + jobParametersToString(params));
152             }
153 
154             mStartedSyncs.delete(jobId);
155             mJobStartUptimes.delete(jobId);
156         }
157         Message m = Message.obtain();
158         m.what = SyncManager.SyncHandler.MESSAGE_STOP_SYNC;
159         m.obj = SyncOperation.maybeCreateFromJobExtras(params.getExtras());
160         if (m.obj == null) {
161             return false;
162         }
163 
164         // Reschedule if this job was NOT explicitly canceled.
165         m.arg1 = params.getStopReason() != JobParameters.REASON_CANCELED ? 1 : 0;
166         // Apply backoff only if stop is called due to timeout.
167         m.arg2 = params.getStopReason() == JobParameters.REASON_TIMEOUT ? 1 : 0;
168 
169         sendMessage(m);
170         return false;
171     }
172 
callJobFinished(int jobId, boolean needsReschedule, String why)173     public void callJobFinished(int jobId, boolean needsReschedule, String why) {
174         synchronized (mLock) {
175             JobParameters params = mJobParamsMap.get(jobId);
176             mLogger.log("callJobFinished()",
177                     " jobid=", jobId,
178                     " needsReschedule=", needsReschedule,
179                     " ", mLogger.jobParametersToString(params),
180                     " why=", why);
181             if (params != null) {
182                 jobFinished(params, needsReschedule);
183                 mJobParamsMap.remove(jobId);
184             } else {
185                 Slog.e(TAG, "Job params not found for " + String.valueOf(jobId));
186             }
187         }
188     }
189 
markSyncStarted(int jobId)190     public void markSyncStarted(int jobId) {
191         synchronized (mLock) {
192             mStartedSyncs.put(jobId, true);
193         }
194     }
195 
jobParametersToString(JobParameters params)196     public static String jobParametersToString(JobParameters params) {
197         if (params == null) {
198             return "job:null";
199         } else {
200             return "job:#" + params.getJobId() + ":"
201                     + "sr=[" + params.getStopReason() + "/" + params.getDebugStopReason() + "]:"
202                     + SyncOperation.maybeCreateFromJobExtras(params.getExtras());
203         }
204     }
205 
wtf(String message)206     private void wtf(String message) {
207         mLogger.log(message);
208         Slog.wtf(TAG, message);
209     }
210 }
211