Stop pings when other syncs in the same account start

* When a mailbox syncs, pings should be aborted, or they appear to
  end up timing out with a stale connection (observation from logs)
* The result of timing out is lack of push until the heartbeat time
  has elapsed and our alarm triggers
* Also refactor code; some of the names of methods was unfortunate
  and these methods were being used in this CL

Bug: 2492848
Change-Id: Ib626a5d3cf6d2c61e3b11f4886a3fedbf9727bfa
This commit is contained in:
Marc Blank 2010-03-05 16:02:13 -08:00
parent e8377ae7d4
commit 99feed44ec
5 changed files with 107 additions and 45 deletions

View File

@ -45,9 +45,6 @@ public abstract class AbstractSyncService implements Runnable {
public String TAG = "AbstractSyncService";
public static final String SUMMARY_PROTOCOL = "_SUMMARY_";
public static final String SYNCED_PROTOCOL = "_SYNCING_";
public static final String MOVE_FAVORITES_PROTOCOL = "_MOVE_FAVORITES_";
public static final int SECONDS = 1000;
public static final int MINUTES = 60*SECONDS;
public static final int HOURS = 60*MINUTES;
@ -56,7 +53,6 @@ public abstract class AbstractSyncService implements Runnable {
public static final int CONNECT_TIMEOUT = 30*SECONDS;
public static final int NETWORK_WAIT = 15*SECONDS;
public static final String IMAP_PROTOCOL = "imap";
public static final String EAS_PROTOCOL = "eas";
public static final int EXIT_DONE = 0;
public static final int EXIT_IO_ERROR = 1;
@ -86,10 +82,17 @@ public abstract class AbstractSyncService implements Runnable {
public abstract void stop();
/**
* Sent by SyncManager to indicate a user request requiring service has been
* added to the service's pending request queue
* Sent by SyncManager to indicate that an alarm has fired for this service. Typically, this
* means that a network operation has timed out. The service is NOT stopped, but service
* behavior is not otherwise defined (i.e. it's service dependent)
*/
public abstract void ping();
public abstract void alarm();
/**
* Sent by SyncManager to request that the service reset itself cleanly; the meaning of this
* operation is service dependent.
*/
public abstract void reset();
/**
* Called to validate an account; abstract to allow each protocol to do what

View File

@ -38,7 +38,7 @@ public class Eas {
public static final int DEBUG_FILE_BIT = 4;
public static final String VERSION = "0.3";
public static final String ACCOUNT_MAILBOX = "__eas";
public static final String ACCOUNT_MAILBOX_PREFIX = "__eas";
// From EAS spec
// Mail Cal

View File

@ -179,8 +179,10 @@ public class EasSyncService extends AbstractSyncService {
private int mPingHighWaterMark = 0;
// Whether we've ever lowered the heartbeat
private boolean mPingHeartbeatDropped = false;
// Whether a POST was aborted due to watchdog timeout
// Whether a POST was aborted due to alarm (watchdog alarm)
private boolean mPostAborted = false;
// Whether a POST was aborted due to reset
private boolean mPostReset = false;
// Whether or not the sync service is valid (usable)
public boolean mIsValid = true;
@ -209,13 +211,40 @@ public class EasSyncService extends AbstractSyncService {
}
@Override
public void ping() {
userLog("Alarm ping received!");
public void alarm() {
synchronized(getSynchronizer()) {
if (mPendingPost != null) {
userLog("Aborting pending POST!");
URI uri = mPendingPost.getURI();
if (uri != null) {
String query = uri.getQuery();
if (query == null) {
query = "POST";
}
userLog("Alert, aborting " + query);
} else {
userLog("Alert, no URI?");
}
mPostAborted = true;
mPendingPost.abort();
} else {
userLog("Alert, no pending POST");
}
}
}
@Override
public void reset() {
synchronized(getSynchronizer()) {
if (mPendingPost != null) {
URI uri = mPendingPost.getURI();
if (uri != null) {
String query = uri.getQuery();
if (query.startsWith("Cmd=Ping")) {
userLog("Reset, aborting Ping");
mPostReset = true;
mPendingPost.abort();
}
}
}
}
}
@ -1404,6 +1433,8 @@ public class EasSyncService extends AbstractSyncService {
// If all pingable boxes are ready for push, send Ping to the server
s.end().end().done();
pingWaitCount = 0;
mPostReset = false;
mPostAborted = false;
// If we've been stopped, this is a good time to return
if (mStop) return;
@ -1463,7 +1494,10 @@ public class EasSyncService extends AbstractSyncService {
// 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 (mPostAborted || (hasMessage && message.contains("reset by peer"))) {
if (mPostReset) {
// Nothing to do in this case; this is SyncManager telling us to try another
// ping.
} else if (mPostAborted || (hasMessage && message.contains("reset by peer"))) {
long pingLength = SystemClock.elapsedRealtime() - pingTime;
if ((pingHeartbeat > PING_MIN_HEARTBEAT) &&
(pingHeartbeat > mPingHighWaterMark)) {
@ -1473,7 +1507,14 @@ public class EasSyncService extends AbstractSyncService {
pingHeartbeat = PING_MIN_HEARTBEAT;
}
userLog("Decreased ping heartbeat to ", pingHeartbeat, "s");
} else if (mPostAborted || (pingLength < 2000)) {
} 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) SyncManager 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 {

View File

@ -30,10 +30,8 @@ public class MailboxAlarmReceiver extends BroadcastReceiver {
@Override
public void onReceive(Context context, Intent intent) {
long mid = intent.getLongExtra("mailbox", -1);
if (SyncManager.INSTANCE != null) {
SyncManager.INSTANCE.log("Alarm received for: " + SyncManager.alarmOwner(mid));
}
SyncManager.ping(context, mid);
SyncManager.log("Alarm received for: " + SyncManager.alarmOwner(mid));
SyncManager.alert(context, mid);
}
}

View File

@ -265,7 +265,7 @@ public class SyncManager extends Service implements Runnable {
if (cb != null) {
cb.syncMailboxStatus(mailboxId, statusCode, progress);
} else if (INSTANCE != null) {
INSTANCE.log("orphan syncMailboxStatus, id=" + mailboxId + " status=" + statusCode);
log("orphan syncMailboxStatus, id=" + mailboxId + " status=" + statusCode);
}
}
};
@ -593,14 +593,14 @@ public class SyncManager extends Service implements Runnable {
private void addAccountMailbox(long acctId) {
Account acct = Account.restoreAccountWithId(getContext(), acctId);
Mailbox main = new Mailbox();
main.mDisplayName = Eas.ACCOUNT_MAILBOX;
main.mServerId = Eas.ACCOUNT_MAILBOX + System.nanoTime();
main.mDisplayName = Eas.ACCOUNT_MAILBOX_PREFIX;
main.mServerId = Eas.ACCOUNT_MAILBOX_PREFIX + System.nanoTime();
main.mAccountKey = acct.mId;
main.mType = Mailbox.TYPE_EAS_ACCOUNT_MAILBOX;
main.mSyncInterval = Mailbox.CHECK_INTERVAL_PUSH;
main.mFlagVisible = false;
main.save(getContext());
INSTANCE.log("Initializing account: " + acct.mDisplayName);
log("Initializing account: " + acct.mDisplayName);
}
}
@ -738,7 +738,7 @@ public class SyncManager extends Service implements Runnable {
@Override
public void onChange(boolean selfChange) {
INSTANCE.log("SyncedMessage changed: (re)setting alarm for 10s");
log("SyncedMessage changed: (re)setting alarm for 10s");
alarmManager.set(AlarmManager.RTC_WAKEUP,
System.currentTimeMillis() + 10*SECONDS, syncAlarmPendingIntent);
}
@ -876,12 +876,6 @@ public class SyncManager extends Service implements Runnable {
}
}
static public void smLog(String str) {
if (INSTANCE != null) {
INSTANCE.log(str);
}
}
protected static void log(String str) {
if (Eas.USER_LOG) {
Log.d(TAG, str);
@ -1045,7 +1039,7 @@ public class SyncManager extends Service implements Runnable {
// See the comment for onCreate for details
if (INSTANCE == null) return;
if (sServiceThread == null) {
INSTANCE.alwaysLog("!!! checkSyncManagerServiceRunning; starting service...");
alwaysLog("!!! checkSyncManagerServiceRunning; starting service...");
INSTANCE.startService(new Intent(INSTANCE, SyncManager.class));
}
}
@ -1145,7 +1139,7 @@ public class SyncManager extends Service implements Runnable {
context.getContentResolver().update(Mailbox.CONTENT_URI, cv,
WHERE_PUSH_OR_PING_NOT_ACCOUNT_MAILBOX,
new String[] {Long.toString(accountId)});
INSTANCE.log("Set push/ping boxes to push/hold");
log("Set push/ping boxes to push/hold");
long id = m.mId;
AbstractSyncService svc = INSTANCE.mServiceMap.get(id);
@ -1282,7 +1276,7 @@ public class SyncManager extends Service implements Runnable {
INSTANCE.releaseWakeLock(id);
}
static public void ping(Context context, long id) {
static public void alert(Context context, long id) {
checkSyncManagerServiceRunning();
if (id < 0) {
kick("ping SyncManager");
@ -1304,7 +1298,7 @@ public class SyncManager extends Service implements Runnable {
}
service.mAccount = Account.restoreAccountWithId(INSTANCE, m.mAccountKey);
service.mMailbox = m;
service.ping();
service.alarm();
}
}
}
@ -1496,7 +1490,13 @@ public class SyncManager extends Service implements Runnable {
}
}
private void startService(AbstractSyncService service, Mailbox m) {
/**
* Starts a service thread and enters it into the service map
* This is the point of instantiation of all sync threads
* @param service the service to start
* @param m the Mailbox on which the service will operate
*/
private void startServiceThread(AbstractSyncService service, Mailbox m) {
synchronized (sSyncToken) {
String mailboxName = m.mDisplayName;
String accountName = service.mAccount.mDisplayName;
@ -1505,10 +1505,30 @@ public class SyncManager extends Service implements Runnable {
thread.start();
mServiceMap.put(m.mId, service);
runAwake(m.mId);
if (!m.mServerId.startsWith(Eas.ACCOUNT_MAILBOX_PREFIX)) {
stopPing(m.mAccountKey);
}
}
}
private void startService(Mailbox m, int reason, Request req) {
/**
* Stop any ping in progress for the given account
* @param accountId
*/
private void stopPing(long accountId) {
// Go through our active mailboxes looking for the right one
for (long mailboxId: mServiceMap.keySet()) {
Mailbox m = Mailbox.restoreMailboxWithId(this, mailboxId);
if (m.mAccountKey == accountId &&
m.mServerId.startsWith(Eas.ACCOUNT_MAILBOX_PREFIX)) {
// Here's our account mailbox; reset him (stopping pings)
AbstractSyncService svc = mServiceMap.get(mailboxId);
svc.reset();
}
}
}
private void requestSync(Mailbox m, int reason, Request req) {
// Don't sync if there's no connectivity
if (sConnectivityHold) return;
synchronized (sSyncToken) {
@ -1523,13 +1543,13 @@ public class SyncManager extends Service implements Runnable {
if (req != null) {
service.addRequest(req);
}
startService(service, m);
startServiceThread(service, m);
}
}
}
}
private void stopServices() {
private void stopServiceThreads() {
synchronized (sSyncToken) {
ArrayList<Long> toStop = new ArrayList<Long>();
@ -1566,7 +1586,7 @@ public class SyncManager extends Service implements Runnable {
// If we're waiting for the long haul, shut down running service threads
if (++cnt > 1) {
stopServices();
stopServiceThreads();
}
// Wait until a network is connected, but let the device sleep
@ -1653,12 +1673,12 @@ public class SyncManager extends Service implements Runnable {
}
}
}
stopServices();
stopServiceThreads();
log("Shutdown requested");
} finally {
// Lots of cleanup here
// Stop our running syncs
stopServices();
stopServiceThreads();
// Stop receivers and content observers
if (mConnectivityReceiver != null) {
@ -1803,14 +1823,14 @@ public class SyncManager extends Service implements Runnable {
long interval = c.getInt(Mailbox.CONTENT_SYNC_INTERVAL_COLUMN);
if (interval == Mailbox.CHECK_INTERVAL_PUSH) {
Mailbox m = EmailContent.getContent(c, Mailbox.class);
startService(m, SYNC_PUSH, null);
requestSync(m, SYNC_PUSH, null);
} else if (type == Mailbox.TYPE_OUTBOX) {
int cnt = EmailContent.count(this, Message.CONTENT_URI,
EasOutboxService.MAILBOX_KEY_AND_NOT_SEND_FAILED,
new String[] {Long.toString(mid)});
if (cnt > 0) {
Mailbox m = EmailContent.getContent(c, Mailbox.class);
startService(new EasOutboxService(this, m), m);
startServiceThread(new EasOutboxService(this, m), m);
}
} else if (interval > 0 && interval <= ONE_DAY_MINUTES) {
long lastSync = c.getLong(Mailbox.CONTENT_SYNC_TIME_COLUMN);
@ -1823,7 +1843,7 @@ public class SyncManager extends Service implements Runnable {
String name = c.getString(Mailbox.CONTENT_DISPLAY_NAME_COLUMN);
if (toNextSync <= 0) {
Mailbox m = EmailContent.getContent(c, Mailbox.class);
startService(m, SYNC_SCHEDULED, null);
requestSync(m, SYNC_SCHEDULED, null);
} else if (toNextSync < nextWait) {
nextWait = toNextSync;
if (Eas.USER_LOG) {
@ -1850,7 +1870,7 @@ public class SyncManager extends Service implements Runnable {
long timeToRequest = requestTime - now;
if (service instanceof AbstractSyncService && timeToRequest <= 0) {
service.mRequestTime = 0;
service.ping();
service.alarm();
} else if (requestTime > 0 && timeToRequest < nextWait) {
if (timeToRequest < 11*MINUTES) {
nextWait = timeToRequest < 250 ? 250 : timeToRequest;
@ -1957,7 +1977,7 @@ public class SyncManager extends Service implements Runnable {
Mailbox m = Mailbox.restoreMailboxWithId(INSTANCE, mailboxId);
if (m != null) {
INSTANCE.log("Starting sync for " + m.mDisplayName);
INSTANCE.startService(m, reason, req);
INSTANCE.requestSync(m, reason, req);
}
}
}