Java tutorial
/* * Copyright (C) 2011 The Android Open Source Project * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. */ package com.android.exchange; import android.content.ContentResolver; import android.content.ContentUris; import android.content.ContentValues; import android.content.Context; import android.database.Cursor; import android.net.TrafficStats; import android.os.SystemClock; import android.provider.CalendarContract; import android.provider.ContactsContract; import android.text.TextUtils; import android.text.format.DateUtils; import com.android.emailcommon.TrafficFlags; import com.android.emailcommon.mail.MessagingException; import com.android.emailcommon.provider.Account; import com.android.emailcommon.provider.EmailContent; import com.android.emailcommon.provider.EmailContent.AccountColumns; import com.android.emailcommon.provider.EmailContent.HostAuthColumns; import com.android.emailcommon.provider.EmailContent.MailboxColumns; import com.android.emailcommon.provider.HostAuth; import com.android.emailcommon.provider.Mailbox; import com.android.emailcommon.provider.MailboxUtilities; import com.android.emailcommon.provider.Policy; import com.android.emailcommon.provider.ProviderUnavailableException; import com.android.emailcommon.service.PolicyServiceProxy; import com.android.exchange.CommandStatusException.CommandStatus; import com.android.exchange.adapter.AccountSyncAdapter; import com.android.exchange.adapter.FolderSyncParser; import com.android.exchange.adapter.Parser.EasParserException; import com.android.exchange.adapter.PingParser; import com.android.exchange.adapter.Serializer; import com.android.exchange.adapter.Tags; import com.android.mail.utils.LogUtils; import com.google.common.annotations.VisibleForTesting; import org.apache.http.Header; import org.apache.http.HttpStatus; import org.apache.http.entity.ByteArrayEntity; import java.io.IOException; import java.io.InputStream; import java.util.ArrayList; import java.util.HashMap; /** * AccountMailbox handles sync for the EAS "account mailbox"; this includes sync of the mailbox list * as well as management of mailbox push (using the EAS "Ping" command */ public class EasAccountService extends EasSyncService { private static final String WHERE_ACCOUNT_AND_SYNC_INTERVAL_PING = MailboxColumns.ACCOUNT_KEY + "=? and " + MailboxColumns.SYNC_INTERVAL + '=' + Mailbox.CHECK_INTERVAL_PING; private static final String AND_FREQUENCY_PING_PUSH_AND_NOT_ACCOUNT_MAILBOX = " AND " + MailboxColumns.SYNC_INTERVAL + " IN (" + Mailbox.CHECK_INTERVAL_PING + ',' + Mailbox.CHECK_INTERVAL_PUSH + ") AND " + MailboxColumns.TYPE + "!=\"" + Mailbox.TYPE_EAS_ACCOUNT_MAILBOX + '\"'; private static final String WHERE_PUSH_HOLD_NOT_ACCOUNT_MAILBOX = MailboxColumns.ACCOUNT_KEY + "=? and " + MailboxColumns.SYNC_INTERVAL + '=' + Mailbox.CHECK_INTERVAL_PUSH_HOLD; private static final String WHERE_ACCOUNT_KEY_AND_SERVER_ID = MailboxColumns.ACCOUNT_KEY + "=? and " + MailboxColumns.SERVER_ID + "=?"; protected static final String WHERE_IN_ACCOUNT_AND_PUSHABLE = MailboxColumns.ACCOUNT_KEY + "=? and type in (" + Mailbox.TYPE_INBOX + ',' + Mailbox.TYPE_EAS_ACCOUNT_MAILBOX + ',' + Mailbox.TYPE_CONTACTS + ',' + Mailbox.TYPE_CALENDAR + ')'; /** * We start with an 8 minute timeout, and increase/decrease by 3 minutes at a time. There's * no point having a timeout shorter than 5 minutes, I think; at that point, we can just let * the ping exception out. The maximum I use is 17 minutes, which is really an empirical * choice; too long and we risk silent connection loss and loss of push for that period. Too * short and we lose efficiency/battery life. * * If we ever have to drop the ping timeout, we'll never increase it again. There's no point * going into hysteresis; the NAT timeout isn't going to change without a change in connection, * which will cause the sync service to be restarted at the starting heartbeat and going through * the process again. */ static private final int PING_MINUTES = 60; // in seconds static private final int PING_FUDGE_LOW = 10; static private final int PING_STARTING_HEARTBEAT = (8 * PING_MINUTES) - PING_FUDGE_LOW; static private final int PING_HEARTBEAT_INCREMENT = 3 * PING_MINUTES; static private final int PROTOCOL_PING_STATUS_COMPLETED = 1; static private final int PROTOCOL_PING_STATUS_BAD_PARAMETERS = 3; static private final int PROTOCOL_PING_STATUS_RETRY = 8; // Fallbacks (in minutes) for ping loop failures static private final int MAX_PING_FAILURES = 1; static private final int PING_FALLBACK_INBOX = 5; static private final int PING_FALLBACK_PIM = 25; // The amount of time the account mailbox will sleep if there are no pingable mailboxes // This could happen if the sync time is set to "never"; we always want to check in from time // to time, however, for folder list/policy changes static private final int ACCOUNT_MAILBOX_SLEEP_TIME = (int) (20 * DateUtils.MINUTE_IN_MILLIS); static private final String ACCOUNT_MAILBOX_SLEEP_TEXT = "Account mailbox sleeping for " + (ACCOUNT_MAILBOX_SLEEP_TIME / DateUtils.MINUTE_IN_MILLIS) + "m"; // Our heartbeat when we are waiting for ping boxes to be ready /*package*/ int mPingForceHeartbeat = 2 * PING_MINUTES; // The minimum heartbeat we will send /*package*/ int mPingMinHeartbeat = (5 * PING_MINUTES) - PING_FUDGE_LOW; // The maximum heartbeat we will send /*package*/ int mPingMaxHeartbeat = (17 * PING_MINUTES) - PING_FUDGE_LOW; // The ping time (in seconds) /*package*/ int mPingHeartbeat = PING_STARTING_HEARTBEAT; // The longest successful ping heartbeat private int mPingHighWaterMark = 0; // Whether we've ever lowered the heartbeat /*package*/ boolean mPingHeartbeatDropped = false; private final String[] mBindArguments = new String[2]; private ArrayList<String> mPingChangeList; protected EasAccountService(Context _context, Mailbox _mailbox) { super(_context, _mailbox); } @VisibleForTesting protected EasAccountService() { } @Override public void run() { mExitStatus = EXIT_DONE; try { // Make sure account and mailbox are still valid if (!setupService()) return; // If we've been stopped, we're done if (mStop) return; try { mDeviceId = ExchangeService.getDeviceId(mContext); int trafficFlags = TrafficFlags.getSyncFlags(mContext, mAccount); TrafficStats.setThreadStatsTag(trafficFlags | TrafficFlags.DATA_EMAIL); if ((mMailbox == null) || (mAccount == null)) { return; } else { sync(); } } catch (EasAuthenticationException e) { userLog("Caught authentication error"); mExitStatus = EXIT_LOGIN_FAILURE; } catch (IOException e) { String message = e.getMessage(); userLog("Caught IOException: ", (message == null) ? "No message" : message); mExitStatus = EXIT_IO_ERROR; } catch (Exception e) { userLog("Uncaught exception in AccountMailboxService", e); } finally { ExchangeService.done(this); if (!mStop) { userLog("Sync finished"); switch (mExitStatus) { case EXIT_SECURITY_FAILURE: // Ask for a new folder list. This should wake up the account mailbox; a // security error in account mailbox should start provisioning ExchangeService.reloadFolderList(mContext, mAccount.mId, true); break; case EXIT_EXCEPTION: errorLog("Sync ended due to an exception."); break; } } else { userLog("Stopped sync finished."); } // Make sure ExchangeService knows about this ExchangeService.kick("sync finished"); } } catch (ProviderUnavailableException e) { LogUtils.e(TAG, "EmailProvider unavailable; sync ended prematurely"); } } /** * If possible, update the account to the new server address; report result * @param resp the EasResponse from the current POST * @return whether or not the redirect is handled and the POST should be retried */ private boolean canHandleAccountMailboxRedirect(EasResponse resp) { userLog("AccountMailbox redirect error"); HostAuth ha = HostAuth.restoreHostAuthWithId(mContext, mAccount.mHostAuthKeyRecv); if (ha != null && getValidateRedirect(resp, ha)) { // Update the account's HostAuth with new values ContentValues haValues = new ContentValues(); haValues.put(HostAuthColumns.ADDRESS, ha.mAddress); ha.update(mContext, haValues); return true; } return false; } /** * Performs FolderSync * * @throws IOException * @throws EasParserException */ public void sync() throws IOException, EasParserException { // Check that the account's mailboxes are consistent MailboxUtilities.checkMailboxConsistency(mContext, mAccount.mId); // Initialize exit status to success try { if (mAccount.mSyncKey == null) { mAccount.mSyncKey = "0"; userLog("Account syncKey INIT to 0"); ContentValues cv = new ContentValues(); cv.put(AccountColumns.SYNC_KEY, mAccount.mSyncKey); mAccount.update(mContext, cv); } boolean firstSync = mAccount.mSyncKey.equals("0"); if (firstSync) { userLog("Initial FolderSync"); } // When we first start up, change all mailboxes to push. ContentValues cv = new ContentValues(); cv.put(Mailbox.SYNC_INTERVAL, Mailbox.CHECK_INTERVAL_PUSH); if (mContentResolver.update(Mailbox.CONTENT_URI, cv, WHERE_ACCOUNT_AND_SYNC_INTERVAL_PING, new String[] { Long.toString(mAccount.mId) }) > 0) { ExchangeService.kick("change ping boxes to push"); } // Determine our protocol version, if we haven't already and save it in the Account // Also re-check protocol version at least once a day (in case of upgrade) if (mAccount.mProtocolVersion == null || firstSync || ((System.currentTimeMillis() - mMailbox.mSyncTime) > DateUtils.DAY_IN_MILLIS)) { userLog("Determine EAS protocol version"); EasResponse resp = sendHttpClientOptions(); try { int code = resp.getStatus(); userLog("OPTIONS response: ", code); if (code == HttpStatus.SC_OK) { Header header = resp.getHeader("MS-ASProtocolCommands"); userLog(header.getValue()); header = resp.getHeader("ms-asprotocolversions"); try { setupProtocolVersion(this, header); } catch (MessagingException e) { // Since we've already validated, this can't really happen // But if it does, we'll rethrow this... throw new IOException(e); } // Save the protocol version cv.clear(); // Save the protocol version in the account; if we're using 12.0 or greater, // set the flag for support of SmartForward cv.put(Account.PROTOCOL_VERSION, mProtocolVersion); if (mProtocolVersionDouble >= 12.0) { cv.put(Account.FLAGS, mAccount.mFlags | Account.FLAGS_SUPPORTS_SMART_FORWARD | Account.FLAGS_SUPPORTS_SEARCH | Account.FLAGS_SUPPORTS_GLOBAL_SEARCH); } mAccount.update(mContext, cv); cv.clear(); // Save the sync time of the account mailbox to current time cv.put(Mailbox.SYNC_TIME, System.currentTimeMillis()); mMailbox.update(mContext, cv); } else if (code == EAS_REDIRECT_CODE && canHandleAccountMailboxRedirect(resp)) { // Cause this to re-run throw new IOException("Will retry after a brief hold..."); } else if (resp.isProvisionError()) { throw new CommandStatusException(CommandStatus.NEEDS_PROVISIONING); } else if (resp.isAuthError()) { mExitStatus = EasSyncService.EXIT_LOGIN_FAILURE; return; } else { errorLog("OPTIONS command failed; throwing IOException"); throw new IOException(); } } finally { resp.close(); } } // Change all pushable boxes to push when we start the account mailbox if (mAccount.mSyncInterval == Account.CHECK_INTERVAL_PUSH) { cv.clear(); cv.put(Mailbox.SYNC_INTERVAL, Mailbox.CHECK_INTERVAL_PUSH); if (mContentResolver.update(Mailbox.CONTENT_URI, cv, WHERE_IN_ACCOUNT_AND_PUSHABLE, new String[] { Long.toString(mAccount.mId) }) > 0) { userLog("Push account; set pushable boxes to push..."); } } while (!isStopped()) { // If we're not allowed to sync (e.g. roaming policy), leave now if (!ExchangeService.canAutoSync(mAccount)) { if (ExchangeService.onSecurityHold(mAccount)) { mExitStatus = EasSyncService.EXIT_SECURITY_FAILURE; } else { // Use backoff rules, etc. mExitStatus = EasSyncService.EXIT_IO_ERROR; } return; } userLog("Sending Account syncKey: ", mAccount.mSyncKey); Serializer s = new Serializer(); s.start(Tags.FOLDER_FOLDER_SYNC).start(Tags.FOLDER_SYNC_KEY).text(mAccount.mSyncKey).end().end() .done(); EasResponse resp = sendHttpClientPost("FolderSync", s.toByteArray()); try { if (isStopped()) break; int code = resp.getStatus(); if (code == HttpStatus.SC_OK) { if (!resp.isEmpty()) { InputStream is = resp.getInputStream(); // Returns true if we need to sync again if (new FolderSyncParser(is, new AccountSyncAdapter(this)).parse()) { continue; } } } else if (resp.isProvisionError()) { throw new CommandStatusException(CommandStatus.NEEDS_PROVISIONING); } else if (resp.isAuthError()) { mExitStatus = EasSyncService.EXIT_LOGIN_FAILURE; return; } else if (code == EAS_REDIRECT_CODE && canHandleAccountMailboxRedirect(resp)) { // This will cause a retry of the FolderSync continue; } else { userLog("FolderSync response error: ", code); } } finally { resp.close(); } // Change all push/hold boxes to push cv.clear(); cv.put(Mailbox.SYNC_INTERVAL, Account.CHECK_INTERVAL_PUSH); if (mContentResolver.update(Mailbox.CONTENT_URI, cv, WHERE_PUSH_HOLD_NOT_ACCOUNT_MAILBOX, new String[] { Long.toString(mAccount.mId) }) > 0) { userLog("Set push/hold boxes to push..."); } // Before each run of the pingLoop, if this Account has a PolicySet, make sure it's // active; otherwise, clear out the key/flag. This should cause a provisioning // error on the next POST, and start the security sequence over again String key = mAccount.mSecuritySyncKey; if (!TextUtils.isEmpty(key)) { Policy policy = Policy.restorePolicyWithId(mContext, mAccount.mPolicyKey); if ((policy != null) && !PolicyServiceProxy.isActive(mContext, policy)) { resetSecurityPolicies(); } } // Wait for push notifications. String threadName = Thread.currentThread().getName(); try { runPingLoop(); } catch (StaleFolderListException e) { // We break out if we get told about a stale folder list userLog("Ping interrupted; folder list requires sync..."); } catch (IllegalHeartbeatException e) { // If we're sending an illegal heartbeat, reset either the min or the max to // that heartbeat resetHeartbeats(e.mLegalHeartbeat); } finally { Thread.currentThread().setName(threadName); } } } catch (CommandStatusException e) { // If the sync error is a provisioning failure (perhaps policies changed), // let's try the provisioning procedure // Provisioning must only be attempted for the account mailbox - trying to // provision any other mailbox may result in race conditions and the // creation of multiple policy keys. int status = e.mStatus; if (CommandStatus.isNeedsProvisioning(status)) { if (!tryProvision(this)) { // Set the appropriate failure status mExitStatus = EasSyncService.EXIT_SECURITY_FAILURE; return; } } else if (CommandStatus.isDeniedAccess(status)) { mExitStatus = EasSyncService.EXIT_ACCESS_DENIED; return; } else { userLog("Unexpected status: " + CommandStatus.toString(status)); mExitStatus = EasSyncService.EXIT_EXCEPTION; } } } /** * Reset either our minimum or maximum ping heartbeat to a heartbeat known to be legal * @param legalHeartbeat a known legal heartbeat (from the EAS server) */ /*package*/ void resetHeartbeats(int legalHeartbeat) { userLog("Resetting min/max heartbeat, legal = " + legalHeartbeat); // We are here because the current heartbeat (mPingHeartbeat) is invalid. Depending on // whether the argument is above or below the current heartbeat, we can infer the need to // change either the minimum or maximum heartbeat if (legalHeartbeat > mPingHeartbeat) { // The legal heartbeat is higher than the ping heartbeat; therefore, our minimum was // too low. We respond by raising either or both of the minimum heartbeat or the // force heartbeat to the argument value if (mPingMinHeartbeat < legalHeartbeat) { mPingMinHeartbeat = legalHeartbeat; } if (mPingForceHeartbeat < legalHeartbeat) { mPingForceHeartbeat = legalHeartbeat; } // If our minimum is now greater than the max, bring them together if (mPingMinHeartbeat > mPingMaxHeartbeat) { mPingMaxHeartbeat = legalHeartbeat; } } else if (legalHeartbeat < mPingHeartbeat) { // The legal heartbeat is lower than the ping heartbeat; therefore, our maximum was // too high. We respond by lowering the maximum to the argument value mPingMaxHeartbeat = legalHeartbeat; // If our maximum is now less than the minimum, bring them together if (mPingMaxHeartbeat < mPingMinHeartbeat) { mPingMinHeartbeat = legalHeartbeat; } } // Set current heartbeat to the legal heartbeat mPingHeartbeat = legalHeartbeat; // Allow the heartbeat logic to run mPingHeartbeatDropped = false; } private void pushFallback(long mailboxId) { Mailbox mailbox = Mailbox.restoreMailboxWithId(mContext, mailboxId); if (mailbox == null) { return; } ContentValues cv = new ContentValues(); int mins = PING_FALLBACK_PIM; if (mailbox.mType == Mailbox.TYPE_INBOX) { mins = PING_FALLBACK_INBOX; } cv.put(Mailbox.SYNC_INTERVAL, mins); mContentResolver.update(ContentUris.withAppendedId(Mailbox.CONTENT_URI, mailboxId), cv, null, null); errorLog("*** PING ERROR LOOP: Set " + mailbox.mDisplayName + " to " + mins + " min sync"); ExchangeService.kick("push fallback"); } /** * Simplistic attempt to determine a NAT timeout, based on experience with various carriers * and networks. The string "reset by peer" is very common in these situations, so we look for * that specifically. We may add additional tests here as more is learned. * @param message * @return whether this message is likely associated with a NAT failure */ private static boolean isLikelyNatFailure(String message) { if (message == null) return false; if (message.contains("reset by peer")) { return true; } return false; } private void sleep(long ms, boolean runAsleep) { if (runAsleep) { ExchangeService.runAsleep(mMailboxId, ms + (5 * DateUtils.SECOND_IN_MILLIS)); } try { Thread.sleep(ms); } catch (InterruptedException e) { // Doesn't matter whether we stop early; it's the thought that counts } finally { if (runAsleep) { ExchangeService.runAwake(mMailboxId); } } } protected EasResponse sendPing(byte[] bytes, int heartbeat) throws IOException { Thread.currentThread().setName(mAccount.mDisplayName + ": Ping"); if (Eas.USER_LOG) { userLog("Send ping, timeout: " + heartbeat + "s, high: " + mPingHighWaterMark + 's'); } return sendHttpClientPost(EasSyncService.PING_COMMAND, new ByteArrayEntity(bytes), (int) ((heartbeat + 5) * DateUtils.SECOND_IN_MILLIS)); } private void runPingLoop() throws IOException, StaleFolderListException, IllegalHeartbeatException, CommandStatusException { int pingHeartbeat = mPingHeartbeat; userLog("runPingLoop"); // Do push for all sync services here long endTime = System.currentTimeMillis() + (30 * DateUtils.MINUTE_IN_MILLIS); HashMap<String, Integer> pingErrorMap = new HashMap<String, Integer>(); ArrayList<String> readyMailboxes = new ArrayList<String>(); ArrayList<String> notReadyMailboxes = new ArrayList<String>(); int pingWaitCount = 0; long inboxId = -1; android.accounts.Account amAccount = new android.accounts.Account(mAccount.mEmailAddress, Eas.EXCHANGE_ACCOUNT_MANAGER_TYPE); while ((System.currentTimeMillis() < endTime) && !isStopped()) { // Count of pushable mailboxes int pushCount = 0; // Count of mailboxes that can be pushed right now int canPushCount = 0; // Count of uninitialized boxes int uninitCount = 0; Serializer s = new Serializer(); Cursor c = mContentResolver.query(Mailbox.CONTENT_URI, Mailbox.CONTENT_PROJECTION, MailboxColumns.ACCOUNT_KEY + '=' + mAccount.mId + AND_FREQUENCY_PING_PUSH_AND_NOT_ACCOUNT_MAILBOX, null, null); if (c == null) throw new ProviderUnavailableException(); notReadyMailboxes.clear(); readyMailboxes.clear(); // Look for an inbox, and remember its id if (inboxId == -1) { inboxId = Mailbox.findMailboxOfType(mContext, mAccount.mId, Mailbox.TYPE_INBOX); } try { // Loop through our pushed boxes seeing what is available to push while (c.moveToNext()) { pushCount++; // Two requirements for push: // 1) ExchangeService tells us the mailbox is syncable (not running/not stopped) // 2) The syncKey isn't "0" (i.e. it's synced at least once) long mailboxId = c.getLong(Mailbox.CONTENT_ID_COLUMN); String mailboxName = c.getString(Mailbox.CONTENT_DISPLAY_NAME_COLUMN); // See what type of box we've got and get authority int mailboxType = c.getInt(Mailbox.CONTENT_TYPE_COLUMN); String authority = EmailContent.AUTHORITY; switch (mailboxType) { case Mailbox.TYPE_CALENDAR: authority = CalendarContract.AUTHORITY; break; case Mailbox.TYPE_CONTACTS: authority = ContactsContract.AUTHORITY; break; } // See whether we can ping for this mailbox int pingStatus; if (!ContentResolver.getSyncAutomatically(amAccount, authority)) { pingStatus = ExchangeService.PING_STATUS_DISABLED; } else { pingStatus = ExchangeService.pingStatus(mailboxId); } if (pingStatus == ExchangeService.PING_STATUS_OK) { String syncKey = c.getString(Mailbox.CONTENT_SYNC_KEY_COLUMN); if ((syncKey == null) || syncKey.equals("0")) { // We can't push until the initial sync is done pushCount--; uninitCount++; continue; } if (canPushCount++ == 0) { // Initialize the Ping command s.start(Tags.PING_PING) .data(Tags.PING_HEARTBEAT_INTERVAL, Integer.toString(pingHeartbeat)) .start(Tags.PING_FOLDERS); } String folderClass = getTargetCollectionClassFromCursor(c); s.start(Tags.PING_FOLDER).data(Tags.PING_ID, c.getString(Mailbox.CONTENT_SERVER_ID_COLUMN)) .data(Tags.PING_CLASS, folderClass).end(); readyMailboxes.add(mailboxName); } else if ((pingStatus == ExchangeService.PING_STATUS_RUNNING) || (pingStatus == ExchangeService.PING_STATUS_WAITING)) { notReadyMailboxes.add(mailboxName); } else if (pingStatus == ExchangeService.PING_STATUS_UNABLE) { pushCount--; userLog(mailboxName, " in error state; ignore"); continue; } else if (pingStatus == ExchangeService.PING_STATUS_DISABLED) { pushCount--; userLog(mailboxName, " disabled by user; ignore"); continue; } } } finally { c.close(); } if (Eas.USER_LOG) { if (!notReadyMailboxes.isEmpty()) { userLog("Ping not ready for: " + notReadyMailboxes); } if (!readyMailboxes.isEmpty()) { userLog("Ping ready for: " + readyMailboxes); } } // If we've waited 10 seconds or more, just ping with whatever boxes are ready // But use a shorter than normal heartbeat boolean forcePing = !notReadyMailboxes.isEmpty() && (pingWaitCount > 5); if ((canPushCount > 0) && ((canPushCount == pushCount) || forcePing)) { // If all pingable boxes are ready for push, send Ping to the server s.end().end().done(); pingWaitCount = 0; mPostAborted = false; mPostReset = false; // If we've been stopped, this is a good time to return if (isStopped()) return; long pingTime = SystemClock.elapsedRealtime(); try { // Send the ping, wrapped by appropriate timeout/alarm if (forcePing) { userLog("Forcing ping after waiting for all boxes to be ready"); } EasResponse resp = sendPing(s.toByteArray(), forcePing ? mPingForceHeartbeat : pingHeartbeat); try { int code = resp.getStatus(); userLog("Ping response: ", code); // If we're not allowed to sync (e.g. roaming policy), terminate gracefully // now; otherwise we might start a sync based on the response if (!ExchangeService.canAutoSync(mAccount)) { stop(); } // Return immediately if we've been asked to stop during the ping if (isStopped()) { userLog("Stopping pingLoop"); return; } if (code == HttpStatus.SC_OK) { if (!resp.isEmpty()) { InputStream is = resp.getInputStream(); int pingResult = parsePingResult(is, mContentResolver, pingErrorMap); // If our ping completed (status = 1), and wasn't forced and we're // not at the maximum, try increasing timeout by two minutes if (pingResult == PROTOCOL_PING_STATUS_COMPLETED && !forcePing) { if (pingHeartbeat > mPingHighWaterMark) { mPingHighWaterMark = pingHeartbeat; userLog("Setting high water mark at: ", mPingHighWaterMark); } if ((pingHeartbeat < mPingMaxHeartbeat) && !mPingHeartbeatDropped) { pingHeartbeat += PING_HEARTBEAT_INCREMENT; if (pingHeartbeat > mPingMaxHeartbeat) { pingHeartbeat = mPingMaxHeartbeat; } userLog("Increase ping heartbeat to ", pingHeartbeat, "s"); } } else if (pingResult == PROTOCOL_PING_STATUS_BAD_PARAMETERS || pingResult == PROTOCOL_PING_STATUS_RETRY) { // These errors appear to be server-related (I've seen a bad // parameters result with known good parameters...) userLog("Server error during Ping: " + pingResult); // Act as if we have an IOException (backoff, etc.) throw new IOException(); } // Make sure to clear out any pending sync errors ExchangeService.removeFromSyncErrorMap(mMailboxId); } else { userLog("Ping returned empty result; throwing IOException"); // Act as if we have an IOException (backoff, etc.) throw new IOException(); } } else if (resp.isAuthError()) { mExitStatus = EasSyncService.EXIT_LOGIN_FAILURE; userLog("Authorization error during Ping: ", code); throw new IOException(); } } finally { resp.close(); } } catch (IOException e) { String message = e.getMessage(); // If we get the exception that is indicative of a NAT timeout and if we // haven't yet "fixed" the timeout, back off by two minutes and "fix" it boolean hasMessage = message != null; userLog("IOException runPingLoop: " + (hasMessage ? message : "[no message]")); if (mPostReset) { // Nothing to do in this case; this is ExchangeService telling us to try // another ping. } else if (mPostAborted || isLikelyNatFailure(message)) { long pingLength = SystemClock.elapsedRealtime() - pingTime; if ((pingHeartbeat > mPingMinHeartbeat) && (pingHeartbeat > mPingHighWaterMark)) { pingHeartbeat -= PING_HEARTBEAT_INCREMENT; mPingHeartbeatDropped = true; if (pingHeartbeat < mPingMinHeartbeat) { pingHeartbeat = mPingMinHeartbeat; } userLog("Decreased ping heartbeat to ", pingHeartbeat, "s"); } else if (mPostAborted) { // There's no point in throwing here; this can happen in two cases // 1) An alarm, which indicates minutes without activity; no sense // backing off // 2) ExchangeService abort, due to sync of mailbox. Again, we want to // keep on trying to ping userLog("Ping aborted; retry"); } else if (pingLength < 2000) { userLog("Abort or NAT type return < 2 seconds; throwing IOException"); throw e; } else { userLog("NAT type IOException"); } } else if (hasMessage && message.contains("roken pipe")) { // The "broken pipe" error (uppercase or lowercase "b") seems to be an // internal error, so let's not throw an exception (which leads to delays) // but rather simply run through the loop again } else { throw e; } } } else if (forcePing) { // In this case, there aren't any boxes that are pingable, but there are boxes // waiting (for IOExceptions) userLog("pingLoop waiting 60s for any pingable boxes"); sleep(60 * DateUtils.SECOND_IN_MILLIS, true); } else if (pushCount > 0) { // If we want to Ping, but can't just yet, wait a little bit // TODO Change sleep to wait and use notify from ExchangeService when a sync ends sleep(2 * DateUtils.SECOND_IN_MILLIS, false); pingWaitCount++; //userLog("pingLoop waited 2s for: ", (pushCount - canPushCount), " box(es)"); } else if (uninitCount > 0) { // In this case, we're doing an initial sync of at least one mailbox. Since this // is typically a one-time case, I'm ok with trying again every 10 seconds until // we're in one of the other possible states. userLog("pingLoop waiting for initial sync of ", uninitCount, " box(es)"); sleep(10 * DateUtils.SECOND_IN_MILLIS, true); } else if (inboxId == -1) { // In this case, we're still syncing mailboxes, so sleep for only a short time sleep(45 * DateUtils.SECOND_IN_MILLIS, true); } else { // We've got nothing to do, so we'll check again in 20 minutes at which time // we'll update the folder list, check for policy changes and/or remote wipe, etc. // Let the device sleep in the meantime... userLog(ACCOUNT_MAILBOX_SLEEP_TEXT); sleep(ACCOUNT_MAILBOX_SLEEP_TIME, true); } } // Save away the current heartbeat mPingHeartbeat = pingHeartbeat; } private int parsePingResult(InputStream is, ContentResolver cr, HashMap<String, Integer> errorMap) throws IOException, StaleFolderListException, IllegalHeartbeatException, CommandStatusException { PingParser pp = new PingParser(is); if (pp.parse()) { // True indicates some mailboxes need syncing... // syncList has the serverId's of the mailboxes... mBindArguments[0] = Long.toString(mAccount.mId); mPingChangeList = pp.getSyncList(); for (String serverId : mPingChangeList) { mBindArguments[1] = serverId; Cursor c = cr.query(Mailbox.CONTENT_URI, Mailbox.CONTENT_PROJECTION, WHERE_ACCOUNT_KEY_AND_SERVER_ID, mBindArguments, null); if (c == null) throw new ProviderUnavailableException(); try { if (c.moveToFirst()) { /** * Check the boxes reporting changes to see if there really were any... * We do this because bugs in various Exchange servers can put us into a * looping behavior by continually reporting changes in a mailbox, even when * there aren't any. * * This behavior is seemingly random, and therefore we must code defensively * by backing off of push behavior when it is detected. * * One known cause, on certain Exchange 2003 servers, is acknowledged by * Microsoft, and the server hotfix for this case can be found at * http://support.microsoft.com/kb/923282 */ // Check the status of the last sync String status = c.getString(Mailbox.CONTENT_SYNC_STATUS_COLUMN); int type = ExchangeService.getStatusType(status); // This check should always be true... if (type == ExchangeService.SYNC_PING) { int changeCount = ExchangeService.getStatusChangeCount(status); if (changeCount > 0) { errorMap.remove(serverId); } else if (changeCount == 0) { // This means that a ping reported changes in error; we keep a count // of consecutive errors of this kind String name = c.getString(Mailbox.CONTENT_DISPLAY_NAME_COLUMN); Integer failures = errorMap.get(serverId); if (failures == null) { userLog("Last ping reported changes in error for: ", name); errorMap.put(serverId, 1); } else if (failures > MAX_PING_FAILURES) { // We'll back off of push for this box pushFallback(c.getLong(Mailbox.CONTENT_ID_COLUMN)); continue; } else { userLog("Last ping reported changes in error for: ", name); errorMap.put(serverId, failures + 1); } } } // If there were no problems with previous sync, we'll start another one ExchangeService.startManualSync(c.getLong(Mailbox.CONTENT_ID_COLUMN), ExchangeService.SYNC_PING, null); } } finally { c.close(); } } } return pp.getPingStatus(); } }