more trace logging

arangod/Dispatcher/Dispatcher.cpp

@@ -123,7 +123,7 @@ int Dispatcher::addJob(std::unique_ptr<Job>& job) {
   job->requestStatisticsAgentSetQueueStart();
 
   // do not start new jobs if we are already shutting down
-  if (_stopping.load(memory_order_relaxed)) {
+  if (_stopping.load(std::memory_order_relaxed)) {
     return TRI_ERROR_DISPATCHER_IS_STOPPING;
   }
 

arangod/Dispatcher/DispatcherQueue.cpp

@@ -98,6 +98,7 @@ int DispatcherQueue::addJob(std::unique_ptr<Job>& job) {
   size_t pos;
 
   if (!_jobPositions.pop(pos)) {
+    LOG_TRACE("cannot add job %p to queue %p. queue is full", (void*) job.get(), (void*) this);
     return TRI_ERROR_QUEUE_FULL;
   }
 

arangod/HttpServer/HttpServer.cpp

@@ -254,6 +254,8 @@ bool HttpServer::handleRequest(HttpCommTask* task,
   // use a dispatcher queue, handler belongs to the job
   std::unique_ptr<Job> job = std::make_unique<HttpServerJob>(this, handler);
 
+  LOG_TRACE("HttpCommTask %p created HttpServerJob %p", (void*) task, (void*) job.get());
+
   // add the job to the dispatcher
   int res = _dispatcher->addJob(job);
 

arangod/Statistics/statistics.cpp

@@ -22,6 +22,7 @@
 ////////////////////////////////////////////////////////////////////////////////
 
 #include "statistics.h"
+#include "Basics/logging.h"
 #include "Basics/Mutex.h"
 #include "Basics/MutexLocker.h"
 #include "Basics/threads.h"
@@ -140,6 +141,8 @@ TRI_request_statistics_t* TRI_AcquireRequestStatistics() {
     return statistics;
   }
 
+  LOG_TRACE("no free element on statistics queue");
+
   return nullptr;
 }
 

arangod/VocBase/compactor.cpp

@@ -989,6 +989,8 @@ static bool CompactifyDocumentCollection(TRI_document_collection_t* document) {
     return false;
   }
 
+  LOG_TRACE("inspecting datafiles of collection '%s' for compaction opportunities", document->_info.namec_str());
+
   size_t start = document->getNextCompactionStartIndex();
 
   // number of documents is protected by the same lock
@@ -1029,7 +1031,7 @@ static bool CompactifyDocumentCollection(TRI_document_collection_t* document) {
     DatafileStatisticsContainer dfi = document->_datafileStatistics.get(df->_fid);
     
     if (dfi.numberUncollected > 0) {
-      LOG_TRACE("cannot compact file %llu because it still has uncollected entries", (unsigned long long) df->_fid);
+      LOG_TRACE("cannot compact datafile %llu of collection '%s' because it still has uncollected entries", (unsigned long long) df->_fid, document->_info.namec_str());
       start = i + 1;
       break;
     }

arangod/VocBase/document-collection.cpp

@@ -259,6 +259,7 @@ int TRI_document_collection_t::beginReadTimed(uint64_t timeout,
         // insert reader
         if (_vocbase->_deadlockDetector.setReaderBlocked(this)) {
           // deadlock
+          LOG_TRACE("deadlock detected while trying to acquire read-lock on collection '%s'", _info.name().c_str());
           return TRI_ERROR_DEADLOCK;
         }
         wasBlocked = true;
@@ -270,6 +271,7 @@ int TRI_document_collection_t::beginReadTimed(uint64_t timeout,
         if (_vocbase->_deadlockDetector.isDeadlocked(this)) {
           // deadlock
           _vocbase->_deadlockDetector.setReaderUnblocked(this);
+          LOG_TRACE("deadlock detected while trying to acquire read-lock on collection '%s'", _info.name().c_str());
           return TRI_ERROR_DEADLOCK;
         }
       }
@@ -338,6 +340,7 @@ int TRI_document_collection_t::beginWriteTimed(uint64_t timeout,
         // insert writer (with method named "setReaderBlocked"..., but it works)
         if (_vocbase->_deadlockDetector.setReaderBlocked(this)) {
           // deadlock
+          LOG_TRACE("deadlock detected while trying to acquire write-lock on collection '%s'", _info.name().c_str());
           return TRI_ERROR_DEADLOCK;
         }
         wasBlocked = true;
@@ -349,6 +352,7 @@ int TRI_document_collection_t::beginWriteTimed(uint64_t timeout,
         if (_vocbase->_deadlockDetector.isDeadlocked(this)) {
           // deadlock
           _vocbase->_deadlockDetector.setReaderUnblocked(this);
+          LOG_TRACE("deadlock detected while trying to acquire write-lock on collection '%s'", _info.name().c_str());
           return TRI_ERROR_DEADLOCK;
         }
       }

lib/Basics/AssocMulti.h

@@ -1086,6 +1086,9 @@ class AssocMulti {
   //////////////////////////////////////////////////////////////////////////////
 
   void resizeInternal(UserData* userData, Bucket& b, size_t size) {
+    LOG_TRACE("resizing index %s, target size: %llu", _contextCallback().c_str(),
+               (unsigned long long)size);
+
     LOG_ACTION("index-resize %s, target size: %llu", _contextCallback().c_str(),
                (unsigned long long)size);
     double start = TRI_microtime();
@@ -1160,6 +1163,8 @@ class AssocMulti {
 
     delete[] oldTable;
     
+    LOG_TRACE("resizing index %s done", _contextCallback().c_str());
+
     LOG_TIMER((TRI_microtime() - start), "index-resize, %s, target size: %llu",
               _contextCallback().c_str(), (unsigned long long)size);
   }

lib/Basics/AssocUnique.h

@@ -193,6 +193,10 @@ class AssocUnique {
     // entries
     static uint64_t const NotificationSizeThreshold = 131072;
 
+    LOG_TRACE("resizing index %s, target size: %llu",
+              _contextCallback().c_str(),
+              (unsigned long long) targetSize);
+
     double start = TRI_microtime();
     if (targetSize > NotificationSizeThreshold) {
       LOG_ACTION("index-resize %s, target size: %llu",
@@ -250,6 +254,8 @@ class AssocUnique {
 
     delete[] oldTable;
     
+    LOG_TRACE("resizing index %s done", _contextCallback().c_str());
+
     LOG_TIMER((TRI_microtime() - start), "index-resize %s, target size: %llu",
               _contextCallback().c_str(), (unsigned long long)targetSize);
   }