/**
* Handle the sync request
*
* @return boolean
* @throws Horde_ActiveSync_Exception
*/
protected function _handle()
{
$this->_logger->info(sprintf('[%s] Handling SYNC command.', $this->_procid));
// Check policy
if (!$this->checkPolicyKey($this->_activeSync->getPolicyKey(), Horde_ActiveSync::SYNC_SYNCHRONIZE)) {
return true;
}
// Check global errors.
if ($error = $this->_activeSync->checkGlobalError()) {
$this->_statusCode = $error;
$this->_handleGlobalSyncError();
return true;
}
// Defaults
$this->_statusCode = self::STATUS_SUCCESS;
$partial = false;
try {
$this->_collections = $this->_activeSync->getCollectionsObject();
} catch (Horde_ActiveSync_Exception $e) {
$this->_statusCode = self::STATUS_SERVERERROR;
$this->_handleGlobalSyncError();
return true;
}
// Sanity check
if ($this->_device->version >= Horde_ActiveSync::VERSION_TWELVEONE) {
// We don't have a previous FOLDERSYNC.
if (!$this->_collections->haveHierarchy()) {
$this->_logger->notice(sprintf('[%s] No HIERARCHY SYNCKEY in sync_cache, invalidating.', $this->_procid));
$this->_statusCode = self::STATUS_FOLDERSYNC_REQUIRED;
$this->_handleGlobalSyncError();
return true;
}
}
// Start decoding request
if (!$this->_decoder->getElementStartTag(Horde_ActiveSync::SYNC_SYNCHRONIZE)) {
if ($this->_device->version >= Horde_ActiveSync::VERSION_TWELVEONE) {
$this->_logger->info(sprintf('[%s] Empty Sync request, taking info from SyncCache.', $this->_procid));
if ($this->_collections->cachedCollectionCount() == 0) {
$this->_logger->warn(sprintf('[%s] Empty SYNC request but no SyncCache or SyncCache with no collections.', $this->_procid));
$this->_statusCode = self::STATUS_REQUEST_INCOMPLETE;
$this->_handleGlobalSyncError();
return true;
} else {
if (!$this->_collections->initEmptySync()) {
$this->_statusCode = self::STATUS_REQUEST_INCOMPLETE;
$this->_handleGlobalSyncError();
return true;
}
}
} else {
$this->_statusCode = self::STATUS_REQUEST_INCOMPLETE;
$this->_handleGlobalSyncError();
$this->_logger->err('Empty Sync request and protocolversion < 12.1');
return true;
}
} else {
// Start decoding request.
$this->_collections->hangingSync = false;
while (($sync_tag = $this->_decoder->getElementStartTag(Horde_ActiveSync::SYNC_WINDOWSIZE) ? Horde_ActiveSync::SYNC_WINDOWSIZE : ($this->_decoder->getElementStartTag(Horde_ActiveSync::SYNC_FOLDERS) ? Horde_ActiveSync::SYNC_FOLDERS : ($this->_decoder->getElementStartTag(Horde_ActiveSync::SYNC_PARTIAL) ? Horde_ActiveSync::SYNC_PARTIAL : ($this->_decoder->getElementStartTag(Horde_ActiveSync::SYNC_WAIT) ? Horde_ActiveSync::SYNC_WAIT : ($this->_decoder->getElementStartTag(Horde_ActiveSync::SYNC_HEARTBEATINTERVAL) ? Horde_ActiveSync::SYNC_HEARTBEATINTERVAL : -1))))) != -1) {
switch ($sync_tag) {
case Horde_ActiveSync::SYNC_HEARTBEATINTERVAL:
if ($hbinterval = $this->_decoder->getElementContent()) {
$this->_collections->setHeartbeat(array('hbinterval' => $hbinterval));
$this->_collections->hangingSync = true;
$this->_decoder->getElementEndTag();
if ($hbinterval > self::MAX_HEARTBEAT) {
$this->_logger->err(sprintf('[%s] HeartbeatInterval outside of allowed range.', $this->_procid));
$this->_statusCode = self::STATUS_INVALID_WAIT_HEARTBEATINTERVAL;
$this->_handleGlobalSyncError(self::MAX_HEARTBEAT);
return true;
}
}
break;
case Horde_ActiveSync::SYNC_WAIT:
if ($wait = $this->_decoder->getElementContent()) {
$this->_collections->setHeartbeat(array('wait' => $wait));
$this->_collections->hangingSync = true;
$this->_decoder->getElementEndTag();
if ($wait > self::MAX_HEARTBEAT / 60) {
$this->_logger->err(sprintf('[%s] Wait value outside of allowed range.', $this->_procid));
$this->_statusCode = self::STATUS_INVALID_WAIT_HEARTBEATINTERVAL;
$this->_handleGlobalSyncError(self::MAX_HEARBEAT / 60);
return true;
}
}
break;
case Horde_ActiveSync::SYNC_PARTIAL:
if ($this->_decoder->getElementContent(Horde_ActiveSync::SYNC_PARTIAL)) {
$this->_decoder->getElementEndTag();
}
$partial = true;
break;
case Horde_ActiveSync::SYNC_WINDOWSIZE:
$this->_collections->setDefaultWindowSize($this->_decoder->getElementContent());
if (!$this->_decoder->getElementEndTag()) {
$this->_logger->err('PROTOCOL ERROR');
return false;
}
break;
case Horde_ActiveSync::SYNC_FOLDERS:
if (!$this->_parseSyncFolders()) {
// Any errors are handled in _parseSyncFolders() and
// appropriate error codes sent to device.
return true;
}
}
}
if ($this->_device->version >= Horde_ActiveSync::VERSION_TWELVEONE) {
// These are not allowed in the same request.
if ($this->_collections->hbinterval !== false && $this->_collections->wait !== false) {
$this->_logger->err(sprintf('[%s] Received both HBINTERVAL and WAIT interval in same request.', $this->_procid));
$this->_statusCode = Horde_ActiveSync_Status::INVALID_XML;
$this->_handleGlobalSyncError();
return true;
}
// Fill in missing sticky data from cache.
$this->_collections->validateFromCache();
}
// Ensure we have OPTIONS values.
$this->_collections->ensureOptions();
// Full or partial sync request?
if ($partial === true) {
$this->_logger->info(sprintf('[%s] Executing a PARTIAL SYNC.', $this->_procid));
if (!$this->_collections->initPartialSync()) {
$this->_statusCode = self::STATUS_REQUEST_INCOMPLETE;
$this->_handleGlobalSyncError();
return true;
}
// Fill in any missing collections that were already sent.
// @TODO: Can we move this to initPartialSync()?
$this->_collections->getMissingCollectionsFromCache();
} else {
// Full request.
$this->_collections->initFullSync();
}
// End SYNC tag.
if (!$this->_decoder->getElementEndTag()) {
$this->_statusCode = self::STATUS_PROTERROR;
$this->_handleGlobalSyncError();
$this->_logger->err('PROTOCOL ERROR: Missing closing SYNC tag');
return false;
}
// We MUST have syncable collections by now.
if (!$this->_collections->haveSyncableCollections($this->_device->version)) {
$this->_statusCode = self::STATUS_KEYMISM;
$this->_handleGlobalSyncError();
return true;
}
// Update the syncCache with the new collection data.
$this->_collections->updateCache();
// Save.
$this->_collections->save(true);
$this->_logger->info(sprintf('[%s] All synckeys confirmed. Continuing with SYNC', $this->_procid));
}
$pingSettings = $this->_driver->getHeartbeatConfig();
// If this is >= 12.1, see if we want a looping SYNC.
if ($this->_collections->canDoLoopingSync() && $this->_device->version >= Horde_ActiveSync::VERSION_TWELVEONE && $this->_statusCode == self::STATUS_SUCCESS) {
// Calculate the heartbeat
if (!($heartbeat = $this->_collections->getHeartbeat())) {
$heartbeat = !empty($pingSettings['heartbeatdefault']) ? $pingSettings['heartbeatdefault'] : 10;
}
// Wait for changes.
$changes = $this->_collections->pollForChanges($heartbeat, $pingSettings['waitinterval']);
if ($changes !== true && $changes !== false) {
switch ($changes) {
case Horde_ActiveSync_Collections::COLLECTION_ERR_STALE:
$this->_logger->notice(sprintf('[%s] Changes in cache detected during looping SYNC exiting here.', $this->_procid));
return true;
case Horde_ActiveSync_Collections::COLLECTION_ERR_FOLDERSYNC_REQUIRED:
$this->_statusCode = self::STATUS_FOLDERSYNC_REQUIRED;
$this->_handleGlobalSyncError();
return true;
case Horde_ActiveSync_Collections::COLLECTION_ERR_SYNC_REQUIRED:
$this->_statusCode = self::STATUS_REQUEST_INCOMPLETE;
$this->_handleGlobalSyncError();
return true;
default:
$this->_statusCode = self::STATUS_SERVERERROR;
$this->_handleGlobalSyncError();
return true;
}
}
}
// See if we can do an empty response
if ($this->_device->version >= Horde_ActiveSync::VERSION_TWELVEONE && $this->_statusCode == self::STATUS_SUCCESS && empty($changes) && $this->_collections->canSendEmptyResponse()) {
$this->_logger->info(sprintf('[%s] Sending an empty SYNC response.', $this->_procid));
$this->_collections->lastsyncendnormal = time();
$this->_collections->save(true);
return true;
}
$this->_logger->info(sprintf('[%s] Completed parsing incoming request. Peak memory usage: %d.', $this->_procid, memory_get_peak_usage(true)));
// Start output to client
$this->_encoder->startWBXML();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_SYNCHRONIZE);
$this->_encoder->startTag(Horde_ActiveSync::SYNC_STATUS);
$this->_encoder->content(self::STATUS_SUCCESS);
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_FOLDERS);
$exporter = new Horde_ActiveSync_Connector_Exporter($this->_activeSync, $this->_encoder);
$cnt_global = 0;
$over_window = false;
foreach ($this->_collections as $id => $collection) {
$statusCode = self::STATUS_SUCCESS;
$changecount = 0;
if ($over_window || $cnt_global > $this->_collections->getDefaultWindowSize()) {
$this->_sendOverWindowResponse($collection);
continue;
}
try {
$this->_collections->initCollectionState($collection);
} catch (Horde_ActiveSync_Exception_StateGone $e) {
$this->_logger->notice(sprintf('[%s] SYNC terminating, state not found', $this->_procid));
$statusCode = self::STATUS_KEYMISM;
} catch (Horde_ActiveSync_Exception_FolderGone $e) {
// This isn't strictly correct, but at least some versions of
// iOS need this in order to catch missing state.
$this->_logger->err($e->getMessage());
$statusCode = self::STATUS_FOLDERSYNC_REQUIRED;
} catch (Horde_ActiveSync_Exception_StaleState $e) {
$this->_logger->notice($e->getMessage());
return false;
} catch (Horde_ActiveSync_Exception $e) {
$this->_logger->err($e->getMessage());
return false;
}
// Outlook explicitly tells the server to NOT check for server
// changes when importing client changes, unlike EVERY OTHER client
// out there. This completely screws up many things like conflict
// detection since we can't update the sync_ts until we actually
// check for changes. So, we need to FORCE a change detection cycle
// to be sure we don't screw up state. Any detected changes will be
// ignored until the next cycle, utilizing the existing mechanism
// for sending MOREITEMS when we will return the previously
// selected changes. getchanges defaults to true if it is missing
// and the synckey != 0, defaults to true if it is present as an
// empty tag. If it is present, but '0' or not present but synckey
// is 0 then it defaults to false.
if (!isset($collection['getchanges']) && $collection['synckey'] != '0') {
$collection['getchanges'] = true;
}
if (!empty($collection['importedchanges']) && empty($collection['getchanges'])) {
$forceChanges = true;
$collection['getchanges'] = true;
$this->_logger->notice(sprintf('[%s] Force a GETCHANGES due to incoming changes.', $this->_procid));
}
if ($statusCode == self::STATUS_SUCCESS && (!empty($collection['getchanges']) || !isset($collection['getchanges']) && $collection['synckey'] != '0')) {
try {
$changecount = $this->_collections->getCollectionChangeCount();
} catch (Horde_ActiveSync_Exception_StaleState $e) {
$this->_logger->err(sprintf('[%s] Force restting of state for %s: %s', $this->_procid, $id, $e->getMessage()));
$this->_state->loadState(array(), null, Horde_ActiveSync::REQUEST_TYPE_SYNC, $id);
$statusCode = self::STATUS_KEYMISM;
} catch (Horde_ActiveSync_Exception_StateGone $e) {
$this->_logger->warn(sprintf('[%s] SYNCKEY not found. Reset required.', $this->_procid));
$statusCode = self::STATUS_KEYMISM;
} catch (Horde_ActiveSync_Exception_FolderGone $e) {
$this->_logger->warn(sprintf('[%s] FOLDERSYNC required, collection gone.', $this->_procid));
$statusCode = self::STATUS_FOLDERSYNC_REQUIRED;
}
}
// Get new synckey if needed. We need a new synckey if there were
// any changes (incoming or outgoing), if this is during the
// initial sync pairing of the collection, or if we received a
// SYNC due to changes found during a PING (since those changes
// may be changes to items that never even made it to the client in
// the first place (See Bug: 12075).
if ($statusCode == self::STATUS_SUCCESS && (!empty($collection['importedchanges']) || !empty($changecount) || $collection['synckey'] == '0' || $this->_state->getSyncKeyCounter($collection['synckey']) == 1 || !empty($collection['fetchids']) || $this->_collections->hasPingChangeFlag($id))) {
try {
$collection['newsynckey'] = $this->_state->getNewSyncKey($collection['synckey']);
$this->_logger->info(sprintf('[%s] Old SYNCKEY: %s, New SYNCKEY: %s', $this->_procid, $collection['synckey'], $collection['newsynckey']));
} catch (Horde_ActiveSync_Exception $e) {
$statusCode = self::STATUS_KEYMISM;
}
}
$this->_encoder->startTag(Horde_ActiveSync::SYNC_FOLDER);
// Not sent in > 12.0
if ($this->_device->version <= Horde_ActiveSync::VERSION_TWELVE) {
$this->_encoder->startTag(Horde_ActiveSync::SYNC_FOLDERTYPE);
$this->_encoder->content($collection['class']);
$this->_encoder->endTag();
}
$this->_encoder->startTag(Horde_ActiveSync::SYNC_SYNCKEY);
if (!empty($collection['newsynckey'])) {
$this->_encoder->content($collection['newsynckey']);
} else {
$this->_encoder->content($collection['synckey']);
}
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_FOLDERID);
$this->_encoder->content($collection['id']);
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_STATUS);
$this->_encoder->content($statusCode);
$this->_encoder->endTag();
if ($statusCode == self::STATUS_SUCCESS) {
// Send server changes to client
if ($statusCode == self::STATUS_SUCCESS && empty($forceChanges) && (!empty($collection['getchanges']) || !isset($collection['getchanges']) && !empty($collection['synckey']))) {
$max_windowsize = !empty($pingSettings['maximumwindowsize']) ? min($collection['windowsize'], $pingSettings['maximumwindowsize']) : $collection['windowsize'];
if (!empty($changecount) && $changecount > $max_windowsize || $cnt_global + $changecount > $this->_collections->getDefaultWindowSize()) {
$this->_logger->info(sprintf('[%s] Sending MOREAVAILABLE. WINDOWSIZE = %d, $changecount = %d, $cnt_global = %d', $this->_procid, $max_windowsize, $changecount, $cnt_global));
$this->_encoder->startTag(Horde_ActiveSync::SYNC_MOREAVAILABLE, false, true);
$over_window = $cnt_global + $changecount > $this->_collections->getDefaultWindowSize();
}
if (!empty($changecount)) {
$exporter->setChanges($this->_collections->getCollectionChanges(false), $collection);
$this->_encoder->startTag(Horde_ActiveSync::SYNC_COMMANDS);
$cnt_collection = 0;
while ($cnt_collection < $max_windowsize && $cnt_global < $this->_collections->getDefaultWindowSize() && ($progress = $exporter->sendNextChange())) {
$this->_logger->info(sprintf('[%s] Peak memory usage after message: %d', $this->_procid, memory_get_peak_usage(true)));
if ($progress === true) {
++$cnt_collection;
++$cnt_global;
}
}
$this->_encoder->endTag();
}
}
if (!empty($collection['clientids']) || !empty($collection['fetchids']) || !empty($collection['missing']) || !empty($collection['importfailures'])) {
$this->_encoder->startTag(Horde_ActiveSync::SYNC_REPLIES);
// Output any SYNC_MODIFY failures
if (!empty($collection['importfailures'])) {
foreach ($collection['importfailures'] as $id => $reason) {
$this->_encoder->startTag(Horde_ActiveSync::SYNC_MODIFY);
$this->_encoder->startTag(Horde_ActiveSync::SYNC_FOLDERTYPE);
$this->_encoder->content($collection['class']);
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_SERVERENTRYID);
$this->_encoder->content($id);
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_STATUS);
$this->_encoder->content($reason);
$this->_encoder->endTag();
$this->_encoder->endTag();
}
}
// Output server IDs for new items we received and added from client
if (!empty($collection['clientids'])) {
foreach ($collection['clientids'] as $clientid => $serverid) {
if ($serverid) {
$status = self::STATUS_SUCCESS;
} else {
$status = self::STATUS_INVALID;
}
$this->_encoder->startTag(Horde_ActiveSync::SYNC_ADD);
// If we have clientids and a CLASS_EMAIL, this is
// a SMS response.
if ($collection['class'] == Horde_ActiveSync::CLASS_EMAIL) {
$this->_encoder->startTag(Horde_ActiveSync::SYNC_FOLDERTYPE);
$this->_encoder->content(Horde_ActiveSync::CLASS_SMS);
$this->_encoder->endTag();
}
$this->_encoder->startTag(Horde_ActiveSync::SYNC_CLIENTENTRYID);
$this->_encoder->content($clientid);
$this->_encoder->endTag();
if ($status == self::STATUS_SUCCESS) {
$this->_encoder->startTag(Horde_ActiveSync::SYNC_SERVERENTRYID);
$this->_encoder->content($serverid);
$this->_encoder->endTag();
}
$this->_encoder->startTag(Horde_ActiveSync::SYNC_STATUS);
$this->_encoder->content($status);
$this->_encoder->endTag();
$this->_encoder->endTag();
}
}
// Output any errors from missing messages in REMOVE requests.
if (!empty($collection['missing'])) {
foreach ($collection['missing'] as $uid) {
$this->_encoder->startTag(Horde_ActiveSync::SYNC_REMOVE);
$this->_encoder->startTag(Horde_ActiveSync::SYNC_CLIENTENTRYID);
$this->_encoder->content($uid);
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_STATUS);
$this->_encoder->content(self::STATUS_NOTFOUND);
$this->_encoder->endTag();
$this->_encoder->endTag();
}
}
if (!empty($collection['fetchids'])) {
// Output any FETCH requests
foreach ($collection['fetchids'] as $fetch_id) {
try {
$data = $this->_driver->fetch($collection['serverid'], $fetch_id, $collection);
$this->_encoder->startTag(Horde_ActiveSync::SYNC_FETCH);
$this->_encoder->startTag(Horde_ActiveSync::SYNC_SERVERENTRYID);
$this->_encoder->content($fetch_id);
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_STATUS);
$this->_encoder->content(self::STATUS_SUCCESS);
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_DATA);
$data->encodeStream($this->_encoder);
$this->_encoder->endTag();
$this->_encoder->endTag();
} catch (Horde_Exception_NotFound $e) {
$this->_logger->err(sprintf('[%s] Unable to fetch %s', $this->_procid, $fetch_id));
$this->_encoder->startTag(Horde_ActiveSync::SYNC_FETCH);
$this->_encoder->startTag(Horde_ActiveSync::SYNC_SERVERENTRYID);
$this->_encoder->content($fetch_id);
$this->_encoder->endTag();
$this->_encoder->startTag(Horde_ActiveSync::SYNC_STATUS);
$this->_encoder->content(self::STATUS_NOTFOUND);
$this->_encoder->endTag();
$this->_encoder->endTag();
}
}
}
$this->_encoder->endTag();
}
// Save the sync state for the next time
if (!empty($collection['newsynckey'])) {
if (!empty($sync) || !empty($importer) || $collection['synckey'] == 0) {
$this->_state->setNewSyncKey($collection['newsynckey']);
$this->_state->save();
} else {
$this->_logger->err(sprintf('[%s] Error saving %s - no state information available.', $this->_procid, $collection['newsynckey']));
}
// Do we need to add the new synckey to the syncCache?
if ($collection['newsynckey'] != $collection['synckey']) {
$this->_collections->addConfirmedKey($collection['newsynckey']);
}
$this->_collections->updateCollection($collection, array('newsynckey' => true, 'unsetChanges' => true, 'unsetPingChangeFlag' => true));
}
}
$this->_encoder->endTag();
$this->_logger->info(sprintf('[%s] Collection output peak memory usage: %d', $this->_procid, memory_get_peak_usage(true)));
}
$this->_encoder->endTag();
$this->_encoder->endTag();
if ($this->_device->version >= Horde_ActiveSync::VERSION_TWELVEONE) {
if ($this->_collections->checkStaleRequest()) {
$this->_logger->info(sprintf('[%s] Changes detected in sync_cache during wait interval, exiting without updating cache.', $this->_procid));
return true;
} else {
$this->_collections->lastsyncendnormal = time();
$this->_collections->save(true);
}
} else {
$this->_collections->save(true);
}
return true;
}