Merge aeb751bc52 into a491620c1a

.gitignore

@@ -4,3 +4,4 @@ onedrive.o
 onedrive.service
 onedrive@.service
 version
+onedrive@.service

README.md

@@ -30,14 +30,14 @@ sudo apt install libsqlite3-dev
 curl -fsS https://dlang.org/install.sh | bash -s dmd
 ```
 
-### Dependencies: Fedora < Version 18 / CentOS / RHEL 
+### Dependencies: Fedora < Version 18 / CentOS / RHEL
 ```sh
 sudo yum install libcurl-devel
 sudo yum install sqlite-devel
 curl -fsS https://dlang.org/install.sh | bash -s dmd
 ```
 
-### Dependencies: Fedora > Version 18 
+### Dependencies: Fedora > Version 18
 ```sh
 sudo dnf install libcurl-devel
 sudo dnf install sqlite-devel
@@ -95,7 +95,7 @@ Example: If the full path is `~/OneDrive/mydir`, the command would be `onedrive
 ### Performing a 'one-way' sync
 In some cases it may be desirable to 'upload only' to OneDrive. To do this use the following command:
 ```
-onedrive --synchronize --upload-only 
+onedrive --synchronize --upload-only
 ```
 
 ### Increasing logging level
@@ -155,14 +155,14 @@ rm -f ~/.config/onedrive/refresh_token
 ```
 
 ## Additional Configuration
-Additional configuration is optional. 
+Additional configuration is optional.
 If you want to change the defaults, you can copy and edit the included config file into your `~/.config/onedrive` directory:
 ```sh
 mkdir -p ~/.config/onedrive
 cp ./config ~/.config/onedrive/config
 nano ~/.config/onedrive/config
 ```
-This file does not get created by default, and should only be created if you want to change the 'default' operational parameters. 
+This file does not get created by default, and should only be created if you want to change the 'default' operational parameters.
 
 Available options:
 * `sync_dir`: directory where the files will be synced

src/log.d

@@ -16,6 +16,9 @@ static this() {
 // enable verbose logging
 bool verbose;
 
+// enable debug logging
+bool debugging;
+
 void init()
 {
 	if (!exists(logFilePath)){
@@ -55,6 +58,15 @@ void vlog(T...)(T args)
 	}
 }
 
+void dlog(T...)(T args)
+{
+	if (debugging) {
+		writeln("[DEBUG] ", args);
+		// Write to log file
+		logfileWriteLine("[DEBUG] ", args);
+	}
+}
+
 void error(T...)(T args)
 {
 	stderr.writeln(args);

src/main.d

@@ -27,8 +27,6 @@ int main(string[] args)
 	bool resync;
 	// remove the current user and sync state
 	bool logout;
-	// enable verbose logging
-	bool verbose;
 	// print the access token
 	bool printAccessToken;
 	// print the version and exit
@@ -82,6 +80,7 @@ int main(string[] args)
 			"synchronize", "Perform a synchronization", &synchronize,
 			"upload-only", "Only upload to OneDrive, do not sync changes from OneDrive locally", &uploadOnly,
 			"verbose|v", "Print more details, useful for debugging", &log.verbose,
+			"debug", "Print even more details, useful for debugging", &log.debugging,
 			"version", "Print the version and exit", &printVersion
 		);
 		if (opt.helpWanted) {
@@ -290,7 +289,7 @@ int main(string[] args)
 					log.log(e.msg);
 				}
 			};
-			if (!downloadOnly) m.init(cfg, verbose);
+			if (!downloadOnly) m.init(cfg);
 			// monitor loop
 			immutable auto checkInterval = dur!"seconds"(45);
 			auto lastCheckTime = MonoTime.currTime();

src/monitor.d

@@ -21,7 +21,6 @@ class MonitorException: ErrnoException
 
 final class Monitor
 {
-	bool verbose;
 	// inotify file descriptor
 	private int fd;
 	// map every inotify watch descriptor to its directory
@@ -44,9 +43,8 @@ final class Monitor
 		this.selectiveSync = selectiveSync;
 	}
 
