6.0.0-git
2018-12-10
Last Modified 2016-11-24 by Michael Rubinsky

ActiveSync Library Technical Information

This page is designed to give anyone working on the ActiveSync library in Horde 5.x a general overview of logic flow and what happens where and when.

General Library Structure

The logic for handling ActiveSync requests is split between 3 different libraries currently - Horde_Rpc, Horde_Core, and obviously Horde_ActiveSync. Horde_Rpc only handles the initial request and basically just passes on control to Horde_ActiveSync so this page will focus only on the other two libraries.

Horde_ActiveSync

This library contains the main logic for decoding WBXML from EAS requests, passing the request to the appropriate controller and then sending properly encoded responses back to the client.

The following is a general overview of the important classes in this library and what they are responsible for:

Horde_ActiveSync
This is the main "server" and the entry point for the library. Also contains some getters for various objects used throughout.
Horde_ActiveSync_Collections
This class is essentially a manager for "collections". A collection is what we call a group of properties related to a single synchable data store (such as an email folder, or a contact list). It is the entry point for the SYNC and PING handlers for asking for changes. It manages the SyncCache, is responsible for ensuring we have all needed information when handling empty SYNC requests, detects concurrent requests, and a bunch more.
Horde_ActiveSync_Device
Manages device information such as OS and version. Also contains code that works around certain quirks that are specific to certain clients.
Horde_ActiveSync_Mime
A wrapper around Horde_Mime_Part that adds to and overrides existing behavior to make it more specific to ActiveSync. There is also Horde_ActiveSync_Mime_Iterator that is changed from the the normal Horde_Mime_Iterator behavior in that we don't include what EAS considers attachments to be returned, and we also include the base part when iterating (whereas Horde_Mime does not). Objects are instantiated from Horde_ActiveSync_Imap_* classes.
Horde_ActiveSync_Rfc822
Deals with handling RFC822 email message strings/streams in the context of EAS. E.g., used when handling incoming SENDMAIL commands.
Horde_ActiveSync_SyncCache
This class is responsible for storing/loading the SyncCache data from the storage/state driver. The SyncCache started life as a way of caching data from SYNC and PING requests that would be needed if the client issued an "empty" SYNC/PING request. Empty requests are required to use the same values as the last non-empty request. It has since grown to be essentially a shared data store that helps keep collection data up to date between any and all running requests. Most (if not all) interaction with this class is through the Horde_ActiveSync_Collections object.
Horde_ActiveSync_Connector
These classes are responsible for sending/receiving the structured WBXML for certain requests. E.g., the H_AS_C_Exporter_Sync object contain methods that are called from the H_AS_Request_Sync object that send the WBXML needed for sending each change. It is passed the message object, encodes it to WBXML, and wraps it with any needed response WBXML before sending it down the output stream. Likewise, the H_AS_C_Importer object reads the structured WBXML for importing changes. These methods are called from the Horde_ActiveSync_Request_* classes after the changes have been fetched.
Horde_ActiveSync_Driver_Base
This is the base class that Horde_Core_ActiveSync_Driver extends.
Horde_ActiveSync_Folder_*
These classes represent a specific collection's state. It's an abstraction around the state data and represents the point in time of the sync represented by the synckey. For non-email collections, this basically stores the last known syncstamp/time along with a few other details. For email folders, this class stores things like the HIGHESTMODSEQ, UIDVALIDITY, NEXTUID, and the list of IMAP UIDS that the are on the client etc... If not using a server that supports CONDSTORE then this will also contain flag information. Also contains logic used to set/get/calculate what UIDs have changed/vanished etc... These objects are used to transport the change set back and forth from the backend driver to the ActiveSync code that fetches and sends each detected change.
Horde_ActiveSync_Imap_*
These classes interact with the IMAP server. H_AS_I_Adapter contains the bulk of the logic for fetching changes, messages, etc.... The Message object wraps a single IMAP message and the MessageBodyData object abstracts access to the message's body taking various things into account (if the client needs HTML body, if it needs truncation) and ensuring the data is proper UTF-8 data.
Horde_ActiveSync_Message_*
These classes represent either an actual message item i.e., a Calendar item or a part of a message item that is contained by a message item i.e., and Attendee or a Flag. Each class is responsible for knowing how to encode itself into WBXML or to decode a WBXML stream into the item's properties.
Horde_ActiveSync_State_*
This is the state/storage driver. Responsible for interacting with the persistent storage used by ActiveSync (normally Sql). This is another one of those classes that has grown too big for it's original name and needs to be broken down for H6. Started as a driver for maintaining the state/synckey "sync-points" but has grown to encompass managing all storage needs. E.g., the SyncCache is actually persisted to storage using this class.

