merging

.hgignore

@@ -9,3 +9,5 @@ test_adapter
 lib
 local.conf
 build/
+# Default ignored files
+.idea/

Adapter.cc

@@ -6,12 +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");
         if (status == PEP_STATUS_OK)
             return;
         if (status >= 0x400 && status <= 0x4ff)
@@ -28,7 +31,7 @@ namespace pEp {
     RuntimeError::RuntimeError(const std::string& _text, PEP_STATUS _status)
         : std::runtime_error(_text.c_str()), text(_text),  status(_status)
     {
-
+        pEpLog("called");
     }
 
     namespace Adapter {
@@ -36,21 +39,25 @@ namespace pEp {
         notifyHandshake_t _notifyHandshake = nullptr;
         std::thread *_sync_thread = nullptr;
 
-        ::utility::locked_queue< SYNC_EVENT, ::free_Sync_event > q;
+        ::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) {
-                    q.clear();
+                    pEpLog("SYNC_EVENT: NULL");
-                    q.push_back(ev);
+                    sync_q.clear();
+                    sync_q.push_back(ev);
                 }
                 else {
-                    q.push_front(ev);
+                    pEpLog("SYNC_EVENT:" << ev);
+                    sync_q.push_front(ev);
                 }
             }
             catch (exception&) {
+                pEpErr("Exception");
                 return 1;
             }
             if (ev == nullptr) {
@@ -61,7 +68,7 @@ namespace pEp {
                         delete _sync_thread;
                         _sync_thread = nullptr;
                         pEpLog("...thread joined");
-                        q.clear();
+                        sync_q.clear();
                     } else  {
                         //FATAL
                         pEpLog("FATAL: sync thread not joinable/detached");
@@ -74,17 +81,22 @@ namespace pEp {
         // threshold: max waiting time in seconds
         SYNC_EVENT _retrieve_next_sync_event(void *management, unsigned threshold)
         {
+            pEpLog("called");
             SYNC_EVENT syncEvent = nullptr;
-            const bool success = q.try_pop_front(syncEvent, std::chrono::seconds(threshold));
+            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");
             if (_sync_thread && _sync_thread->get_id() == this_thread::get_id())
                 return true;
             else
@@ -93,7 +105,8 @@ namespace pEp {
 
         PEP_SESSION session(session_action action)
         {
-            std::lock_guard<mutex> lock(m);
+            pEpLog("called");
+            std::lock_guard<mutex> lock(mutex_global);
             bool in_sync = on_sync_thread();
 
             thread_local static PEP_SESSION _session = nullptr;
@@ -102,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:
@@ -117,6 +135,7 @@ namespace pEp {
             }
 
             throw_status(status);
+            pEpLog("returning session: " << _session);
             return _session;
         }
 
@@ -131,6 +150,7 @@ namespace pEp {
 
         bool is_sync_running()
         {
+            pEpLog("called");
             return _sync_thread != nullptr;
         }
     }

Adapter.hh

@@ -8,14 +8,6 @@
 #include <pEp/sync_api.h>
 #include <stdexcept>
 
-// TODO: put into not yet existing libpEpAdapter_utils.h, to be across whole libpEpAdapter
-#ifdef NDEBUG
-    #define pEpLog(msg)  do{}while(0)
-#else
-    #include <iostream>
-    #define pEpLog(msg) do{std::cerr << __FILE__ << "::" << __FUNCTION__ << " - " << msg << '\n';} while(0)
-#endif
-
 namespace pEp {
 
     // throws std::bad_alloc if status==PEP_OUT_OF_MEMORY,

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;
 

Makefile

@@ -17,7 +17,7 @@ ifdef BUILD_CONFIG
     $(info ================================================)
 endif
 
-.PHONY: all, lib, test, install, uninstall, clean
+.PHONY: all lib test install uninstall clean
 
 SOURCE=$(wildcard *.cc)
 HEADERS=$(wildcard *.hh *.hxx)

Makefile.conf

@@ -32,11 +32,11 @@ else
     CXXFLAGS+=-DNDEBUG=1
 endif
 
-######### Engine #########
+# Defaults
 ENGINE_LIB_PATH=$(HOME)/lib
 ENGINE_INC_PATH=$(HOME)/include
 
-######### Overrides #########
+# Config File
 -include $(HERE)/local.conf
 
 # Add -L Prefixes to LIB/INC paths,

test/Makefile

@@ -6,7 +6,7 @@ CXXFLAGS+=-I../
 
 .PHONY=all, test_adapter, test_adapter_cxx, test_library
 
-all: test_adapter test_adapter_cxx test_library
+all: test_adapter test_adapter_cxx test_library test_peplog
 
 test_adapter: test_adapter.cc ../libpEpAdapter.a
 
@@ -14,6 +14,9 @@ test_adapter_cxx: test_adapter_cxx.cc ../libpEpAdapter.a
 
 test_library: test_library.cc ../libpEpAdapter.a
 
+test_peplog: test_peplog.cc
+
+
 clean:	
 	rm -vf test_adapter
 	rm -rvf test_adapter.dSYM

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;
+    useconds_t sleepuSec = 1000 * 1000;
-    unsigned long long int nrIters = 1000 * 1000 * 1000;
+    unsigned long long int nrIters = 3;//1000 * 1000 * 1000;
     for (int i = 0; i < nrIters; i++) {
-        pEpLog("RUN NR: ");
+        pEpLog("RUN NR: " << i);
-        pEpLog(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;
 

test/test_peplog.cc

@@ -0,0 +1,16 @@
+// This file is under GNU General Public License 3.0
+// see LICENSE.txt
+
+#include "utils.hh"
+// Single threaded test of pEpLog() function.
+// check for uniformity of time
+
+int main()
+{
+    pEpLog("Test Starting... observe uniformity of timestamp.");
+    int nr_log_lines = 1000000;
+    for (int i; i < nr_log_lines; i++) {
+        pEpLog("log line nr: " << i);
+    }
+    return 0;
+}

utils.hh

@@ -0,0 +1,42 @@
+#pragma once
+#include <iostream>
+#include <thread>
+#include <sstream>
+#include <iomanip>
+
+// Returns a timestamp string featuring microseconds precision
+// Uses system clock, so time might not pass uniformly
+
+inline std::string timestamp_usec() {
+    std::ostringstream buffer;
+    std::chrono::system_clock::duration d = std::chrono::system_clock::now().time_since_epoch();
+
+    std::chrono::microseconds us = std::chrono::duration_cast<std::chrono::microseconds>(d);
+    std::chrono::seconds       s = std::chrono::duration_cast<std::chrono::seconds>     (d);
+
+    std::time_t t = s.count();
+    std::tm tm = *std::localtime(&t);
+
+    std::size_t fractional_seconds = us.count() % 1000000;
+    buffer << std::put_time(&tm, "%H%:%M:%S") << "." << fractional_seconds;
+
+    return buffer.str();
+}
+
+// pEpLog(msg) - logs to STDOUT
+// pEpErr(msg) - logs to STDERR
+//
+// Log format is:
+// TIMESTAMP.usecs THREAD-ID SRC_FILE_NAME::FUNCTION_NAME - msg
+//
+// example:
+// 21:06:04.214884 Thread:0x10f2ce5c0 test_peplog.cc::main - test run nr: 436744
+//
+// if -DNDEBUG=1 (for release builds), all pEpLog() calls will be optimized away.
+
+#ifdef NDEBUG
+#define pEpLog(msg) do{}while(0)
+#else
+#define pEpLog(msg) do{ std::cout << std::unitbuf; std::cout << timestamp_usec() << " Thread:" << std::this_thread::get_id() << ' ' <<__FILE__ << "::" << __FUNCTION__ << " - " << msg << std::endl;} while(0)
+#endif
+#define pEpErr(msg) do{ std::cerr << std::unitbuf; std::cerr << timestamp_usec() << " Thread:" << std::this_thread::get_id() << ' ' <<__FILE__ << "::" << __FUNCTION__ << " - " << msg << std::endl;} while(0)