-	void init(Config cfg, bool verbose)
+	void init(Config cfg)
 	{
-		this.verbose = verbose;
 
 		fd = inotify_init();
 		if (fd == -1) throw new MonitorException("inotify_init failed");
@@ -64,6 +62,7 @@ final class Monitor
 	{
 		// skip filtered items
 		if (dirname != ".") {
+			log.dlog("monitor.addRecursive Checking '", dirname, "' for exclusion... ");
 			if (selectiveSync.isNameExcluded(baseName(dirname))) {
 				return;
 			}
@@ -85,7 +84,7 @@ final class Monitor
 		int wd = inotify_add_watch(fd, toStringz(dirname), mask);
 		if (wd == -1) {
                     if (errno() == ENOSPC) {
-                        log.log("The maximum number of inotify wathches is probably too low.");
+                        log.log("The maximum number of inotify watches is probably too low.");
                         log.log("");
                         log.log("To see the current max number of watches run");
                         log.log("");
@@ -152,58 +151,69 @@ final class Monitor
 
 			int i = 0;
 			while (i < length) {
+				bool skipped = false;
 				inotify_event *event = cast(inotify_event*) &buffer[i];
 				string path;
 
+				log.dlog("monitor.update event.mask: ", format("%#x", event.mask));
 				if (event.mask & IN_IGNORED) {
 					// forget the directory associated to the watch descriptor
+					log.dlog("monitor.update ignoring '", event.wd, "'");
 					wdToDirName.remove(event.wd);
-					goto skip;
+					skipped = true;
+					// goto skip;
 				} else if (event.mask & IN_Q_OVERFLOW) {
 					throw new MonitorException("Inotify overflow, events missing");
 				}
 
 				// skip filtered items
 				path = getPath(event);
+				log.dlog("monitor.update Checking '", path, "' for exclusion... ");
 				if (selectiveSync.isNameExcluded(baseName(path))) {
-					goto skip;
+					skipped = true;
+					// goto skip;
 				}
 				if (selectiveSync.isPathExcluded(path)) {
-					goto skip;
+					skipped = true;
+					// goto skip;
 				}
 
-				if (event.mask & IN_MOVED_FROM) {
-					cookieToPath[event.cookie] = path;
-				} else if (event.mask & IN_MOVED_TO) {
-					if (event.mask & IN_ISDIR) addRecursive(path);
-					auto from = event.cookie in cookieToPath;
-					if (from) {
-						cookieToPath.remove(event.cookie);
-						if (useCallbacks) onMove(*from, path);
-					} else {
-						// item moved from the outside
-						if (event.mask & IN_ISDIR) {
-							if (useCallbacks) onDirCreated(path);
+				if (!skipped) {
+					if (event.mask & IN_MOVED_FROM) {
+						cookieToPath[event.cookie] = path;
+					} else if (event.mask & IN_MOVED_TO) {
+						if (event.mask & IN_ISDIR) addRecursive(path);
+						auto from = event.cookie in cookieToPath;
+						if (from) {
+							cookieToPath.remove(event.cookie);
+							if (useCallbacks) onMove(*from, path);
 						} else {
+							// item moved from the outside
+							if (event.mask & IN_ISDIR) {
+								if (useCallbacks) onDirCreated(path);
+							} else {
+								if (useCallbacks) onFileChanged(path);
+							}
+						}
+					} else if (event.mask & IN_CREATE) {
+						if (event.mask & IN_ISDIR) {
+							addRecursive(path);
+							if (useCallbacks) onDirCreated(path);
+						}
+					} else if (event.mask & IN_DELETE) {
+						if (useCallbacks) onDelete(path);
+					} else if (event.mask & IN_ATTRIB || event.mask & IN_CLOSE_WRITE) {
+						if (!(event.mask & IN_ISDIR)) {
 							if (useCallbacks) onFileChanged(path);
 						}
+					} else {
+						log.log("Unknown inotify event: ", format("%#x", event.mask));
 					}
-				} else if (event.mask & IN_CREATE) {
-					if (event.mask & IN_ISDIR) {
-						addRecursive(path);
-						if (useCallbacks) onDirCreated(path);
-					}
-				} else if (event.mask & IN_DELETE) {
-					if (useCallbacks) onDelete(path);
-				} else if (event.mask & IN_ATTRIB || event.mask & IN_CLOSE_WRITE) {
-					if (!(event.mask & IN_ISDIR)) {
-						if (useCallbacks) onFileChanged(path);
-					}
-				} else {
-					log.log("Unknow inotify event: ", format("%#x", event.mask));
 				}
-
-				skip:
+				if (skipped) {
+					log.dlog("monitor.update Skipping '", path, "'");
+				}
+				// skip:
 				i += inotify_event.sizeof + event.len;
 			}
 			// assume that the items moved outside the watched directory has been deleted

src/sync.d

@@ -480,6 +480,7 @@ final class SyncEngine
 
 		bool unwanted;
 		unwanted |= skippedItems.find(item.parentId).length != 0;
+		log.dlog("sync.applyDifference testing name '", item.name, "'");	
 		unwanted |= selectiveSync.isNameExcluded(item.name);
 
 		// check the item type
@@ -504,6 +505,7 @@ final class SyncEngine
 			if (itemdb.idInLocalDatabase(item.driveId, item.parentId)){				
 				path = itemdb.computePath(item.driveId, item.parentId) ~ "/" ~ item.name;
 				path = buildNormalizedPath(path);
+				log.dlog("sync.applyDifference testing path '", path, "'");	
 				unwanted = selectiveSync.isPathExcluded(path);
 			} else {
 				unwanted = true;
@@ -728,9 +730,12 @@ final class SyncEngine
 		log.vlog("Processing ", item.name);
 
 		string path;
+
+		log.dlog("sync.uploadDifferences testing name '", item.name, "'");	
 		bool unwanted = selectiveSync.isNameExcluded(item.name);
 		if (!unwanted) {
 			path = itemdb.computePath(item.driveId, item.id);
+			log.dlog("sync.uploadDifferences testing path '", path, "'");	
 			unwanted = selectiveSync.isPathExcluded(path);
 		}
 
@@ -954,11 +959,11 @@ final class SyncEngine
 			// filter out user configured items to skip
 			if (path != ".") {
 				if (selectiveSync.isNameExcluded(baseName(path))) {
-					log.vlog("Skipping item - excluded by skip_file config: ", path);
+					log.dlog("sync.uploadNewItems Skipping item - excluded by skip_file config: ", path);
 					return;
 				}
 				if (selectiveSync.isPathExcluded(path)) {
-					log.vlog("Skipping item - path excluded: ", path);
+					log.dlog("sync.uploadNewItems Skipping item - path excluded: ", path);
 					return;
 				}
 			}

src/util.d

@@ -12,6 +12,7 @@ import std.string;
 import std.algorithm;
 import std.uri;
 import qxor;
+static import log;
 
 private string deviceName;
 
@@ -102,7 +103,7 @@ Regex!char wild2regex(const(char)[] pattern)
 			break;
 		case ' ':
 			str ~= "\\s+";
-			break;	
+			break;
 		case '/':
 			str ~= "\\/";
 			break;
@@ -112,6 +113,9 @@ Regex!char wild2regex(const(char)[] pattern)
 		}
 	}
 	str ~= "$";
+
+	log.dlog("Wild Card expression: ", pattern);
+	log.dlog("Regular Expression: ", str);
 	return regex(str, "i");
 }
 
@@ -145,7 +149,7 @@ bool isValidName(string path)
 	// Restriction and limitations about windows naming files
 	// https://msdn.microsoft.com/en-us/library/aa365247
 	// https://support.microsoft.com/en-us/help/3125202/restrictions-and-limitations-when-you-sync-files-and-folders
-	
+
 	// allow root item
 	if (path == ".") {
 		return true;
@@ -165,14 +169,14 @@ bool isValidName(string path)
 		);
 	auto m = match(itemName, invalidNameReg);
 	matched = m.empty;
-	
+
 	// Additional explicit validation checks
 	if (itemName == "Icon") {matched = false;}
 	if (itemName == ".lock") {matched = false;}
 	if (itemName == "desktop.ini") {matched = false;}
 	// _vti_ cannot appear anywhere in a file or folder name
 	if(canFind(itemName, "_vti_")){matched = false;}
-	
+
 	// return response
 	return matched;
 }
@@ -183,7 +187,7 @@ bool containsBadWhiteSpace(string path)
 	if (path == ".") {
 		return true;
 	}
-	
+
 	// https://github.com/abraunegg/onedrive/issues/35
 	// Issue #35 presented an interesting issue where the filename contained a newline item
 	//		'State-of-the-art, challenges, and open issues in the integration of Internet of'$'\n''Things and Cloud Computing.pdf'
@@ -191,9 +195,9 @@ bool containsBadWhiteSpace(string path)
 	//		/v1.0/me/drive/root:/.%2FState-of-the-art%2C%20challenges%2C%20and%20open%20issues%20in%20the%20integration%20of%20Internet%20of%0AThings%20and%20Cloud%20Computing.pdf
 	// The '$'\n'' is translated to %0A which causes the OneDrive query to fail
 	// Check for the presence of '%0A' via regex
-	
+
 	string itemName = encodeComponent(baseName(path));
-	
+
 	auto invalidWhitespaceReg =
 		ctRegex!(
 			// Check for \n which is %0A when encoded
@@ -202,7 +206,7 @@ bool containsBadWhiteSpace(string path)
 	auto m = match(itemName, invalidWhitespaceReg);
 
 	return m.empty;
-	
+
 }