grommunio /
grommunio-sync
| Total Complexity | 190 |
| Total Lines | 949 |
| Duplicated Lines | 0 % |
| Changes | 1 | ||
| Bugs | 0 | Features | 0 |
Complex classes like LoopDetection often do a lot of different things. To break such a class down, we need to identify a cohesive component within that class. A common approach to find such a component is to look for fields/methods that share the same prefixes, or suffixes.
Once you have determined the fields that belong together, you can apply the Extract Class refactoring. If the component makes sense as a sub-class, Extract Subclass is also a candidate, and is often faster.
While breaking up the class, it is a good idea to analyze how other classes use LoopDetection, and based on these observations, apply Extract Interface, too.
| 1 | <?php |
||
| 15 | class LoopDetection extends InterProcessData { |
||
| 16 | public const INTERPROCESSLD = "processstack"; |
||
| 17 | public const BROKENMSGS = "brokenmsgs"; |
||
| 18 | private static $processident; |
||
| 19 | private static $processentry; |
||
| 20 | private $ignore_messageid; |
||
| 21 | private $broken_message_uuid; |
||
| 22 | private $broken_message_counter; |
||
| 23 | |||
| 24 | /** |
||
| 25 | * Constructor. |
||
| 26 | */ |
||
| 27 | public function __construct() { |
||
| 28 | // initialize super parameters |
||
| 29 | $this->allocate = 1024000; // 1 MB |
||
| 30 | $this->type = "grommunio-sync:loopdetection"; |
||
| 31 | parent::__construct(); |
||
| 32 | |||
| 33 | $this->ignore_messageid = false; |
||
| 34 | } |
||
| 35 | |||
| 36 | /** |
||
| 37 | * PROCESS LOOP DETECTION. |
||
| 38 | */ |
||
| 39 | |||
| 40 | /** |
||
| 41 | * Adds the process entry to the process stack. |
||
| 42 | * |
||
| 43 | * @return bool |
||
| 44 | */ |
||
| 45 | public function ProcessLoopDetectionInit() { |
||
| 46 | return $this->updateProcessStack(); |
||
| 47 | } |
||
| 48 | |||
| 49 | /** |
||
| 50 | * Marks the process entry as termineted successfully on the process stack. |
||
| 51 | * |
||
| 52 | * @return bool |
||
| 53 | */ |
||
| 54 | public function ProcessLoopDetectionTerminate() { |
||
| 55 | // just to be sure that the entry is there |
||
| 56 | self::GetProcessEntry(); |
||
| 57 | |||
| 58 | self::$processentry['end'] = time(); |
||
| 59 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->ProcessLoopDetectionTerminate()"); |
||
| 60 | |||
| 61 | return $this->updateProcessStack(); |
||
| 62 | } |
||
| 63 | |||
| 64 | /** |
||
| 65 | * Returns a unique identifier for the internal process tracking. |
||
| 66 | * |
||
| 67 | * @return string |
||
| 68 | */ |
||
| 69 | public static function GetProcessIdentifier() { |
||
| 70 | if (!isset(self::$processident)) { |
||
| 71 | self::$processident = sprintf('%04x%04x', mt_rand(0, 0xFFFF), mt_rand(0, 0xFFFF)); |
||
| 72 | } |
||
| 73 | |||
| 74 | return self::$processident; |
||
| 75 | } |
||
| 76 | |||
| 77 | /** |
||
| 78 | * Returns a unique entry with information about the current process. |
||
| 79 | * |
||
| 80 | * @return array |
||
| 81 | */ |
||
| 82 | public static function GetProcessEntry() { |
||
| 83 | if (!isset(self::$processentry)) { |
||
| 84 | self::$processentry = []; |
||
| 85 | self::$processentry['id'] = self::GetProcessIdentifier(); |
||
| 86 | self::$processentry['pid'] = self::$pid; |
||
| 87 | self::$processentry['time'] = self::$start; |
||
| 88 | self::$processentry['cc'] = Request::GetCommandCode(); |
||
| 89 | } |
||
| 90 | |||
| 91 | return self::$processentry; |
||
| 92 | } |
||
| 93 | |||
| 94 | /** |
||
| 95 | * Adds an Exceptions to the process tracking. |
||
| 96 | * |
||
| 97 | * @param Exception $exception |
||
| 98 | * |
||
| 99 | * @return bool |
||
| 100 | */ |
||
| 101 | public function ProcessLoopDetectionAddException($exception) { |
||
| 102 | // generate entry if not already there |
||
| 103 | self::GetProcessEntry(); |
||
| 104 | |||
| 105 | if (!isset(self::$processentry['stat'])) { |
||
| 106 | self::$processentry['stat'] = []; |
||
| 107 | } |
||
| 108 | |||
| 109 | self::$processentry['stat'][$exception::class] = $exception->getCode(); |
||
| 110 | |||
| 111 | $this->updateProcessStack(); |
||
| 112 | |||
| 113 | return true; |
||
| 114 | } |
||
| 115 | |||
| 116 | /** |
||
| 117 | * Adds a folderid and connected status code to the process tracking. |
||
| 118 | * |
||
| 119 | * @param string $folderid |
||
| 120 | * @param int $status |
||
| 121 | * |
||
| 122 | * @return bool |
||
| 123 | */ |
||
| 124 | public function ProcessLoopDetectionAddStatus($folderid, $status) { |
||
| 125 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->ProcessLoopDetectionAddStatus: '%s' with status %d", $folderid ?: 'hierarchy', $status)); |
||
| 126 | // generate entry if not already there |
||
| 127 | self::GetProcessEntry(); |
||
| 128 | |||
| 129 | if ($folderid === false) { |
||
|
introduced
by
|
|||
| 130 | $folderid = "hierarchy"; |
||
| 131 | } |
||
| 132 | |||
| 133 | if (!isset(self::$processentry['stat'])) { |
||
| 134 | self::$processentry['stat'] = []; |
||
| 135 | } |
||
| 136 | |||
| 137 | self::$processentry['stat'][$folderid] = $status; |
||
| 138 | |||
| 139 | $this->updateProcessStack(); |
||
| 140 | |||
| 141 | return true; |
||
| 142 | } |
||
| 143 | |||
| 144 | /** |
||
| 145 | * Marks the current process as a PUSH connection. |
||
| 146 | * |
||
| 147 | * @return bool |
||
| 148 | */ |
||
| 149 | public function ProcessLoopDetectionSetAsPush() { |
||
| 150 | // generate entry if not already there |
||
| 151 | self::GetProcessEntry(); |
||
| 152 | self::$processentry['push'] = true; |
||
| 153 | |||
| 154 | return $this->updateProcessStack(); |
||
| 155 | } |
||
| 156 | |||
| 157 | /** |
||
| 158 | * Indicates if a simple Hierarchy sync should be done after Ping. |
||
| 159 | * |
||
| 160 | * When trying to sync a non existing folder, Sync will return Status 12. |
||
| 161 | * This should trigger a hierarchy sync by the client, but this is not always done. |
||
| 162 | * Clients continue trying to Ping, which fails as well and triggers a Sync again. |
||
| 163 | * |
||
| 164 | * Ping could indicate to perform a FolderSync as well after a few Sync/Ping cycles. |
||
| 165 | * |
||
| 166 | * @return bool |
||
| 167 | */ |
||
| 168 | public function ProcessLoopDetectionIsHierarchySyncAdvised() { |
||
| 221 | } |
||
| 222 | |||
| 223 | /** |
||
| 224 | * Indicates if a full Hierarchy Resync is necessary. |
||
| 225 | * |
||
| 226 | * In some occasions the mobile tries to sync a folder with an invalid/not-existing ID. |
||
| 227 | * In these cases a status exception like SYNC_STATUS_FOLDERHIERARCHYCHANGED is returned |
||
| 228 | * so the mobile executes a FolderSync expecting that some action is taken on that folder (e.g. remove). |
||
| 229 | * |
||
| 230 | * If the FolderSync is not doing anything relevant, then the Sync is attempted again |
||
| 231 | * resulting in the same error and looping between these two processes. |
||
| 232 | * |
||
| 233 | * This method checks if in the last process stack a Sync and FolderSync were triggered to |
||
| 234 | * catch the loop at the 2nd interaction (Sync->FolderSync->Sync->FolderSync => ReSync) |
||
| 235 | * |
||
| 236 | * @return bool |
||
| 237 | */ |
||
| 238 | public function ProcessLoopDetectionIsHierarchyResyncRequired() { |
||
| 239 | $seenFailed = []; |
||
| 240 | $seenFolderSync = false; |
||
| 241 | |||
| 242 | $lookback = self::$start - 600; // look at the last 5 min |
||
| 243 | foreach ($this->getProcessStack() as $se) { |
||
| 244 | if ($se['time'] > $lookback && $se['time'] < (self::$start - 1)) { |
||
| 245 | // look for sync command |
||
| 246 | if (isset($se['stat']) && ($se['cc'] == GSync::COMMAND_SYNC || $se['cc'] == GSync::COMMAND_PING)) { |
||
| 247 | foreach ($se['stat'] as $key => $value) { |
||
| 248 | // don't count PING with changes on a folder or sync with success |
||
| 249 | if (($se['cc'] == GSync::COMMAND_PING && $value == SYNC_PINGSTATUS_CHANGES) || |
||
| 250 | ($se['cc'] == GSync::COMMAND_SYNC && $value == SYNC_STATUS_SUCCESS)) { |
||
| 251 | continue; |
||
| 252 | } |
||
| 253 | if (!isset($seenFailed[$key])) { |
||
| 254 | $seenFailed[$key] = 0; |
||
| 255 | } |
||
| 256 | ++$seenFailed[$key]; |
||
| 257 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->ProcessLoopDetectionIsHierarchyResyncRequired(): seen command with Exception or folderid '%s' and code '%s'", $key, $value)); |
||
| 258 | } |
||
| 259 | } |
||
| 260 | // look for FolderSync command with previous failed commands |
||
| 261 | if ($se['cc'] == GSync::COMMAND_FOLDERSYNC && !empty($seenFailed) && $se['id'] != self::GetProcessIdentifier()) { |
||
| 262 | // a full folderresync was already triggered |
||
| 263 | if (isset($se['stat'], $se['stat']['hierarchy']) && $se['stat']['hierarchy'] == SYNC_FSSTATUS_SYNCKEYERROR) { |
||
| 264 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->ProcessLoopDetectionIsHierarchyResyncRequired(): a full FolderReSync was already requested. Resetting fail counter."); |
||
| 265 | $seenFailed = []; |
||
| 266 | } |
||
| 267 | else { |
||
| 268 | $seenFolderSync = true; |
||
| 269 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->ProcessLoopDetectionIsHierarchyResyncRequired(): seen FolderSync after other failing command"); |
||
| 270 | } |
||
| 271 | } |
||
| 272 | } |
||
| 273 | } |
||
| 274 | |||
| 275 | $filtered = []; |
||
| 276 | foreach ($seenFailed as $k => $count) { |
||
| 277 | if ($count > 1) { |
||
| 278 | $filtered[] = $k; |
||
| 279 | } |
||
| 280 | } |
||
| 281 | |||
| 282 | if ($seenFolderSync && !empty($filtered)) { |
||
| 283 | SLog::Write(LOGLEVEL_INFO, "LoopDetection->ProcessLoopDetectionIsHierarchyResyncRequired(): Potential loop detected. Full hierarchysync indicated."); |
||
| 284 | |||
| 285 | return true; |
||
| 286 | } |
||
| 287 | |||
| 288 | return false; |
||
| 289 | } |
||
| 290 | |||
| 291 | /** |
||
| 292 | * Indicates if a previous process could not be terminated. |
||
| 293 | * |
||
| 294 | * Checks if there is an end time for the last entry on the stack |
||
| 295 | * |
||
| 296 | * @return bool |
||
| 297 | */ |
||
| 298 | public function ProcessLoopDetectionPreviousConnectionFailed() { |
||
| 299 | $stack = $this->getProcessStack(); |
||
| 300 | $errors = false; |
||
| 301 | if (count($stack) > 1) { |
||
| 302 | $se = $stack[0]; |
||
| 303 | if (!isset($se['end']) && $se['cc'] != GSync::COMMAND_PING && !isset($se['push'])) { |
||
| 304 | // there is no end time |
||
| 305 | SLog::Write(LOGLEVEL_ERROR, sprintf("LoopDetection->ProcessLoopDetectionPreviousConnectionFailed(): Command '%s' at %s with pid '%d' terminated unexpectedly or is still running.", Utils::GetCommandFromCode($se['cc']), Utils::GetFormattedTime($se['time']), $se['pid'])); |
||
| 306 | SLog::Write(LOGLEVEL_ERROR, "Please check your logs for this PID and errors like PHP-Fatals or Apache segmentation faults and report your results to the grommunio dev team."); |
||
| 307 | $errors = true; |
||
| 308 | } |
||
| 309 | } |
||
| 310 | |||
| 311 | return $errors; |
||
| 312 | } |
||
| 313 | |||
| 314 | /** |
||
| 315 | * Gets the PID of an outdated search process. |
||
| 316 | * |
||
| 317 | * Returns false if there isn't any process |
||
| 318 | * |
||
| 319 | * @return bool |
||
| 320 | */ |
||
| 321 | public function ProcessLoopDetectionGetOutdatedSearchPID() { |
||
| 322 | $stack = $this->getProcessStack(); |
||
| 323 | if (count($stack) > 1) { |
||
| 324 | $se = $stack[0]; |
||
| 325 | if ($se['cc'] == GSync::COMMAND_SEARCH || $se['cc'] == GSync::COMMAND_FIND) { |
||
| 326 | return $se['pid']; |
||
| 327 | } |
||
| 328 | } |
||
| 329 | |||
| 330 | return false; |
||
| 331 | } |
||
| 332 | |||
| 333 | /** |
||
| 334 | * Inserts or updates the current process entry on the stack. |
||
| 335 | * |
||
| 336 | * @return bool |
||
| 337 | */ |
||
| 338 | private function updateProcessStack() { |
||
| 339 | // initialize params |
||
| 340 | $this->initializeParams(); |
||
| 341 | |||
| 342 | $ok = false; |
||
| 343 | $tryCount = 1; |
||
| 344 | while (!$ok && $tryCount < 5) { |
||
| 345 | [$stack, $stackRaw] = $this->getDeviceUserData($this->type, parent::$devid, parent::$user, self::INTERPROCESSLD, true); |
||
| 346 | |||
| 347 | // insert/update current process entry |
||
| 348 | $nstack = []; |
||
| 349 | $updateentry = self::GetProcessEntry(); |
||
| 350 | $found = false; |
||
| 351 | |||
| 352 | foreach ($stack as $entry) { |
||
| 353 | if ($entry['id'] != $updateentry['id']) { |
||
| 354 | $nstack[] = $entry; |
||
| 355 | } |
||
| 356 | else { |
||
| 357 | $nstack[] = $updateentry; |
||
| 358 | $found = true; |
||
| 359 | } |
||
| 360 | } |
||
| 361 | |||
| 362 | if (!$found) { |
||
| 363 | $nstack[] = $updateentry; |
||
| 364 | } |
||
| 365 | |||
| 366 | if (count($nstack) > 10) { |
||
| 367 | $nstack = array_slice($nstack, -10, 10); |
||
| 368 | } |
||
| 369 | |||
| 370 | // update loop data |
||
| 371 | $ok = $this->setDeviceUserData($this->type, $nstack, parent::$devid, parent::$user, self::INTERPROCESSLD, $doCas = "replace", $stackRaw); |
||
| 372 | if (!$ok) { |
||
| 373 | $l = LOGLEVEL_INFO; |
||
| 374 | if ($tryCount > 1) { |
||
| 375 | $l = LOGLEVEL_WARN; |
||
| 376 | } |
||
| 377 | SLog::Write($l, sprintf("LoopDetection->updateProcessStack(): CAS failed on try %d!", $tryCount)); |
||
| 378 | usleep(100000); |
||
| 379 | ++$tryCount; |
||
| 380 | } |
||
| 381 | } |
||
| 382 | |||
| 383 | return $ok; |
||
| 384 | } |
||
| 385 | |||
| 386 | /** |
||
| 387 | * Returns the current process stack. |
||
| 388 | * |
||
| 389 | * @return array |
||
| 390 | */ |
||
| 391 | private function getProcessStack() { |
||
| 392 | // initialize params |
||
| 393 | $this->initializeParams(); |
||
| 394 | |||
| 395 | return $this->getDeviceUserData($this->type, parent::$devid, parent::$user, self::INTERPROCESSLD); |
||
| 396 | } |
||
| 397 | |||
| 398 | /* |
||
| 399 | * TRACKING OF BROKEN MESSAGES |
||
| 400 | * if a previousily ignored message is streamed again to the device it's tracked here. |
||
| 401 | * |
||
| 402 | * There are two outcomes: |
||
| 403 | * - next uuid counter is higher than current -> message is fixed and successfully synchronized |
||
| 404 | * - next uuid counter is the same or uuid changed -> message is still broken |
||
| 405 | */ |
||
| 406 | |||
| 407 | /** |
||
| 408 | * Adds a message to the tracking of broken messages |
||
| 409 | * Being tracked means that a broken message was streamed to the device. |
||
| 410 | * We save the latest uuid and counter so if on the next sync the counter is higher |
||
| 411 | * the message was accepted by the device. |
||
| 412 | * |
||
| 413 | * @param string $folderid the parent folder of the message |
||
| 414 | * @param string $id the id of the message |
||
| 415 | * |
||
| 416 | * @return bool |
||
| 417 | */ |
||
| 418 | public function SetBrokenMessage($folderid, $id) { |
||
| 419 | if ($folderid == false || |
||
| 420 | !isset($this->broken_message_uuid) || |
||
| 421 | !isset($this->broken_message_counter) || |
||
| 422 | $this->broken_message_uuid == false || |
||
| 423 | $this->broken_message_counter == false) { |
||
| 424 | return false; |
||
| 425 | } |
||
| 426 | |||
| 427 | $ok = false; |
||
| 428 | $brokenkey = self::BROKENMSGS . "-" . $folderid; |
||
| 429 | |||
| 430 | // initialize params |
||
| 431 | $this->initializeParams(); |
||
| 432 | $tryCount = 1; |
||
| 433 | while (!$ok && $tryCount < 5) { |
||
| 434 | [$brokenmsgs, $brokenmsgsRaw] = $this->getDeviceUserData($this->type, parent::$devid, parent::$user, $brokenkey, true); |
||
| 435 | |||
| 436 | $brokenmsgs[$id] = ['uuid' => $this->broken_message_uuid, 'counter' => $this->broken_message_counter]; |
||
| 437 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->SetBrokenMessage('%s', '%s'): tracking broken message", $folderid, $id)); |
||
| 438 | |||
| 439 | // update data |
||
| 440 | $ok = $this->setDeviceUserData($this->type, $brokenmsgs, parent::$devid, parent::$user, $brokenkey, $doCas = "replace", $brokenmsgsRaw); |
||
| 441 | if (!$ok) { |
||
| 442 | SLog::Write(LOGLEVEL_WARN, sprintf("LoopDetection->SetBrokenMessage(): CAS failed on try %d!", $tryCount)); |
||
| 443 | usleep(100000); |
||
| 444 | ++$tryCount; |
||
| 445 | } |
||
| 446 | } |
||
| 447 | |||
| 448 | return $ok; |
||
| 449 | } |
||
| 450 | |||
| 451 | /** |
||
| 452 | * Gets a list of all ids of a folder which were tracked and which were |
||
| 453 | * accepted by the device from the last sync. |
||
| 454 | * |
||
| 455 | * @param string $folderid the parent folder of the message |
||
| 456 | * |
||
| 457 | * @return array |
||
| 458 | */ |
||
| 459 | public function GetSyncedButBeforeIgnoredMessages($folderid) { |
||
| 460 | if ($folderid == false || |
||
| 461 | !isset($this->broken_message_uuid) || |
||
| 462 | !isset($this->broken_message_counter) || |
||
| 463 | $this->broken_message_uuid == false || |
||
| 464 | $this->broken_message_counter == false) { |
||
| 465 | return []; |
||
| 466 | } |
||
| 467 | |||
| 468 | $brokenkey = self::BROKENMSGS . "-" . $folderid; |
||
| 469 | $removeIds = []; |
||
| 470 | $okIds = []; |
||
| 471 | |||
| 472 | // initialize params |
||
| 473 | $this->initializeParams(); |
||
| 474 | |||
| 475 | $ok = false; |
||
| 476 | $tryCount = 1; |
||
| 477 | while (!$ok && $tryCount < 5) { |
||
| 478 | [$brokenmsgs, $brokenmsgsRaw] = $this->getDeviceUserData($this->type, parent::$devid, parent::$user, $brokenkey, true); |
||
| 479 | |||
| 480 | if (empty($brokenmsgs)) { |
||
| 481 | break; |
||
| 482 | } |
||
| 483 | |||
| 484 | foreach ($brokenmsgs as $id => $data) { |
||
| 485 | // previously broken message was successfully synced! |
||
| 486 | if ($data['uuid'] == $this->broken_message_uuid && $data['counter'] < $this->broken_message_counter) { |
||
| 487 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->GetSyncedButBeforeIgnoredMessages('%s'): message '%s' was successfully synchronized", $folderid, $id)); |
||
| 488 | $okIds[] = $id; |
||
| 489 | } |
||
| 490 | |||
| 491 | // if the uuid has changed this is old data which should also be removed |
||
| 492 | if ($data['uuid'] != $this->broken_message_uuid) { |
||
| 493 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->GetSyncedButBeforeIgnoredMessages('%s'): stored message id '%s' for uuid '%s' is obsolete", $folderid, $id, $data['uuid'])); |
||
| 494 | $removeIds[] = $id; |
||
| 495 | } |
||
| 496 | } |
||
| 497 | |||
| 498 | // remove data |
||
| 499 | foreach (array_merge($okIds, $removeIds) as $id) { |
||
| 500 | unset($brokenmsgs[$id]); |
||
| 501 | } |
||
| 502 | |||
| 503 | if (empty($brokenmsgs)) { |
||
| 504 | $this->delDeviceUserData($this->type, parent::$devid, parent::$user, $brokenkey); |
||
| 505 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->GetSyncedButBeforeIgnoredMessages('%s'): removed folder from tracking of ignored messages", $folderid)); |
||
| 506 | |||
| 507 | break; |
||
| 508 | } |
||
| 509 | |||
| 510 | // update data |
||
| 511 | $ok = $this->setDeviceUserData($this->type, $brokenmsgs, parent::$devid, parent::$user, $brokenkey, $doCas = "replace", $brokenmsgsRaw); |
||
| 512 | if (!$ok) { |
||
| 513 | SLog::Write(LOGLEVEL_WARN, sprintf("LoopDetection->GetSyncedButBeforeIgnoredMessages(): CAS failed on try %d!", $tryCount)); |
||
| 514 | usleep(100000); |
||
| 515 | ++$tryCount; |
||
| 516 | } |
||
| 517 | } |
||
| 518 | |||
| 519 | return $okIds; |
||
| 520 | } |
||
| 521 | |||
| 522 | /** |
||
| 523 | * Marks a SyncState as "already used", e.g. when an import process started. |
||
| 524 | * This is most critical for DiffBackends, as an imported message would be exported again |
||
| 525 | * in the heartbeat if the notification is triggered before the import is complete. |
||
| 526 | * |
||
| 527 | * @param string $folderid folder id |
||
| 528 | * @param string $uuid synkkey |
||
| 529 | * @param string $counter synckey counter |
||
| 530 | * |
||
| 531 | * @return bool |
||
| 532 | */ |
||
| 533 | public function SetSyncStateUsage($folderid, $uuid, $counter) { |
||
| 567 | } |
||
| 568 | |||
| 569 | /** |
||
| 570 | * Checks if the given counter for a certain uuid+folderid was exported before. |
||
| 571 | * Returns also true if the counter are the same but previously there were |
||
| 572 | * changes to be exported. |
||
| 573 | * |
||
| 574 | * @param string $folderid folder id |
||
| 575 | * @param string $uuid synkkey |
||
| 576 | * @param string $counter synckey counter |
||
| 577 | * |
||
| 578 | * @return bool indicating if an uuid+counter were exported (with changes) before |
||
| 579 | */ |
||
| 580 | public function IsSyncStateObsolete($folderid, $uuid, $counter) { |
||
| 581 | // initialize params |
||
| 582 | $this->initializeParams(); |
||
| 583 | |||
| 584 | $obsolete = false; |
||
| 585 | |||
| 586 | $current = $this->getDeviceUserData($this->type, parent::$devid, parent::$user, $folderid); |
||
| 587 | |||
| 588 | if (!empty($current)) { |
||
| 589 | if (!isset($current["uuid"]) || $current["uuid"] != $uuid) { |
||
| 590 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->IsSyncStateObsolete(): yes, uuid changed or not set"); |
||
| 591 | $obsolete = true; |
||
| 592 | } |
||
| 593 | else { |
||
| 594 | SLog::Write(LOGLEVEL_DEBUG, sprintf( |
||
| 595 | "LoopDetection->IsSyncStateObsolete(): check folderid: '%s' uuid '%s' counter: %d - last counter: %d with %d queued", |
||
| 596 | $folderid, |
||
| 597 | $uuid, |
||
| 598 | $counter, |
||
| 599 | $current["count"], |
||
| 600 | $current["queued"] |
||
| 601 | )); |
||
| 602 | |||
| 603 | if ($current["uuid"] == $uuid && ( |
||
| 604 | $current["count"] > $counter || |
||
| 605 | ($current["count"] == $counter && $current["queued"] > 0) || |
||
| 606 | (isset($current["usage"]) && $current["usage"] >= $counter) |
||
| 607 | )) { |
||
| 608 | $usage = isset($current["usage"]) ? sprintf(" - counter %d already expired", $current["usage"]) : ""; |
||
| 609 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->IsSyncStateObsolete(): yes, counter already processed" . $usage); |
||
| 610 | $obsolete = true; |
||
| 611 | } |
||
| 612 | } |
||
| 613 | } |
||
| 614 | else { |
||
| 615 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->IsSyncStateObsolete(): check folderid: '%s' uuid '%s' counter: %d - no data found: not obsolete", $folderid, $uuid, $counter)); |
||
| 616 | } |
||
| 617 | |||
| 618 | return $obsolete; |
||
| 619 | } |
||
| 620 | |||
| 621 | /* |
||
| 622 | * MESSAGE LOOP DETECTION. |
||
| 623 | */ |
||
| 624 | |||
| 625 | /** |
||
| 626 | * Loop detection mechanism. |
||
| 627 | * |
||
| 628 | * 1. request counter is higher than the previous counter (somehow default) |
||
| 629 | * 1.1) standard situation -> do nothing |
||
| 630 | * 1.2) loop information exists |
||
| 631 | * 1.2.1) request counter < maxCounter AND no ignored data -> continue in loop mode |
||
| 632 | * 1.2.2) request counter < maxCounter AND ignored data -> we have already encountered issue, return to normal |
||
| 633 | * |
||
| 634 | * 2. request counter is the same as the previous, but no data was sent on the last request (standard situation) |
||
| 635 | * |
||
| 636 | * 3. request counter is the same as the previous and last time objects were sent (loop!) |
||
| 637 | * 3.0) no loop was detected before, but with big window size -> lower window size first - NO LOOP mode yet |
||
| 638 | * 3.1) no loop was detected before, entering loop mode -> save loop data, loopcount = 1 |
||
| 639 | * 3.2) loop was detected before, but are gone -> loop resolved |
||
| 640 | * 3.3) loop was detected before, continuing in loop mode -> this is probably the broken element,loopcount++, |
||
| 641 | * 3.3.1) item identified, loopcount >= 3 -> ignore item, set ignoredata flag |
||
| 642 | * |
||
| 643 | * @param string $folderid the current folder id to be worked on |
||
| 644 | * @param string $uuid the synkkey |
||
| 645 | * @param string $counter the synckey counter |
||
| 646 | * @param string $maxItems the current amount of items to be sent to the mobile |
||
| 647 | * @param string $queuedMessages the amount of messages which were found by the exporter |
||
| 648 | * |
||
| 649 | * @return bool|int when returning true if a loop has been identified - returns new suggested window size if window might have been too big |
||
| 650 | */ |
||
| 651 | public function Detect($folderid, $uuid, $counter, $maxItems, $queuedMessages) { |
||
| 652 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->Detect(): folderid:'%s' uuid:'%s' counter:'%s' max:'%s' queued:'%s'", $folderid, $uuid, $counter, $maxItems, $queuedMessages)); |
||
| 653 | $this->broken_message_uuid = $uuid; |
||
| 654 | $this->broken_message_counter = $counter; |
||
| 655 | |||
| 656 | // if an incoming loop is already detected, do nothing |
||
| 657 | if ($maxItems === 0 && $queuedMessages > 0) { |
||
| 658 | GSync::GetTopCollector()->AnnounceInformation("Incoming loop!", true); |
||
| 659 | |||
| 660 | return true; |
||
| 661 | } |
||
| 662 | |||
| 663 | // initialize params |
||
| 664 | $this->initializeParams(); |
||
| 665 | |||
| 666 | $loop = false; |
||
| 667 | |||
| 668 | $ok = false; |
||
| 669 | $tryCount = 1; |
||
| 670 | while (!$ok && $tryCount < 5) { |
||
| 671 | [$current, $currentRaw] = $this->getDeviceUserData($this->type, parent::$devid, parent::$user, $folderid, true); |
||
| 672 | |||
| 673 | // completely new/unknown UUID |
||
| 674 | if (empty($current)) { |
||
| 675 | $current = ["uuid" => $uuid, "count" => $counter - 1, "queued" => $queuedMessages]; |
||
| 676 | } |
||
| 677 | |||
| 678 | // old UUID in cache - the device requested a new state!! |
||
| 679 | if (isset($current['uuid']) && $current['uuid'] != $uuid) { |
||
| 680 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->Detect(): UUID changed for folder"); |
||
| 681 | |||
| 682 | // some devices (iPhones) may request new UUIDs after broken items were sent several times |
||
| 683 | if (isset($current['queued']) && $current['queued'] > 0 && |
||
| 684 | (isset($current['maxCount']) && $current['maxCount'] > $current['count'] + 1 || $counter == 1)) { |
||
| 685 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->Detect(): UUID changed and while items where sent to device - forcing loop mode"); |
||
| 686 | $loop = true; // force loop mode |
||
| 687 | $current['queued'] = $queuedMessages; |
||
| 688 | } |
||
| 689 | else { |
||
| 690 | $current['queued'] = 0; |
||
| 691 | } |
||
| 692 | |||
| 693 | // set new data, unset old loop information |
||
| 694 | $current["uuid"] = $uuid; |
||
| 695 | $current['count'] = $counter; |
||
| 696 | unset($current['loopcount'], $current['ignored'], $current['maxCount'], $current['potential'], $current['windowLimit']); |
||
| 697 | } |
||
| 698 | |||
| 699 | // see if there are values |
||
| 700 | if (isset($current['uuid']) && $current['uuid'] == $uuid && |
||
| 701 | isset($current['count'])) { |
||
| 702 | // case 1 - standard, during loop-resolving & resolving |
||
| 703 | if ($current['count'] < $counter) { |
||
| 704 | // case 1.1 |
||
| 705 | $current['count'] = $counter; |
||
| 706 | $current['queued'] = $queuedMessages; |
||
| 707 | if (isset($current["usage"]) && $current["usage"] < $current['count']) { |
||
| 708 | unset($current["usage"]); |
||
| 709 | } |
||
| 710 | |||
| 711 | // case 1.2 |
||
| 712 | if (isset($current['maxCount'])) { |
||
| 713 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->Detect(): case 1.2 detected"); |
||
| 714 | |||
| 715 | // case 1.2.1 |
||
| 716 | // broken item not identified yet |
||
| 717 | if (!isset($current['ignored']) && $counter < $current['maxCount']) { |
||
| 718 | $current['loopcount'] = 1; |
||
| 719 | $loop = true; // continue in loop-resolving |
||
| 720 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->Detect(): case 1.2.1 detected"); |
||
| 721 | } |
||
| 722 | // case 1.2.2 - if there were any broken items they should be gone, return to normal |
||
| 723 | else { |
||
| 724 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->Detect(): case 1.2.2 detected"); |
||
| 725 | unset($current['loopcount'], $current['ignored'], $current['maxCount'], $current['potential'], $current['windowLimit']); |
||
| 726 | } |
||
| 727 | } |
||
| 728 | } |
||
| 729 | |||
| 730 | // case 2 - same counter, but there were no changes before and are there now |
||
| 731 | elseif ($current['count'] == $counter && $current['queued'] == 0 && $queuedMessages > 0) { |
||
| 732 | $current['queued'] = $queuedMessages; |
||
| 733 | if (isset($current["usage"]) && $current["usage"] < $current['count']) { |
||
| 734 | unset($current["usage"]); |
||
| 735 | } |
||
| 736 | } |
||
| 737 | |||
| 738 | // case 3 - same counter, changes sent before, hanging loop and ignoring |
||
| 739 | elseif ($current['count'] == $counter && $current['queued'] > 0) { |
||
| 740 | if (!isset($current['loopcount'])) { |
||
| 741 | // We are potentially syncing a lot of data, e.g. OL with 512 WindowSize |
||
| 742 | // In case there are more then 40 items in the last request, we limit to 25 items |
||
| 743 | // before entering 1-by-1 loop detection if counter is re-requested |
||
| 744 | if ($maxItems > 40 && !isset($current['windowLimit'])) { |
||
| 745 | // case 3.0) we have just encountered a loop, but with a big window size, lower window first |
||
| 746 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->Detect(): case 3.0 detected - big windowsize of %d, lowering before entering loop mode", $maxItems)); |
||
| 747 | // return suggested new window size |
||
| 748 | $current['windowLimit'] = 25; |
||
| 749 | $loop = $current['windowLimit']; |
||
| 750 | } |
||
| 751 | else { |
||
| 752 | // case 3.1) we have just encountered a loop! |
||
| 753 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->Detect(): case 3.1 detected - loop detected, init loop mode"); |
||
| 754 | if (isset($current['windowLimit'])) { |
||
| 755 | $maxItems = $current['windowLimit']; |
||
| 756 | unset($current['windowLimit']); |
||
| 757 | } |
||
| 758 | $current['loopcount'] = 1; |
||
| 759 | // the MaxCount is the max number of messages exported before |
||
| 760 | $current['maxCount'] = $counter + (($maxItems < $queuedMessages) ? $maxItems : $queuedMessages); |
||
| 761 | $loop = true; // loop mode!! |
||
| 762 | } |
||
| 763 | } |
||
| 764 | elseif ($queuedMessages == 0) { |
||
| 765 | // case 3.2) there was a loop before but now the changes are GONE |
||
| 766 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->Detect(): case 3.2 detected - changes gone - clearing loop data"); |
||
| 767 | $current['queued'] = 0; |
||
| 768 | unset($current['loopcount'], $current['ignored'], $current['maxCount'], $current['potential'], $current['windowLimit']); |
||
| 769 | } |
||
| 770 | else { |
||
| 771 | // case 3.3) still looping the same message! Increase counter |
||
| 772 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->Detect(): case 3.3 detected - in loop mode, increase loop counter"); |
||
| 773 | ++$current['loopcount']; |
||
| 774 | |||
| 775 | // case 3.3.1 - we got our broken item! |
||
| 776 | if ($current['loopcount'] >= 3 && isset($current['potential'])) { |
||
| 777 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->Detect(): case 3.3.1 detected - broken item should be next, attempt to ignore it - id '%s'", $current['potential'])); |
||
| 778 | $this->ignore_messageid = $current['potential']; |
||
| 779 | } |
||
| 780 | $current['maxCount'] = $counter + (($maxItems < $queuedMessages) ? $maxItems : $queuedMessages); |
||
| 781 | $loop = true; // loop mode!! |
||
| 782 | } |
||
| 783 | } |
||
| 784 | } |
||
| 785 | if (isset($current['loopcount'])) { |
||
| 786 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->Detect(): loop data: loopcount(%d), maxCount(%d), queued(%d), ignored(%s)", $current['loopcount'], $current['maxCount'], $current['queued'], $current['ignored'] ?? 'false')); |
||
| 787 | } |
||
| 788 | |||
| 789 | // update loop data |
||
| 790 | $ok = $this->setDeviceUserData($this->type, $current, parent::$devid, parent::$user, $folderid, $doCas = "replace", $currentRaw); |
||
| 791 | if (!$ok) { |
||
| 792 | SLog::Write(LOGLEVEL_WARN, sprintf("LoopDetection->Detect(): CAS failed on try %d!", $tryCount)); |
||
| 793 | usleep(100000); |
||
| 794 | ++$tryCount; |
||
| 795 | } |
||
| 796 | } |
||
| 797 | // end exclusive block |
||
| 798 | |||
| 799 | if ($loop === true && $this->ignore_messageid === false) { |
||
| 800 | GSync::GetTopCollector()->AnnounceInformation("Loop detection", true); |
||
| 801 | } |
||
| 802 | |||
| 803 | return $loop; |
||
| 804 | } |
||
| 805 | |||
| 806 | /** |
||
| 807 | * Indicates if the next messages should be ignored (not be sent to the mobile!). |
||
| 808 | * |
||
| 809 | * @param string $messageid (opt) id of the message which is to be exported next |
||
| 810 | * @param string $folderid (opt) parent id of the message |
||
| 811 | * @param bool $markAsIgnored (opt) to peek without setting the next message to be |
||
| 812 | * ignored, set this value to false |
||
| 813 | * |
||
| 814 | * @return bool |
||
| 815 | */ |
||
| 816 | public function IgnoreNextMessage($markAsIgnored = true, $messageid = false, $folderid = false) { |
||
| 817 | // as the next message id is not available at all point this method is called, we use different indicators. |
||
| 818 | // potentialbroken indicates that we know that the broken message should be exported next, |
||
| 819 | // alltho we do not know for sure as it's export message orders can change |
||
| 820 | // if the $messageid is available and matches then we are sure and only then really ignore it |
||
| 821 | |||
| 822 | $potentialBroken = false; |
||
| 823 | $realBroken = false; |
||
| 824 | if (Request::GetCommandCode() == GSync::COMMAND_SYNC && $this->ignore_messageid !== false) { |
||
| 825 | $potentialBroken = true; |
||
| 826 | } |
||
| 827 | |||
| 828 | if ($messageid !== false && $this->ignore_messageid == $messageid) { |
||
| 829 | $realBroken = true; |
||
| 830 | } |
||
| 831 | |||
| 832 | // this call is just to know what should be happening |
||
| 833 | // no further actions necessary |
||
| 834 | if ($markAsIgnored === false) { |
||
| 835 | return $potentialBroken; |
||
| 836 | } |
||
| 837 | |||
| 838 | // we should really do something here |
||
| 839 | |||
| 840 | // first we check if we are in the loop mode, if so, |
||
| 841 | // we update the potential broken id message so we loop count the same message |
||
| 842 | |||
| 843 | $changedData = false; |
||
| 844 | $ok = false; |
||
| 845 | $tryCount = 1; |
||
| 846 | while (!$ok && $tryCount < 5) { |
||
| 847 | [$current, $currentRaw] = $this->getDeviceUserData($this->type, parent::$devid, parent::$user, $folderid, true); |
||
| 848 | |||
| 849 | // we found our broken message! |
||
| 850 | if ($realBroken) { |
||
| 851 | $this->ignore_messageid = false; |
||
| 852 | $current['ignored'] = $messageid; |
||
| 853 | $changedData = true; |
||
| 854 | |||
| 855 | // check if this message was broken before - here we know that it still is and remove it from the tracking |
||
| 856 | $brokenkey = self::BROKENMSGS . "-" . $folderid; |
||
| 857 | // TODO: this is currently not supported here! It's in a different structure now! |
||
| 858 | // if (isset($loopdata[self::$devid][self::$user][$brokenkey]) && isset($loopdata[self::$devid][self::$user][$brokenkey][$messageid])) { |
||
| 859 | // SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->IgnoreNextMessage(): previously broken message '%s' is still broken and will not be tracked anymore", $messageid)); |
||
| 860 | // unset($loopdata[self::$devid][self::$user][$brokenkey][$messageid]); |
||
| 861 | // } |
||
| 862 | } |
||
| 863 | // not the broken message yet |
||
| 864 | else { |
||
| 865 | // update potential id if looping on an item |
||
| 866 | if (isset($current['loopcount'])) { |
||
| 867 | $current['potential'] = $messageid; |
||
| 868 | |||
| 869 | // this message should be the broken one, but is not!! |
||
| 870 | // we should reset the loop count because this is certainly not the broken one |
||
| 871 | if ($potentialBroken) { |
||
| 872 | $current['loopcount'] = 1; |
||
| 873 | SLog::Write(LOGLEVEL_DEBUG, "LoopDetection->IgnoreNextMessage(): this should be the broken one, but is not! Resetting loop count."); |
||
| 874 | } |
||
| 875 | |||
| 876 | SLog::Write(LOGLEVEL_DEBUG, sprintf("LoopDetection->IgnoreNextMessage(): Loop mode, potential broken message id '%s'", $current['potential'])); |
||
| 877 | |||
| 878 | $changedData = true; |
||
| 879 | } |
||
| 880 | } |
||
| 881 | |||
| 882 | if ($changedData !== true) { |
||
| 883 | break; |
||
| 884 | } |
||
| 885 | // update loop data |
||
| 886 | $ok = $this->setDeviceUserData($this->type, $current, parent::$devid, parent::$user, $folderid, $doCas = "replace", $currentRaw); |
||
| 887 | if (!$ok) { |
||
| 888 | SLog::Write(LOGLEVEL_WARN, sprintf("LoopDetection->Detect(): CAS failed on try %d!", $tryCount)); |
||
| 889 | usleep(100000); |
||
| 890 | ++$tryCount; |
||
| 891 | } |
||
| 892 | } |
||
| 893 | |||
| 894 | if ($realBroken) { |
||
| 895 | GSync::GetTopCollector()->AnnounceInformation("Broken message ignored", true); |
||
| 896 | } |
||
| 897 | |||
| 898 | return $realBroken; |
||
| 899 | } |
||
| 900 | |||
| 901 | /** |
||
| 902 | * Clears loop detection data. |
||
| 903 | * |
||
| 904 | * @param string $user (opt) user which data should be removed - user can not be specified without |
||
| 905 | * @param string $devid (opt) device id which data to be removed |
||
| 906 | * |
||
| 907 | * @return bool |
||
| 908 | */ |
||
| 909 | public function ClearData($user = false, $devid = false) { |
||
| 910 | $stat = true; |
||
| 911 | $ok = false; |
||
| 912 | // TODO: implement this |
||
| 913 | // exclusive block |
||
| 914 | if ($this->blockMutex()) { |
||
| 915 | $loopdata = ($this->hasData()) ? $this->getData() : []; |
||
| 916 | |||
| 917 | if ($user == false && $devid == false) { |
||
| 918 | $loopdata = []; |
||
| 919 | } |
||
| 920 | elseif ($user == false && $devid != false) { |
||
| 921 | $loopdata[$devid] = []; |
||
| 922 | } |
||
| 923 | elseif ($user != false && $devid != false) { |
||
| 924 | $loopdata[$devid][$user] = []; |
||
| 925 | } |
||
| 926 | elseif ($user != false && $devid == false) { |
||
| 927 | SLog::Write(LOGLEVEL_WARN, sprintf("Not possible to reset loop detection data for user '%s' without a specifying a device id", $user)); |
||
| 928 | $stat = false; |
||
| 929 | } |
||
| 930 | |||
| 931 | if ($stat) { |
||
| 932 | $ok = $this->setData($loopdata); |
||
| 933 | } |
||
| 934 | |||
| 935 | $this->releaseMutex(); |
||
| 936 | } |
||
| 937 | // end exclusive block |
||
| 938 | |||
| 939 | return $stat && $ok; |
||
| 940 | } |
||
| 941 | |||
| 942 | /** |
||
| 943 | * Returns loop detection data for a user and device. |
||
| 944 | * |
||
| 945 | * @param string $user |
||
| 946 | * @param string $devid |
||
| 947 | * |
||
| 948 | * @return array|bool returns false if data not available |
||
| 949 | */ |
||
| 950 | public function GetCachedData($user, $devid) { |
||
| 964 | } |
||
| 965 | } |
||
| 966 |
Loading history...
