Also pass csync logs through QMessageLogger

This allows using logging rules and custom message patterns with csync.
This also pass the a relative verbosity to the message logger.

Issue #5647

csync/src/csync.c

@@ -160,7 +160,7 @@ int csync_update(CSYNC *ctx) {
   csync_memstat_check();
 
   if (!ctx->excludes) {
-      CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "No exclude file loaded or defined!");
+      CSYNC_LOG(CSYNC_LOG_PRIORITY_INFO, "No exclude file loaded or defined!");
   }
 
   /* update detection for local replica */
@@ -524,7 +524,7 @@ int csync_commit(CSYNC *ctx) {
 
   if (ctx->statedb.db != NULL
       && csync_statedb_close(ctx) < 0) {
-    CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "ERR: closing of statedb failed.");
+    CSYNC_LOG(CSYNC_LOG_PRIORITY_WARN, "ERR: closing of statedb failed.");
     rc = -1;
   }
   ctx->statedb.db = NULL;
@@ -559,7 +559,7 @@ int csync_destroy(CSYNC *ctx) {
 
   if (ctx->statedb.db != NULL
       && csync_statedb_close(ctx) < 0) {
-    CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "ERR: closing of statedb failed.");
+    CSYNC_LOG(CSYNC_LOG_PRIORITY_WARN, "ERR: closing of statedb failed.");
     rc = -1;
   }
   ctx->statedb.db = NULL;

csync/src/csync.h