Horde_Core

Core contains any code specific to handling Horde Groupware collections. This is where requests for information and changes to information are actually handled.

Horde_Core_ActiveSync_Auth
Wraps authentication driver for use in ActiveSync (see Authentication section below).
Horde_Core_ActiveSync_Connector
Wraps calls to the various application APIs (except for IMP) from Horde_Core_ActiveSync_Driver.
Horde_Core_ActiveSync_Driver
Concrete implementation of Horde_ActiveSync_Driver_Base.
Horde_Core_ActiveSync_Mail
Handles sending/replying/forwarding email.

Factories

Horde_Core_Factory_ActiveSyncServer
Creates the main Horde_ActiveSync object. Injects the Horde_Core_ActiveSync_Driver, the WBXML encoder/decoder objects, the Horde_ActiveSync_State_[Sql|Mongo] storage object and the Horde_Controller_Request object.
Horde_Core_Factory_ActiveSyncState
Creates the state storage handler. The name is misleading (and will change in Horde 6) as this class has evolved to be more of a general storage handler and now handles more than just device state. We will assume a Sql storage backend for this document.
Horde_Core_Factory_ActiveSyncBackend
Creates the Horde_Core_ActiveSync_Driver backend driver. Injects Horde_Core_ActiveSync_Connector, Horde_Core_ActiveSync_Imap_Factory (if needed), the state storage driver, and the Horde_Core_ActiveSync_Auth object.
Horde_Core_ActiveSync_Imap_Factory
Responsible for constructing the Horde_ActiveSync_Imap_Adapter, for returning the folder tree, and information on available user-defined flags. This factory is injected into the backend driver.
Horde_Core_ActiveSync_Logger_Factory
Obviously, provides the logger object used for the synclog.

Protocol Overview

It's beyond the scope to explain the ActiveSync protocol in detail. For that, there is the official documentation. The most useful of these are
MS-ASCMD
Details every command/request and it's schema.
MS-ASHTTP
Documents the requirements and flow of the HTTP protocol as used in the EAS protocol.

There are also the individual documents for each collection type, such as MS-ASEMAIL, MS-ASTASKS etc... These documents are the best place to start when trying to track down issues such as "Protocol Error" issues with certain clients.

The basic bit to know about the EAS protocol is that it is encoded using WBXML. That is, binary encoded XML data. Again, the structure/schema of WBXML data is beyond the scope of this page. Instead of decoding the entire request first and then handling it, Horde_ActiveSync decodes the data and handles it on the fly. That is, we decode each individual message/object as it comes in and handle it in-line, so to speak. This is to avoid keeping more in memory than is necessary. The same is true for encoding - we don't wait to enocde the entire response - we encode and send the response to the output stream as soon as we can. The actual encoding/decoding is done in the Horde_ActiveSync_Wbxml_* classes. The codepages/schema is defined in //Horde_ActiveSync_Wbxml::.

Logic Flow

I have a long-standing item on my todo list to generate an activity diagram for the program flow of an EAS request, but in the meantime here is a description of what happens.

