PIM: enhanced progress notifications (FDO #72114)

This adds GetPeerStatus() and "progress" events.

To detect DB changes as they happen, the SyncSource operations are
monitored. Upon entry, a counter gets increased and transmitted
through to the PIM manager in syncevo-dbus-server using extended
SourceProgress structs (only visible internally - public API must not
be extended!). This will count operations which fail and count those
twice which get resumed, so the counts will be too high
occasionally. That is in line with the API definition; because it is
not exact, the API only exposes a "modified" flag.

Progress is reported based on the "item received" Synthesis event and
the total item count. A modified libsynthesis is needed where the
SyncML binfile client on the target side of the local sync actually
sends the total item count (via NumberOfChanges). This cannot be done
yet right at the start of the sync, only the second SyncML message
will have it. That is acceptable, because completion is reached very
quickly anyway for syncs involving only one message.

At the moment, SyncContext::displaySourceProgress() holds back "item
received" events until a different event needs to be emitted. Progress
reporting might get more fine-grained when adding allowing held back
events to be emitted at a fixed rate, every 0.1s. This is not done yet
because it seems to work well enough already.

For testing and demonstration purposes, sync.py gets command line
arguments for setting progress frequency and showing progress either
via listening to signals or polling.
This commit is contained in:
Patrick Ohly 2014-01-30 21:02:10 +01:00
parent d7b7f6dc35
commit 3c01a1ebf6
15 changed files with 519 additions and 32 deletions

View File

@ -164,6 +164,16 @@ bool DBusSync::displaySourceProgress(SyncSource &source,
{
bool cached = SyncContext::displaySourceProgress(source, event, flush);
if (!cached) {
// Tell parent about current source statistics directly before
// PEV_ITEMRECEIVED. The PIM Manager relies on that extra
// information.
if (event.m_type == sysync::PEV_ITEMRECEIVED) {
m_helper.emitSourceProgress(sysync::PEV_ITEMPROCESSED, source.getName(),
source.getFinalSyncMode(),
source.getAdded(),
source.getUpdated(),
source.getDeleted());
}
m_helper.emitSourceProgress(event.m_type, source.getName(), source.getFinalSyncMode(),
event.m_extra1, event.m_extra2, event.m_extra3);
}

View File

@ -346,6 +346,8 @@ photo later.
Additional control over syncing is possible via the flags dictionary
in SyncPeerWithFlags(). The following keys are possible:
"progress-frequency": double - desired frequency in Hz (= events
per second) of the SyncProgress "progress" event. Default is 1/s.
"pbap-sync": string "text"|"all"|"incremental" - synchronize only
text properties, all properties or first text, then all. The default is
taken from SYNCEVOLUTION_PBAP_SYNC if set, otherwise it is "incremental".
@ -357,12 +359,73 @@ behaves like a single sync of the peer.
The SyncProgress is triggered by SyncEvolution with three different
keys (in this order, with "modified" occuring zero or more times):
"started" "modified"* "done"
"started" ("modified" | "progress")* "done"
"started" and "done" send an empty data dictionary. "modified" sends
the same dictionary as the one returned by SyncPeer(), if contact data
was modified. So by definition, "modified" will be True in the
dictionary, but is included anyway for the sake of consistency.
the same dictionary as the one returned by SyncPeer(), if and only if
contact data was modified. So by definition, "modified" will be True
in the dictionary, but is included anyway for the sake of consistency.
"progress" sends a dictionary with these keys:
- "percent": double - value from 0 (start of sync) to 1 (end of sync)
- "modified": undefined value - set if the database was modified since the
last "progress" event. Detecting the exact moment when a change is made can
be hard, so the implementation may err on the side of caution and
signal a change more often than strictly necessary. The recipient must
check the database anyway to determine what changed. The value is
intentionally undefined at the moment and the recipient must not make
assumptions about it. Instead it should just check for the presence
of the entry. In the future, more specific information about what was
modified might be included as value.
- "sync-cycle": string - describes in what phase the sync is at the moment,
see "pbap-sync" in SyncPeerWithFlags()
- "text" - text-only sync active
- "all" - non-incremental text and picture sync active
- "incremental-text" - incremental sync active, currently syncing text
- "incremental-picture" - incremental sync active, done with text, now syncing pictures
- "" - some other kind of sync (non-PBAP, for example)
"progress" is guaranteed to be emitted at the end of each cycle. In
contrast to "modified", it will also be sent throughout the sync *if
and only if* progress has been made, regardless whether that progress
led to contact data changes or an increase in the completion
percentage. That way, the event also serves as a heartbeat mechanism.
The completion percentage is based purely on the number of contacts on
the peer, which is the only thing known about the peer at the start of
a sync. In a simple sync involving just one cycle, the percentage is
"number of processed contacts / total contacts".
In a sync involving two cycles, it is "number of processed contacts /
2 / total contacts". Because each contact gets processed once per
cycle, that gives 50% completion at the end of the first cycle and
100% at the end of the second.
Note that progress will not be linear over time even for a simple
sync, because some contacts will take more time to download and
process than others. For an incremental sync, the first cycle is
likely to be much faster than the second one because the second one
includes photo data.
Progress events get emitted at the time when progress is made. If that
is too close in time to the last progress event (see
"progress-frequency"), the event is skipped. Events are not simply
sent at regular intervals because that would emit events even when
syncing is not making progress and distort the timing information (for
example, 50% reached and recorded at time t, actual event with 50%
sent at t + delta). In practice, the number of progress events is
limited by various chunk sizes in the implementation (internal SyncML
message size, amount of new data that must come in via PBAP before
processing it), leading to a refresh rate during Bluetooth transfers
which is closer to every two seconds.
GetPeerStatus() returns two additional entries in the dictionary:
"progress": same dictionary as the SyncProgress "progress" value
"last-progress": double - time in seconds since the last "progress"
event. This is included to let a polling client determine whether
the sync is still alive.
Contact Data

View File

@ -36,8 +36,19 @@ import functools
import sys
import traceback
import itertools
import time
from optparse import OptionParser
# Needed for --poll-progress.
glib = None
try:
import glib
except ImportError:
try:
from gi.repository import GLib as glib
except ImportError:
pass
parser = OptionParser()
parser.add_option("-b", "--bt-mac", dest="mac",
default=None,
@ -46,6 +57,18 @@ parser.add_option("-b", "--bt-mac", dest="mac",
parser.add_option("-d", "--debug",
action="store_true", default=False,
help="Print debug output coming from SyncEvolution server.")
parser.add_option("-p", "--progress",
action="store_true", default=False,
help="Print progress information during a sync, triggered by PIM Manager signals.")
parser.add_option("", "--poll-progress",
action="store", type="float", default=None,
help="Print progress information during a sync, pulled via polling at the given frequency.")
parser.add_option("-m", "--mode",
action="store", default='',
help="Override default PBAP sync mode. One of 'all', 'text', 'incremental' (default).")
parser.add_option("-f", "--progress-frequency",
action="store", type="float", default=0.0,
help="Override default progress event frequency.")
parser.add_option("-c", "--configure",
action="store_true", default=False,
help="Enable configuring the peer.")
@ -76,12 +99,47 @@ manager = dbus.Interface(bus.get_object('org._01.pim.contacts',
# Capture and print debug output.
def log_output(path, level, output, component):
print '%s %s: %s' % (level, (component or 'sync'), output)
# Format seconds as mm:ss[.mmm].
def format_seconds(seconds, with_milli):
if with_milli:
format = '%02d:%06.3f'
else:
format = '%02d:%02d'
return format % (seconds / 60, seconds % 60)
# Keep track of time when progress messages were received.
last = time.time()
start = last
BAR_LENGTH = 20
def log_progress(uid, event, data):
global last, start
now = time.time()
prefix = '%s/+%s:' % (format_seconds(now - start, False),
format_seconds(now - last, True))
if event == 'progress':
percent = data['percent']
del data['percent']
bar = int(percent * BAR_LENGTH) * '-'
if len(bar) > 0 and len(bar) < BAR_LENGTH:
bar = bar[0:-1] + '>'
print prefix, '|%s%s| %.1f%% %s' % (bar, (BAR_LENGTH - len(bar)) * ' ', percent * 100, strip_dbus(data))
else:
print prefix, '%s = %s' % (event, strip_dbus(data))
last = now
if options.debug:
bus.add_signal_receiver(log_output,
"LogOutput",
"org.syncevolution.Server",
"org.syncevolution",
None)
if options.progress:
bus.add_signal_receiver(log_progress,
"SyncProgress",
"org._01.pim.contacts.Manager",
"org._01.pim.contacts",
None)
# Simplify the output of values returned via D-Bus by replacing
# types like dbus.Dictionary with a normal Python dictionary
@ -168,11 +226,41 @@ if not error and options.configure:
manager.SetPeer(peername, peer, **async_args)
run()
def pull_progress():
status = manager.GetPeerStatus(peername)
print 'Poll status:', strip_dbus(status)
return True
if not error and options.sync:
# Do it once before starting the sync.
if options.poll_progress is not None:
pull_progress()
print 'syncing peer %s' % peername
manager.SyncPeer(peername, **async_args)
flags = {}
if options.progress_frequency != 0.0:
flags['progress-frequency'] = options.progress_frequency
if options.mode:
flags['pbap-sync'] = options.mode
if flags:
manager.SyncPeerWithFlags(peername, flags, **async_args)
else:
manager.SyncPeer(peername, **async_args)
# Start regular polling of status.
timeout = None
if options.poll_progress is not None:
timeout = glib.Timeout(int(1 / options.poll_progress * 1000))
timeout.set_callback(pull_progress)
timeout.attach(loop.get_context())
# Wait for completion of sync.
run()
# Stop polling, in case that remove the peer.
if timeout:
timeout.destroy()
if not error and options.remove:
print 'removing peer %s' % peername
manager.RemovePeer(peername, **async_args)

View File

@ -157,6 +157,7 @@ void Manager::init()
add(this, &Manager::syncPeer, "SyncPeer");
add(this, &Manager::syncPeerWithFlags, "SyncPeerWithFlags");
add(this, &Manager::stopSync, "StopSync");
add(this, &Manager::getPeerStatus, "GetPeerStatus");
add(this, &Manager::getAllPeers, "GetAllPeers");
add(this, &Manager::addContact, "AddContact");
add(this, &Manager::modifyContact, "ModifyContact");
@ -1264,6 +1265,99 @@ void Manager::doSetPeer(const boost::shared_ptr<Session> &session,
result->done();
}
static Manager::SyncResult SourceProgress2SyncProgress(Session *session,
int32_t percent,
const Session::SourceProgresses_t &progress)
{
Manager::SyncResult result;
// As default, always trust the normal completion computation.
// PBAP syncing is handled as special case below.
result["percent"] = (double)percent / 100;
// Non-PBAP sync as default, with empty string as default.
Manager::SyncResult::mapped_type &syncCycle = result["sync-cycle"];
syncCycle = std::string("");
// It should have the well-known source.
static const std::string name = MANAGER_LOCAL_SOURCE;
Session::SourceProgresses_t::const_iterator it;
if ((it = progress.find(name)) != progress.end()) {
const SourceProgress &source = it->second;
Session::SourceProgresses_t last;
session->getLastProgress(last);
Session::SourceProgresses_t::iterator it = last.find(name);
if ((source.m_added > 0 || source.m_updated > 0 || source.m_deleted > 0) &&
(it == last.end() ||
source.m_added != it->second.m_added ||
source.m_updated != it->second.m_updated ||
source.m_deleted != it->second.m_deleted)) {
// Create the entry. We don't specify what it contains and "None" would
// be best, but boost::variant cannot be empty and void is not supported
// by our D-Bus wrapper, so set it to 'true'.
result["modified"] = true;
}
if (session->getSyncMode() == "pbap") {
StringMap env = session->getSyncEnv();
StringMap::const_iterator var = env.find("SYNCEVOLUTION_PBAP_SYNC");
int cycles = (var != env.end() && var->second == "incremental") ? 2 : 1;
double percent = 0;
SyncSourceReport report;
if (cycles == 2 && session->getSyncSourceReport(name, report)) {
// Done first cycle.
percent = 0.5;
syncCycle = std::string("incremental-picture");
} else if (cycles == 2) {
syncCycle = std::string("incremental-text");
} else if (var != env.end() && var->second == "text") {
syncCycle = std::string("text");
} else {
syncCycle = std::string("all");
}
if (source.m_receiveTotal > 0 && source.m_phase == "receiving") {
percent += (double)source.m_receiveCount / (cycles * source.m_receiveTotal);
}
result["percent"] = percent;
}
}
return result;
}
Manager::PeerStatus Manager::getPeerStatus(const std::string &uid)
{
checkPeerUID(uid);
PeerStatus status;
// Idle unless we find a running session.
status["status"] = "idle";
// Same logic as in stopPeer().
std::string syncConfigName = StringPrintf("%s@%s%s",
MANAGER_LOCAL_CONFIG,
MANAGER_PREFIX,
uid.c_str());
boost::shared_ptr<Session> session = m_server->getSyncSession();
if (session) {
std::string configName = session->getConfigName();
if (configName == syncConfigName) {
status["status"] = "syncing";
int32_t percent;
Session::SourceProgresses_t sources;
session->getProgress(percent, sources);
status["progress"] = SourceProgress2SyncProgress(session.get(),
percent,
sources);
status["last-progress"] = (Timespec::monotonic() - session->getLastProgressTimestamp()).duration();
}
}
return status;
}
Manager::PeersMap Manager::getAllPeers()
{
PeersMap peers;
@ -1448,6 +1542,9 @@ void Manager::doSyncPeer(const boost::shared_ptr<Session> &session,
emitSyncProgress(uid, "started", SyncResult());
session->m_doneSignal.connect(boost::bind(boost::ref(emitSyncProgress), uid, "done", SyncResult()));
session->m_sourceSynced.connect(boost::bind(&Manager::report2SyncProgress, m_self, uid, _1, _2));
// React *before* Session updates its value for getLastProgress(). */
session->m_progressSignal.connect(boost::bind(&Manager::progress2SyncProgress, m_self, uid, session.get(), _1, _2),
boost::signals2::at_front);
// Determine sync mode. "pbap" is valid only when the remote
// source uses the PBAP backend. Otherwise we use "ephemeral",
@ -1473,11 +1570,27 @@ void Manager::doSyncPeer(const boost::shared_ptr<Session> &session,
SE_THROW(StringPrintf("SyncPeerWithFlags flag 'pbap-sync' expects one of 'text', 'all', or 'incremental': %s", value->c_str()));
}
env["SYNCEVOLUTION_PBAP_SYNC"] = *value;
} else if (entry.first == "progress-frequency") {
const double *value = boost::get<const double>(&entry.second);
if (!value) {
SE_THROW(StringPrintf("SyncPeerWithFlags flag 'progress-frequency' expects a double value"));
}
if (*value <= 0) {
SE_THROW(StringPrintf("SyncPeerWithFlags flag 'progress-frequency' must be a positive, non-zero frequency value (Hz): %lf", *value));
}
// Configure session progress frequency.
session->setProgressTimeout(1 / *value * 1000 /* ms */);
} else {
SE_THROW(StringPrintf("invalid SyncPeerWithFlags flag: %s", entry.first.c_str()));
}
}
// Always be explicit about the PBAP sync mode. Needed to have syncing
// and PIM Manager aligned on the exact mode.
if (env.find("SYNCEVOLUTION_PBAP_SYNC") == env.end()) {
env["SYNCEVOLUTION_PBAP_SYNC"] = getEnv("SYNCEVOLUTION_PBAP_SYNC", "incremental");
}
// After sync(), the session is tracked as the active sync session
// by the server. It was removed from our own m_pending list by
// doSession().
@ -1495,6 +1608,14 @@ void Manager::report2SyncProgress(const std::string &uid,
emitSyncProgress(uid, "modified", SyncReport2Result(report));
}
void Manager::progress2SyncProgress(const std::string &uid,
Session *session,
int32_t percent,
const Session::SourceProgresses_t &progress)
{
emitSyncProgress(uid, "progress", SourceProgress2SyncProgress(session, percent, progress));
}
void Manager::stopSync(const boost::shared_ptr<GDBusCXX::Result0> &result,
const std::string &uid)
{

View File

@ -143,12 +143,12 @@ class Manager : public GDBusCXX::DBusObjectHelper
const std::string &uid);
public:
typedef std::map<std::string, boost::variant<bool, int> > SyncResult;
typedef std::map<std::string, boost::variant<bool, int, double, std::string> > SyncResult;
/** Manager.SyncPeer() */
void syncPeer(const boost::shared_ptr<GDBusCXX::Result1<SyncResult> > &result,
const std::string &uid);
typedef std::map<std::string, boost::variant<std::string> > SyncFlags;
typedef std::map<std::string, boost::variant<std::string, double> > SyncFlags;
/** Manager.SyncPeerWithFlags() */
void syncPeerWithFlags(const boost::shared_ptr<GDBusCXX::Result1<SyncResult> > &result,
const std::string &uid,
@ -169,12 +169,20 @@ class Manager : public GDBusCXX::DBusObjectHelper
void report2SyncProgress(const std::string &uid,
const std::string &sourceName,
const SyncSourceReport &source);
void progress2SyncProgress(const std::string &uid,
Session *session,
int32_t percent,
const Session::SourceProgresses_t &progress);
public:
/** Manager.StopSync() */
void stopSync(const boost::shared_ptr<GDBusCXX::Result0> &result,
const std::string &uid);
typedef std::map<std::string, boost::variant<std::string, SyncResult, double> > PeerStatus;
/** Manager.GetPeerStatus() */
PeerStatus getPeerStatus(const std::string &uid);
typedef std::map<std::string, StringMap> PeersMap;
/** Manager.GetAllPeers() */
PeersMap getAllPeers();

View File

@ -51,6 +51,10 @@ address book. That information is passed via D-Bus as a
string-to-string dict, with keys and their values being defined by the
implementation.
For the sake of API and implementation simplicity, a peer can have
only one running sync at a time. The API uses the peer ID for
information about such a running sync (see "SyncProgress" signal).
Address books
-------------
@ -266,6 +270,18 @@ Methods:
which started such a sync will return with an "aborted" error
once the sync was stopped.
dict GetPeerStatus(string uid)
Returns information about the peer and its sync status. The returned
dictionary contains:
"status": string "idle", "syncing" - describes whether
a sync is currently running. Idle means "no active sync"; there might
be a pending SyncPeer().
Implementations can also provide information similar to the data
provided by the SyncProgress signal.
dict of UID to string key/value dict GetAllPeers()
Returns information about all currently configured peers.

View File

@ -836,7 +836,7 @@ XDG root.
pass
syncProgress = []
signal = bus.add_signal_receiver(lambda uid, event, data: (logging.printf('received SyncProgress: %s, %s, %s', uid, event, data), syncProgress.append((uid, event, data)), logging.printf('progress %s' % syncProgress)),
signal = bus.add_signal_receiver(lambda uid, event, data: (logging.printf('received SyncProgress: %s, %s, %s', self.stripDBus(uid, sortLists=False), self.stripDBus(event, sortLists=False), self.stripDBus(data, sortLists=False)), syncProgress.append((uid, event, data)), logging.printf('progress %s' % self.stripDBus(syncProgress, sortLists=False))),
'SyncProgress',
'org._01.pim.contacts.Manager',
None, #'org._01.pim.contacts',
@ -852,7 +852,7 @@ XDG root.
progress.append((uid, 'modified', intermediateResult))
progress.append((uid, 'modified', expectedResult))
progress.append((uid, 'done', {}))
self.assertEqual(progress, syncProgress)
self.assertEqual(progress, [(u, e, d) for u, e, d in syncProgress if e != 'progress'])
# Must be the Bluetooth MAC address (like A0:4E:04:1E:AD:30)
@ -1136,14 +1136,14 @@ END:VCARD
'removed': 0}
syncProgress = []
result = self.manager.SyncPeerWithFlags(uid, { 'pbap-sync': 'text' })
duration, result = timeFunction(self.manager.SyncPeerWithFlags, uid, { 'pbap-sync': 'text' })
# TODO: check that we actually do text-only sync
checkSync(expectedResult,
result,
None)
syncProgress = []
result = self.manager.SyncPeerWithFlags(uid, { 'pbap-sync': 'all' })
duration, result = timeFunction(self.manager.SyncPeerWithFlags, uid, { 'pbap-sync': 'all' })
expectedResult = {'modified': False,
'added': 0,
'updated': 0,
@ -1154,7 +1154,7 @@ END:VCARD
None)
syncProgress = []
result = self.manager.SyncPeerWithFlags(uid, { 'pbap-sync': 'incremental' })
duration, result = timeFunction(self.manager.SyncPeerWithFlags, uid, { 'pbap-sync': 'incremental' })
expectedResult = {'modified': False,
'added': 0,
'updated': 0,

View File

@ -375,6 +375,9 @@ void Session::syncExtended(const std::string &mode, const SessionCommon::SourceM
SE_THROW_EXCEPTION(InvalidCall, "session is not active, call not allowed at this time");
}
m_syncMode = mode;
m_syncEnv = env;
// Turn session into "running sync" now, before returning to
// caller. Starting the helper (if needed) and making it
// execute the sync is part of "running sync".
@ -513,6 +516,14 @@ void Session::getStatus(std::string &status,
sources = m_sourceStatus;
}
void Session::getAPIProgress(int32_t &progress,
APISourceProgresses_t &sources)
{
PushLogger<Logger> guard(m_me);
progress = m_progData.getProgress();
sources = m_sourceProgress;
}
void Session::getProgress(int32_t &progress,
SourceProgresses_t &sources)
{
@ -521,6 +532,17 @@ void Session::getProgress(int32_t &progress,
sources = m_sourceProgress;
}
bool Session::getSyncSourceReport(const std::string &sourceName, SyncSourceReport &report) const
{
SyncSourceReports::const_iterator it = m_syncSourceReports.find(sourceName);
if (it != m_syncSourceReports.end()) {
report = it->second;
return true;
} else {
return false;
}
}
void Session::fireStatus(bool flush)
{
PushLogger<Logger> guard(m_me);
@ -535,7 +557,7 @@ void Session::fireStatus(bool flush)
m_statusTimer.reset();
getStatus(status, error, sources);
emitStatus(status, error, sources);
m_statusSignal(status, error, sources);
}
void Session::fireProgress(bool flush)
@ -551,7 +573,7 @@ void Session::fireProgress(bool flush)
m_progressTimer.reset();
getProgress(progress, sources);
emitProgress(progress, sources);
m_progressSignal(progress, sources);
}
boost::shared_ptr<Session> Session::createSession(Server &server,
@ -565,6 +587,11 @@ boost::shared_ptr<Session> Session::createSession(Server &server,
return me;
}
static void SetProgress(Session::SourceProgresses_t &to, const Session::SourceProgresses_t &from)
{
to = from;
}
Session::Session(Server &server,
const std::string &peerDeviceID,
const std::string &config_name,
@ -591,6 +618,7 @@ Session::Session(Server &server,
m_stepIsWaiting(false),
m_priority(PRI_DEFAULT),
m_error(0),
m_lastProgressTimestamp(Timespec::monotonic()),
m_statusTimer(100),
m_progressTimer(50),
m_restoreSrcTotal(0),
@ -616,12 +644,16 @@ Session::Session(Server &server,
add(this, &Session::abort, "Abort");
add(this, &Session::suspend, "Suspend");
add(this, &Session::getStatus, "GetStatus");
add(this, &Session::getProgress, "GetProgress");
add(this, &Session::getAPIProgress, "GetProgress");
add(this, &Session::restore, "Restore");
add(this, &Session::checkPresence, "CheckPresence");
add(this, &Session::execute, "Execute");
add(emitStatus);
add(emitProgress);
m_statusSignal.connect(boost::bind(boost::ref(emitStatus), _1, _2, _3));
m_progressSignal.connect(boost::bind(&Timespec::resetMonotonic, &m_lastProgressTimestamp));
m_progressSignal.connect(boost::bind(SetProgress, boost::ref(m_lastProgress), _2));
m_progressSignal.connect(boost::bind(boost::ref(emitProgress), _1, _2));
SE_LOG_DEBUG(NULL, "session %s created", getPath());
}
@ -962,6 +994,7 @@ void Session::onConnect(const GDBusCXX::DBusConnectionPtr &conn) throw ()
m_helper->m_syncProgress.activate(boost::bind(&Session::syncProgress, this, _1, _2, _3, _4));
m_helper->m_sourceProgress.activate(boost::bind(&Session::sourceProgress, this, _1, _2, _3, _4, _5, _6));
m_helper->m_sourceSynced.activate(boost::bind(boost::ref(m_sourceSynced), _1, _2));
m_sourceSynced.connect(boost::bind(StoreSyncSourceReport, boost::ref(m_syncSourceReports), _1, _2));
m_helper->m_waiting.activate(boost::bind(&Session::setWaiting, this, _1));
m_helper->m_syncSuccessStart.activate(boost::bind(boost::ref(Session::m_syncSuccessStartSignal)));
m_helper->m_configChanged.activate(boost::bind(boost::ref(m_server.m_configChangedSignal), ""));
@ -1193,11 +1226,25 @@ void Session::sourceProgress(sysync::TProgressEventEnum type,
progress.m_receiveCount = extra1;
progress.m_receiveTotal = extra2;
m_progData.itemReceive(sourceName, extra1, extra2);
fireProgress(true);
fireProgress();
}
break;
case sysync::PEV_ITEMPROCESSED:
progress.m_added = extra1;
progress.m_updated = extra2;
progress.m_deleted = extra3;
// Do not fireProgress() here! We are going to get a
// PEV_ITEMRECEIVED directly afterwards (see
// dbus-sync.cpp).
break;
case sysync::PEV_ALERTED:
if (sourceSyncMode != SYNC_NONE) {
// Reset item counts, must be set (a)new.
// Relevant in multi-cycle syncing.
progress.m_receiveCount = -1;
progress.m_receiveTotal = -1;
progress.m_sendCount = -1;
progress.m_sendTotal = -1;
status.set(PrettyPrintSyncMode(sourceSyncMode), "running", 0);
fireStatus(true);
m_progData.setStep(ProgressData::PRO_SYNC_DATA);

View File

@ -81,8 +81,19 @@ class Session : public GDBusCXX::DBusObjectHelper,
SYNC_ILLEGAL
};
/** Part of D-Bus API. */
typedef std::map<std::string, SourceStatus> SourceStatuses_t;
typedef std::map<std::string, SourceProgress> SourceProgresses_t;
/** Part of D-Bus API. */
typedef std::map<std::string, APISourceProgress> APISourceProgresses_t;
/** Internal, with automatic conversion to APISourceProgresses_t when needed. */
struct SourceProgresses_t : public std::map<std::string, SourceProgress> {
operator APISourceProgresses_t () const {
APISourceProgresses_t to;
to.insert(begin(), end());
return to;
}
};
private:
Server &m_server;
@ -211,6 +222,8 @@ class Session : public GDBusCXX::DBusObjectHelper,
uint32_t m_error;
SourceProgresses_t m_sourceProgress;
Timespec m_lastProgressTimestamp;
SourceProgresses_t m_lastProgress;
// syncProgress() and sourceProgress() turn raw data from helper
// into usable information on D-Bus server side
@ -254,6 +267,20 @@ class Session : public GDBusCXX::DBusObjectHelper,
*/
SessionCommon::RunOperation m_cmdlineOp;
// parameters from syncExtended()
std::string m_syncMode;
StringMap m_syncEnv;
typedef std::map<std::string, SyncSourceReport> SyncSourceReports;
static void StoreSyncSourceReport(SyncSourceReports &reports, const std::string &name, const SyncSourceReport &report) { reports[name] = report; }
/** Recorded during a sync for getSyncSourceReport. */
SyncSourceReports m_syncSourceReports;
public:
SessionCommon::RunOperation getOperation() const { return m_runOperation; }
std::string getSyncMode() const { return m_syncMode; }
StringMap getSyncEnv() const { return m_syncEnv; }
/** Session.Attach() */
void attach(const GDBusCXX::Caller_t &caller);
@ -265,9 +292,17 @@ class Session : public GDBusCXX::DBusObjectHelper,
uint32_t &error,
SourceStatuses_t &sources);
/** Session.GetProgress() */
void getAPIProgress(int32_t &progress,
APISourceProgresses_t &sources);
/** Internal, with more information. */
void getProgress(int32_t &progress,
SourceProgresses_t &sources);
/** Timestamp is set each time that m_progressSignal is triggered. */
Timespec getLastProgressTimestamp() const { return m_lastProgressTimestamp; }
/** SourceProgresses_t is set each time that m_progressSignal is triggered. */
void getLastProgress(Session::SourceProgresses_t &progress) const { progress = m_lastProgress; }
/** Session.Restore() */
void restore(const string &dir, bool before, const std::vector<std::string> &sources);
void restore2(const string &dir, bool before, const std::vector<std::string> &sources);
@ -279,6 +314,7 @@ class Session : public GDBusCXX::DBusObjectHelper,
void execute(const vector<string> &args, const map<string, string> &vars);
void execute2(const vector<string> &args, const map<string, string> &vars);
private:
/**
* Must be called each time that properties changing the
* overall status are changed (m_syncStatus, m_error, m_sourceStatus).
@ -294,14 +330,31 @@ class Session : public GDBusCXX::DBusObjectHelper,
/** like fireStatus() for progress information */
void fireProgress(bool flush = false);
public:
/** Session.StatusChanged */
GDBusCXX::EmitSignal3<const std::string &,
uint32_t,
const SourceStatuses_t &> emitStatus;
/** Session.ProgressChanged */
GDBusCXX::EmitSignal2<int32_t,
const SourceProgresses_t &> emitProgress;
const APISourceProgresses_t &> emitProgress;
public:
boost::signals2::signal<void (const std::string &,
uint32_t,
const SourceStatuses_t &)> m_statusSignal;
boost::signals2::signal<void (int32_t,
const SourceProgresses_t &)> m_progressSignal;
/**
* Sets minimum period of time in milliseconds between progress
* signals. Events coming to short after the previous one get
* skipped, to ensure that if an event gets emitted, it gets
* emitted at the time of the change.
*
* There is no guarantee that progress can be emitted very
* frequently (say, every second). In practice it gets updated at
* the end of processing each SyncML message.
*/
void setProgressTimeout(unsigned long ms) { m_progressTimer.setTimeout(ms); }
/**
* Sessions must always be held in a shared pointer
@ -459,6 +512,9 @@ public:
typedef boost::signals2::signal<void (const std::string &, const SyncSourceReport &)> SourceSyncedSignal_t;
SourceSyncedSignal_t m_sourceSynced;
/** gets latest SyncSourceReport of a source, returns false if none available yet */
bool getSyncSourceReport(const std::string &sourceName, SyncSourceReport &report) const;
/**
* Called by server when the session is ready to run.
* Only the session itself can deactivate itself.

View File

@ -25,9 +25,10 @@
#include <syncevo/declarations.h>
SE_BEGIN_CXX
struct SourceProgress
/** Part of the D-Bus API, see GetProgress() and ProgressChanged. */
struct APISourceProgress
{
SourceProgress() :
APISourceProgress() :
m_phase(""),
m_prepareCount(-1), m_prepareTotal(-1),
m_sendCount(-1), m_sendTotal(-1),
@ -40,18 +41,38 @@ struct SourceProgress
int32_t m_receiveCount, m_receiveTotal;
};
/** Used internally. */
struct SourceProgress : public APISourceProgress
{
SourceProgress() :
m_added(0), m_updated(0), m_deleted(0)
{}
// Statistics from actual SyncSource operations. May differ
// from item operations processed and counted by the sync engine.
int32_t m_added, m_updated, m_deleted;
};
SE_END_CXX
namespace GDBusCXX {
using namespace SyncEvo;
template<> struct dbus_traits<APISourceProgress> :
public dbus_struct_traits<APISourceProgress,
dbus_member<APISourceProgress, std::string, &APISourceProgress::m_phase,
dbus_member<APISourceProgress, int32_t, &APISourceProgress::m_prepareCount,
dbus_member<APISourceProgress, int32_t, &APISourceProgress::m_prepareTotal,
dbus_member<APISourceProgress, int32_t, &APISourceProgress::m_sendCount,
dbus_member<APISourceProgress, int32_t, &APISourceProgress::m_sendTotal,
dbus_member<APISourceProgress, int32_t, &APISourceProgress::m_receiveCount,
dbus_member_single<APISourceProgress, int32_t, &APISourceProgress::m_receiveTotal> > > > > > > >
{};
template<> struct dbus_traits<SourceProgress> :
public dbus_struct_traits<SourceProgress,
dbus_member<SourceProgress, std::string, &SourceProgress::m_phase,
dbus_member<SourceProgress, int32_t, &SourceProgress::m_prepareCount,
dbus_member<SourceProgress, int32_t, &SourceProgress::m_prepareTotal,
dbus_member<SourceProgress, int32_t, &SourceProgress::m_sendCount,
dbus_member<SourceProgress, int32_t, &SourceProgress::m_sendTotal,
dbus_member<SourceProgress, int32_t, &SourceProgress::m_receiveCount,
dbus_member_single<SourceProgress, int32_t, &SourceProgress::m_receiveTotal> > > > > > > >
dbus_base<SourceProgress, APISourceProgress,
dbus_member<SourceProgress, int32_t, &SourceProgress::m_added,
dbus_member<SourceProgress, int32_t, &SourceProgress::m_updated,
dbus_member_single<SourceProgress, int32_t, &SourceProgress::m_deleted> > > > >
{};
}

View File

@ -1917,6 +1917,8 @@ bool SyncContext::displaySourceProgress(SyncSource &source,
SharedKey contextKey = m_engine.OpenKeyByPath(sessionKey, "/sessionvars");
m_engine.SetInt32Value(contextKey, "keepPhotoData", false);
}
// Reset "started" flags for PEV_SYNCSTART.
m_sourceStarted.clear();
}
} else {
SE_LOG_INFO(NULL, "%s: restore from backup", source.getDisplayName().c_str());
@ -1926,9 +1928,12 @@ bool SyncContext::displaySourceProgress(SyncSource &source,
}
case sysync::PEV_SYNCSTART:
/* sync started */
/* Get's triggered by libsynthesis frequently. Not very useful. */
/* SE_LOG_INFO(NULL, "%s: started",
source.getDisplayName().c_str()); */
/* Get's triggered by libsynthesis frequently. Limit it to once per sync cycle. */
if (m_sourceStarted.find(source.getName()) == m_sourceStarted.end()) {
SE_LOG_INFO(NULL, "%s: started",
source.getDisplayName().c_str());
m_sourceStarted.insert(source.getName());
}
break;
case sysync::PEV_ITEMRECEIVED:
/* item received, extra1=current item count,

View File

@ -742,6 +742,7 @@ class SyncContext : public SyncConfig {
// Cache for use in displaySourceProgress().
SyncSource *m_sourceProgress;
SyncSourceEvent m_sourceEvent;
std::set<std::string> m_sourceStarted;
public:
/**

View File

@ -191,14 +191,25 @@ string SyncSourceBase::getNativeDatatypeName()
return info.m_native;
}
static void BumpCounter(int32_t &counter)
{
counter++;
}
SyncSource::SyncSource(const SyncSourceParams &params) :
SyncSourceConfig(params.m_name, params.m_nodes),
m_numDeleted(0),
m_added(0),
m_updated(0),
m_deleted(0),
m_forceSlowSync(false),
m_database("", ""),
m_name(params.getDisplayName()),
m_needChanges(true)
{
m_operations.m_insertItemAsKey.getPreSignal().connect(boost::bind(BumpCounter, boost::ref(m_added)));
m_operations.m_updateItemAsKey.getPreSignal().connect(boost::bind(BumpCounter, boost::ref(m_updated)));
m_operations.m_deleteItem.getPreSignal().connect(boost::bind(BumpCounter, boost::ref(m_deleted)));
}
SDKInterface *SyncSource::getSynthesisAPI() const

View File

@ -1925,6 +1925,15 @@ class SyncSource : virtual public SyncSourceBase, public SyncSourceConfig, publi
*/
virtual void close() = 0;
/**
* Number of InsertItem operations, regardless whether the
* operation succeeded or failed. Operations which get suspended
* are counted again each time they are resumed.
*/
int32_t getAdded() const { return m_added; }
int32_t getUpdated() const { return m_updated; }
int32_t getDeleted() const { return m_deleted; }
/**
* return Synthesis API pointer, if one currently is available
* (between SyncEvolution_Module_CreateContext() and
@ -2047,6 +2056,11 @@ class SyncSource : virtual public SyncSourceBase, public SyncSourceConfig, publi
*/
long m_numDeleted;
/**
* Counter for InsertItem operations. Updated by hooking into the operation.
*/
int32_t m_added, m_updated, m_deleted;
bool m_forceSlowSync;
/**

View File

@ -8366,7 +8366,9 @@ Comparison was impossible.
*** @default/addressbook ***
Comparison was impossible.
[INFO] @default/addressbook: started
[INFO] @default/addressbook: sent 1
[INFO @client] @client/addressbook: started
[INFO @client] @client/addressbook: received 1/1
[INFO] @default/addressbook: first time sync done successfully
[INFO @client] @client/addressbook: first time sync done successfully
@ -8459,6 +8461,8 @@ no changes
*** @default/addressbook ***
no changes
[INFO] @default/addressbook: started
[INFO @client] @client/addressbook: started
[INFO] @default/addressbook: normal sync done successfully
[INFO @client] @client/addressbook: normal sync done successfully
[INFO @client] creating complete data backup after sync (enabled with dumpData and needed for printChanges)
@ -8548,7 +8552,9 @@ VERSION:3.0 VERSION:3.0
END:VCARD END:VCARD
-------------------------------------------------------------------------------
[INFO] @default/addressbook: started
[INFO] @default/addressbook: sent 1
[INFO @client] @client/addressbook: started
[INFO @client] @client/addressbook: received 1/1
[INFO] @default/addressbook: normal sync done successfully
[INFO @client] @client/addressbook: normal sync done successfully
@ -8642,7 +8648,9 @@ VERSION:3.0 <
END:VCARD <
-------------------------------------------------------------------------------
[INFO] @default/addressbook: started
[INFO] @default/addressbook: sent 1
[INFO @client] @client/addressbook: started
[INFO @client] @client/addressbook: received 1/1
[INFO] @default/addressbook: normal sync done successfully
[INFO @client] @client/addressbook: normal sync done successfully
@ -8747,12 +8755,16 @@ Comparison was impossible.
*** @default/addressbook ***
Comparison was impossible.
[INFO] @default/addressbook: started
[INFO] creating complete data backup of source calendar before sync (enabled with dumpData and needed for printChanges)
*** @default/calendar ***
Comparison was impossible.
[INFO] @default/calendar: started
[INFO] @default/addressbook: sent 1
[INFO @client] @client/addressbook: started
[INFO @client] @client/addressbook: received 1/1
[INFO @client] @client/calendar: started
[INFO] @default/addressbook: first time sync done successfully
[INFO] @default/calendar: first time sync done successfully
[INFO @client] @client/addressbook: first time sync done successfully
@ -8859,10 +8871,14 @@ no changes
*** @default/addressbook ***
no changes
[INFO] @default/addressbook: started
[INFO] creating complete data backup of source calendar before sync (enabled with dumpData and needed for printChanges)
*** @default/calendar ***
no changes
[INFO] @default/calendar: started
[INFO @client] @client/addressbook: started
[INFO @client] @client/calendar: started
[INFO] @default/addressbook: normal sync done successfully
[INFO] @default/calendar: normal sync done successfully
[INFO @client] @client/addressbook: normal sync done successfully
@ -8972,12 +8988,16 @@ VERSION:3.0 VERSION:3.0
END:VCARD END:VCARD
-------------------------------------------------------------------------------
[INFO] @default/addressbook: started
[INFO] creating complete data backup of source calendar before sync (enabled with dumpData and needed for printChanges)
*** @default/calendar ***
no changes
[INFO] @default/calendar: started
[INFO] @default/addressbook: sent 1
[INFO @client] @client/addressbook: started
[INFO @client] @client/addressbook: received 1/1
[INFO @client] @client/calendar: started
[INFO] @default/addressbook: normal sync done successfully
[INFO] @default/calendar: normal sync done successfully
[INFO @client] @client/addressbook: normal sync done successfully
@ -9090,12 +9110,16 @@ VERSION:3.0 <
END:VCARD <
-------------------------------------------------------------------------------
[INFO] @default/addressbook: started
[INFO] creating complete data backup of source calendar before sync (enabled with dumpData and needed for printChanges)
*** @default/calendar ***
no changes
[INFO] @default/calendar: started
[INFO] @default/addressbook: sent 1
[INFO @client] @client/addressbook: started
[INFO @client] @client/addressbook: received 1/1
[INFO @client] @client/calendar: started
[INFO] @default/addressbook: normal sync done successfully
[INFO] @default/calendar: normal sync done successfully
[INFO @client] @client/addressbook: normal sync done successfully
@ -9194,6 +9218,8 @@ no changes
*** @default/addressbook ***
no changes
[INFO] @default/addressbook: started
[INFO @client] @client/addressbook: started
[INFO] @default/addressbook: normal sync done successfully
[INFO @client] @client/addressbook: normal sync done successfully
[INFO @client] creating complete data backup after sync (enabled with dumpData and needed for printChanges)