unexpected slow syncs: no explanation when only one source active (MB #9156)mb9156

The reason was that the code which aborted the sync and prints the explanation
wasn't triggered here: the Synthesis engine stops all by itself because the
only active source failed.

I changed the printing of the explanation so that:
- it is printed when aborting, to explain the ERROR
  that is printed there
- it is always (including the previous case) printed
  again underneath the final status overview produced
  by the command line

For this to work without code duplication, the formatting of the explanation
was moved into SyncReport. It kind of fits there because the message can be
generated for a SyncReport instance. For that case it would be nice if the
actual peer name used for that sync session was in the report; I didn't want to
make too many changes at once, though.

3 files changed, 70 insertions, 14 deletions

diff --git a/src/syncevo/SyncContext.cpp b/src/syncevo/SyncContext.cpp
index 07ca2724..34ab16e4 100644
--- a/src/syncevo/SyncContext.cpp
+++ b/src/syncevo/SyncContext.cpp
@@ -716,6 +716,7 @@ public:
     std::map<std::string, SourceConfigSpecials > m_configSpecials; /*Indicating whether the corresponding sync source is forced slow*/
 private:
     LogDir m_logdir;     /**< our logging directory */
+    SyncContext &m_client; /**< the context in which we were instantiated */
     bool m_prepared;     /**< remember whether syncPrepare() dumped databases successfully */
     bool m_doLogging;    /**< true iff the normal logdir handling is enabled
                             (creating and expiring directoties, before/after comparison) */
@@ -771,6 +772,7 @@ public:
 
     SourceList(SyncContext &client, bool doLogging) :
         m_logdir(client),
+        m_client(client),
         m_prepared(false),
         m_doLogging(doLogging),
         m_reportTodo(true),
@@ -909,6 +911,10 @@ public:
                 }
                 if (m_logLevel > LOGGING_QUIET && report) {
                     cout << *report;
+                    std::string slowSync = report->slowSyncExplanation(m_client.getPeer());
+                    if (!slowSync.empty()) {
+                        cout << endl << slowSync;
+                    }
                 }
 
                 // compare databases?
@@ -2557,24 +2563,14 @@ SyncMLStatus SyncContext::doSync()
                         sources.push_back(source->getName());
                     }
                 }
-                if (!sources.empty()) {
+                string explanation = SyncReport::slowSyncExplanation(m_server,
+                                                                     sources);
+                if (!explanation.empty()) {
                     string sourceparam = boost::join(sources, " ");
                     SE_LOG_ERROR(NULL, NULL,
                                  "Aborting because of unexpected slow sync for source(s): %s",
                                  sourceparam.c_str());
-                    SE_LOG_INFO(NULL, NULL,
-                                "Doing a slow synchronization may lead to duplicated items or\n"
-                                "lost data when the server merges items incorrectly. Choosing\n"
-                                "a different synchronization mode may be the better alternative.\n"
-                                "Restart synchronization of affected source(s) with one of the\n"
-                                "following sync modes to recover from this problem:\n"
-                                "    slow, refresh-from-server, refresh-from-client\n\n"
-                                "Analyzing the current state:\n"
-                                "    syncevolution --status %s %s\n\n"
-                                "Running with one of the three modes:\n"
-                                "    syncevolution --sync [slow|refresh-from-server|refresh-from-client] %s %s\n",
-                                m_server.c_str(), sourceparam.c_str(),
-                                m_server.c_str(), sourceparam.c_str());
+                    SE_LOG_INFO(NULL, NULL, "%s", explanation.c_str());
                 } else {
                     // we should not get here, but if we do, at least log something
                     SE_LOG_ERROR(NULL, NULL, "aborting as requested by script");
diff --git a/src/syncevo/SyncML.cpp b/src/syncevo/SyncML.cpp
index da254759..db7760f8 100644
--- a/src/syncevo/SyncML.cpp
+++ b/src/syncevo/SyncML.cpp
@@ -30,6 +30,7 @@
 #include <boost/algorithm/string/classification.hpp>
 #include <boost/algorithm/string/predicate.hpp>
 #include <boost/algorithm/string/replace.hpp>
+#include <boost/algorithm/string/join.hpp>
 
 #include <synthesis/syerror.h>
 
@@ -739,6 +740,43 @@ std::string SyncReport::formatSyncTimes() const
     return out.str();
 }
 
+std::string SyncReport::slowSyncExplanation(const std::string &peer,
+                                            const std::list<std::string> &sources)
+{
+    if (sources.empty()) {
+        return "";
+    }
+
+    string sourceparam = boost::join(sources, " ");
+    std::string explanation =
+        StringPrintf("Doing a slow synchronization may lead to duplicated items or\n"
+                     "lost data when the server merges items incorrectly. Choosing\n"
+                     "a different synchronization mode may be the better alternative.\n"
+                     "Restart synchronization of affected source(s) with one of the\n"
+                     "following sync modes to recover from this problem:\n"
+                     "    slow, refresh-from-server, refresh-from-client\n\n"
+                     "Analyzing the current state:\n"
+                     "    syncevolution --status %s %s\n\n"
+                     "Running with one of the three modes:\n"
+                     "    syncevolution --sync [slow|refresh-from-server|refresh-from-client] %s %s\n",
+                     peer.c_str(), sourceparam.c_str(),
+                     peer.c_str(), sourceparam.c_str());
+    return explanation;
+}
+
+std::string SyncReport::slowSyncExplanation(const std::string &peer) const
+{
+    std::list<std::string> sources;
+    BOOST_FOREACH(const SyncReport::value_type &entry, *this) {
+        const std::string &name = entry.first;
+        const SyncSourceReport &source = entry.second;
+        if (source.getStatus() == STATUS_UNEXPECTED_SLOW_SYNC) {
+            sources.push_back(name);
+        }
+    }
+    return slowSyncExplanation(peer, sources);
+}
+
 ConfigNode &operator << (ConfigNode &node, const SyncReport &report)
 {
     node.setProperty("start", static_cast<long>(report.getStart()));
diff --git a/src/syncevo/SyncML.h b/src/syncevo/SyncML.h
index 7fd1cc40..5baaf54e 100644
--- a/src/syncevo/SyncML.h
+++ b/src/syncevo/SyncML.h
@@ -23,6 +23,7 @@
 
 #include <string>
 #include <map>
+#include <list>
 #include <ostream>
 #include <string.h>
 
@@ -311,6 +312,27 @@ class SyncReport : public std::map<std::string, SyncSourceReport> {
         WITHOUT_REJECTS = 1 << 4,
         WITH_TOTAL = 1 << 5
     };
+
+    /**
+     * Produces a non-localized explanation for recovering from unexpected 
+     * slow syncs, targeted towards command line users.
+     *
+     * @param peer     config name used to select the affected peer (nor necessarily normalized)
+     * @param sources  list of affected sources
+     * @return explanation, empty string if list of sources is empty
+     */
+    static std::string slowSyncExplanation(const std::string &peer,
+                                           const std::list<std::string> &sources);
+
+    /**
+     * Produces a non-localized explanation for recovering from unexpected 
+     * slow syncs, targeted towards command line users. Uses the information
+     * about sources stored in the report.
+     *
+     * @param peer     config name used to select the affected peer (nor necessarily normalized)
+     * @return explanation, empty string if list of sources is empty
+     */
+    std::string slowSyncExplanation(const std::string &peer) const;
 };
 
 /** pretty-print the report as an ASCII table */