1 /*
2  * Copyright (C) 2013 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.exchange.eas;
18 
19 import android.content.ContentResolver;
20 import android.content.ContentValues;
21 import android.content.Context;
22 import android.database.Cursor;
23 import android.os.Bundle;
24 import android.os.SystemClock;
25 import android.provider.CalendarContract;
26 import android.provider.ContactsContract;
27 import android.text.format.DateUtils;
28 
29 import com.android.emailcommon.provider.Account;
30 import com.android.emailcommon.provider.EmailContent;
31 import com.android.emailcommon.provider.EmailContent.AccountColumns;
32 import com.android.emailcommon.provider.EmailContent.MailboxColumns;
33 import com.android.emailcommon.provider.Mailbox;
34 import com.android.exchange.CommandStatusException.CommandStatus;
35 import com.android.exchange.Eas;
36 import com.android.exchange.EasResponse;
37 import com.android.exchange.adapter.PingParser;
38 import com.android.exchange.adapter.Serializer;
39 import com.android.exchange.adapter.Tags;
40 import com.android.mail.utils.LogUtils;
41 
42 import org.apache.http.HttpEntity;
43 
44 import java.io.IOException;
45 import java.util.ArrayList;
46 import java.util.HashSet;
47 
48 /**
49  * Performs an Exchange Ping, which is the command for receiving push notifications.
50  * See http://msdn.microsoft.com/en-us/library/ee200913(v=exchg.80).aspx for more details.
51  */
52 public class EasPing extends EasOperation {
53     private static final String TAG = Eas.LOG_TAG;
54 
55     private static final String WHERE_ACCOUNT_KEY_AND_SERVER_ID =
56             MailboxColumns.ACCOUNT_KEY + "=? and " + MailboxColumns.SERVER_ID + "=?";
57 
58     private final android.accounts.Account mAmAccount;
59     private long mPingDuration;
60 
61     /**
62      * The default heartbeat interval specified to the Exchange server. This is the maximum amount
63      * of time (in seconds) that the server should wait before responding to the ping request.
64      */
65     private static final long DEFAULT_PING_HEARTBEAT =
66             8 * (DateUtils.MINUTE_IN_MILLIS / DateUtils.SECOND_IN_MILLIS);
67 
68     /**
69      * The minimum heartbeat interval we should ever use, in seconds.
70      */
71     private static final long MINIMUM_PING_HEARTBEAT =
72             8 * (DateUtils.MINUTE_IN_MILLIS / DateUtils.SECOND_IN_MILLIS);
73 
74     /**
75      * The maximum heartbeat interval we should ever use, in seconds.
76      */
77     private static final long MAXIMUM_PING_HEARTBEAT =
78             28 * (DateUtils.MINUTE_IN_MILLIS / DateUtils.SECOND_IN_MILLIS);
79 
80     /**
81      * The maximum amount that we can change with each adjustment, in seconds.
82      */
83     private static final long MAXIMUM_HEARTBEAT_INCREMENT =
84             5 * (DateUtils.MINUTE_IN_MILLIS / DateUtils.SECOND_IN_MILLIS);
85 
86     /**
87      * The extra time for the timeout used for the HTTP POST (in milliseconds). Notionally this
88      * should be the same as ping heartbeat but in practice is a few seconds longer to allow for
89      * latency in the server's response.
90      */
91     private static final long EXTRA_POST_TIMEOUT_MILLIS = 5 * DateUtils.SECOND_IN_MILLIS;
92 
EasPing(final Context context, final Account account, final android.accounts.Account amAccount)93     public EasPing(final Context context, final Account account,
94             final android.accounts.Account amAccount) {
95         super(context, account);
96         mAmAccount = amAccount;
97         mPingDuration = account.mPingDuration;
98         if (mPingDuration == 0) {
99             mPingDuration = DEFAULT_PING_HEARTBEAT;
100         }
101         LogUtils.d(TAG, "initial ping duration " + mPingDuration + " account " + getAccountId());
102     }
103 
doPing()104     public final int doPing() {
105         final long startTime = SystemClock.elapsedRealtime();
106         final int result = performOperation();
107         if (result == RESULT_RESTART) {
108             return PingParser.STATUS_EXPIRED;
109         } else  if (result == RESULT_NETWORK_PROBLEM) {
110             final long timeoutDuration = SystemClock.elapsedRealtime() - startTime;
111             LogUtils.d(TAG, "doPing request failure, timed out after %d millis", timeoutDuration);
112             decreasePingDuration();
113         }
114         return result;
115     }
116 
decreasePingDuration()117     private void decreasePingDuration() {
118         mPingDuration = Math.max(MINIMUM_PING_HEARTBEAT,
119                 mPingDuration - MAXIMUM_HEARTBEAT_INCREMENT);
120         LogUtils.d(TAG, "decreasePingDuration adjusting by " + MAXIMUM_HEARTBEAT_INCREMENT +
121                 " new duration " + mPingDuration + " account " + getAccountId());
122         storePingDuration();
123     }
124 
increasePingDuration()125     private void increasePingDuration() {
126         mPingDuration = Math.min(MAXIMUM_PING_HEARTBEAT,
127                 mPingDuration + MAXIMUM_HEARTBEAT_INCREMENT);
128         LogUtils.d(TAG, "increasePingDuration adjusting by " + MAXIMUM_HEARTBEAT_INCREMENT +
129                 " new duration " + mPingDuration + " account " + getAccountId());
130         storePingDuration();
131     }
132 
storePingDuration()133     private void storePingDuration() {
134         final ContentValues values = new ContentValues(1);
135         values.put(AccountColumns.PING_DURATION, mPingDuration);
136         Account.update(mContext, Account.CONTENT_URI, getAccountId(), values);
137     }
138 
getAmAccount()139     public final android.accounts.Account getAmAccount() {
140         return mAmAccount;
141     }
142 
143     @Override
getCommand()144     protected String getCommand() {
145         return "Ping";
146     }
147 
148     @Override
getRequestEntity()149     protected HttpEntity getRequestEntity() throws IOException {
150         // Get the mailboxes that need push notifications.
151         final Cursor c = Mailbox.getMailboxesForPush(mContext.getContentResolver(),
152                 getAccountId());
153         if (c == null) {
154             throw new IllegalStateException("Could not read mailboxes");
155         }
156 
157         // TODO: Ideally we never even get here unless we already know we want a push.
158         Serializer s = null;
159         try {
160             while (c.moveToNext()) {
161                 final Mailbox mailbox = new Mailbox();
162                 mailbox.restore(c);
163                 s = handleOneMailbox(s, mailbox);
164             }
165         } finally {
166             c.close();
167         }
168 
169         if (s == null) {
170             abort();
171             throw new IOException("No mailboxes want push");
172         }
173         // This sequence of end()s corresponds to the start()s that occur in handleOneMailbox when
174         // the Serializer is first created. If either side changes, the other must be kept in sync.
175         s.end().end().done();
176         return makeEntity(s);
177     }
178 
179     @Override
handleResponse(final EasResponse response)180     protected int handleResponse(final EasResponse response) throws IOException {
181         if (response.isEmpty()) {
182             // TODO this should probably not be an IOException, maybe something more descriptive?
183             throw new IOException("Empty ping response");
184         }
185 
186         LogUtils.d(TAG, "EasPing.handleResponse");
187 
188         // Handle a valid response.
189         final PingParser pp = new PingParser(response.getInputStream());
190         pp.parse();
191         final int pingStatus = pp.getPingStatus();
192 
193         // Take the appropriate action for this response.
194         // Many of the responses require no explicit action here, they just influence
195         // our re-ping behavior, which is handled by the caller.
196         final long accountId = getAccountId();
197         switch (pingStatus) {
198             case PingParser.STATUS_EXPIRED:
199                 LogUtils.i(TAG, "Ping expired for account %d", accountId);
200                 // On successful expiration, we can increase our ping duration
201                 increasePingDuration();
202                 break;
203             case PingParser.STATUS_CHANGES_FOUND:
204                 LogUtils.i(TAG, "Ping found changed folders for account %d", accountId);
205                 requestSyncForSyncList(pp.getSyncList());
206                 break;
207             case PingParser.STATUS_REQUEST_INCOMPLETE:
208             case PingParser.STATUS_REQUEST_MALFORMED:
209                 // These two cases indicate that the ping request was somehow bad.
210                 // TODO: It's insanity to re-ping with the same data and expect a different
211                 // result. Improve this if possible.
212                 LogUtils.e(TAG, "Bad ping request for account %d", accountId);
213                 break;
214             case PingParser.STATUS_REQUEST_HEARTBEAT_OUT_OF_BOUNDS:
215                 long newDuration = pp.getHeartbeatInterval();
216                 LogUtils.i(TAG, "Heartbeat out of bounds for account %d, " +
217                         "old duration %d new duration %d", accountId, mPingDuration, newDuration);
218                 mPingDuration = newDuration;
219                 storePingDuration();
220                 break;
221             case PingParser.STATUS_REQUEST_TOO_MANY_FOLDERS:
222                 LogUtils.i(TAG, "Too many folders for account %d", accountId);
223                 break;
224             case PingParser.STATUS_FOLDER_REFRESH_NEEDED:
225                 LogUtils.i(TAG, "FolderSync needed for account %d", accountId);
226                 requestFolderSync();
227                 break;
228             case PingParser.STATUS_SERVER_ERROR:
229                 LogUtils.i(TAG, "Server error for account %d", accountId);
230                 break;
231             case CommandStatus.SERVER_ERROR_RETRY:
232                 // Try again later.
233                 LogUtils.i(TAG, "Retryable server error for account %d", accountId);
234                 return RESULT_RESTART;
235 
236             // These errors should not happen.
237             case CommandStatus.USER_DISABLED_FOR_SYNC:
238             case CommandStatus.USERS_DISABLED_FOR_SYNC:
239             case CommandStatus.USER_ON_LEGACY_SERVER_CANT_SYNC:
240             case CommandStatus.DEVICE_QUARANTINED:
241             case CommandStatus.ACCESS_DENIED:
242             case CommandStatus.USER_ACCOUNT_DISABLED:
243             case CommandStatus.NOT_PROVISIONABLE_PARTIAL:
244             case CommandStatus.NOT_PROVISIONABLE_LEGACY_DEVICE:
245             case CommandStatus.TOO_MANY_PARTNERSHIPS:
246                 LogUtils.e(TAG, "Unexpected error %d on ping", pingStatus);
247                 return RESULT_AUTHENTICATION_ERROR;
248 
249             // These errors should not happen.
250             case CommandStatus.SYNC_STATE_NOT_FOUND:
251             case CommandStatus.SYNC_STATE_LOCKED:
252             case CommandStatus.SYNC_STATE_CORRUPT:
253             case CommandStatus.SYNC_STATE_EXISTS:
254             case CommandStatus.SYNC_STATE_INVALID:
255             case CommandStatus.NEEDS_PROVISIONING_WIPE:
256             case CommandStatus.NEEDS_PROVISIONING:
257             case CommandStatus.NEEDS_PROVISIONING_REFRESH:
258             case CommandStatus.NEEDS_PROVISIONING_INVALID:
259             case CommandStatus.WTF_INVALID_COMMAND:
260             case CommandStatus.WTF_INVALID_PROTOCOL:
261             case CommandStatus.WTF_DEVICE_CLAIMS_EXTERNAL_MANAGEMENT:
262             case CommandStatus.WTF_UNKNOWN_ITEM_TYPE:
263             case CommandStatus.WTF_REQUIRES_PROXY_WITHOUT_SSL:
264             case CommandStatus.ITEM_NOT_FOUND:
265                 LogUtils.e(TAG, "Unexpected error %d on ping", pingStatus);
266                 return RESULT_OTHER_FAILURE;
267 
268             default:
269                 break;
270         }
271 
272         return pingStatus;
273     }
274 
275 
276     @Override
addPolicyKeyHeaderToRequest()277     protected boolean addPolicyKeyHeaderToRequest() {
278         return false;
279     }
280 
281     @Override
getTimeout()282     protected long getTimeout() {
283         return mPingDuration * DateUtils.SECOND_IN_MILLIS + EXTRA_POST_TIMEOUT_MILLIS;
284     }
285 
286     /**
287      * If mailbox is eligible for push, add it to the ping request, creating the {@link Serializer}
288      * for the request if necessary.
289      * @param mailbox The mailbox to check.
290      * @param s The {@link Serializer} for this request, or null if it hasn't been created yet.
291      * @return The {@link Serializer} for this request, or null if it hasn't been created yet.
292      * @throws IOException
293      */
handleOneMailbox(Serializer s, final Mailbox mailbox)294     private Serializer handleOneMailbox(Serializer s, final Mailbox mailbox) throws IOException {
295         // We can't push until the initial sync is done
296         if (mailbox.mSyncKey != null && !mailbox.mSyncKey.equals("0")) {
297             if (ContentResolver.getSyncAutomatically(mAmAccount,
298                     Mailbox.getAuthority(mailbox.mType))) {
299                 if (s == null) {
300                     // No serializer yet, so create and initialize it.
301                     // Note that these start()s correspond to the end()s in doInBackground.
302                     // If either side changes, the other must be kept in sync.
303                     s = new Serializer();
304                     s.start(Tags.PING_PING);
305                     s.data(Tags.PING_HEARTBEAT_INTERVAL, Long.toString(mPingDuration));
306                     s.start(Tags.PING_FOLDERS);
307                 }
308                 s.start(Tags.PING_FOLDER);
309                 s.data(Tags.PING_ID, mailbox.mServerId);
310                 s.data(Tags.PING_CLASS, Eas.getFolderClass(mailbox.mType));
311                 s.end();
312             }
313         }
314         return s;
315     }
316 
317     /**
318      * Make the appropriate calls to {@link ContentResolver#requestSync} indicated by the
319      * current ping response.
320      * @param syncList The list of folders that need to be synced.
321      */
requestSyncForSyncList(final ArrayList<String> syncList)322     private void requestSyncForSyncList(final ArrayList<String> syncList) {
323         final String[] bindArguments = new String[2];
324         bindArguments[0] = Long.toString(getAccountId());
325 
326         final ArrayList<Long> emailMailboxIds = new ArrayList<Long>();
327         final ArrayList<Long> calendarMailboxIds = new ArrayList<Long>();
328         final ArrayList<Long> contactsMailboxIds = new ArrayList<Long>();
329 
330         for (final String serverId : syncList) {
331             bindArguments[1] = serverId;
332             // TODO: Rather than one query per ping mailbox, do it all in one?
333             final Cursor c = mContext.getContentResolver().query(Mailbox.CONTENT_URI,
334                     Mailbox.CONTENT_PROJECTION, WHERE_ACCOUNT_KEY_AND_SERVER_ID,
335                     bindArguments, null);
336             if (c == null) {
337                 // TODO: proper error handling.
338                 break;
339             }
340             try {
341                 /**
342                  * Check the boxes reporting changes to see if there really were any...
343                  * We do this because bugs in various Exchange servers can put us into a
344                  * looping behavior by continually reporting changes in a mailbox, even
345                  * when there aren't any.
346                  *
347                  * This behavior is seemingly random, and therefore we must code
348                  * defensively by backing off of push behavior when it is detected.
349                  *
350                  * One known cause, on certain Exchange 2003 servers, is acknowledged by
351                  * Microsoft, and the server hotfix for this case can be found at
352                  * http://support.microsoft.com/kb/923282
353                  */
354                 // TODO: Implement the above
355                 if (c.moveToFirst()) {
356                     final long mailboxId = c.getLong(Mailbox.CONTENT_ID_COLUMN);
357                     final int contentType = c.getInt(Mailbox.CONTENT_TYPE_COLUMN);
358                     switch (contentType) {
359                         case Mailbox.TYPE_MAIL:
360                         case Mailbox.TYPE_INBOX:
361                         case Mailbox.TYPE_DRAFTS:
362                         case Mailbox.TYPE_SENT:
363                         case Mailbox.TYPE_TRASH:
364                         case Mailbox.TYPE_JUNK:
365                             emailMailboxIds.add(mailboxId);
366                         case Mailbox.TYPE_CALENDAR:
367                             calendarMailboxIds.add(mailboxId);
368                         case Mailbox.TYPE_CONTACTS:
369                             contactsMailboxIds.add(mailboxId);
370                         default:
371                             LogUtils.e(LOG_TAG, "unexpected collectiontype %d in EasPing",
372                                     contentType);
373                     }
374                 }
375             } finally {
376                 c.close();
377             }
378         }
379         requestSyncForMailboxes(mAmAccount, EmailContent.AUTHORITY, emailMailboxIds);
380         requestSyncForMailboxes(mAmAccount, CalendarContract.AUTHORITY, calendarMailboxIds);
381         requestSyncForMailboxes(mAmAccount, ContactsContract.AUTHORITY, contactsMailboxIds);
382     }
383 
384     /**
385      * Issue a {@link ContentResolver#requestSync} to trigger a FolderSync for an account.
386      */
requestFolderSync()387     private void requestFolderSync() {
388         final Bundle extras = new Bundle(1);
389         extras.putBoolean(Mailbox.SYNC_EXTRA_ACCOUNT_ONLY, true);
390         ContentResolver.requestSync(mAmAccount, EmailContent.AUTHORITY, extras);
391         LogUtils.i(LOG_TAG, "requestFolderSync EasPing %s, %s",
392                 mAmAccount.toString(), extras.toString());
393     }
394 
395     /**
396      * Request a ping-only sync via the SyncManager. This is used in error paths, which is also why
397      * we don't just create and start a new ping task immediately: in the case where we have loss
398      * of network, we want to take advantage of the SyncManager to schedule this when we expect it
399      * to be able to work.
400      * @param amAccount Account that needs to ping.
401      */
requestPing(final android.accounts.Account amAccount)402     public static void requestPing(final android.accounts.Account amAccount) {
403         final Bundle extras = new Bundle(2);
404         extras.putBoolean(Mailbox.SYNC_EXTRA_PUSH_ONLY, true);
405         extras.putBoolean(ContentResolver.SYNC_EXTRAS_MANUAL, true);
406         ContentResolver.requestSync(amAccount, EmailContent.AUTHORITY, extras);
407         LogUtils.i(LOG_TAG, "requestPing EasOperation %s, %s",
408                 amAccount.toString(), extras.toString());
409     }
410 
411 }
412