deblan-mirror/abraunegg-onedrive
deblan-mirror/abraunegg-onedrive
1
0
Fork 0
mirror of https://github.com/abraunegg/onedrive synced 2024-05-09 17:26:47 +02:00
Code Issues Projects Releases Wiki Activity

Update handling of fullScanRequired and syncListConfiguredFullScanOverride (Issue #896) (#899)

Browse source 
* Change 'syncListConfigured' to 'syncListConfiguredFullScanOverride' as this is what this variable
* Update handling of fullScanRequired and syncListConfiguredFullScanOverride
* When a 429 or 504 is generated when querying for 'changes' inside a changeset bundle, dont restart scanning changes from the beginning, retry original request after a delay
This commit is contained in:
abraunegg 2020-05-02 04:05:06 +10:00 committed by GitHub
parent a61d291340
commit bc9f2cf893
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
2 changed files with 257 additions and 61 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

122
src/main.d
View file

@ -676,8 +676,10 @@ int main(string[] args)
return EXIT_FAILURE;
}
}
// perform a --synchronize sync
performSync(sync, cfg.getValueString("single_directory"), cfg.getValueBool("download_only"), cfg.getValueBool("local_first"), cfg.getValueBool("upload_only"), LOG_NORMAL, true, syncListConfigured);
// perform a --synchronize sync
// fullScanRequired = false, for final true-up
// but if we have sync_list configured, use syncListConfigured which = true
performSync(sync, cfg.getValueString("single_directory"), cfg.getValueBool("download_only"), cfg.getValueBool("local_first"), cfg.getValueBool("upload_only"), LOG_NORMAL, false, syncListConfigured);
}
}
@ -764,10 +766,11 @@ int main(string[] args)
auto logMonitorCounter = 0;
auto fullScanCounter = 0;
bool fullScanRequired = true;
bool syncListConfiguredOverride = false;
bool syncListConfiguredFullScanOverride = false;
// if sync list is configured, set to true
if (syncListConfigured) {
syncListConfiguredOverride = true;
// sync list is configured
syncListConfiguredFullScanOverride = true;
}
while (true) {
@ -780,27 +783,24 @@ int main(string[] args)
logMonitorCounter = 1;
}
// full scan of sync_dir
// do we perform a full scan of sync_dir?
fullScanCounter += 1;
if (fullScanCounter > fullScanFrequency){
// loop counter has exceeded
fullScanCounter = 1;
fullScanRequired = true;
if (syncListConfigured) {
syncListConfiguredOverride = true;
// sync list is configured
syncListConfiguredFullScanOverride = true;
}
}
// Monitor Loop Counter
log.vdebug("fullScanCounter = ", fullScanCounter);
log.vdebug("fullScanCounter = ", fullScanCounter);
// sync option handling per sync loop
log.vdebug("syncListConfigured = ", syncListConfigured);
log.vdebug("fullScanRequired = ", fullScanRequired);
log.vdebug("syncListConfiguredOverride = ", syncListConfiguredOverride);
// log.logAndNotify("DEBUG trying to create checkpoint");
// auto res = itemdb.db_checkpoint();
// log.logAndNotify("Checkpoint return: ", res);
// itemdb.dump_open_statements();
log.vdebug("syncListConfigured = ", syncListConfigured);
log.vdebug("fullScanRequired = ", fullScanRequired);
log.vdebug("syncListConfiguredFullScanOverride = ", syncListConfiguredFullScanOverride);
try {
if (!initSyncEngine(sync)) {
@ -810,7 +810,7 @@ int main(string[] args)
try {
// perform a --monitor sync
log.vlog("Starting a sync with OneDrive");
performSync(sync, cfg.getValueString("single_directory"), cfg.getValueBool("download_only"), cfg.getValueBool("local_first"), cfg.getValueBool("upload_only"), (logMonitorCounter == logInterval ? MONITOR_LOG_QUIET : MONITOR_LOG_SILENT), fullScanRequired, syncListConfiguredOverride);
performSync(sync, cfg.getValueString("single_directory"), cfg.getValueBool("download_only"), cfg.getValueBool("local_first"), cfg.getValueBool("upload_only"), (logMonitorCounter == logInterval ? MONITOR_LOG_QUIET : MONITOR_LOG_SILENT), fullScanRequired, syncListConfiguredFullScanOverride);
if (!cfg.getValueBool("download_only")) {
// discard all events that may have been generated by the sync
m.update(false);
@ -829,7 +829,7 @@ int main(string[] args)
log.vlog("Sync with OneDrive is complete");
fullScanRequired = false;
if (syncListConfigured) {
syncListConfiguredOverride = false;
syncListConfiguredFullScanOverride = false;
}
lastCheckTime = MonoTime.currTime();
GC.collect();
@ -876,12 +876,19 @@ bool initSyncEngine(SyncEngine sync)
}
// try to synchronize the folder three times
void performSync(SyncEngine sync, string singleDirectory, bool downloadOnly, bool localFirst, bool uploadOnly, long logLevel, bool fullScanRequired, bool syncListConfigured)
void performSync(SyncEngine sync, string singleDirectory, bool downloadOnly, bool localFirst, bool uploadOnly, long logLevel, bool fullScanRequired, bool syncListConfiguredFullScanOverride)
{
int count;
string remotePath = "/";
string localPath = ".";
// performSync API scan triggers
log.vdebug("performSync API scan triggers");
log.vdebug("-----------------------------");
log.vdebug("fullScanRequired = ", fullScanRequired);
log.vdebug("syncListConfiguredFullScanOverride = ", syncListConfiguredFullScanOverride);
log.vdebug("-----------------------------");
// Are we doing a single directory sync?
if (singleDirectory != ""){
// Need two different path strings here
@ -937,28 +944,73 @@ void performSync(SyncEngine sync, string singleDirectory, bool downloadOnly, boo
// sync local files first before downloading from OneDrive
if (logLevel < MONITOR_LOG_QUIET) log.log("Syncing changes from local path first before downloading changes from OneDrive ...");
sync.scanForDifferences(localPath);
sync.applyDifferences(syncListConfigured);
// if syncListConfiguredFullScanOverride = true
if (syncListConfiguredFullScanOverride) {
// perform a full walk of OneDrive objects
sync.applyDifferences(syncListConfiguredFullScanOverride);
} else {
// perform a walk based on if a full scan is required
sync.applyDifferences(fullScanRequired);
}
} else {
// sync from OneDrive first before uploading files to OneDrive
if (logLevel < MONITOR_LOG_SILENT) log.log("Syncing changes from OneDrive ...");
// For the initial sync, always use the delta link so that we capture all the right delta changes including adds, moves & deletes
log.vdebug("Calling sync.applyDifferences(false);");
sync.applyDifferences(false);
// Is a full scan of the entire sync_dir required?
if (fullScanRequired) {
// is this a download only request?
if (!downloadOnly) {
// process local changes walking the entire path checking for changes
// in monitor mode all local changes are captured via inotify
// thus scanning every 'monitor_interval' (default 45 seconds) for local changes is excessive and not required
sync.scanForDifferences(localPath);
// ensure that the current remote state is updated locally to ensure everything is consistent
if (syncListConfigured) {
// for the 'true-up' sync, if sync_list is configured, syncListConfigured = true, thus a FULL walk of all OneDrive objects will be requested and used if required
sync.applyDifferences(syncListConfigured);
} else {
// for the 'true-up' sync, if fullScanRequired = true, thus a FULL walk of all OneDrive objects will be requested and used if required
sync.applyDifferences(fullScanRequired);
}
// is this a download only request?
if (!downloadOnly) {
// process local changes walking the entire path checking for changes
// in monitor mode all local changes are captured via inotify
// thus scanning every 'monitor_interval' (default 45 seconds) for local changes is excessive and not required
log.vdebug("Calling sync.scanForDifferences(localPath);");
sync.scanForDifferences(localPath);
// At this point, all OneDrive changes / local changes should be uploaded and in sync
// This MAY not be the case when using sync_list, thus a full walk of OneDrive ojects is required
// --synchronize & no sync_list : fullScanRequired = false, syncListConfiguredFullScanOverride = false
// --synchronize & sync_list in use : fullScanRequired = false, syncListConfiguredFullScanOverride = true
// --monitor loops around 10 iterations. On the 1st loop, sets fullScanRequired = true, syncListConfiguredFullScanOverride = true if requried
// --monitor & no sync_list (loop #1) : fullScanRequired = true, syncListConfiguredFullScanOverride = false
// --monitor & no sync_list (loop #2 - #10) : fullScanRequired = false, syncListConfiguredFullScanOverride = false
// --monitor & sync_list in use (loop #1) : fullScanRequired = true, syncListConfiguredFullScanOverride = true
// --monitor & sync_list in use (loop #2 - #10) : fullScanRequired = false, syncListConfiguredFullScanOverride = false
// Do not perform a full walk of the OneDrive objects
if ((!fullScanRequired) && (!syncListConfiguredFullScanOverride)){
log.vdebug("Final True-Up: Do not perform a full walk of the OneDrive objects - not required");
log.vdebug("Calling sync.applyDifferences(false);");
sync.applyDifferences(false);
return;
}
// Perform a full walk of OneDrive objects because sync_list is in use / or trigger was set in --monitor loop
if ((!fullScanRequired) && (syncListConfiguredFullScanOverride)){
log.vdebug("Final True-Up: Perform a full walk of OneDrive objects because sync_list is in use / or trigger was set in --monitor loop");
log.vdebug("Calling sync.applyDifferences(true);");
sync.applyDifferences(true);
return;
}
// Perform a full walk of OneDrive objects because a full scan was required
if ((fullScanRequired) && (!syncListConfiguredFullScanOverride)){
log.vdebug("Final True-Up: Perform a full walk of OneDrive objects because a full scan was required");
log.vdebug("Calling sync.applyDifferences(true);");
sync.applyDifferences(true);
return;
}
// Perform a full walk of OneDrive objects because a full scan was required and sync_list is in use and trigger was set in --monitor loop
if ((fullScanRequired) && (syncListConfiguredFullScanOverride)){
log.vdebug("Final True-Up: Perform a full walk of OneDrive objects because a full scan was required and sync_list is in use and trigger was set in --monitor loop");
log.vdebug("Calling sync.applyDifferences(true);");
sync.applyDifferences(true);
return;
}
}
}

196
src/sync.d
View file

@ -900,13 +900,18 @@ final class SyncEngine
idToQuery = id;
}
// query for changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink);
try {
// Fetch the changes relative to the path id we want to query
// changes with or without deltaLink
changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink);
changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable);
if (changes.type() == JSONType.object) {
log.vdebug("Query 'changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink)' performed successfully");
}
} catch (OneDriveException e) {
// OneDrive threw an error
log.vdebug("OneDrive threw an error when querying for these changes:");
log.vdebug("------------------------------------------------------------------");
log.vdebug("Query Error: changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink)");
log.vdebug("driveId: ", driveId);
log.vdebug("idToQuery: ", idToQuery);
log.vdebug("deltaLink: ", deltaLink);
@ -931,11 +936,7 @@ final class SyncEngine
if (e.httpStatusCode == 429) {
// HTTP request returned status code 429 (Too Many Requests). We need to leverage the response Retry-After HTTP header to ensure minimum delay until the throttle is removed.
handleOneDriveThrottleRequest();
// Retry original request by calling function again to avoid replicating any further error handling
log.vdebug("Retrying original request that generated the OneDrive HTTP 429 Response Code (Too Many Requests) - calling applyDifferences(driveId, idToQuery, performFullItemScan);");
applyDifferences(driveId, idToQuery, performFullItemScan);
// return back to original call
return;
log.vdebug("Retrying original request that generated the OneDrive HTTP 429 Response Code (Too Many Requests) - attempting to query changes from OneDrive using deltaLink");
}
// HTTP request returned status code 500 (Internal Server Error)
@ -945,18 +946,142 @@ final class SyncEngine
return;
}
// HTTP request returned status code 504 (Gateway Timeout)
if (e.httpStatusCode == 504) {
// Retry by calling applyDifferences() again
log.log("OneDrive returned a 'HTTP 504 - Gateway Timeout' - retrying request");
applyDifferences(driveId, idToQuery, performFullItemScan);
// HTTP request returned status code 504 (Gateway Timeout) or 429 retry
if ((e.httpStatusCode == 429) || (e.httpStatusCode == 504)) {
// If an error is returned when querying 'changes' and we recall the original function, we go into a never ending loop where the sync never ends
// re-try the specific changes queries
if (e.httpStatusCode == 504) {
log.log("OneDrive returned a 'HTTP 504 - Gateway Timeout' when attempting to query for changes - retrying applicable request");
log.vdebug("changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink) previously threw an error - retrying");
// The server, while acting as a proxy, did not receive a timely response from the upstream server it needed to access in attempting to complete the request.
log.vdebug("Thread sleeping for 30 seconds as the server did not receive a timely response from the upstream server it needed to access in attempting to complete the request");
Thread.sleep(dur!"seconds"(30));
log.vdebug("Retrying Query - using original deltaLink after delay");
}
// re-try original request - retried for 429 and 504
try {
log.vdebug("Retrying Query: changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink)");
changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink);
log.vdebug("Query 'changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink)' performed successfully on re-try");
} catch (OneDriveException e) {
// display what the error is
log.vdebug("Query Error: changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink) on re-try after delay");
if (e.httpStatusCode == 504) {
log.log("OneDrive returned a 'HTTP 504 - Gateway Timeout' when attempting to query for changes - retrying applicable request");
log.vdebug("changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink) previously threw an error - retrying with empty deltaLink");
try {
// try query with empty deltaLink value
changes = onedrive.viewChangesById(driveId, idToQuery, "");
log.vdebug("Query 'changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink)' performed successfully on re-try");
} catch (OneDriveException e) {
// Tried 3 times, give up
displayOneDriveErrorMessage(e.msg);
return;
}
} else {
// error was not a 504 this time
displayOneDriveErrorMessage(e.msg);
return;
}
}
} else {
// Default operation if not 404, 410, 429, 500 or 504 errors
// display what the error is
displayOneDriveErrorMessage(e.msg);
return;
}
}
// query for changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable);
try {
// Fetch the changes relative to the path id we want to query
// changes based on deltaLink
changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable);
if (changesAvailable.type() == JSONType.object) {
log.vdebug("Query 'changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable)' performed successfully");
}
} catch (OneDriveException e) {
// OneDrive threw an error
log.vdebug("------------------------------------------------------------------");
log.vdebug("Query Error: changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable)");
log.vdebug("driveId: ", driveId);
log.vdebug("idToQuery: ", idToQuery);
log.vdebug("deltaLink: ", deltaLink);
// HTTP request returned status code 404 (Not Found)
if (e.httpStatusCode == 404) {
// Stop application
log.log("\n\nOneDrive returned a 'HTTP 404 - Item not found'");
log.log("The item id to query was not found on OneDrive");
log.log("\nRemove your '", cfg.databaseFilePath, "' file and try to sync again\n");
return;
}
// HTTP request returned status code 410 (The requested resource is no longer available at the server)
if (e.httpStatusCode == 410) {
log.vlog("Delta link expired, re-syncing...");
deltaLink = null;
continue;
}
// HTTP request returned status code 429 (Too Many Requests)
if (e.httpStatusCode == 429) {
// HTTP request returned status code 429 (Too Many Requests). We need to leverage the response Retry-After HTTP header to ensure minimum delay until the throttle is removed.
handleOneDriveThrottleRequest();
log.vdebug("Retrying original request that generated the OneDrive HTTP 429 Response Code (Too Many Requests) - attempting to query changes from OneDrive using deltaLink");
}
// HTTP request returned status code 500 (Internal Server Error)
if (e.httpStatusCode == 500) {
// display what the error is
displayOneDriveErrorMessage(e.msg);
return;
}
// HTTP request returned status code 504 (Gateway Timeout) or 429 retry
if ((e.httpStatusCode == 429) || (e.httpStatusCode == 504)) {
// If an error is returned when querying 'changes' and we recall the original function, we go into a never ending loop where the sync never ends
// re-try the specific changes queries
if (e.httpStatusCode == 504) {
log.log("OneDrive returned a 'HTTP 504 - Gateway Timeout' when attempting to query for changes - retrying applicable request");
log.vdebug("changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable) previously threw an error - retrying");
// The server, while acting as a proxy, did not receive a timely response from the upstream server it needed to access in attempting to complete the request.
log.vdebug("Thread sleeping for 30 seconds as the server did not receive a timely response from the upstream server it needed to access in attempting to complete the request");
Thread.sleep(dur!"seconds"(30));
log.vdebug("Retrying Query - using original deltaLink after delay");
}
// re-try original request - retried for 429 and 504
try {
log.vdebug("Retrying Query: changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable)");
changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable);
log.vdebug("Query 'changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable)' performed successfully on re-try");
} catch (OneDriveException e) {
// display what the error is
log.vdebug("Query Error: changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable) on re-try after delay");
if (e.httpStatusCode == 504) {
log.log("OneDrive returned a 'HTTP 504 - Gateway Timeout' when attempting to query for changes - retrying applicable request");
log.vdebug("changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable) previously threw an error - retrying with empty deltaLinkAvailable");
try {
// try query with empty deltaLink value
changesAvailable = onedrive.viewChangesById(driveId, idToQuery, "");
log.vdebug("Query 'changesAvailable = onedrive.viewChangesById(driveId, idToQuery, deltaLinkAvailable)' performed successfully on re-try");
} catch (OneDriveException e) {
// Tried 3 times, give up
displayOneDriveErrorMessage(e.msg);
return;
}
} else {
// error was not a 504 this time
displayOneDriveErrorMessage(e.msg);
return;
}
}
} else {
// Default operation if not 404, 410, 429, 500 or 504 errors
// display what the error is
displayOneDriveErrorMessage(e.msg);
return;
}
}
// is changesAvailable a valid JSON response
@ -965,7 +1090,7 @@ final class SyncEngine
// are there any delta changes?
if (("value" in changesAvailable) != null) {
deltaChanges = count(changesAvailable["value"].array);
log.vdebug("deltaLink query reports that there are " , deltaChanges , " changes that need processing on OneDrive");
log.vdebug("changesAvailable query reports that there are " , deltaChanges , " changes that need processing on OneDrive");
}
}
@ -992,8 +1117,14 @@ final class SyncEngine
// unset now the full scan trigger if set
unsetOneDriveFullScanTrigger();
} else {
// no sync_list, no full scan was triggered
log.vlog("Processing ", nrChanges, " changes");
// no sync_list in use, oneDriveFullScanTrigger not set via sync_list or skip_dir
if (performFullItemScan){
// performFullItemScan was set
log.vlog("Processing ", nrChanges, " OneDrive items to ensure consistent local state due to a full scan being requested");
} else {
// default processing message
log.vlog("Processing ", nrChanges, " OneDrive items to ensure consistent local state");
}
}
} else {
// sync_list is being used - why are we going through the entire OneDrive contents?
@ -1010,14 +1141,14 @@ final class SyncEngine
// oneDriveFullScanTrigger should be false unless set by actions on OneDrive and only if sync_list or skip_dir is used
log.vdebug("performFullItemScan or oneDriveFullScanTrigger = true");
// full scan was requested or triggered
log.vdebug("Number of items from OneDrive to process due to a full scan being triggered: ", nrChanges);
log.vlog("Processing ", nrChanges, " OneDrive items to ensure consistent local state due to a full scan being requested");
// unset now the full scan trigger if set
if (oneDriveFullScanTrigger) {
unsetOneDriveFullScanTrigger();
}
} else {
// standard message
log.vdebug("Number of changes from OneDrive to process: ", nrChanges);
log.vlog("Number of items from OneDrive to process: ", nrChanges);
}
}
@ -1218,9 +1349,22 @@ final class SyncEngine
}
// the response may contain either @odata.deltaLink or @odata.nextLink
if ("@odata.deltaLink" in changes) deltaLink = changes["@odata.deltaLink"].str;
if (deltaLink) itemdb.setDeltaLink(driveId, id, deltaLink);
if ("@odata.nextLink" in changes) deltaLink = changes["@odata.nextLink"].str;
if ("@odata.deltaLink" in changes) {
deltaLink = changes["@odata.deltaLink"].str;
log.vdebug("Setting next deltaLink to (@odata.deltaLink): ", deltaLink);
}
if (deltaLink != "") {
// we initialise deltaLink to a blank string - if it is blank, dont update the DB to be empty
log.vdebug("Updating completed deltaLink in DB to: ", deltaLink);
itemdb.setDeltaLink(driveId, id, deltaLink);
}
if ("@odata.nextLink" in changes) {
// Update deltaLink to next changeSet bundle
deltaLink = changes["@odata.nextLink"].str;
// Update deltaLinkAvailable to next changeSet bundle to quantify how many changes we have to process
deltaLinkAvailable = changes["@odata.nextLink"].str;
log.vdebug("Setting next deltaLink & deltaLinkAvailable to (@odata.nextLink): ", deltaLink);
}
else break;
} else {
// Log that an invalid JSON object was returned
@ -4170,12 +4314,6 @@ final class SyncEngine
try {
changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink);
} catch (OneDriveException e) {
// OneDrive threw an error
log.vdebug("OneDrive threw an error when querying for these changes:");
log.vdebug("driveId: ", driveId);
log.vdebug("idToQuery: ", idToQuery);
log.vdebug("deltaLink: ", deltaLink);
if (e.httpStatusCode == 429) {
// HTTP request returned status code 429 (Too Many Requests). We need to leverage the response Retry-After HTTP header to ensure minimum delay until the throttle is removed.
handleOneDriveThrottleRequest();
@ -4185,6 +4323,12 @@ final class SyncEngine
// return back to original call
return;
} else {
// OneDrive threw an error
log.vdebug("Error query: changes = onedrive.viewChangesById(driveId, idToQuery, deltaLink)");
log.vdebug("OneDrive threw an error when querying for these changes:");
log.vdebug("driveId: ", driveId);
log.vdebug("idToQuery: ", idToQuery);
log.vdebug("deltaLink: ", deltaLink);
displayOneDriveErrorMessage(e.msg);
return;
}