Improved sync reporting

ReactNativeClient/src/base-model.js

@@ -109,6 +109,12 @@ class BaseModel {
 		return options;
 	}
 
+	static count() {
+		return this.db().selectOne('SELECT count(*) as total FROM `' + this.tableName() + '`').then((r) => {
+			return r ? r['total'] : 0;
+		});
+	}
+
 	static load(id) {
 		return this.loadByField('id', id);
 	}
@@ -116,19 +122,19 @@ class BaseModel {
 	static modelSelectOne(sql, params = null) {
 		if (params === null) params = [];
 		return this.db().selectOne(sql, params).then((model) => {
-			return this.addModelMd(model);
+			return this.filter(this.addModelMd(model));
 		});
 	}
 
 	static modelSelectAll(sql, params = null) {
 		if (params === null) params = [];
 		return this.db().selectAll(sql, params).then((models) => {
-			return this.addModelMd(models);
+			return this.filterArray(this.addModelMd(models));
 		});
 	}
 
 	static loadByField(fieldName, fieldValue) {	
-		return this.modelSelectOne('SELECT * FROM ' + this.tableName() + ' WHERE `' + fieldName + '` = ?', [fieldValue]);
+		return this.modelSelectOne('SELECT * FROM `' + this.tableName() + '` WHERE `' + fieldName + '` = ?', [fieldValue]);
 	}
 
 	static applyPatch(model, patch) {
@@ -200,9 +206,10 @@ class BaseModel {
 
 	static save(o, options = null) {
 		options = this.modOptions(options);
-
 		options.isNew = options.isNew == 'auto' ? !o.id : options.isNew;
 
+		o = this.filter(o);
+
 		let queries = [];
 		let saveQuery = this.saveQuery(o, options);
 		let itemId = saveQuery.id;
@@ -242,7 +249,7 @@ class BaseModel {
 			o = Object.assign({}, o);
 			o.id = itemId;
 			o = this.addModelMd(o);
-			return o;
+			return this.filter(o);
 		}).catch((error) => {
 			Log.error('Cannot save model', error);
 		});
@@ -256,6 +263,18 @@ class BaseModel {
 		return this.db().exec('DELETE FROM deleted_items WHERE item_id = ?', [itemId]);
 	}
 
+	static filterArray(models) {
+		let output = [];
+		for (let i = 0; i < models.length; i++) {
+			output.push(this.filter(models[i]));
+		}
+		return output;
+	}
+
+	static filter(model) {
+		return model;
+	}
+
 	static delete(id, options = null) {
 		options = this.modOptions(options);
 

ReactNativeClient/src/database-driver-node.js

@@ -15,7 +15,7 @@ class DatabaseDriverNode {
 		});
 	}
 
-	setDebugEnabled(v) {
+	setDebugMode(v) {
 		// ??
 	}
 

ReactNativeClient/src/database-driver-react-native.js

@@ -13,8 +13,8 @@ class DatabaseDriverReactNative {
 		});
 	}
 
-	setDebugEnabled(v) {
-		SQLite.DEBUG(v);
+	setDebugMode(v) {
+		//SQLite.DEBUG(v);
 	}
 
 	selectOne(sql, params = null) {

ReactNativeClient/src/database.js

@@ -141,8 +141,8 @@ class Database {
 		return this.logger_;
 	}
 
-	setDebugEnabled(v) {
-		this.driver_.setDebugEnabled(v);
+	setDebugMode(v) {
+		//this.driver_.setDebugMode(v);
 		this.debugMode_ = v;
 	}
 
@@ -283,6 +283,7 @@ class Database {
 
 	logQuery(sql, params = null) {
 		if (!this.debugMode()) return;
+
 		if (params !== null) {
 			this.logger().debug('DB: ' + sql, JSON.stringify(params));
 		} else {

ReactNativeClient/src/models/note.js

@@ -74,6 +74,16 @@ class Note extends BaseItem {
 		});
 	}
 
+	static filter(note) {
+		if (!note) return note;
+
+		let output = Object.assign({}, note);
+		if ('longitude' in output) output.longitude = Number(!output.longitude ? 0 : output.longitude).toFixed(8);
+		if ('latitude' in output) output.latitude = Number(!output.latitude ? 0 : output.latitude).toFixed(8);
+		if ('altitude' in output) output.altitude = Number(!output.altitude ? 0 : output.altitude).toFixed(4);
+		return output;
+	}
+
 	static all(parentId) {
 		return this.modelSelectAll('SELECT * FROM notes WHERE is_conflict = 0 AND parent_id = ?', [parentId]);
 	}

ReactNativeClient/src/root.js

@@ -192,7 +192,7 @@ class AppComponent extends React.Component {
 	componentDidMount() {
 		let db = new Database(new DatabaseDriverReactNative());
 		//db.setDebugEnabled(Registry.debugMode());
-		db.setDebugEnabled(false);
+		db.setDebugMode(false);
 
 		BaseModel.dispatch = this.props.dispatch;
 		BaseModel.db_ = db;

ReactNativeClient/src/synchronizer.js

@@ -12,12 +12,17 @@ import moment from 'moment';
 class Synchronizer {
 
 	constructor(db, api) {
+		this.state_ = 'idle';
 		this.db_ = db;
 		this.api_ = api;
 		this.syncDirName_ = '.sync';
 		this.logger_ = new Logger();
 	}
 
+	state() {
+		return this.state_;
+	}
+
 	db() {
 		return this.db_;
 	}
@@ -34,6 +39,38 @@ class Synchronizer {
 		return this.logger_;
 	}
 
+	logSyncOperation(action, local, remote, reason) {
+		let line = ['Sync'];
+		line.push(action);
+		line.push(reason);
+
+		if (local) {
+			let s = [];
+			s.push(local.id);
+			if ('title' in local) s.push('"' + local.title + '"');
+			line.push('(Local ' + s.join(', ') + ')');
+		}
+
+		if (remote) {
+			let s = [];
+			s.push(remote.id);
+			if ('title' in remote) s.push('"' + remote.title + '"');
+			line.push('(Remote ' + s.join(', ') + ')');
+		}
+
+		this.logger().debug(line.join(': '));
+	}
+
+	async logSyncSummary(report) {
+		for (let n in report) {
+			this.logger().info(n + ': ' + (report[n] ? report[n] : '-'));
+		}
+		let folderCount = await Folder.count();
+		let noteCount = await Note.count();
+		this.logger().info('Total folders: ' + folderCount);
+		this.logger().info('Total notes: ' + noteCount);
+	}
+
 	async createWorkDir() {
 		if (this.syncWorkDir_) return this.syncWorkDir_;
 		let dir = await this.api().mkdir(this.syncDirName_);
@@ -41,12 +78,31 @@ class Synchronizer {
 	}
 
 	async start() {
+		if (this.state() != 'idle') {
+			this.logger().warn('Synchronization is already in progress. State: ' + this.state());
+			return;
+		}	
+
 		// ------------------------------------------------------------------------
 		// First, find all the items that have been changed since the
 		// last sync and apply the changes to remote.
 		// ------------------------------------------------------------------------
 
-		this.logger().info('Starting synchronization...');
+		let synchronizationId = time.unixMs().toString();
+		this.logger().info('Starting synchronization... [' + synchronizationId + ']');
+
+		this.state_ = 'started';
+
+		let report = {
+			createLocal: 0,
+			updateLocal: 0,
+			deleteLocal: 0,
+			createRemote: 0,
+			updateRemote: 0,
+			deleteRemote: 0,
+			folderConflict: 0,
+			noteConflict: 0,
+		};
 
 		await this.createWorkDir();
 
@@ -67,13 +123,16 @@ class Synchronizer {
 				let content = ItemClass.serialize(local);
 				let action = null;
 				let updateSyncTimeOnly = true;
+				let reason = '';
 
 				if (!remote) {
 					if (!local.sync_time) {
 						action = 'createRemote';
+						reason = 'remote does not exist, and local is new and has never been synced';
 					} else {
 						// Note or folder was modified after having been deleted remotely
 						action = local.type_ == BaseModel.MODEL_TYPE_NOTE ? 'noteConflict' : 'folderConflict';
+						reason = 'remote has been deleted, but local has changes';
 					}
 				} else {
 					if (remote.updated_time > local.sync_time) {
@@ -81,18 +140,20 @@ class Synchronizer {
 						// remote has been modified after the sync time, it means both notes have been
 						// modified and so there's a conflict.
 						action = local.type_ == BaseModel.MODEL_TYPE_NOTE ? 'noteConflict' : 'folderConflict';
+						reason = 'both remote and local have changes';
 					} else {
 						action = 'updateRemote';
+						reason = 'local has changes';
 					}
 				}
 
-				this.logger().debug('Sync action (1): ' + action);
+				this.logSyncOperation(action, local, remote, reason);
 
 				if (action == 'createRemote' || action == 'updateRemote') {
 
 					// Make the operation atomic by doing the work on a copy of the file
 					// and then copying it back to the original location.
-					let tempPath = this.syncDirName_ + '/' + path;
+					let tempPath = this.syncDirName_ + '/' + path + '_' + time.unixMs();
 					
 					await this.api().put(tempPath, content);
 					await this.api().setTimestamp(tempPath, local.updated_time);
@@ -131,6 +192,8 @@ class Synchronizer {
 
 				}
 
+				report[action]++;
+
 				donePaths.push(path);
 			}
 
@@ -145,9 +208,11 @@ class Synchronizer {
 		for (let i = 0; i < deletedItems.length; i++) {
 			let item = deletedItems[i];
 			let path = BaseItem.systemPath(item.item_id)
-			this.logger().debug('Sync action (2): deleteRemote');
+			this.logSyncOperation('deleteRemote', null, { id: item.item_id }, 'local has been deleted');
 			await this.api().delete(path);
 			await BaseModel.remoteDeletedItem(item.item_id);
+
+			report['deleteRemote']++;
 		}
 
 		// ------------------------------------------------------------------------
@@ -172,33 +237,37 @@ class Synchronizer {
 			let local = await BaseItem.loadItemByPath(path);
 			if (!local) {
 				action = 'createLocal';
-				reason = 'Local exists but remote does not';
+				reason = 'remote exists but local does not';
 			} else {
 				if (remote.updated_time > local.updated_time) {
 					action = 'updateLocal';
-					reason = sprintf('Remote (%s) is more recent than local (%s)', time.unixMsToIso(remote.updated_time), time.unixMsToIso(local.updated_time));
+					reason = sprintf('remote is more recent than local'); // , time.unixMsToIso(remote.updated_time), time.unixMsToIso(local.updated_time)
 				}
 			}
 
 			if (!action) continue;
 
-			this.logger().debug('Sync action (3): ' + action);
-			this.logger().debug('Reason: ' + reason);
-
 			if (action == 'createLocal' || action == 'updateLocal') {
 				let content = await this.api().get(path);
 				if (!content) {
-					this.logger().warn('Remote item has been deleted between now and the list() call? In that case it will handled during the next sync: ' + path);
+					this.logger().warn('Remote has been deleted between now and the list() call? In that case it will be handled during the next sync: ' + path);
 					continue;
 				}
 				content = BaseItem.unserialize(content);
 				let ItemClass = BaseItem.itemClass(content);
 
-				content.sync_time = time.unixMs();
+				let newContent = Object.assign({}, content);
+				newContent.sync_time = time.unixMs();
 				let options = { autoTimestamp: false };
 				if (action == 'createLocal') options.isNew = true;
-				await ItemClass.save(content, options);
+				await ItemClass.save(newContent, options);
+
+				this.logSyncOperation(action, local, content, reason);
+			} else {
+				this.logSyncOperation(action, local, remote, reason);
 			}
+
+			report[action]++;
 		}
 
 		// ------------------------------------------------------------------------
@@ -208,14 +277,18 @@ class Synchronizer {
 
 		let noteIds = await Folder.syncedNoteIds();
 		for (let i = 0; i < noteIds.length; i++) {
-			if (remoteIds.indexOf(noteIds[i]) < 0) {
-				this.logger().debug('Sync action (4): deleteLocal: ' + noteIds[i]);
-				await Note.delete(noteIds[i], { trackDeleted: false });
+			let noteId = noteIds[i];
+			if (remoteIds.indexOf(noteId) < 0) {
+				this.logSyncOperation('deleteLocal', { id: noteId }, null, 'remote has been deleted');
+				await Note.delete(noteId, { trackDeleted: false });
+				report['deleteLocal']++;
 			}
 		}
 
-		// Number of sync items (Created, updated, deleted Local/Remote)
-		// Total number of items
+		this.logger().info('Synchronization complete [' + synchronizationId + ']:');
+		await this.logSyncSummary(report);
+
+		this.state_ = 'idle';
 
 		return Promise.resolve();
 	}