Merge pull request #148 in ZP/z-push from feature/ZP-832-detect-folder-changes-faster to develop

* commit 'bc067ce2':
  ZP-832 Run SyncCollections->CheckForChanges() stat comparing only on first run, improved comment.
  ZP-832 Add check if stats table can be loaded for shared users - log to INFO if that does not work, sync folders where no stat can be found only once a hour, include PR_CONTENT_COUNT, PR_CONTENT_UNREAD and PR_DELETED_MSG_COUNT into stat to reflect all kind of changes, SyncCollection->CheckForChanges() compares folderstats for changes when initiating, in case of error remove the folderstat to ensure folder is synchronized next Sync request, remove 'savestate' functionality as it is not used.
  ZP-832 Request folder statistics from the backend and setup the exporter only if the stat indicate that the folder contains changes. Per default the statistics are disabled (backend has to enable them). If disabled, an exporter will be setup for each folder.
  ZP-832 Log GlobalWindow size override only once.

src/backend/zarafa/mapi/mapitags.php

@@ -1252,3 +1252,6 @@ define('PR_ZC_CONTACT_FOLDER_NAMES'                   ,mapi_prop_tag(PT_MV_TSTRI
 
 //Properties defined for Z-Push
 define('PR_TODO_ITEM_FLAGS'                           ,mapi_prop_tag(PT_LONG,        0x0E2B));
+define('PR_LOCAL_COMMIT_TIME_MAX'                     ,mapi_prop_tag(PT_SYSTIME,     0x670A));
+define('PR_DELETED_MSG_COUNT'                         ,mapi_prop_tag(PT_LONG,        0x6640));
+

src/backend/zarafa/zarafa.php

@@ -89,6 +89,7 @@ class BackendZarafa implements IBackend, ISearchProvider {
     private $changesSinkStores;
     private $wastebasket;
     private $addressbook;
+    private $folderStatCache;
 
     // ZCP config parameter for PR_EC_ENABLED_FEATURES / PR_EC_DISABLED_FEATURES
     const ZPUSH_ENABLED = 'mobile';
@@ -115,6 +116,7 @@ class BackendZarafa implements IBackend, ISearchProvider {
         $this->changesSinkStores = array();
         $this->wastebasket = false;
         $this->session = false;
+        $this->folderStatCache = array();
 
         ZLog::Write(LOGLEVEL_DEBUG, sprintf("BackendZarafa using PHP-MAPI version: %s", phpversion("mapi")));
     }
@@ -1291,6 +1293,80 @@ class BackendZarafa implements IBackend, ISearchProvider {
         return $this->storeName;
     }
 
+    /**
+     * Indicates if the Backend supports folder statistics.
+     *
+     * @access public
+     * @return boolean
+     */
+    public function HasFolderStats() {
+        return true;
+    }
+
+    /**
+     * Returns a status indication of the folder.
+     * If there are changes in the folder, the returned value must change.
+     * The returned values are compared with '===' to determine if a folder needs synchronization or not.
+     *
+     * @param string $store         the store where the folder resides
+     * @param string $folderid      the folder id
+     *
+     * @access public
+     * @return string
+     */
+    public function GetFolderStat($store, $folderid) {
+        list($user, $domain) = Utils::SplitDomainUser($store);
+        if ($user === false) {
+            $user = $this->mainUser;
+        }
+
+        if (!isset($this->folderStatCache[$user])) {
+            $this->folderStatCache[$user] = array();
+        }
+
+        // TODO remove nameCache
+        if (!isset($this->nameCache))
+            $this->nameCache = array();
+
+        // if there is nothing in the cache for a store, load the data for all folders of it
+        if (empty($this->folderStatCache[$user])) {
+            // get the store
+            $userstore = $this->openMessageStore($user);
+            $rootfolder = mapi_msgstore_openentry($userstore);
+            $hierarchy =  mapi_folder_gethierarchytable($rootfolder, CONVENIENT_DEPTH);
+            $rows = mapi_table_queryallrows($hierarchy, array(PR_SOURCE_KEY, PR_LOCAL_COMMIT_TIME_MAX, PR_CONTENT_COUNT, PR_CONTENT_UNREAD, PR_DELETED_MSG_COUNT, PR_DISPLAY_NAME));
+
+            if (count($rows) == 0) {
+                ZLog::Write(LOGLEVEL_INFO, sprintf("ZarafaBackend->GetFolderStat(): could not access folder statistics for user '%s'. Probably missing 'read' permissions on the root folder! Folders of this store will be synchronized ONCE per hour only!", $user));
+            }
+
+            foreach($rows as $folder) {
+                $commit_time = isset($folder[PR_LOCAL_COMMIT_TIME_MAX])? $folder[PR_LOCAL_COMMIT_TIME_MAX] : "0000000000";
+                $content_count = isset($folder[PR_CONTENT_COUNT])? $folder[PR_CONTENT_COUNT] : -1;
+                $content_unread = isset($folder[PR_CONTENT_UNREAD])? $folder[PR_CONTENT_UNREAD] : -1;
+                $content_deleted = isset($folder[PR_DELETED_MSG_COUNT])? $folder[PR_DELETED_MSG_COUNT] : -1;
+
+                $this->folderStatCache[$user][bin2hex($folder[PR_SOURCE_KEY])] = $commit_time ."/". $content_count ."/". $content_unread ."/". $content_deleted;
+                $this->nameCache[bin2hex($folder[PR_SOURCE_KEY])] = $folder[PR_DISPLAY_NAME];
+            }
+            ZLog::Write(LOGLEVEL_DEBUG, sprintf("ZarafaBackend->GetFolderStat() fetched status information of %d folders for store '%s'", count($this->folderStatCache[$user]), $user));
+            // TODO remove logging
+            foreach($this->folderStatCache[$user] as $fid => $stat) {
+                ZLog::Write(LOGLEVEL_INFO, sprintf("FolderStat: %s %s %s\t%s", $user, $fid, $stat, $this->nameCache[$fid]));
+            }
+        }
+
+        if (isset($this->folderStatCache[$user][$folderid])) {
+            // TODO remove nameCache output
+            ZLog::Write(LOGLEVEL_DEBUG, sprintf("ZarafaBackend->GetFolderStat() found stat for '%s': %s", $this->nameCache[$folderid], $this->folderStatCache[$user][$folderid]));
+            return $this->folderStatCache[$user][$folderid];
+        }
+        else {
+            // a timestamp that changes once per hour is returned in case there is no data found for this folder. It will be synchronized only once per hour.
+            return gmdate("Y-m-d-H");
+        }
+    }
+
     /**----------------------------------------------------------------------------------------------------------
      * Private methods
      */

src/lib/core/synccollections.php

@@ -70,6 +70,7 @@ class SyncCollections implements Iterator {
     private $lastSyncTime;
 
     private $waitingTime = 0;
+    private $loggedGlobalWindowSizeOverwrite = false;
 
 
     /**
@@ -368,7 +369,10 @@ class SyncCollections implements Iterator {
         }
 
         if (defined("SYNC_MAX_ITEMS") && SYNC_MAX_ITEMS < $globalWindowSize) {
+            if (!$this->loggedGlobalWindowSizeOverwrite) {
                 ZLog::Write(LOGLEVEL_DEBUG, sprintf("SyncCollections->GetGlobalWindowSize() overwriting requested global window size of %d by %d forced in configuration.", $globalWindowSize, SYNC_MAX_ITEMS));
+                $this->loggedGlobalWindowSizeOverwrite = true;
+            }
             $globalWindowSize = SYNC_MAX_ITEMS;
         }
 
@@ -454,29 +458,41 @@ class SyncCollections implements Iterator {
 
         $pingTracking = new PingTracking();
         $this->changes = array();
-        $changesAvailable = false;
 
         ZPush::GetDeviceManager()->AnnounceProcessAsPush();
         ZPush::GetTopCollector()->AnnounceInformation(sprintf("lifetime %ds", $lifetime), true);
         ZLog::Write(LOGLEVEL_INFO, sprintf("SyncCollections->CheckForChanges(): Waiting for %s changes... (lifetime %d seconds)", (empty($classes))?'policy':'store', $lifetime));
 
         // use changes sink where available
-        $changesSink = false;
-
-        // do not create changessink if there are no folders
-        if (!empty($classes) && ZPush::GetBackend()->HasChangesSink()) {
-            $changesSink = true;
+        $changesSink = ZPush::GetBackend()->HasChangesSink();
 
+        // create changessink and check folder stats if there are folders to Ping
+        if (!empty($classes)) {
             // initialize all possible folders
             foreach ($this->collections as $folderid => $spa) {
                 if ($onlyPingable && $spa->GetPingableFlag() !== true)
                     continue;
 
-                // switch user store if this is a additional folder and initialize sink
-                ZPush::GetBackend()->Setup(ZPush::GetAdditionalSyncFolderStore($folderid));
+                // get the user store if this is a additional folder
+                $store = ZPush::GetAdditionalSyncFolderStore($folderid);
+
+                // initialize sink if no immediate changes were found so far
+                if ($changesSink && empty($this->changes)) {
+                    ZPush::GetBackend()->Setup($store);
                     if (! ZPush::GetBackend()->ChangesSinkInitialize($folderid))
                         throw new StatusException(sprintf("Error initializing ChangesSink for folder id '%s'", $folderid), self::ERROR_WRONG_HIERARCHY);
                 }
+
+                // check if the folder stat changed since the last sync, if so generate a change for it (only on first run)
+                if ($this->waitingTime == 0 && ZPush::GetBackend()->HasFolderStats() && $spa->HasFolderStat() && ZPush::GetBackend()->GetFolderStat($store, $spa->GetFolderId()) !== $spa->GetFolderStat()) {
+                    $this->changes[$spa->GetFolderId()] = 1;
+                }
+            }
+        }
+
+        if (!empty($this->changes)) {
+            ZLog::Write(LOGLEVEL_DEBUG, "SyncCollections->CheckForChanges(): Using ChangesSink but found changes verifying the folder stats");
+            return true;
         }
 
         // wait for changes
@@ -622,28 +638,23 @@ class SyncCollections implements Iterator {
             if ($ste->getCode() == SYNC_STATUS_FOLDERHIERARCHYCHANGED) {
                 ZLog::Write(LOGLEVEL_WARN, "SyncCollections->CountChange(): exporter can not be re-configured due to state error, emulating change in folder to force Sync.");
                 $this->changes[$folderid] = 1;
+                // make sure this folder is fully synched on next Sync request
+                if($spa->HasFolderStat()) {
+                    ZLog::Write(LOGLEVEL_DEBUG, sprintf("SyncCollections->CountChange(): removing folder stat '%s' for folderid '%s'", $spa->GetFolderStat(), $spa->GetFolderId()));
+                    $spa->DelFolderStat();
+                    $this->SaveCollection($spa);
+                }
                 return true;
             }
             throw new StatusException("SyncCollections->CountChange(): exporter can not be re-configured.", self::ERROR_WRONG_HIERARCHY, null, LOGLEVEL_WARN);
         }
 
         // start over if exporter can not be configured atm
-        if ($changecount === false )
+        if ($changecount === false)
             ZLog::Write(LOGLEVEL_WARN, "SyncCollections->CountChange(): no changes received from Exporter.");
 
         $this->changes[$folderid] = $changecount;
 
-        if(isset($this->addparms[$folderid]['savestate'])) {
-            try {
-                // Discard any data
-                while(is_array($exporter->Synchronize()));
-                $this->addparms[$folderid]['savestate'] = $exporter->GetState();
-            }
-            catch (StatusException $ste) {
-                throw new StatusException("SyncCollections->CountChange(): could not get new state from exporter", self::ERROR_WRONG_HIERARCHY, null, LOGLEVEL_WARN);
-            }
-        }
-
         return ($changecount > 0);
      }
 

src/lib/core/syncparameters.php

@@ -71,6 +71,7 @@ class SyncParameters extends StateObject {
                                     'contentparameters' => array(),
                                     'foldersynctotal' => false,
                                     'foldersyncremaining' => false,
+                                    'folderstat' => false,
                                 );
 
     /**

src/lib/default/backend.php

@@ -238,6 +238,34 @@ abstract class Backend implements IBackend {
         return $this->GetUserDetails(Request::GetAuthUser());
     }
 
+    /**
+     * Indicates if the Backend supports folder statistics.
+     *
+     * @access public
+     * @return boolean
+     */
+    public function HasFolderStats() {
+        return false;
+    }
+
+    /**
+     * Returns a status indication of the folder.
+     * If there are changes in the folder, the returned value must change.
+     * The returned values are compared with '===' to determine if a folder needs synchronization or not.
+     *
+     * @param string $store         the store where the folder resides
+     * @param string $folderid      the folder id
+     *
+     * @access public
+     * @return string
+     */
+    public function GetFolderStat($store, $folderid) {
+        // As this is not implemented, the value returned will change every hour.
+        // This will only be called if HasFolderStats() returns true.
+        return "not implemented-".gmdate("Y-m-d-H");
+    }
+
+
     /**----------------------------------------------------------------------------------------------------------
      * Protected methods for BackendStorage
      *

src/lib/interface/ibackend.php

@@ -307,4 +307,25 @@ interface IBackend {
      * @return Array
      */
     public function GetCurrentUsername();
+
+    /**
+     * Indicates if the Backend supports folder statistics.
+     *
+     * @access public
+     * @return boolean
+     */
+    public function HasFolderStats();
+
+    /**
+     * Returns a status indication of the folder.
+     * If there are changes in the folder, the returned value must change.
+     * The returned values are compared with '===' to determine if a folder needs synchronization or not.
+     *
+     * @param string $store         the store where the folder resides
+     * @param string $folderid      the folder id
+     *
+     * @access public
+     * @return string
+     */
+    public function GetFolderStat($store, $folderid);
 }

src/lib/request/sync.php

@@ -695,10 +695,31 @@ class Sync extends RequestProcessor {
             $changecount = false;
             $exporter = false;
             $streamimporter = false;
+            $newFolderStat = false;
+            $setupExporter = true;
 
             // TODO we could check against $sc->GetChangedFolderIds() on heartbeat so we do not need to configure all exporter again
             if($status == SYNC_STATUS_SUCCESS && ($sc->GetParameter($spa, "getchanges") || ! $spa->HasSyncKey())) {
 
+                // compare the folder statistics if the backend supports this
+                if (self::$backend->HasFolderStats()) {
+                    // check if the folder stats changed -> if not, don't setup the exporter, there are no changes!
+                    $newFolderStat = self::$backend->GetFolderStat(ZPush::GetAdditionalSyncFolderStore($spa->GetFolderId()), $spa->GetFolderId());
+                    if ($newFolderStat === $spa->GetFolderStat()) {
+                        $changecount = 0;
+                        $setupExporter = false;
+                        ZLog::Write(LOGLEVEL_DEBUG, "Sync(): Folder stat from the backend indicates that the folder did not change. Exporter will not run.");
+                    }
+                }
+
+                // no need to run the exporter if the globalwindowsize is already full
+                if ($sc->GetGlobalWindowSize() - $this->globallyExportedItems == 0) {
+                    ZLog::Write(LOGLEVEL_DEBUG, "Sync(): no exporter setup as GlobalWindowSize is full.");
+                    $setupExporter = false;
+                }
+
+                // Do a full Exporter setup if we can't avoid it
+                if ($setupExporter) {
                     //make sure the states are loaded
                     $status = $this->loadStates($sc, $spa, $actiondata);
 
@@ -745,9 +766,10 @@ class Sync extends RequestProcessor {
                                 self::$deviceManager->SetFolderSyncStatus($folderid, DeviceManager::FLD_SYNC_INITIALIZED);
                             }
                         }
-                    else if ($status != SYNC_STATUS_SUCCESS)
+                        else if ($status != SYNC_STATUS_SUCCESS) {
                             self::$topCollector->AnnounceInformation(sprintf("StatusException code: %d", $status), true);
-
+                        }
+                    }
                 }
             }
 
@@ -773,13 +795,13 @@ class Sync extends RequestProcessor {
             }
 
             // Fir AS 14.0+ omit output for folder, if there were no incoming or outgoing changes and no Fetch
-            if (Request::GetProtocolVersion() >= 14.0 && ! $spa->HasNewSyncKey() && $changecount == 0 && empty($actiondata["fetchids"]) && $status == SYNC_STATUS_SUCCESS) {
+            if (Request::GetProtocolVersion() >= 14.0 && ! $spa->HasNewSyncKey() && $changecount == 0 && empty($actiondata["fetchids"]) && $status == SYNC_STATUS_SUCCESS && $spa->GetFolderStat() === $newFolderStat) {
                 ZLog::Write(LOGLEVEL_DEBUG, sprintf("HandleSync: No changes found for %s folder id '%s'. Omitting output.", $spa->GetContentClass(), $spa->GetFolderId()));
                 continue;
             }
 
             // there is something to send here, sync folder to output
-            $this->syncFolder($sc, $spa, $exporter, $changecount, $streamimporter, $status);
+            $this->syncFolder($sc, $spa, $exporter, $changecount, $streamimporter, $status, $newFolderStat);
 
             // reset status for the next folder
             $status = SYNC_STATUS_SUCCESS;
@@ -833,10 +855,12 @@ class Sync extends RequestProcessor {
      * @param int                   $changecount          Amount of changes expected
      * @param ImportChangesStream   $streamimporter       Output stream
      * @param int                   $status               current status of the folder processing
+     * @param string                $newFolderStat        the new folder stat to be set if everything was exported
+     *
      * @throws StatusException
      * @return int  sync status code
      */
-    private function syncFolder($sc, $spa, $exporter, $changecount, $streamimporter, $status) {
+    private function syncFolder($sc, $spa, $exporter, $changecount, $streamimporter, $status, $newFolderStat) {
         $actiondata = $sc->GetParameter($spa, "actiondata");
 
         // send the WBXML start tags (if not happened already)
@@ -983,6 +1007,7 @@ class Sync extends RequestProcessor {
             // send <MoreAvailable/> if there are more changes than fit in the folder windowsize
             if($changecount > $windowSize) {
                 self::$encoder->startTag(SYNC_MOREAVAILABLE, false, true);
+                $spa->DelFolderStat();
             }
         }
 
@@ -1048,8 +1073,10 @@ class Sync extends RequestProcessor {
                 $spa->SetFolderSyncRemaining($changecount);
             }
             // changecount is initialized with 'false', so 0 means no changes!
-            if ($changecount === 0 || ($changecount !== false && $changecount <= $windowSize))
+            if ($changecount === 0 || ($changecount !== false && $changecount <= $windowSize)) {
                 self::$deviceManager->SetFolderSyncStatus($spa->GetFolderId(), DeviceManager::FLD_SYNC_COMPLETED);
+                $spa->SetFolderStat($newFolderStat);
+            }
             else
                 self::$deviceManager->SetFolderSyncStatus($spa->GetFolderId(), DeviceManager::FLD_SYNC_INPROGRESS);
         }