EAS requests hit rpc.php first. There are a number of ways that these are differentiated from other RPC requests, but the main give-away is the REQUEST_URI containing Microsoft-Server-ActiveSync. A few things happen here before continuing. First, EAS requests are session-less, meaning that the entire Horde environment needs to be setup for each request. This is handled by explicitly setting $session_control = 'None' to force the use of the Null session driver in Horde. From there, we perform the same logic and checks like every other Horde RPC request. This includes having to initialize the Horde environment with NO authentication.

From here, we instantiate a Horde_Rpc_ActiveSync object and inject a Horde_ActiveSync object (which is created using Horde_Core_Factory_ActiveSyncServer).

Here, we perform some sanity checking on the request and sniff out what type of request we are handling. OPTIONS and Autodiscover requests are handled a little differently, but for now we will concentrate on the "normal" request handling.

The client must send certain data, apart from the WBXML structure, with each request. This data is either present as "normal" GET variables or is sent as BASE64 encoded binary data sent in QUERY_STRING (see Horde_ActiveSync::getGetVars()). The format of this binary data is beyond the scope of this page, but the data is decoded in Horde_ActiveSync_Utils::decodeBase64().

Cmd
This is the command or request type. E.g., SYNC, PING, FOLDESYNC
DeviceId
This is a unique identifier for the client. This value is only unique to the client, not to the account. I.e., the same physical device/application will have the same DeviceId. Multiple users can be associated with the same DeviceId.

Flow is turned over to Horde_ActiveSync::handleRequest(). This is where the interesting stuff starts to happen.

Authentication

First, we perform some checks, normalization, and call the versionCallback hook if it's present. If all is well, we finally attempt authentication. Authentication to Horde is a massive topic and it's only complicated more by layering ActiveSync on top of it. I will try to give a brief overview here. For a more detailed description of the general Horde authentication layer, see Jan's excellent series of posts on his blog.

Thanks to broken clients, different supported authentication mechanisms and other idiosyncrasies, we need to perform some magic to make sure we have the user's credentials. For this, there is Horde_ActiveSync_Credentials. This class, when constructed and injected with the Horde_ActiveSync object, will have two properties set: username and password. For the purposes of this page, we will assume a typical setup where the client properly sends credentials using HTTP BASIC and we are NOT using X509 certificates.

Once we have found the credentials, we call Horde_ActiveSync::authenticate(). This performs a few checks then ultimately passes control to Horde_Core_ActiveSync_Driver::authenticate(). Since some broken clients always send the email address as the username, plus the fact the Autodiscover requests ALWAYS use the email address, we need to normalize the username to the correct form. This is handled in Horde_Core_ActiveSync_Driver::getUsernameFromEmail() and is partially affected by the $GLOBALS['conf']['activesync']['autodiscovery'] setting (yes, this name is misleading since it is now used for more than just autodiscovery).

Once in Horde_Core_ActiveSync_Driver::authenticate() we use the Horde_Core_ActiveSync_Auth object that was injected when the driver was created to perform the actual authentication. The reason for this authentication wrapper is to allow for combinations of a "normal" Horde auth driver along with a transparent driver like X509 to support clients that allow for certificates along WITH credentials. For this page, we will assume a "normal" authentication - and as such, the actual authentication task is delegated to the 'base_driver' in Horde_Core_ActiveSync_Auth. That is, the authentication driver that is returned by

$injector->getInstance('Horde_Core_Factory_Auth')->create()

Device

Note that for BC reasons we refer to the client as "Device". We treat these two terms are interchangeable unless explicitly mentioned that we are talking about the physical device that the client is running on.