@@ -287,8 +287,7 @@ typedef int (*csync_auth_callback) (const char *prompt, char *buf, size_t len,
 
 typedef void (*csync_log_callback) (int verbosity,
                                     const char *function,
-                                    const char *buffer,
-                                    void *userdata);
+                                    const char *buffer);
 
 typedef void (*csync_update_callback) (bool local,
                                     const char *dirUrl,
@@ -438,22 +437,6 @@ csync_log_callback OCSYNC_EXPORT csync_get_log_callback(void);
  */
 int OCSYNC_EXPORT csync_set_log_callback(csync_log_callback cb);
 
-/**
- * @brief get the userdata set for the logging callback.
- *
- * @return              The userdata or NULL.
- */
-void OCSYNC_EXPORT *csync_get_log_userdata(void);
-
-/**
- * @brief Set the userdata passed to the logging callback.
- *
- * @param[in]  data     The userdata to set.
- *
- * @return              0 on success, less than 0 if an error occurred.
- */
-int OCSYNC_EXPORT csync_set_log_userdata(void *data);
-
 /* Used for special modes or debugging */
 CSYNC_STATUS OCSYNC_EXPORT csync_get_status(CSYNC *ctx);
 

csync/src/csync_log.c

@@ -29,48 +29,22 @@
 
 CSYNC_THREAD int csync_log_level;
 CSYNC_THREAD csync_log_callback csync_log_cb;
-CSYNC_THREAD void *csync_log_userdata;
-
-static void csync_log_stderr(int verbosity,
-                             const char *function,
-                             const char *buffer)
-{
-    fprintf(stderr, "[%d] %s", verbosity, function);
-    fprintf(stderr, "  %s\n", buffer);
-}
-static void csync_log_function(int verbosity,
-                               const char *function,
-                               const char *buffer)
-{
-    csync_log_callback log_fn = csync_get_log_callback();
-    if (log_fn) {
-        char buf[1024];
-
-        snprintf(buf, sizeof(buf), "%s: %s", function, buffer);
-
-        log_fn(verbosity,
-               function,
-               buf,
-               csync_get_log_userdata());
-        return;
-    }
-
-    csync_log_stderr(verbosity, function, buffer);
-}
-
 
 void csync_log(int verbosity,
                const char *function,
                const char *format, ...)
 {
-    char buffer[1024];
-    va_list va;
-
-    if (verbosity <= csync_get_log_level()) {
+    csync_log_callback log_fn = csync_get_log_callback();
+    if (log_fn && verbosity <= csync_get_log_level()) {
+        char buffer[1024];
+        va_list va;
+ 
         va_start(va, format);
         vsnprintf(buffer, sizeof(buffer), format, va);
         va_end(va);
-        csync_log_function(verbosity, function, buffer);
+
+        log_fn(verbosity, function, buffer);
+        return;
     }
 }
 
@@ -101,16 +75,3 @@ int csync_set_log_callback(csync_log_callback cb) {
 csync_log_callback csync_get_log_callback(void) {
   return csync_log_cb;
 }
-
-void *csync_get_log_userdata(void)
-{
-    return csync_log_userdata;
-}
-
-int csync_set_log_userdata(void *data)
-{
-    csync_log_userdata = data;
-
-    return 0;
-}
-

csync/src/csync_reconcile.c

@@ -341,7 +341,7 @@ static int _csync_merge_algorithm_visitor(void *obj, void *data) {
     {
         if(cur->type == CSYNC_FTW_TYPE_DIR)
         {
-            CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG,
+            CSYNC_LOG(CSYNC_LOG_PRIORITY_INFO,
                       "%-30s %s dir:  %s",
                       csync_instruction_str(cur->instruction),
                       repo,
@@ -349,7 +349,7 @@ static int _csync_merge_algorithm_visitor(void *obj, void *data) {
         }
         else
         {
-            CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG,
+            CSYNC_LOG(CSYNC_LOG_PRIORITY_INFO,
                       "%-30s %s file: %s",
                       csync_instruction_str(cur->instruction),
                       repo,

csync/src/csync_statedb.c

@@ -168,7 +168,7 @@ int csync_statedb_load(CSYNC *ctx, const char *statedb, sqlite3 **pdb) {
   //
   result = csync_statedb_query(db, "SELECT sqlite_version();");
   if (result && result->count >= 1) {
-      CSYNC_LOG(CSYNC_LOG_PRIORITY_NOTICE, "sqlite3 version \"%s\"", *result->vector);
+      CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "sqlite3 version \"%s\"", *result->vector);
   }
   c_strlist_destroy(result);
 
@@ -186,7 +186,7 @@ int csync_statedb_load(CSYNC *ctx, const char *statedb, sqlite3 **pdb) {
 #endif
   *pdb = db;
 
-   CSYNC_LOG(CSYNC_LOG_PRIORITY_NOTICE, "Success");
+  CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "Success");
 
   return 0;
 out:
@@ -218,7 +218,7 @@ int csync_statedb_close(CSYNC *ctx) {
   ctx->statedb.lastReturnValue = SQLITE_OK;
 
   int sr = sqlite3_close(ctx->statedb.db);
-  CSYNC_LOG(CSYNC_LOG_PRIORITY_NOTICE, "sqlite3_close=%d", sr);
+  CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "sqlite3_close=%d", sr);
 
   ctx->statedb.db = 0;
 
@@ -295,7 +295,7 @@ static int _csync_file_stat_from_metadata_table( csync_file_stat_t **st, sqlite3
         }
     } else {
         if( rc != SQLITE_DONE ) {
-            CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "WARN: Query results in %d", rc);
+            CSYNC_LOG(CSYNC_LOG_PRIORITY_WARN, "Query results in %d", rc);
         }
     }
     return rc;

csync/src/csync_update.c

@@ -263,7 +263,7 @@ static int _csync_detect_update(CSYNC *ctx, const char *file,
 
     if(tmp && tmp->phash == h ) { /* there is an entry in the database */
         /* we have an update! */
-        CSYNC_LOG(CSYNC_LOG_PRIORITY_TRACE, "Database entry found, compare: %" PRId64 " <-> %" PRId64
+        CSYNC_LOG(CSYNC_LOG_PRIORITY_INFO, "Database entry found, compare: %" PRId64 " <-> %" PRId64
                                             ", etag: %s <-> %s, inode: %" PRId64 " <-> %" PRId64
                                             ", size: %" PRId64 " <-> %" PRId64 ", perms: %s <-> %s, ignore: %d",
                   ((int64_t) fs->mtime), ((int64_t) tmp->modtime),
@@ -414,7 +414,7 @@ static int _csync_detect_update(CSYNC *ctx, const char *file,
             }
             if(tmp ) {                           /* tmp existing at all */
                 if ( _csync_filetype_different(tmp, fs)) {
-                    CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "WARN: file types different is not!");
+                    CSYNC_LOG(CSYNC_LOG_PRIORITY_WARN, "file types different is not!");
                     st->instruction = CSYNC_INSTRUCTION_NEW;
                     goto out;
                 }
@@ -446,7 +446,7 @@ static int _csync_detect_update(CSYNC *ctx, const char *file,
         }
     }
   } else  {
-      CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "Unable to open statedb" );
+      CSYNC_LOG(CSYNC_LOG_PRIORITY_WARN, "Unable to open statedb" );
       csync_file_stat_free(st);
       ctx->status_code = CSYNC_STATUS_UNSUCCESSFUL;
       return -1;
@@ -528,7 +528,7 @@ out:
     default:
       break;
   }
-  CSYNC_LOG(CSYNC_LOG_PRIORITY_DEBUG, "file: %s, instruction: %s <<=", st->path,
+  CSYNC_LOG(CSYNC_LOG_PRIORITY_INFO, "file: %s, instruction: %s <<=", st->path,
       csync_instruction_str(st->instruction));
 
   return 0;

csync/tests/csync_tests/check_csync_log.c

@@ -59,8 +59,7 @@ static int teardown(void **state) {
 
 static void check_log_callback(int verbosity,
                                const char *function,
-                               const char *buffer,
-                               void *userdata)
+                               const char *buffer)
 {
     int rc;
 
@@ -70,8 +69,6 @@ static void check_log_callback(int verbosity,
     assert_non_null(buffer);
     assert_false(buffer[0] == '\0');
 
-    (void) userdata; /* unused */
-
     rc = system("touch /tmp/check_csync1/cb_called");
     assert_int_equal(rc, 0);
 }

src/libsync/discoveryphase.cpp

@@ -686,7 +686,6 @@ void DiscoveryJob::start() {
 
     csync_set_log_callback(_log_callback);
     csync_set_log_level(_log_level);
-    csync_set_log_userdata(_log_userdata);
     _lastUpdateProgressCallbackCall.invalidate();
     int ret = csync_update(_csync_ctx);
 

src/libsync/discoveryphase.h

@@ -208,7 +208,6 @@ class DiscoveryJob : public QObject {
     CSYNC              *_csync_ctx;
     csync_log_callback  _log_callback;
     int                 _log_level;
-    void*               _log_userdata;
     QElapsedTimer       _lastUpdateProgressCallbackCall;
 
     /**
@@ -243,7 +242,6 @@ public:
         // and updates run in another thread
         _log_callback = csync_get_log_callback();
         _log_level = csync_get_log_level();
-        _log_userdata = csync_get_log_userdata();
     }
 
     QStringList _selectiveSyncBlackList;

src/libsync/logger.cpp

@@ -20,9 +20,12 @@
 #include <qmetaobject.h>
 
 #include "csync.h"
+#include "csync_log.h"
 
 namespace OCC {
 
+Q_LOGGING_CATEGORY(lcCsync, "sync.csync", QtInfoMsg)
+
 #if QT_VERSION < QT_VERSION_CHECK(5, 0, 0)
 // logging handler.
 static void mirallLogCatcher(QtMsgType type, const char *msg)
@@ -50,12 +53,25 @@ static void mirallLogCatcher(QtMsgType type, const QMessageLogContext &ctx, cons
 }
 #endif
 
-static void csyncLogCatcher(int /*verbosity*/,
-                        const char * /*function*/,
-                        const char *buffer,
-                        void * /*userdata*/)
+static void csyncLogCatcher(int verbosity,
+                        const char *function,
+                        const char *buffer)
 {
-    Logger::instance()->csyncLog( QString::fromUtf8(buffer) );
+    if (verbosity <= CSYNC_LOG_PRIORITY_FATAL) {
+        QMessageLogger(0, 0, function, lcCsync().categoryName()).fatal("%s", buffer);
+    } else if (verbosity <= CSYNC_LOG_PRIORITY_CRIT) {
+        if (lcCsync().isCriticalEnabled())
+            QMessageLogger(0, 0, function, lcCsync().categoryName()).critical("%s", buffer);
+    } else if (verbosity <= CSYNC_LOG_PRIORITY_WARN) {
+        if (lcCsync().isWarningEnabled())
+            QMessageLogger(0, 0, function, lcCsync().categoryName()).warning("%s", buffer);
+    } else if (verbosity <= CSYNC_LOG_PRIORITY_INFO) {
+        if (lcCsync().isInfoEnabled())
+            QMessageLogger(0, 0, function, lcCsync().categoryName()).info("%s", buffer);
+    } else if (verbosity <= CSYNC_LOG_PRIORITY_NOTSET) {
+        if (lcCsync().isDebugEnabled())
+            QMessageLogger(0, 0, function, lcCsync().categoryName()).debug("%s", buffer);
+    }
 }
 
 Logger *Logger::instance()
@@ -74,7 +90,12 @@ Logger::Logger( QObject* parent) : QObject(parent),
     qInstallMessageHandler(mirallLogCatcher);
 #else
     Q_UNUSED(mirallLogCatcher)
+    // Always get logging from csync in that case.
+    csync_set_log_level(11);
 #endif
+
+    // Setup CSYNC logging to forward to our own logger
+    csync_set_log_callback(csyncLogCatcher);
 }
 
 Logger::~Logger() {
@@ -145,21 +166,6 @@ void Logger::doLog(const QString& msg)
     emit logWindowLog(msg);
 }
 
-void Logger::csyncLog( const QString& message )
-{
-    auto logger = Logger::instance();
-    if (logger->isNoop()) {
-        return;
-    }
-
-    Log log;
-    log.source = Log::CSync;
-    log.timeStamp = QDateTime::currentDateTime();
-    log.message = message;
-
-    logger->log(log);
-}
-
 void Logger::mirallLog( const QString& message )
 {
     Log log_;
@@ -174,8 +180,6 @@ void Logger::setLogWindowActivated(bool activated)
 {
     QMutexLocker locker(&_mutex);
 
-    // Setup CSYNC logging to forward to our own logger
-    csync_set_log_callback(csyncLogCatcher);
     csync_set_log_level(11);
 
     _logWindowActivated = activated;
@@ -185,10 +189,8 @@ void Logger::setLogFile(const QString & name)
 {
     QMutexLocker locker(&_mutex);
 
-    // Setup CSYNC logging to forward to our own logger
-    csync_set_log_callback(csyncLogCatcher);
     csync_set_log_level(11);
-
+    
     if( _logstream ) {
         _logstream.reset(0);
         _logFile.close();

src/libsync/logger.h

@@ -50,7 +50,6 @@ public:
   void log(Log log);
   void doLog(const QString &log);
 
-  static void csyncLog( const QString& message );
   static void mirallLog( const QString& message );
 
   const QList<Log>& logs() const {return _logs;}