Improved Logging, prefixed with thread_id now. (DEBUG build only)

added pEpErr() (DEBUG and RELEASE build)
non-local vars names with len == 1 are not handy at all

Adapter.cc

@@ -6,13 +6,15 @@
 #include <iomanip>
 #include <assert.h>
 #include "status_to_string.hh"
+#include "utils.hh"
+
 
 using namespace std;
 
 namespace pEp {
     void throw_status(PEP_STATUS status)
     {
-        pEpLog("called");
+        //pEpLog("called");
         if (status == PEP_STATUS_OK)
             return;
         if (status >= 0x400 && status <= 0x4ff)
@@ -38,21 +40,24 @@ namespace pEp {
         std::thread *_sync_thread = nullptr;
 
         ::utility::locked_queue< SYNC_EVENT, ::free_Sync_event > sync_q;
-        std::mutex m;
+        std::mutex mutex_global;
 
         int _inject_sync_event(SYNC_EVENT ev, void *management)
         {
             pEpLog("called");
             try {
                 if (ev == nullptr) {
+                    pEpLog("SYNC_EVENT: NULL");
                     sync_q.clear();
                     sync_q.push_back(ev);
                 }
                 else {
+                    pEpLog("SYNC_EVENT:" << ev);
                     sync_q.push_front(ev);
                 }
             }
             catch (exception&) {
+                pEpErr("Exception");
                 return 1;
             }
             if (ev == nullptr) {
@@ -80,15 +85,18 @@ namespace pEp {
             SYNC_EVENT syncEvent = nullptr;
             const bool success = sync_q.try_pop_front(syncEvent, std::chrono::seconds(threshold));
 
-            if (!success)
+            if (!success) {
+                pEpLog("timeout after [sec]: " << threshold);
                 return new_sync_timeout_event();
+            }
 
+            pEpLog("returning SYNC_EVENT: "  << syncEvent);
             return syncEvent;
         }
 
         bool on_sync_thread()
         {
-            pEpLog("called");
+            //pEpLog("called");
             if (_sync_thread && _sync_thread->get_id() == this_thread::get_id())
                 return true;
             else
@@ -98,7 +106,7 @@ namespace pEp {
         PEP_SESSION session(session_action action)
         {
             pEpLog("called");
-            std::lock_guard<mutex> lock(m);
+            std::lock_guard<mutex> lock(mutex_global);
             bool in_sync = on_sync_thread();
 
             thread_local static PEP_SESSION _session = nullptr;
@@ -107,14 +115,19 @@ namespace pEp {
             switch (action) {
                 case release:
                     if (_session) {
+                        pEpLog("action = release: releasing session: " << _session);
                         ::release(_session);
                         _session = nullptr;
+                    } else {
+                        pEpLog("action = release: No session to release");
                     }
                     break;
 
                 case init:
-                    if (!_session)
+                    if (!_session) {
+                        pEpLog("action = init: creating new session");
                         status = ::init(&_session, _messageToSend, _inject_sync_event);
+                    }
                     break;
 
                 default:
@@ -122,6 +135,7 @@ namespace pEp {
             }
 
             throw_status(status);
+            pEpLog("returning session: " << _session);
             return _session;
         }
 

Adapter.hh

@@ -7,7 +7,6 @@
 #include <string>
 #include <pEp/sync_api.h>
 #include <stdexcept>
-#include "utils.hh"
 
 namespace pEp {
 

Adapter.hxx

@@ -6,6 +6,7 @@
 #include <thread>
 #include "locked_queue.hh"
 #include <cassert>
+#include "utils.hh"
 
 namespace pEp {
     namespace Adapter {
@@ -16,7 +17,7 @@ namespace pEp {
         extern std::thread *_sync_thread;
 
         extern ::utility::locked_queue< SYNC_EVENT, ::free_Sync_event > q;
-        extern std::mutex m;
+        extern std::mutex mutex_global;
 
         SYNC_EVENT _retrieve_next_sync_event(void *management, unsigned threshold);
 
@@ -25,6 +26,7 @@ namespace pEp {
 
         template< class T > void sync_thread(T *obj, function< void(T *) > _startup, function< void(T *) > _shutdown)
         {
+            pEpLog("called");
             _ex = nullptr;
             assert(_messageToSend);
             assert(_notifyHandshake);
@@ -67,6 +69,8 @@ namespace pEp {
         )
             throw (RuntimeError)
         {
+            pEpLog("called");
+
             if (messageToSend)
                 _messageToSend = messageToSend;
 

test/test_adapter.cc

@@ -1,24 +1,25 @@
 // This file is under GNU General Public License 3.0
 // see LICENSE.txt
 
-#include "Adapter.hh"
 #include <iostream>
 #include <assert.h>
 #include <unistd.h>
 #include <pEp/keymanagement.h>
+#include "Adapter.hh"
+#include "../utils.hh"
 
 using namespace std;
 using namespace pEp::Adapter;
 
 PEP_STATUS messageToSend(struct _message *msg)
 {
-    pEpLog("called()");
+    pEpLog("called");
     return PEP_STATUS_OK;
 }
 
 PEP_STATUS notifyHandshake(pEp_identity *me, pEp_identity *partner, sync_handshake_signal signal)
 {
-    pEpLog("called()");
+    pEpLog("called");
     return PEP_STATUS_OK;
 }
 
@@ -33,17 +34,16 @@ int main()
     pEp::throw_status(status);
 
     // start and stop sync repeatedly
-    useconds_t sleepuSec = 1000 * 100;
-    unsigned long long int nrIters = 1000 * 1000 * 1000;
+    useconds_t sleepuSec = 1000 * 1000;
+    unsigned long long int nrIters = 3;//1000 * 1000 * 1000;
     for (int i = 0; i < nrIters; i++) {
-        pEpLog("RUN NR: ");
-        pEpLog(i);
+        pEpLog("RUN NR: " << i);
         pEpLog("SYNC START");
-        pEpLog("starting the adapter including sync");
         startup(messageToSend, notifyHandshake);
         pEpLog("SYNC STOP");
         usleep(sleepuSec);
         shutdown();
+        usleep(sleepuSec);
     }
     return 0;
 }

test/test_adapter_cxx.cc

@@ -1,11 +1,12 @@
 // This file is under GNU General Public License 3.0
 // see LICENSE.txt
 
-#include "Adapter.hh"
 #include <iostream>
 #include <assert.h>
 #include <unistd.h>
 #include <pEp/keymanagement.h>
+#include "Adapter.hh"
+#include "../utils.hh"
 
 using namespace pEp::Adapter;
 

utils.hh

@@ -1,9 +1,12 @@
 #pragma once
 
+#include <iostream>
+#include <thread>
 
 #ifdef NDEBUG
     #define pEpLog(msg)  do{}while(0)
 #else
-    #include <iostream>
-    #define pEpLog(msg) do{std::cerr << __FILE__ << "::" << __FUNCTION__ << " - " << msg << '\n';} while(0)
+    #define pEpLog(msg) do{std::cout << "Thread:" << std::this_thread::get_id() << ' ' <<__FILE__ << "::" << __FUNCTION__ << " - " << msg << '\n';} while(0)
 #endif
+
+#define pEpErr(msg) do{std::cerr << "Thread:" << std::this_thread::get_id() << ' ' <<__FILE__ << "::" << __FUNCTION__ << " - " << msg << '\n';} while(0)