Once we have gotten authentication out the way, we perform some checks on the device/client. This includes things like making sure the device entry exists in our storage backend (or gets created if it doesn't), checking to see if the maximum protocol version we can handle has changed - and if so, notifying the client. We also call some hooks and callbacks to allow checking various permissions etc... All of this is handled in Horde_ActiveSync::_handleDevice(). At the end of that call (if successful), we know we have a device object available and the client is allowed to connect. Any failure here will result in an Exception being thrown and subsequently an appropriate HTTP error code to be sent back to the client.

Provisioning

Now we take care of setting the provisioning flag and read the WBXML header in from the input stream. Provisioning support allows the server to take control of certain security settings on the client and also enables the ability to remote-wipe the client from the server. The provisioning flag is from Horde's permissions system and indicates the level of security required:

Enable
This means the only clients that support full provisioning are allowed to connect to the server. Clients that don't support this or that have broken support (early Android clients) will NOT work.
Allow
This means that we enforce provisioning on clients that support it, but also allow non-compliant clients to connect.
Disable
No provisioning is done.

Multipart

Next we check to see if the client accepts Multipart responses. This is typically used when fetching large amounts of data like e.g, an email attachment. This is indicated by the presence of a specific header or GET variable. We will assume this is not the case for this page.

Command

Now we can take care of the actual command the client is attempting to perform. These are handled by Horde_ActiveSync_Request_* objects. Again, the name of these objects are a bit outdated and are planned to be renamed in H6. The object is instantiated and the handle() request is called. If all goes well, a value of true is returned and control is returned back to the RPC layer to finish up.

The Horde_ActiveSync_Request_* objects are responsible for enforcing the schema of whatever request is being handled, passing off any incoming additions/deletions/changes to the backend and delegating the responsibility for storing any data that needs to be persisted. This includes the collection state and the sync cache. This are explained in the section on the client life cycle.

I should be noted here that ActiveSync clients are able to issue requests while other requests are still running. I.e., if the user changes an entry, a new SYNC request can be issued, even though there is currently a PING request running. After the SYNC request is handled, the client can then issue another PING reqeust etc... The sync cache is used to track this and detect these concurrent requests and kill off the most appropriate request.

There are almost 2 dozen different types of requests that handle things from synchronizing the folder structure to validating S/MIME certificates. The more common request objects are:

Horde_ActiveSync_Request_Sync
This is the main code responsible for accepting and sending object changes, handling "hanging syncs" (which are SYNC requests that also act as PING requests) as well as handling certain options that the client sets (such as truncation, sync window etc...).
Horde_ActiveSync_Request_Ping
This handles PING requests, which basically just continuously check for a change in the backend. It doesn't care what the change is, or how many there are. Much less resource intensive than a SYNC for this reason.

This is where the bulk of the action is performed and this description is of course a gross over-simplification. There are many other objects that are involved in handling the request - the responsibility of each of these objects are outlined in the General Library Structure section.

Life Cycle of a Client.

What we will describe is the life cycle of a client-server pairing from the initial connection to be able to synchronize changes. Let's start with a fresh, never before connected client. The details and order of things vary from EAS version to version. This is designed as a general overview and most closely resembles what happens in EAS version >= 14.

OPTIONS

The first thing that happens is the OPTIONS request. This essentially tells the server what protocol versions the client supports and the server responds with (among other things) the version that it will be using. This is usually where the device object is first created. TODO: Flesh this out with more details.

SETTINGS

Second will normally be a SETTINGS request. This is where the client can give the server details about the device and/or OS, application name etc... Normally this is responded to with server details about the user account. The following is an example synclog of the SETTINGS request and response using a Windows 10 Mail client:

2016-11-14T17:03:59+00:00 INFO: [10030] Horde_Core_ActiveSync_Driver::authenticate() attempt for mike
2016-11-14T17:03:59+00:00 INFO: [10030] SETTINGS request received for user mike
2016-11-14T17:03:59+00:00 INFO: [10030] Device entry exists for 340B5431BBC4241BB73F622B4C6D18E9, updating userAgent, version, and supported.
2016-11-14T17:03:59+00:00 INFO: [10030] GET VARIABLES: Array
(
    [ProtVer] => 14.1
    [Cmd] => Settings
    [Locale] => 1033
    [DeviceId] => 340b5431bbc4241bb73f622b4c6d18e9
    [PolicyKey] => 0
    [DeviceType] => WindowsMail
)

2016-11-14T17:03:59+00:00 DEBUG: [10030] I  <Settings:Settings>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I   <Settings:DeviceInformation>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I    <Settings:Set>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:Model>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I       VMware Virtual Platform
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     </Settings:Model>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:IMEI />
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:FriendlyName>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I       DESKTOP-E96J0OF
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     </Settings:FriendlyName>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:OS>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I       Windows 10.0.14393
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     </Settings:OS>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:OSLanguage>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I       English
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     </Settings:OSLanguage>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:PhoneNumber />
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:UserAgent>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I       MSFT-WIN-3/10.0.14393
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     </Settings:UserAgent>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:EnableOutboundSMS>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     <Settings:MobileOperator>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I       OperatorName
2016-11-14T17:03:59+00:00 DEBUG: [10030] I     </Settings:MobileOperator>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I    </Settings:Set>
2016-11-14T17:03:59+00:00 INFO: [10030] Device entry exists for 340B5431BBC4241BB73F622B4C6D18E9, updating userAgent, version, and supported.
2016-11-14T17:03:59+00:00 DEBUG: [10030] I   </Settings:DeviceInformation>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I   <Settings:UserInformation>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I    <Settings:Get />
2016-11-14T17:03:59+00:00 DEBUG: [10030] I   </Settings:UserInformation>
2016-11-14T17:03:59+00:00 DEBUG: [10030] I  </Settings:Settings>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O  <Settings:Settings>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O   <Settings:Status>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O    1
2016-11-14T17:03:59+00:00 DEBUG: [10030] O   </Settings:Status>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O   <Settings:DeviceInformation>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O    <Settings:Status>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O     1
2016-11-14T17:03:59+00:00 DEBUG: [10030] O    </Settings:Status>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O   </Settings:DeviceInformation>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O   <Settings:UserInformation>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O    <Settings:Status>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O     1
2016-11-14T17:03:59+00:00 DEBUG: [10030] O    </Settings:Status>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O    <Settings:Get>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O     <Settings:Accounts>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O      <Settings:Account>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O       <Settings:AccountName>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O        Default Identity
2016-11-14T17:03:59+00:00 DEBUG: [10030] O       </Settings:AccountName>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O       <Settings:EmailAddresses>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O        <Settings:PrimarySmtpAddress>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O         mike@theupstairsroom.com
2016-11-14T17:03:59+00:00 DEBUG: [10030] O        </Settings:PrimarySmtpAddress>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O        <Settings:SmtpAddress>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O         mike@theupstairsroom.com
2016-11-14T17:03:59+00:00 DEBUG: [10030] O        </Settings:SmtpAddress>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O       </Settings:EmailAddresses>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O      </Settings:Account>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O     </Settings:Accounts>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O    </Settings:Get>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O   </Settings:UserInformation>
2016-11-14T17:03:59+00:00 DEBUG: [10030] O  </Settings:Settings>

FOLDERSYNC

For the purposes of this page, we are going to ignore the PROVISIONING stuff. The next step is the FOLDERSYNC request:

2016-11-14T17:03:59+00:00 DEBUG: [10029] I  <FolderHierarchy:FolderSync>
2016-11-14T17:03:59+00:00 DEBUG: [10029] I   <FolderHierarchy:SyncKey>
2016-11-14T17:03:59+00:00 DEBUG: [10029] I     0
2016-11-14T17:03:59+00:00 DEBUG: [10029] I   </FolderHierarchy:SyncKey>
2016-11-14T17:03:59+00:00 DEBUG: [10029] I  </FolderHierarchy:FolderSync>

First, the client requests a SyncKey of 0. This indicates it is a fresh start and that the server should discard any previous sets of state it may have for this client and user. The server fetches the list of folders that are available. For this purpose each groupware share (address book, calendar etc...) is considered a folder. The entry point for this is Horde_Core_ActiveSync_Driver::getFolderList().

At this point we should talk about the backend's id and the ActiveSync UID for each folder. From the client's point of view, all it cares about is the uid for the folder. We create new UIDs whenever a new folder is encountered. The mapping of UIDs to backend ids is managed by the Horde_ActiveSync_State driver. So, you will see something like this in the sync log:

2016-11-14T17:03:59+00:00 INFO: [10029] Horde_Core_ActiveSync_Driver::getFolderList()
2016-11-14T17:03:59+00:00 INFO: [10029] Device entry exists for 340B5431BBC4241BB73F622B4C6D18E9, updating userAgent, version, and supported.
2016-11-14T12:04:00-05:00 INFO: [10029] Creating new folder uuid for Calendar:1w_UP1B0Fbgun61fg3dAqLJ: A2603e3ee
2016-11-14T12:04:00-05:00 INFO: [10029] Creating new folder uuid for @Contacts@: Cd1b7031f
2016-11-14T12:04:00-05:00 INFO: [10029] Creating new folder uuid for @Tasks@: Tb666e6ce
2016-11-14T12:04:00-05:00 INFO: [10029] Creating new folder uuid for @Notes@: N6d6ecbe3
2016-11-14T12:04:00-05:00 INFO: [10029] Polling Horde_Core_ActiveSync_Driver::_getMailFolders()
2016-11-14T12:04:00-05:00 INFO: [10029] Creating new folder uuid for INBOX: Fe4d57a40

Now we send the folder tree to the client, along with a synckey (only showing one folder for brevity's sake):

2016-11-14T12:04:00-05:00 DEBUG: [10029] O  <FolderHierarchy:FolderSync>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O   <FolderHierarchy:Status>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O    1
2016-11-14T12:04:00-05:00 DEBUG: [10029] O   </FolderHierarchy:Status>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O   <FolderHierarchy:SyncKey>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O    {5829ee7f-b60c-405a-822f-272dc0a80160}1
2016-11-14T12:04:00-05:00 DEBUG: [10029] O   </FolderHierarchy:SyncKey>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O   <FolderHierarchy:Changes>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O    <FolderHierarchy:Count>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     87
2016-11-14T12:04:00-05:00 DEBUG: [10029] O    </FolderHierarchy:Count>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O    <FolderHierarchy:Add>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     <FolderHierarchy:ServerEntryId>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O      Tb666e6ce
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     </FolderHierarchy:ServerEntryId>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     <FolderHierarchy:ParentId>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O      0
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     </FolderHierarchy:ParentId>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     <FolderHierarchy:DisplayName>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O      Tasks
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     </FolderHierarchy:DisplayName>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     <FolderHierarchy:Type>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O      7
2016-11-14T12:04:00-05:00 DEBUG: [10029] O     </FolderHierarchy:Type>
2016-11-14T12:04:00-05:00 DEBUG: [10029] O    </FolderHierarchy:Add>
2016-11-14T12:04:01-05:00 DEBUG: [10029] O   </FolderHierarchy:Changes>
2016-11-14T12:04:01-05:00 DEBUG: [10029] O  </FolderHierarchy:FolderSync>

This is a good time to mention the SyncKey. The SyncKey is the unique identifier a specific set of state. It represents the state of the collection being synced at that point in time. It always has the following form:

{xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx}y where y is a continuously increasing counter. That increments any time changes are received from or sent to the client. The GUID-looking value in front of the counter will remain constant after it's generated for each collection.

SYNC

Next, the client can issue SYNC requests for each folder it wants to populate. Unlike the FOLDERSYNC request, the SYNC request doesn't send the actual changes back with the 1st synckey. E.g., the first SYNC request for a mail folder contains some options such as the filtertype (how far back to sync), bodytype preferences etc... The server sets those options in the SyncCache for that collection, creates a new synckey, stores it in the collection's state and sends back the initial response.

2016-11-14T17:04:03+00:00 DEBUG: [10030] I  <Synchronize>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I   <Folders>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I    <Folder>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I     <SyncKey>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       0
2016-11-14T17:04:03+00:00 DEBUG: [10030] I     </SyncKey>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I     <FolderId>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       Fe4d57a40
2016-11-14T17:04:03+00:00 DEBUG: [10030] I     </FolderId>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I     <Options>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      <FilterType>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I        5
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      </FilterType>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      <AirSyncBase:BodyPreference>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       <AirSyncBase:Type>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I         1
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       </AirSyncBase:Type>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       <AirSyncBase:Preview>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I         128
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       </AirSyncBase:Preview>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      </AirSyncBase:BodyPreference>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      <AirSyncBase:BodyPreference>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       <AirSyncBase:Type>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I         2
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       </AirSyncBase:Type>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       <AirSyncBase:Preview>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I         128
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       </AirSyncBase:Preview>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      </AirSyncBase:BodyPreference>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      <MIMESupport>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I        1
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      </MIMESupport>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      <AirSyncBase:BodyPreference>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       <AirSyncBase:Type>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I         4
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       </AirSyncBase:Type>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       <AirSyncBase:TruncationSize>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I         107520
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       </AirSyncBase:TruncationSize>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       <AirSyncBase:Preview>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I         128
2016-11-14T17:04:03+00:00 DEBUG: [10030] I       </AirSyncBase:Preview>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      </AirSyncBase:BodyPreference>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      <Conflict>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I        1
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      </Conflict>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      <RightsManagement:RightsManagementSupport>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I        1
2016-11-14T17:04:03+00:00 DEBUG: [10030] I      </RightsManagement:RightsManagementSupport>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I     </Options>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I    </Folder>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I   </Folders>
2016-11-14T17:04:03+00:00 DEBUG: [10030] I  </Synchronize>

2016-11-14T17:04:03+00:00 DEBUG: [10030] O  <Synchronize>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O   <Status>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O    1
2016-11-14T17:04:03+00:00 DEBUG: [10030] O   </Status>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O   <Folders>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O    <Folder>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O     <SyncKey>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O      {5829ee83-11e8-472d-bc66-272ec0a80160}1
2016-11-14T17:04:03+00:00 DEBUG: [10030] O     </SyncKey>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O     <FolderId>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O      Fe4d57a40
2016-11-14T17:04:03+00:00 DEBUG: [10030] O     </FolderId>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O     <Status>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O      1
2016-11-14T17:04:03+00:00 DEBUG: [10030] O     </Status>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O    </Folder>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O   </Folders>
2016-11-14T17:04:03+00:00 DEBUG: [10030] O  </Synchronize>

Now, the next SYNC request for this folder will be sent with the SyncKey of {5829ee83-11e8-472d-bc66-272ec0a80160}1. At this point we know it's the "first sync" i.e., all objects are "new" from the client's point of view, so we do some optimizations and take advantage of this. Otherwise, all the future SYNC requests will behave the same way - the client sends the last SyncKey it knows about, the server uses that to get the state of whatever collection we are syncing, calculates the changes, increments the SyncKey counter, sends it all and saves the new state.

The general flow for getting server changes would be something like this:

In ActiveSync_Request_Sync::_handle() --->
call into Horde_ActiveSync_Collections::getCollectionChanges() --->
which calls into Horde_ActiveSync_State_Base::getChanges() --->
which finally calls Horde_Core_ActiveSync_Driver::getServerChanges() to get the changes.

Once we have the change set in H_AS_Request_Sync::_handle(), we set it into the exporter object the loop and send each change (see Horde_ActiveSync_Connector_Exporter_Sync::sendNextChange()).