EasSyncService.java revision 726d60d9b758f0383f8f8481190fc1a638427209
1/*
2 * Copyright (C) 2008-2009 Marc Blank
3 * Licensed to The Android Open Source Project.
4 *
5 * Licensed under the Apache License, Version 2.0 (the "License");
6 * you may not use this file except in compliance with the License.
7 * You may obtain a copy of the License at
8 *
9 *      http://www.apache.org/licenses/LICENSE-2.0
10 *
11 * Unless required by applicable law or agreed to in writing, software
12 * distributed under the License is distributed on an "AS IS" BASIS,
13 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14 * See the License for the specific language governing permissions and
15 * limitations under the License.
16 */
17
18package com.android.exchange;
19
20import com.android.email.codec.binary.Base64;
21import com.android.email.mail.AuthenticationFailedException;
22import com.android.email.mail.MessagingException;
23import com.android.email.provider.EmailContent.Account;
24import com.android.email.provider.EmailContent.AccountColumns;
25import com.android.email.provider.EmailContent.Attachment;
26import com.android.email.provider.EmailContent.AttachmentColumns;
27import com.android.email.provider.EmailContent.HostAuth;
28import com.android.email.provider.EmailContent.Mailbox;
29import com.android.email.provider.EmailContent.MailboxColumns;
30import com.android.email.provider.EmailContent.Message;
31import com.android.exchange.adapter.AbstractSyncAdapter;
32import com.android.exchange.adapter.AccountSyncAdapter;
33import com.android.exchange.adapter.ContactsSyncAdapter;
34import com.android.exchange.adapter.EmailSyncAdapter;
35import com.android.exchange.adapter.FolderSyncParser;
36import com.android.exchange.adapter.PingParser;
37import com.android.exchange.adapter.Serializer;
38import com.android.exchange.adapter.Tags;
39import com.android.exchange.adapter.Parser.EasParserException;
40
41import org.apache.http.Header;
42import org.apache.http.HttpEntity;
43import org.apache.http.HttpResponse;
44import org.apache.http.HttpStatus;
45import org.apache.http.client.HttpClient;
46import org.apache.http.client.methods.HttpOptions;
47import org.apache.http.client.methods.HttpPost;
48import org.apache.http.client.methods.HttpRequestBase;
49import org.apache.http.conn.ClientConnectionManager;
50import org.apache.http.entity.ByteArrayEntity;
51import org.apache.http.impl.client.DefaultHttpClient;
52import org.apache.http.params.BasicHttpParams;
53import org.apache.http.params.HttpConnectionParams;
54import org.apache.http.params.HttpParams;
55
56import android.content.ContentResolver;
57import android.content.ContentUris;
58import android.content.ContentValues;
59import android.content.Context;
60import android.database.Cursor;
61import android.os.RemoteException;
62import android.os.SystemClock;
63
64import java.io.File;
65import java.io.FileOutputStream;
66import java.io.IOException;
67import java.io.InputStream;
68import java.net.URI;
69import java.net.URLEncoder;
70import java.security.cert.CertificateException;
71import java.util.ArrayList;
72import java.util.HashMap;
73
74public class EasSyncService extends AbstractSyncService {
75    private static final String EMAIL_WINDOW_SIZE = "5";
76    public static final String PIM_WINDOW_SIZE = "5";
77    private static final String WHERE_ACCOUNT_KEY_AND_SERVER_ID =
78        MailboxColumns.ACCOUNT_KEY + "=? and " + MailboxColumns.SERVER_ID + "=?";
79    private static final String WHERE_ACCOUNT_AND_SYNC_INTERVAL_PING =
80        MailboxColumns.ACCOUNT_KEY + "=? and " + MailboxColumns.SYNC_INTERVAL +
81        '=' + Mailbox.CHECK_INTERVAL_PING;
82    private static final String AND_FREQUENCY_PING_PUSH_AND_NOT_ACCOUNT_MAILBOX = " AND " +
83        MailboxColumns.SYNC_INTERVAL + " IN (" + Mailbox.CHECK_INTERVAL_PING +
84        ',' + Mailbox.CHECK_INTERVAL_PUSH + ") AND " + MailboxColumns.TYPE + "!=\"" +
85        Mailbox.TYPE_EAS_ACCOUNT_MAILBOX + '\"';
86    private static final String WHERE_PUSH_HOLD_NOT_ACCOUNT_MAILBOX =
87        MailboxColumns.ACCOUNT_KEY + "=? and " + MailboxColumns.SYNC_INTERVAL +
88        '=' + Mailbox.CHECK_INTERVAL_PUSH_HOLD;
89    private static final String[] SYNC_STATUS_PROJECTION =
90        new String[] {MailboxColumns.ID, MailboxColumns.SYNC_STATUS};
91    static private final int CHUNK_SIZE = 16*1024;
92
93    static private final String PING_COMMAND = "Ping";
94    static private final int COMMAND_TIMEOUT = 20*SECONDS;
95
96    /**
97     * We start with an 8 minute timeout, and increase/decrease by 3 minutes at a time.  There's
98     * no point having a timeout shorter than 5 minutes, I think; at that point, we can just let
99     * the ping exception out.  The maximum I use is 17 minutes, which is really an empirical
100     * choice; too long and we risk silent connection loss and loss of push for that period.  Too
101     * short and we lose efficiency/battery life.
102     *
103     * If we ever have to drop the ping timeout, we'll never increase it again.  There's no point
104     * going into hysteresis; the NAT timeout isn't going to change without a change in connection,
105     * which will cause the sync service to be restarted at the starting heartbeat and going through
106     * the process again.
107     */
108    static private final int PING_MINUTES = 60; // in seconds
109    static private final int PING_FUDGE_LOW = 10;
110    static private final int PING_STARTING_HEARTBEAT = (8*PING_MINUTES)-PING_FUDGE_LOW;
111    static private final int PING_MIN_HEARTBEAT = (5*PING_MINUTES)-PING_FUDGE_LOW;
112    static private final int PING_MAX_HEARTBEAT = (17*PING_MINUTES)-PING_FUDGE_LOW;
113    static private final int PING_HEARTBEAT_INCREMENT = 3*PING_MINUTES;
114    static private final int PING_FORCE_HEARTBEAT = 2*PING_MINUTES;
115
116    static private final int PROTOCOL_PING_STATUS_COMPLETED = 1;
117    static private final int PROTOCOL_PING_STATUS_CHANGES_FOUND = 2;
118
119    // Fallbacks (in minutes) for ping loop failures
120    static private final int MAX_PING_FAILURES = 2;
121    static private final int PING_FALLBACK_INBOX = 5;
122    static private final int PING_FALLBACK_PIM = 30;
123
124    // Reasonable default
125    String mProtocolVersion = "2.5";
126    public Double mProtocolVersionDouble;
127    protected String mDeviceId = null;
128    private String mDeviceType = "Android";
129    private String mAuthString = null;
130    private String mCmdString = null;
131    public String mHostAddress;
132    public String mUserName;
133    public String mPassword;
134    private boolean mSsl = true;
135    private boolean mTrustSsl = false;
136    public ContentResolver mContentResolver;
137    private String[] mBindArguments = new String[2];
138    private ArrayList<String> mPingChangeList;
139    private HttpPost mPendingPost = null;
140    // The ping time (in seconds)
141    private int mPingHeartbeat = PING_STARTING_HEARTBEAT;
142    // The longest successful ping heartbeat
143    private int mPingHighWaterMark = 0;
144    // Whether we've ever lowered the heartbeat
145    private boolean mPingHeartbeatDropped = false;
146
147    public EasSyncService(Context _context, Mailbox _mailbox) {
148        super(_context, _mailbox);
149        mContentResolver = _context.getContentResolver();
150        HostAuth ha = HostAuth.restoreHostAuthWithId(_context, mAccount.mHostAuthKeyRecv);
151        mSsl = (ha.mFlags & HostAuth.FLAG_SSL) != 0;
152        mTrustSsl = (ha.mFlags & HostAuth.FLAG_TRUST_ALL_CERTIFICATES) != 0;
153    }
154
155    private EasSyncService(String prefix) {
156        super(prefix);
157    }
158
159    public EasSyncService() {
160        this("EAS Validation");
161    }
162
163    @Override
164    public void ping() {
165        userLog("Alarm ping received!");
166        synchronized(getSynchronizer()) {
167            if (mPendingPost != null) {
168                userLog("Aborting pending POST!");
169                mPendingPost.abort();
170            }
171        }
172    }
173
174    @Override
175    public void stop() {
176        mStop = true;
177        synchronized(getSynchronizer()) {
178            if (mPendingPost != null) {
179                mPendingPost.abort();
180            }
181        }
182    }
183
184    /**
185     * Determine whether an HTTP code represents an authentication error
186     * @param code the HTTP code returned by the server
187     * @return whether or not the code represents an authentication error
188     */
189    protected boolean isAuthError(int code) {
190        return ((code == HttpStatus.SC_UNAUTHORIZED) || (code == HttpStatus.SC_FORBIDDEN));
191    }
192
193    @Override
194    public void validateAccount(String hostAddress, String userName, String password, int port,
195            boolean ssl, boolean trustCertificates, Context context) throws MessagingException {
196        try {
197            userLog("Testing EAS: ", hostAddress, ", ", userName, ", ssl = ", ssl ? "1" : "0");
198            EasSyncService svc = new EasSyncService("%TestAccount%");
199            svc.mContext = context;
200            svc.mHostAddress = hostAddress;
201            svc.mUserName = userName;
202            svc.mPassword = password;
203            svc.mSsl = ssl;
204            svc.mTrustSsl = trustCertificates;
205            svc.mDeviceId = SyncManager.getDeviceId();
206            HttpResponse resp = svc.sendHttpClientOptions();
207            int code = resp.getStatusLine().getStatusCode();
208            userLog("Validation (OPTIONS) response: " + code);
209            if (code == HttpStatus.SC_OK) {
210                // No exception means successful validation
211                userLog("Validation successful");
212                return;
213            }
214            if (isAuthError(code)) {
215                userLog("Authentication failed");
216                throw new AuthenticationFailedException("Validation failed");
217            } else {
218                // TODO Need to catch other kinds of errors (e.g. policy) For now, report the code.
219                userLog("Validation failed, reporting I/O error: ", code);
220                throw new MessagingException(MessagingException.IOERROR);
221            }
222        } catch (IOException e) {
223            Throwable cause = e.getCause();
224            if (cause != null && cause instanceof CertificateException) {
225                userLog("CertificateException caught: ", e.getMessage());
226                throw new MessagingException(MessagingException.GENERAL_SECURITY);
227            }
228            userLog("IOException caught: ", e.getMessage());
229            throw new MessagingException(MessagingException.IOERROR);
230        }
231
232    }
233
234    private void doStatusCallback(long messageId, long attachmentId, int status) {
235        try {
236            SyncManager.callback().loadAttachmentStatus(messageId, attachmentId, status, 0);
237        } catch (RemoteException e) {
238            // No danger if the client is no longer around
239        }
240    }
241
242    private void doProgressCallback(long messageId, long attachmentId, int progress) {
243        try {
244            SyncManager.callback().loadAttachmentStatus(messageId, attachmentId,
245                    EmailServiceStatus.IN_PROGRESS, progress);
246        } catch (RemoteException e) {
247            // No danger if the client is no longer around
248        }
249    }
250
251    public File createUniqueFileInternal(String dir, String filename) {
252        File directory;
253        if (dir == null) {
254            directory = mContext.getFilesDir();
255        } else {
256            directory = new File(dir);
257        }
258        if (!directory.exists()) {
259            directory.mkdirs();
260        }
261        File file = new File(directory, filename);
262        if (!file.exists()) {
263            return file;
264        }
265        // Get the extension of the file, if any.
266        int index = filename.lastIndexOf('.');
267        String name = filename;
268        String extension = "";
269        if (index != -1) {
270            name = filename.substring(0, index);
271            extension = filename.substring(index);
272        }
273        for (int i = 2; i < Integer.MAX_VALUE; i++) {
274            file = new File(directory, name + '-' + i + extension);
275            if (!file.exists()) {
276                return file;
277            }
278        }
279        return null;
280    }
281
282    /**
283     * Loads an attachment, based on the PartRequest passed in.  The PartRequest is basically our
284     * wrapper for Attachment
285     * @param req the part (attachment) to be retrieved
286     * @throws IOException
287     */
288    protected void getAttachment(PartRequest req) throws IOException {
289        Attachment att = req.att;
290        Message msg = Message.restoreMessageWithId(mContext, att.mMessageKey);
291        doProgressCallback(msg.mId, att.mId, 0);
292        DefaultHttpClient client = new DefaultHttpClient();
293        String us = makeUriString("GetAttachment", "&AttachmentName=" + att.mLocation);
294        HttpPost method = new HttpPost(URI.create(us));
295        method.setHeader("Authorization", mAuthString);
296
297        HttpResponse res = client.execute(method);
298        int status = res.getStatusLine().getStatusCode();
299        if (status == HttpStatus.SC_OK) {
300            HttpEntity e = res.getEntity();
301            int len = (int)e.getContentLength();
302            String type = e.getContentType().getValue();
303            InputStream is = res.getEntity().getContent();
304            File f = (req.destination != null)
305                    ? new File(req.destination)
306                    : createUniqueFileInternal(req.destination, att.mFileName);
307            if (f != null) {
308                // Ensure that the target directory exists
309                File destDir = f.getParentFile();
310                if (!destDir.exists()) {
311                    destDir.mkdirs();
312                }
313                FileOutputStream os = new FileOutputStream(f);
314                if (len > 0) {
315                    try {
316                        mPendingPartRequest = req;
317                        byte[] bytes = new byte[CHUNK_SIZE];
318                        int length = len;
319                        while (len > 0) {
320                            int n = (len > CHUNK_SIZE ? CHUNK_SIZE : len);
321                            int read = is.read(bytes, 0, n);
322                            os.write(bytes, 0, read);
323                            len -= read;
324                            int pct = ((length - len) * 100 / length);
325                            doProgressCallback(msg.mId, att.mId, pct);
326                        }
327                    } finally {
328                        mPendingPartRequest = null;
329                    }
330                }
331                os.flush();
332                os.close();
333
334                // EmailProvider will throw an exception if we try to update an unsaved attachment
335                if (att.isSaved()) {
336                    String contentUriString = (req.contentUriString != null)
337                            ? req.contentUriString
338                            : "file://" + f.getAbsolutePath();
339                    ContentValues cv = new ContentValues();
340                    cv.put(AttachmentColumns.CONTENT_URI, contentUriString);
341                    cv.put(AttachmentColumns.MIME_TYPE, type);
342                    att.update(mContext, cv);
343                    doStatusCallback(msg.mId, att.mId, EmailServiceStatus.SUCCESS);
344                }
345            }
346        } else {
347            doStatusCallback(msg.mId, att.mId, EmailServiceStatus.MESSAGE_NOT_FOUND);
348        }
349    }
350
351    @SuppressWarnings("deprecation")
352    private String makeUriString(String cmd, String extra) throws IOException {
353         // Cache the authentication string and the command string
354        String safeUserName = URLEncoder.encode(mUserName);
355        if (mAuthString == null) {
356            String cs = mUserName + ':' + mPassword;
357            mAuthString = "Basic " + new String(Base64.encodeBase64(cs.getBytes()));
358            mCmdString = "&User=" + safeUserName + "&DeviceId=" + mDeviceId + "&DeviceType="
359                    + mDeviceType;
360        }
361        String us = (mSsl ? (mTrustSsl ? "httpts" : "https") : "http") + "://" + mHostAddress +
362            "/Microsoft-Server-ActiveSync";
363        if (cmd != null) {
364            us += "?Cmd=" + cmd + mCmdString;
365        }
366        if (extra != null) {
367            us += extra;
368        }
369        return us;
370    }
371
372    private void setHeaders(HttpRequestBase method) {
373        method.setHeader("Authorization", mAuthString);
374        method.setHeader("MS-ASProtocolVersion", mProtocolVersion);
375        method.setHeader("Connection", "keep-alive");
376        method.setHeader("User-Agent", mDeviceType + '/' + Eas.VERSION);
377    }
378
379    private ClientConnectionManager getClientConnectionManager() {
380        return SyncManager.getClientConnectionManager();
381    }
382
383    private HttpClient getHttpClient(int timeout) {
384        HttpParams params = new BasicHttpParams();
385        HttpConnectionParams.setConnectionTimeout(params, 15*SECONDS);
386        HttpConnectionParams.setSoTimeout(params, timeout);
387        HttpConnectionParams.setSocketBufferSize(params, 8192);
388        HttpClient client = new DefaultHttpClient(getClientConnectionManager(), params);
389        return client;
390    }
391
392    protected HttpResponse sendHttpClientPost(String cmd, byte[] bytes) throws IOException {
393        return sendHttpClientPost(cmd, new ByteArrayEntity(bytes), COMMAND_TIMEOUT);
394    }
395
396    protected HttpResponse sendHttpClientPost(String cmd, HttpEntity entity) throws IOException {
397        return sendHttpClientPost(cmd, entity, COMMAND_TIMEOUT);
398    }
399
400    protected HttpResponse sendPing(byte[] bytes, int pingHeartbeat) throws IOException {
401       int timeout = (pingHeartbeat+15)*SECONDS;
402       Thread.currentThread().setName(mAccount.mDisplayName + ": Ping");
403
404       if (Eas.USER_LOG) {
405           userLog("Sending ping, timeout: " + pingHeartbeat +
406                   "s, high water mark: " + mPingHighWaterMark + 's');
407       }
408
409       SyncManager.runAsleep(mMailboxId, timeout);
410       try {
411           HttpResponse res = sendHttpClientPost(PING_COMMAND, new ByteArrayEntity(bytes), timeout);
412           return res;
413       } finally {
414           SyncManager.runAwake(mMailboxId);
415       }
416    }
417
418    protected HttpResponse sendHttpClientPost(String cmd, HttpEntity entity, int timeout)
419            throws IOException {
420        HttpClient client = getHttpClient(timeout);
421
422        // Split the mail sending commands
423        String extra = null;
424        boolean msg = false;
425        if (cmd.startsWith("SmartForward&") || cmd.startsWith("SmartReply&")) {
426            int cmdLength = cmd.indexOf('&');
427            extra = cmd.substring(cmdLength);
428            cmd = cmd.substring(0, cmdLength);
429            msg = true;
430        } else if (cmd.startsWith("SendMail&")) {
431            msg = true;
432        }
433
434        String us = makeUriString(cmd, extra);
435        HttpPost method = new HttpPost(URI.create(us));
436        if (msg) {
437            method.setHeader("Content-Type", "message/rfc822");
438        } else {
439            method.setHeader("Content-Type", "application/vnd.ms-sync.wbxml");
440        }
441        setHeaders(method);
442        method.setEntity(entity);
443        synchronized(getSynchronizer()) {
444            mPendingPost = method;
445        }
446        try {
447            return client.execute(method);
448        } finally {
449            synchronized(getSynchronizer()) {
450                mPendingPost = null;
451            }
452        }
453    }
454
455    protected HttpResponse sendHttpClientOptions() throws IOException {
456        HttpClient client = getHttpClient(COMMAND_TIMEOUT);
457        String us = makeUriString("OPTIONS", null);
458        HttpOptions method = new HttpOptions(URI.create(us));
459        setHeaders(method);
460        return client.execute(method);
461    }
462
463    String getTargetCollectionClassFromCursor(Cursor c) {
464        int type = c.getInt(Mailbox.CONTENT_TYPE_COLUMN);
465        if (type == Mailbox.TYPE_CONTACTS) {
466            return "Contacts";
467        } else if (type == Mailbox.TYPE_CALENDAR) {
468            return "Calendar";
469        } else {
470            return "Email";
471        }
472    }
473
474    /**
475     * Performs FolderSync
476     *
477     * @throws IOException
478     * @throws EasParserException
479     */
480    public void runAccountMailbox() throws IOException, EasParserException {
481        // Initialize exit status to success
482        mExitStatus = EmailServiceStatus.SUCCESS;
483        try {
484            try {
485                SyncManager.callback()
486                    .syncMailboxListStatus(mAccount.mId, EmailServiceStatus.IN_PROGRESS, 0);
487            } catch (RemoteException e1) {
488                // Don't care if this fails
489            }
490
491            if (mAccount.mSyncKey == null) {
492                mAccount.mSyncKey = "0";
493                userLog("Account syncKey INIT to 0");
494                ContentValues cv = new ContentValues();
495                cv.put(AccountColumns.SYNC_KEY, mAccount.mSyncKey);
496                mAccount.update(mContext, cv);
497            }
498
499            boolean firstSync = mAccount.mSyncKey.equals("0");
500            if (firstSync) {
501                userLog("Initial FolderSync");
502            }
503
504            // When we first start up, change all mailboxes to push.
505            ContentValues cv = new ContentValues();
506            cv.put(Mailbox.SYNC_INTERVAL, Mailbox.CHECK_INTERVAL_PUSH);
507            if (mContentResolver.update(Mailbox.CONTENT_URI, cv,
508                    WHERE_ACCOUNT_AND_SYNC_INTERVAL_PING,
509                    new String[] {Long.toString(mAccount.mId)}) > 0) {
510                SyncManager.kick("change ping boxes to push");
511            }
512
513            // Determine our protocol version, if we haven't already
514            if (mAccount.mProtocolVersion == null) {
515                userLog("Determine EAS protocol version");
516                HttpResponse resp = sendHttpClientOptions();
517                int code = resp.getStatusLine().getStatusCode();
518                userLog("OPTIONS response: ", code);
519                if (code == HttpStatus.SC_OK) {
520                    Header header = resp.getFirstHeader("MS-ASProtocolCommands");
521                    userLog(header.getValue());
522                    header = resp.getFirstHeader("ms-asprotocolversions");
523                    String versions = header.getValue();
524                    if (versions != null) {
525                        if (versions.contains("12.0")) {
526                            mProtocolVersion = "12.0";
527                        }
528                        mProtocolVersionDouble = Double.parseDouble(mProtocolVersion);
529                        mAccount.mProtocolVersion = mProtocolVersion;
530                        userLog(versions);
531                        userLog("Using version ", mProtocolVersion);
532                    } else {
533                        errorLog("No protocol versions in OPTIONS response");
534                        throw new IOException();
535                    }
536                } else {
537                    errorLog("OPTIONS command failed; throwing IOException");
538                    throw new IOException();
539                }
540            }
541
542            // Change all pushable boxes to push when we start the account mailbox
543            if (mAccount.mSyncInterval == Account.CHECK_INTERVAL_PUSH) {
544                cv = new ContentValues();
545                cv.put(Mailbox.SYNC_INTERVAL, Mailbox.CHECK_INTERVAL_PUSH);
546                if (mContentResolver.update(Mailbox.CONTENT_URI, cv,
547                        SyncManager.WHERE_IN_ACCOUNT_AND_PUSHABLE,
548                        new String[] {Long.toString(mAccount.mId)}) > 0) {
549                    userLog("Push account; set pushable boxes to push...");
550                }
551            }
552
553            while (!mStop) {
554                 userLog("Sending Account syncKey: ", mAccount.mSyncKey);
555                 Serializer s = new Serializer();
556                 s.start(Tags.FOLDER_FOLDER_SYNC).start(Tags.FOLDER_SYNC_KEY)
557                     .text(mAccount.mSyncKey).end().end().done();
558                 HttpResponse resp = sendHttpClientPost("FolderSync", s.toByteArray());
559                 if (mStop) break;
560                 int code = resp.getStatusLine().getStatusCode();
561                 if (code == HttpStatus.SC_OK) {
562                     HttpEntity entity = resp.getEntity();
563                     int len = (int)entity.getContentLength();
564                     if (len > 0) {
565                         InputStream is = entity.getContent();
566                         // Returns true if we need to sync again
567                         if (new FolderSyncParser(is, new AccountSyncAdapter(mMailbox, this))
568                                 .parse()) {
569                             continue;
570                         }
571                     }
572                 } else if (isAuthError(code)) {
573                    mExitStatus = EXIT_LOGIN_FAILURE;
574                } else {
575                    userLog("FolderSync response error: ", code);
576                }
577
578                // Change all push/hold boxes to push
579                cv = new ContentValues();
580                cv.put(Mailbox.SYNC_INTERVAL, Account.CHECK_INTERVAL_PUSH);
581                if (mContentResolver.update(Mailbox.CONTENT_URI, cv,
582                        WHERE_PUSH_HOLD_NOT_ACCOUNT_MAILBOX,
583                        new String[] {Long.toString(mAccount.mId)}) > 0) {
584                    userLog("Set push/hold boxes to push...");
585                }
586
587                try {
588                    SyncManager.callback()
589                        .syncMailboxListStatus(mAccount.mId, mExitStatus, 0);
590                } catch (RemoteException e1) {
591                    // Don't care if this fails
592                }
593
594                // Wait for push notifications.
595                String threadName = Thread.currentThread().getName();
596                try {
597                    runPingLoop();
598                } catch (StaleFolderListException e) {
599                    // We break out if we get told about a stale folder list
600                    userLog("Ping interrupted; folder list requires sync...");
601                } finally {
602                    Thread.currentThread().setName(threadName);
603                }
604            }
605         } catch (IOException e) {
606            // We catch this here to send the folder sync status callback
607            // A folder sync failed callback will get sent from run()
608            try {
609                if (!mStop) {
610                    SyncManager.callback()
611                        .syncMailboxListStatus(mAccount.mId,
612                                EmailServiceStatus.CONNECTION_ERROR, 0);
613                }
614            } catch (RemoteException e1) {
615                // Don't care if this fails
616            }
617            throw e;
618        }
619    }
620
621    void pushFallback(long mailboxId) {
622        Mailbox mailbox = Mailbox.restoreMailboxWithId(mContext, mailboxId);
623        ContentValues cv = new ContentValues();
624        int mins = PING_FALLBACK_PIM;
625        if (mailbox.mType == Mailbox.TYPE_INBOX) {
626            mins = PING_FALLBACK_INBOX;
627        }
628        cv.put(Mailbox.SYNC_INTERVAL, mins);
629        mContentResolver.update(ContentUris.withAppendedId(Mailbox.CONTENT_URI, mailboxId),
630                cv, null, null);
631        errorLog("*** PING ERROR LOOP: Backing off sync of " + mailbox.mDisplayName + " to " +
632                mins + " mins");
633        SyncManager.kick("push fallback");
634    }
635
636    /**
637     * Check the boxes reporting changes to see if there really were any...
638     * We do this because bugs in various Exchange servers can put us into a looping
639     * behavior by continually reporting changes in a mailbox, even when there aren't any.
640     *
641     * This behavior is seemingly random, and therefore we must code defensively by
642     * backing off of push behavior when it is detected.
643     *
644     * One known cause, on certain Exchange 2003 servers, is acknowledged by Microsoft, and the
645     * server hotfix for this case can be found at http://support.microsoft.com/kb/923282
646     */
647
648    void checkPingErrors(HashMap<String, Integer> errorMap) {
649        mBindArguments[0] = Long.toString(mAccount.mId);
650        for (String serverId: mPingChangeList) {
651            // Find the id and sync status for each box
652            mBindArguments[1] = serverId;
653            Cursor c = mContentResolver.query(Mailbox.CONTENT_URI, SYNC_STATUS_PROJECTION,
654                    WHERE_ACCOUNT_KEY_AND_SERVER_ID, mBindArguments, null);
655            try {
656                if (c.moveToFirst()) {
657                    String status = c.getString(1);
658                    int type = SyncManager.getStatusType(status);
659                    // This check should always be true...
660                    if (type == SyncManager.SYNC_PING) {
661                        int changeCount = SyncManager.getStatusChangeCount(status);
662                        if (changeCount > 0) {
663                            errorMap.remove(serverId);
664                        } else if (changeCount == 0) {
665                            // This means that a ping reported changes in error; we keep a count
666                            // of consecutive errors of this kind
667                            Integer failures = errorMap.get(serverId);
668                            if (failures == null) {
669                                errorMap.put(serverId, 1);
670                            } else if (failures > MAX_PING_FAILURES) {
671                                // We'll back off of push for this box
672                                pushFallback(c.getLong(0));
673                                return;
674                            } else {
675                                errorMap.put(serverId, failures + 1);
676                            }
677                        }
678                    }
679                }
680            } finally {
681                c.close();
682            }
683        }
684    }
685
686    void runPingLoop() throws IOException, StaleFolderListException {
687        int pingHeartbeat = mPingHeartbeat;
688        userLog("runPingLoop");
689        // Do push for all sync services here
690        long endTime = System.currentTimeMillis() + (30*MINUTES);
691        HashMap<String, Integer> pingErrorMap = new HashMap<String, Integer>();
692
693        int pingWaitCount = 0;
694
695        while ((System.currentTimeMillis() < endTime) && !mStop) {
696            userLog("runPingLoop, top of loop, pingWaitCount = " + pingWaitCount);
697            // Count of pushable mailboxes
698            int pushCount = 0;
699            // Count of mailboxes that can be pushed right now
700            int canPushCount = 0;
701            // Count of uninitialized boxes
702            int uninitCount = 0;
703
704            Serializer s = new Serializer();
705            Cursor c = mContentResolver.query(Mailbox.CONTENT_URI, Mailbox.CONTENT_PROJECTION,
706                    MailboxColumns.ACCOUNT_KEY + '=' + mAccount.mId +
707                    AND_FREQUENCY_PING_PUSH_AND_NOT_ACCOUNT_MAILBOX, null, null);
708            try {
709                // Loop through our pushed boxes seeing what is available to push
710                while (c.moveToNext()) {
711                    pushCount++;
712                    // Two requirements for push:
713                    // 1) SyncManager tells us the mailbox is syncable (not running, not stopped)
714                    // 2) The syncKey isn't "0" (i.e. it's synced at least once)
715                    long mailboxId = c.getLong(Mailbox.CONTENT_ID_COLUMN);
716                    int pingStatus = SyncManager.pingStatus(mailboxId);
717                    String mailboxName = c.getString(Mailbox.CONTENT_DISPLAY_NAME_COLUMN);
718                    if (pingStatus == SyncManager.PING_STATUS_OK) {
719
720                        String syncKey = c.getString(Mailbox.CONTENT_SYNC_KEY_COLUMN);
721                        if ((syncKey == null) || syncKey.equals("0")) {
722                            // We can't push until the initial sync is done
723                            pushCount--;
724                            uninitCount++;
725                            continue;
726                        }
727
728                        if (canPushCount++ == 0) {
729                            // Initialize the Ping command
730                            s.start(Tags.PING_PING)
731                                .data(Tags.PING_HEARTBEAT_INTERVAL,
732                                        Integer.toString(pingHeartbeat))
733                                .start(Tags.PING_FOLDERS);
734                        }
735
736                        String folderClass = getTargetCollectionClassFromCursor(c);
737                        s.start(Tags.PING_FOLDER)
738                            .data(Tags.PING_ID, c.getString(Mailbox.CONTENT_SERVER_ID_COLUMN))
739                            .data(Tags.PING_CLASS, folderClass)
740                            .end();
741                        userLog("Ping ready for: ", folderClass, ", ", mailboxName, " (",
742                                c.getString(Mailbox.CONTENT_SERVER_ID_COLUMN), ")");
743                    } else if ((pingStatus == SyncManager.PING_STATUS_RUNNING) ||
744                            (pingStatus == SyncManager.PING_STATUS_WAITING)) {
745                        userLog(mailboxName, " not ready for ping");
746                    } else if (pingStatus == SyncManager.PING_STATUS_UNABLE) {
747                        pushCount--;
748                        userLog(mailboxName, " in error state; ignore");
749                        continue;
750                    }
751                }
752            } finally {
753                c.close();
754            }
755
756            // If we've waited 10 seconds or more, just ping with whatever boxes are ready
757            // But use a shorter than normal heartbeat
758            boolean forcePing = (pingWaitCount > 9);
759
760            if ((canPushCount > 0) && ((canPushCount == pushCount) || forcePing)) {
761                userLog("runPingLoop, about to send ping, setting pingWaitCount = 0");
762                // If all pingable boxes are ready for push, send Ping to the server
763                s.end().end().done();
764                pingWaitCount = 0;
765
766                // If we've been stopped, this is a good time to return
767                if (mStop) return;
768
769                long pingTime = SystemClock.elapsedRealtime();
770                try {
771                    // Send the ping, wrapped by appropriate timeout/alarm
772                    if (forcePing) {
773                        userLog("Forcing ping after waiting for all boxes to be ready");
774                    }
775                    HttpResponse res =
776                        sendPing(s.toByteArray(), forcePing ? PING_FORCE_HEARTBEAT : pingHeartbeat);
777
778                    int code = res.getStatusLine().getStatusCode();
779                    userLog("Ping response: ", code);
780
781                    // Return immediately if we've been asked to stop during the ping
782                    if (mStop) {
783                        userLog("Stopping pingLoop");
784                        return;
785                    }
786
787                    if (code == HttpStatus.SC_OK) {
788                        HttpEntity e = res.getEntity();
789                        int len = (int)e.getContentLength();
790                        InputStream is = res.getEntity().getContent();
791                        if (len > 0) {
792                            int status = parsePingResult(is, mContentResolver);
793                            // If our ping completed (status = 1), and we weren't forced and we're
794                            // not at the maximum, try increasing timeout by two minutes
795                            if (status == PROTOCOL_PING_STATUS_COMPLETED && !forcePing) {
796                                if (pingHeartbeat > mPingHighWaterMark) {
797                                    mPingHighWaterMark = pingHeartbeat;
798                                    userLog("Setting high water mark at: ", mPingHighWaterMark);
799                                }
800                                if ((pingHeartbeat < PING_MAX_HEARTBEAT) &&
801                                        !mPingHeartbeatDropped) {
802                                    pingHeartbeat += PING_HEARTBEAT_INCREMENT;
803                                    if (pingHeartbeat > PING_MAX_HEARTBEAT) {
804                                        pingHeartbeat = PING_MAX_HEARTBEAT;
805                                    }
806                                    userLog("Increasing ping heartbeat to ", pingHeartbeat, "s");
807                                }
808                            } else if (status == PROTOCOL_PING_STATUS_CHANGES_FOUND) {
809                                checkPingErrors(pingErrorMap);
810                            }
811                        } else {
812                            userLog("Ping returned empty result; throwing IOException");
813                            throw new IOException();
814                        }
815                    } else if (isAuthError(code)) {
816                        mExitStatus = EXIT_LOGIN_FAILURE;
817                        userLog("Authorization error during Ping: ", code);
818                        throw new IOException();
819                    }
820                } catch (IOException e) {
821                    String msg = e.getMessage();
822                    // If we get the exception that is indicative of a NAT timeout and if we
823                    // haven't yet "fixed" the timeout, back off by two minutes and "fix" it
824                    if ((msg != null) && msg.contains("reset by peer")) {
825                        if ((pingHeartbeat > PING_MIN_HEARTBEAT) &&
826                                (pingHeartbeat > mPingHighWaterMark)) {
827                            pingHeartbeat -= PING_HEARTBEAT_INCREMENT;
828                            mPingHeartbeatDropped = true;
829                            if (pingHeartbeat < PING_MIN_HEARTBEAT) {
830                                pingHeartbeat = PING_MIN_HEARTBEAT;
831                            }
832                            userLog("Decreased ping heartbeat to ", pingHeartbeat, "s");
833                        } else if ((SystemClock.elapsedRealtime() - pingTime) < 2000) {
834                            userLog("NAT type IOException < 2 seconds; throwing IOException");
835                            throw e;
836                        } else {
837                            userLog("NAT type IOException > 2 seconds?");
838                        }
839                    } else {
840                        userLog("IOException detected in runPingLoop: " +
841                                ((msg != null) ? msg : "no message"));
842                        throw e;
843                    }
844                }
845            } else if (pushCount > 0) {
846                // If we want to Ping, but can't just yet, wait a little bit
847                // TODO Change sleep to wait and use notify from SyncManager when a sync ends
848                sleep(1*SECONDS);
849                pingWaitCount++;
850                userLog("pingLoop waited for: ", (pushCount - canPushCount), " box(es), count = "
851                        + pingWaitCount);
852            } else if (uninitCount > 0) {
853                // In this case, we're doing an initial sync of at least one mailbox.  Since this
854                // is typically a one-time case, I'm ok with trying again every 10 seconds until
855                // we're in one of the other possible states.
856                userLog("pingLoop waiting for ", uninitCount, " box(es) to do an initial sync");
857                sleep(10*SECONDS);
858            } else {
859                // We've got nothing to do, so we'll check again in 30 minutes at which time
860                // we'll update the folder list.  Let the device sleep in the meantime...
861                SyncManager.runAsleep(mMailboxId, (30*MINUTES)+(15*SECONDS));
862                sleep(30*MINUTES);
863                SyncManager.runAwake(mMailboxId);
864            }
865        }
866    }
867
868    void sleep(long ms) {
869        try {
870            Thread.sleep(ms);
871        } catch (InterruptedException e) {
872            // Doesn't matter whether we stop early; it's the thought that counts
873        }
874    }
875
876    private int parsePingResult(InputStream is, ContentResolver cr)
877        throws IOException, StaleFolderListException {
878        PingParser pp = new PingParser(is, this);
879        if (pp.parse()) {
880            // True indicates some mailboxes need syncing...
881            // syncList has the serverId's of the mailboxes...
882            mBindArguments[0] = Long.toString(mAccount.mId);
883            mPingChangeList = pp.getSyncList();
884            for (String serverId: mPingChangeList) {
885                mBindArguments[1] = serverId;
886                Cursor c = cr.query(Mailbox.CONTENT_URI, Mailbox.CONTENT_PROJECTION,
887                        WHERE_ACCOUNT_KEY_AND_SERVER_ID, mBindArguments, null);
888                try {
889                    if (c.moveToFirst()) {
890                        SyncManager.startManualSync(c.getLong(Mailbox.CONTENT_ID_COLUMN),
891                                SyncManager.SYNC_PING, null);
892                    }
893                } finally {
894                    c.close();
895                }
896            }
897        }
898        return pp.getSyncStatus();
899    }
900
901    private String getFilterType() {
902        String filter = Eas.FILTER_1_WEEK;
903        switch (mAccount.mSyncLookback) {
904            case com.android.email.Account.SYNC_WINDOW_1_DAY: {
905                filter = Eas.FILTER_1_DAY;
906                break;
907            }
908            case com.android.email.Account.SYNC_WINDOW_3_DAYS: {
909                filter = Eas.FILTER_3_DAYS;
910                break;
911            }
912            case com.android.email.Account.SYNC_WINDOW_1_WEEK: {
913                filter = Eas.FILTER_1_WEEK;
914                break;
915            }
916            case com.android.email.Account.SYNC_WINDOW_2_WEEKS: {
917                filter = Eas.FILTER_2_WEEKS;
918                break;
919            }
920            case com.android.email.Account.SYNC_WINDOW_1_MONTH: {
921                filter = Eas.FILTER_1_MONTH;
922                break;
923            }
924            case com.android.email.Account.SYNC_WINDOW_ALL: {
925                filter = Eas.FILTER_ALL;
926                break;
927            }
928        }
929        return filter;
930    }
931
932    /**
933     * Common code to sync E+PIM data
934     *
935     * @param target, an EasMailbox, EasContacts, or EasCalendar object
936     */
937    public void sync(AbstractSyncAdapter target) throws IOException {
938        Mailbox mailbox = target.mMailbox;
939
940        boolean moreAvailable = true;
941        while (!mStop && moreAvailable) {
942            // If we have no connectivity, just exit cleanly.  SyncManager will start us up again
943            // when connectivity has returned
944            if (!hasConnectivity()) {
945                userLog("No connectivity in sync; finishing sync");
946                mExitStatus = EXIT_DONE;
947                return;
948            }
949
950            while (true) {
951                PartRequest req = null;
952                synchronized (mPartRequests) {
953                    if (mPartRequests.isEmpty()) {
954                        break;
955                    } else {
956                        req = mPartRequests.get(0);
957                    }
958                }
959                getAttachment(req);
960                synchronized(mPartRequests) {
961                    mPartRequests.remove(req);
962                }
963            }
964
965            Serializer s = new Serializer();
966            String className = target.getCollectionName();
967            String syncKey = target.getSyncKey();
968            userLog("Sending ", className, " syncKey: ", syncKey);
969            s.start(Tags.SYNC_SYNC)
970                .start(Tags.SYNC_COLLECTIONS)
971                .start(Tags.SYNC_COLLECTION)
972                .data(Tags.SYNC_CLASS, className)
973                .data(Tags.SYNC_SYNC_KEY, syncKey)
974                .data(Tags.SYNC_COLLECTION_ID, mailbox.mServerId)
975                .tag(Tags.SYNC_DELETES_AS_MOVES);
976
977            // EAS doesn't like GetChanges if the syncKey is "0"; not documented
978            if (!syncKey.equals("0")) {
979                s.tag(Tags.SYNC_GET_CHANGES);
980            }
981            s.data(Tags.SYNC_WINDOW_SIZE,
982                    className.equals("Email") ? EMAIL_WINDOW_SIZE : PIM_WINDOW_SIZE);
983            boolean options = false;
984            if (!className.equals("Contacts")) {
985                // Set the lookback appropriately (EAS calls this a "filter")
986                s.start(Tags.SYNC_OPTIONS).data(Tags.SYNC_FILTER_TYPE, getFilterType());
987                options = true;
988            }
989            if (mProtocolVersionDouble >= 12.0) {
990                if (!options) {
991                    options = true;
992                    s.start(Tags.SYNC_OPTIONS);
993                }
994                s.start(Tags.BASE_BODY_PREFERENCE)
995                    // HTML for email; plain text for everything else
996                    .data(Tags.BASE_TYPE, (className.equals("Email") ? Eas.BODY_PREFERENCE_HTML
997                            : Eas.BODY_PREFERENCE_TEXT))
998                    .end();
999            }
1000            if (options) {
1001                s.end();
1002            }
1003
1004            // Send our changes up to the server
1005            target.sendLocalChanges(s);
1006
1007            s.end().end().end().done();
1008            HttpResponse resp = sendHttpClientPost("Sync", s.toByteArray());
1009            int code = resp.getStatusLine().getStatusCode();
1010            if (code == HttpStatus.SC_OK) {
1011                 InputStream is = resp.getEntity().getContent();
1012                if (is != null) {
1013                    moreAvailable = target.parse(is);
1014                    target.cleanup();
1015                }
1016            } else {
1017                userLog("Sync response error: ", code);
1018                if (isAuthError(code)) {
1019                    mExitStatus = EXIT_LOGIN_FAILURE;
1020                } else {
1021                    mExitStatus = EXIT_IO_ERROR;
1022                }
1023                return;
1024            }
1025        }
1026        mExitStatus = EXIT_DONE;
1027    }
1028
1029    protected void setupService() {
1030        // Make sure account and mailbox are always the latest from the database
1031        mAccount = Account.restoreAccountWithId(mContext, mAccount.mId);
1032        mMailbox = Mailbox.restoreMailboxWithId(mContext, mMailbox.mId);
1033
1034        mThread = Thread.currentThread();
1035        android.os.Process.setThreadPriority(android.os.Process.THREAD_PRIORITY_BACKGROUND);
1036        TAG = mThread.getName();
1037
1038        HostAuth ha = HostAuth.restoreHostAuthWithId(mContext, mAccount.mHostAuthKeyRecv);
1039        mHostAddress = ha.mAddress;
1040        mUserName = ha.mLogin;
1041        mPassword = ha.mPassword;
1042    }
1043
1044    /* (non-Javadoc)
1045     * @see java.lang.Runnable#run()
1046     */
1047    public void run() {
1048        setupService();
1049
1050        try {
1051            SyncManager.callback().syncMailboxStatus(mMailboxId, EmailServiceStatus.IN_PROGRESS, 0);
1052        } catch (RemoteException e1) {
1053            // Don't care if this fails
1054        }
1055
1056        // Whether or not we're the account mailbox
1057        try {
1058            mDeviceId = SyncManager.getDeviceId();
1059            if ((mMailbox == null) || (mAccount == null)) {
1060                return;
1061            } else if (mMailbox.mType == Mailbox.TYPE_EAS_ACCOUNT_MAILBOX) {
1062                runAccountMailbox();
1063            } else {
1064                AbstractSyncAdapter target;
1065                mProtocolVersion = mAccount.mProtocolVersion;
1066                mProtocolVersionDouble = Double.parseDouble(mProtocolVersion);
1067                if (mMailbox.mType == Mailbox.TYPE_CONTACTS) {
1068                    target = new ContactsSyncAdapter(mMailbox, this);
1069                } else {
1070                    target = new EmailSyncAdapter(mMailbox, this);
1071                }
1072                // We loop here because someone might have put a request in while we were syncing
1073                // and we've missed that opportunity...
1074                do {
1075                    if (mRequestTime != 0) {
1076                        userLog("Looping for user request...");
1077                        mRequestTime = 0;
1078                    }
1079                    sync(target);
1080                } while (mRequestTime != 0);
1081            }
1082        } catch (IOException e) {
1083            String message = e.getMessage();
1084            userLog("Caught IOException: ", ((message == null) ? "No message" : message));
1085            mExitStatus = EXIT_IO_ERROR;
1086        } catch (Exception e) {
1087            userLog("Uncaught exception in EasSyncService", e);
1088        } finally {
1089            if (!mStop) {
1090                userLog(mMailbox.mDisplayName, ": sync finished");
1091                SyncManager.done(this);
1092                // If this is the account mailbox, wake up SyncManager
1093                // Because this box has a "push" interval, it will be restarted immediately
1094                // which will cause the folder list to be reloaded...
1095                int status;
1096                switch (mExitStatus) {
1097                    case EXIT_IO_ERROR:
1098                        status = EmailServiceStatus.CONNECTION_ERROR;
1099                        break;
1100                    case EXIT_DONE:
1101                        status = EmailServiceStatus.SUCCESS;
1102                        break;
1103                    case EXIT_LOGIN_FAILURE:
1104                        status = EmailServiceStatus.LOGIN_FAILED;
1105                        break;
1106                    default:
1107                        status = EmailServiceStatus.REMOTE_EXCEPTION;
1108                        errorLog("Sync ended due to an exception.");
1109                        break;
1110                }
1111
1112                try {
1113                    SyncManager.callback().syncMailboxStatus(mMailboxId, status, 0);
1114                } catch (RemoteException e1) {
1115                    // Don't care if this fails
1116                }
1117
1118                // Save the sync time and status
1119                ContentValues cv = new ContentValues();
1120                cv.put(Mailbox.SYNC_TIME, System.currentTimeMillis());
1121                String s = "S" + mSyncReason + ':' + status + ':' + mChangeCount;
1122                cv.put(Mailbox.SYNC_STATUS, s);
1123                mContentResolver.update(ContentUris
1124                        .withAppendedId(Mailbox.CONTENT_URI, mMailboxId), cv, null, null);
1125            } else {
1126                userLog(mMailbox.mDisplayName, ": stopped thread finished.");
1127            }
1128
1129            // Make sure SyncManager knows about this
1130            SyncManager.kick("sync finished");
1131       }
1132    }
1133}
1134