Add more debug logs to replication

This commit is contained in:
Miroslav Bajtoš 2015-03-04 15:00:53 +01:00
parent 2885317634
commit b381c5df7e
2 changed files with 48 additions and 3 deletions

View File

@ -446,10 +446,13 @@ module.exports = function(Change) {
Change.prototype.debug = function() { Change.prototype.debug = function() {
if (debug.enabled) { if (debug.enabled) {
var args = Array.prototype.slice.call(arguments); var args = Array.prototype.slice.call(arguments);
args[0] = args[0] + ' %s';
args.push(this.modelName);
debug.apply(this, args); debug.apply(this, args);
debug('\tid', this.id); debug('\tid', this.id);
debug('\trev', this.rev); debug('\trev', this.rev);
debug('\tprev', this.prev); debug('\tprev', this.prev);
debug('\tcheckpoint', this.checkpoint);
debug('\tmodelName', this.modelName); debug('\tmodelName', this.modelName);
debug('\tmodelId', this.modelId); debug('\tmodelId', this.modelId);
debug('\ttype', this.type()); debug('\ttype', this.type());

View File

@ -8,6 +8,7 @@ var runtime = require('./runtime');
var assert = require('assert'); var assert = require('assert');
var async = require('async'); var async = require('async');
var deprecated = require('depd')('loopback'); var deprecated = require('depd')('loopback');
var debug = require('debug')('loopback:persisted-model');
/** /**
* Extends Model with basic query and CRUD support. * Extends Model with basic query and CRUD support.
@ -855,6 +856,15 @@ PersistedModel.replicate = function(since, targetModel, options, callback) {
if (err) throw err; if (err) throw err;
}; };
debug('replicating %s since %s to %s since %s',
sourceModel.modelName,
since.source,
targetModel.modelName,
since.target);
if (options.filter) {
debug('\twith filter %j', options.filter);
}
var tasks = [ var tasks = [
checkpoints, checkpoints,
getSourceChanges, getSourceChanges,
@ -866,17 +876,38 @@ PersistedModel.replicate = function(since, targetModel, options, callback) {
async.waterfall(tasks, done); async.waterfall(tasks, done);
function getSourceChanges(cb) { function getSourceChanges(cb) {
sourceModel.changes(since.source, options.filter, cb); sourceModel.changes(since.source, options.filter, debug.enabled ? log : cb);
function log(err, result) {
if (err) return cb(err);
debug('\tusing source changes');
result.forEach(function(it) { debug('\t\t%j', it); });
cb(err, result);
}
} }
function getDiffFromTarget(sourceChanges, cb) { function getDiffFromTarget(sourceChanges, cb) {
targetModel.diff(since.target, sourceChanges, cb); targetModel.diff(since.target, sourceChanges, debug.enabled ? log : cb);
function log(err, result) {
if (err) return cb(err);
if (result.conflicts && result.conflicts.length) {
debug('\tdiff conflicts');
result.conflicts.forEach(function(d) { debug('\t\t%j', d); });
}
if (result.deltas && result.deltas.length) {
debug('\tdiff deltas');
result.deltas.forEach(function(it) { debug('\t\t%j', it); });
}
cb(err, result);
}
} }
function createSourceUpdates(_diff, cb) { function createSourceUpdates(_diff, cb) {
diff = _diff; diff = _diff;
diff.conflicts = diff.conflicts || []; diff.conflicts = diff.conflicts || [];
if (diff && diff.deltas && diff.deltas.length) { if (diff && diff.deltas && diff.deltas.length) {
debug('\tbuilding a list of updates');
sourceModel.createUpdates(diff.deltas, cb); sourceModel.createUpdates(diff.deltas, cb);
} else { } else {
// nothing to replicate // nothing to replicate
@ -884,7 +915,9 @@ PersistedModel.replicate = function(since, targetModel, options, callback) {
} }
} }
function bulkUpdate(updates, cb) { function bulkUpdate(_updates, cb) {
debug('\tstarting bulk update');
updates = _updates;
targetModel.bulkUpdate(updates, cb); targetModel.bulkUpdate(updates, cb);
} }
@ -894,6 +927,9 @@ PersistedModel.replicate = function(since, targetModel, options, callback) {
newSourceCp = source.seq; newSourceCp = source.seq;
targetModel.checkpoint(function(err, target) { targetModel.checkpoint(function(err, target) {
newTargetCp = target.seq; newTargetCp = target.seq;
debug('\tcreated checkpoints');
debug('\t\t%s for source model %s', newSourceCp, sourceModel.modelName);
debug('\t\t%s for target model %s', newTargetCp, targetModel.modelName);
cb(err); cb(err);
}); });
}); });
@ -902,6 +938,12 @@ PersistedModel.replicate = function(since, targetModel, options, callback) {
function done(err) { function done(err) {
if (err) return callback(err); if (err) return callback(err);
debug('\treplication finished');
debug('\t\t%s conflict(s) detected', diff.conflicts.length);
debug('\t\t%s change(s) applied', updates && updates.length);
debug('\t\tnew checkpoints: { source: %j, target: %j }',
newSourceCp, newTargetCp);
var conflicts = diff.conflicts.map(function(change) { var conflicts = diff.conflicts.map(function(change) {
return new Change.Conflict( return new Change.Conflict(
change.modelId, sourceModel, targetModel change.modelId, sourceModel, targetModel