Commit 2c0bf844 authored by Sebastian Kummer's avatar Sebastian Kummer

ZP-1077 Added ProcessLoopDetection to catch a Ping/Sync loop where sync

has errors but Ping continues to trigger syncs for it; added
ProcessLoopDetection for the case where Ping sees state errors for a
synched folder, triggers a sync but the folder is not being
synchronized.
In both cases Ping will invoke a FolderSync (status 7) instead of
sending fake changes. FolderSync will check the relation between the
hierarchy cache and synched data information and remove states of
folders that are not in the hierarchycache anymore.

Released under the Affero GNU General Public License (AGPL) version 3.
parent 016e688b
...@@ -729,6 +729,11 @@ class DeviceManager { ...@@ -729,6 +729,11 @@ class DeviceManager {
public function IsHierarchySyncRequired() { public function IsHierarchySyncRequired() {
$this->loadDeviceData(); $this->loadDeviceData();
if ($this->loopdetection->ProcessLoopDetectionIsHierarchySyncAdvised()) {
ZLog::Write(LOGLEVEL_ERROR, "DeviceManager->IsHierarchySyncRequired(): jAAAAAAAAAAAAAAAAAAAAAA________A!!!!!!!!!!!!!!!!!");
return true;
}
// if the hash of the additional folders changed, we have to sync the hierarchy // if the hash of the additional folders changed, we have to sync the hierarchy
if ($this->additionalFoldersHash != $this->getAdditionalFoldersHash()) { if ($this->additionalFoldersHash != $this->getAdditionalFoldersHash()) {
$this->hierarchySyncRequired = true; $this->hierarchySyncRequired = true;
...@@ -841,6 +846,32 @@ class DeviceManager { ...@@ -841,6 +846,32 @@ class DeviceManager {
return $this->loopdetection->SetSyncStateUsage($folderid, $uuid, $counter); return $this->loopdetection->SetSyncStateUsage($folderid, $uuid, $counter);
} }
/**
* Checks the data integrity of the data in the hierarchy cache and the data of the content data (synchronized folders).
* If a folder is deleted, the sync states could still be on the server (and being loaded by PING) while
* the folder is not being synchronized anymore. See also https://jira.z-hub.io/browse/ZP-1077
*
* @access public
* @return boolean
*/
public function CheckFolderData() {
ZLog::Write(LOGLEVEL_DEBUG, "DeviceManager->CheckFolderData() checking integrity of hierarchy cache with synchronized folders");
$hc = $this->device->GetHierarchyCache();
$notInCache = array();
foreach ($this->device->GetAllFolderIds() as $folderid) {
$uuid = $this->device->GetFolderUUID($folderid);
if ($uuid) {
// has a UUID but is not in the cache?! This is deleted, remove the states.
if (! $hc->GetFolder($folderid)) {
ZLog::Write(LOGLEVEL_WARN, sprintf("DeviceManager->CheckFolderData(): Folder '%s' has sync states but is not in the hierarchy cache. Removing states.", $folderid));
StateManager::UnLinkState($this->device, $folderid);
}
}
}
return true;
}
/** /**
* Sets the current status of the folder * Sets the current status of the folder
* *
......
...@@ -162,6 +162,7 @@ class LoopDetection extends InterProcessData { ...@@ -162,6 +162,7 @@ class LoopDetection extends InterProcessData {
* @return boolean * @return boolean
*/ */
public function ProcessLoopDetectionAddStatus($folderid, $status) { public function ProcessLoopDetectionAddStatus($folderid, $status) {
ZLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->ProcessLoopDetectionAddStatus: '%s' with status %d", $folderid?$folderid:'hierarchy', $status));
// generate entry if not already there // generate entry if not already there
self::GetProcessEntry(); self::GetProcessEntry();
...@@ -192,6 +193,73 @@ class LoopDetection extends InterProcessData { ...@@ -192,6 +193,73 @@ class LoopDetection extends InterProcessData {
return $this->updateProcessStack(); return $this->updateProcessStack();
} }
/**
* Indicates if a simple Hierarchy sync should be done after Ping.
*
* When trying to sync a non existing folder, Sync will return Status 12.
* This should trigger a hierarchy sync by the client, but this is not always done.
* Clients continue trying to Ping, which fails as well and triggers a Sync again.
* This goes on forever, like here: https://jira.z-hub.io/browse/ZP-1077
*
* Ping could indicate to perform a FolderSync as well after a few Sync/Ping cycles.
*
* @access public
* @return boolean
*
*/
public function ProcessLoopDetectionIsHierarchySyncAdvised() {
$me = self::GetProcessEntry();
if ($me['cc'] !== ZPush::COMMAND_PING) {
return false;
}
$loopingFolders = array();
$lookback = self::$start - 600; // look at the last 5 min
foreach ($this->getProcessStack() as $se) {
if ($se['time'] > $lookback && $se['time'] < (self::$start-1)) {
// look for sync command
if (isset($se['stat']) && ($se['cc'] == ZPush::COMMAND_SYNC || $se['cc'] == ZPush::COMMAND_PING)) {
foreach($se['stat'] as $key => $value) {
// we only care about hierarchy errors of this folder
if ($se['cc'] == ZPush::COMMAND_SYNC) {
if ($value == SYNC_STATUS_FOLDERHIERARCHYCHANGED) {
ZLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->ProcessLoopDetectionIsHierarchySyncAdvised(): seen Sync command with Exception or folderid '%s' and code '%s'", $key, $value ));
}
}
if (!isset($loopingFolders[$key])) {
$loopingFolders[$key] = array(ZPush::COMMAND_SYNC => array(), ZPush::COMMAND_PING => array());
}
if (!isset($loopingFolders[$key][$se['cc']][$value])) {
$loopingFolders[$key][$se['cc']][$value] = 0;
}
$loopingFolders[$key][$se['cc']][$value]++;
}
}
}
}
$filtered = array();
foreach ($loopingFolders as $fid => $data) {
// Ping is constantly generating changes for this folder
if (isset($data[ZPush::COMMAND_PING][SYNC_PINGSTATUS_CHANGES]) && $data[ZPush::COMMAND_PING][SYNC_PINGSTATUS_CHANGES] >= 3) {
// but the Sync request is not treating it (not being requested)
if (count($data[ZPush::COMMAND_SYNC]) == 0) {
ZLog::Write(LOGLEVEL_INFO, sprintf("LoopDetection->ProcessLoopDetectionIsHierarchySyncAdvised(): Ping loop of folderid '%s' detected that is not being synchronized.", $fid));
return true;
}
// Sync is executed, but a foldersync should be executed (hierarchy errors)
if (isset($data[ZPush::COMMAND_SYNC][SYNC_STATUS_FOLDERHIERARCHYCHANGED]) &&
$data[ZPush::COMMAND_SYNC][SYNC_STATUS_FOLDERHIERARCHYCHANGED] > 3 ) {
ZLog::Write(LOGLEVEL_INFO, sprintf("LoopDetection->ProcessLoopDetectionIsHierarchySyncAdvised(): Sync(with error)/Ping loop of folderid '%s' detected.", $fid));
return true;
}
}
}
return false;
}
/** /**
* Indicates if a full Hierarchy Resync is necessary * Indicates if a full Hierarchy Resync is necessary
* *
...@@ -220,6 +288,11 @@ class LoopDetection extends InterProcessData { ...@@ -220,6 +288,11 @@ class LoopDetection extends InterProcessData {
// look for sync command // look for sync command
if (isset($se['stat']) && ($se['cc'] == ZPush::COMMAND_SYNC || $se['cc'] == ZPush::COMMAND_PING)) { if (isset($se['stat']) && ($se['cc'] == ZPush::COMMAND_SYNC || $se['cc'] == ZPush::COMMAND_PING)) {
foreach($se['stat'] as $key => $value) { foreach($se['stat'] as $key => $value) {
// don't count PING with changes on a folder or sync with success
if (($se['cc'] == ZPush::COMMAND_PING && $value == SYNC_PINGSTATUS_CHANGES) ||
($se['cc'] == ZPush::COMMAND_SYNC && $value == SYNC_STATUS_SUCCESS) ) {
continue;
}
if (!isset($seenFailed[$key])) if (!isset($seenFailed[$key]))
$seenFailed[$key] = 0; $seenFailed[$key] = 0;
$seenFailed[$key]++; $seenFailed[$key]++;
......
...@@ -256,6 +256,9 @@ class FolderSync extends RequestProcessor { ...@@ -256,6 +256,9 @@ class FolderSync extends RequestProcessor {
self::$encoder->endTag(); self::$encoder->endTag();
self::$topCollector->AnnounceInformation(sprintf("Outgoing %d folders",$changeCount), true); self::$topCollector->AnnounceInformation(sprintf("Outgoing %d folders",$changeCount), true);
if ($changeCount == 0) {
self::$deviceManager->CheckFolderData();
}
// everything fine, save the sync state for the next time // everything fine, save the sync state for the next time
if ($synckey == $newsynckey) { if ($synckey == $newsynckey) {
self::$deviceManager->GetStateManager()->SetSyncState($newsynckey, $newsyncstate); self::$deviceManager->GetStateManager()->SetSyncState($newsynckey, $newsyncstate);
......
...@@ -73,6 +73,11 @@ class Ping extends RequestProcessor { ...@@ -73,6 +73,11 @@ class Ping extends RequestProcessor {
$pingstatus = SYNC_PINGSTATUS_FAILINGPARAMS; $pingstatus = SYNC_PINGSTATUS_FAILINGPARAMS;
self::$topCollector->AnnounceInformation("StateInvalidException: require PingParameters", true); self::$topCollector->AnnounceInformation("StateInvalidException: require PingParameters", true);
} }
elseif (self::$deviceManager->IsHierarchySyncRequired()) {
// we could be in a looping - see LoopDetection->ProcessLoopDetectionIsHierarchySyncAdvised()
$pingstatus = SYNC_PINGSTATUS_FOLDERHIERSYNCREQUIRED;
self::$topCollector->AnnounceInformation("Potential loop detection: require HierarchySync", true);
}
else { else {
// we do not have a ping status for this, but SyncCollections should have generated fake changes for the folders which are broken // we do not have a ping status for this, but SyncCollections should have generated fake changes for the folders which are broken
$fakechanges = $sc->GetChangedFolderIds(); $fakechanges = $sc->GetChangedFolderIds();
...@@ -231,6 +236,7 @@ class Ping extends RequestProcessor { ...@@ -231,6 +236,7 @@ class Ping extends RequestProcessor {
self::$encoder->endTag(); self::$encoder->endTag();
if (empty($fakechanges)) if (empty($fakechanges))
self::$topCollector->AnnounceInformation(sprintf("Found change in %s", $sc->GetCollection($folderid)->GetContentClass()), true); self::$topCollector->AnnounceInformation(sprintf("Found change in %s", $sc->GetCollection($folderid)->GetContentClass()), true);
self::$deviceManager->AnnounceProcessStatus($folderid, SYNC_PINGSTATUS_CHANGES);
} }
} }
self::$encoder->endTag(); self::$encoder->endTag();
......
...@@ -747,6 +747,7 @@ class Sync extends RequestProcessor { ...@@ -747,6 +747,7 @@ class Sync extends RequestProcessor {
// global status // global status
// SYNC_COMMONSTATUS_* start with values from 101 // SYNC_COMMONSTATUS_* start with values from 101
if ($status != SYNC_COMMONSTATUS_SUCCESS && ($status == SYNC_STATUS_FOLDERHIERARCHYCHANGED || $status > 100)) { if ($status != SYNC_COMMONSTATUS_SUCCESS && ($status == SYNC_STATUS_FOLDERHIERARCHYCHANGED || $status > 100)) {
self::$deviceManager->AnnounceProcessStatus($folderid, $status);
$this->sendStartTags(); $this->sendStartTags();
self::$encoder->startTag(SYNC_STATUS); self::$encoder->startTag(SYNC_STATUS);
self::$encoder->content($status); self::$encoder->content($status);
...@@ -854,6 +855,7 @@ class Sync extends RequestProcessor { ...@@ -854,6 +855,7 @@ class Sync extends RequestProcessor {
self::$topCollector->AnnounceInformation(sprintf("StatusException code: %d", $status), $this->singleFolder); self::$topCollector->AnnounceInformation(sprintf("StatusException code: %d", $status), $this->singleFolder);
$this->saveMultiFolderInfo("exception", "StatusException"); $this->saveMultiFolderInfo("exception", "StatusException");
} }
self::$deviceManager->AnnounceProcessStatus($spa->GetFolderId(), $status);
} }
} }
} }
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment