Logging infrastructure: See qpidd --long-help for details.

* src/qpid/log/*: Logging infrastructure, QPID_LOG macro.
* src/*: changed output to cout/cerr to logging.
* src/qpidd.cpp: logging options.
* src/tests/Makefile.am: fixed issues with valgrind
* src/tests/kill|start_broker: use broker daemon options.
* src/tests/run_test: run tests in valgrind. Disabled till leaks in
  client_test are fixed.
* src/test/unit/logging.cpp: Logging unit test using boost test framework.
  Eventually we should move all unit tests to boost & drop CppUnit.
* src/test/unit/test_tools.h: useful extensions to boost framework:
  Regular expression check, ostream << for vectors.


git-svn-id: https://svn.apache.org/repos/asf/incubator/qpid/trunk/qpid@542855 13f79535-47bb-0310-9956-ffa450edef68

8 files changed, 33 insertions, 29 deletions

diff --git a/cpp/src/qpid/sys/apr/APRAcceptor.cpp b/cpp/src/qpid/sys/apr/APRAcceptor.cpp
index e9ce24ac2d..0f0853b35d 100644
--- a/cpp/src/qpid/sys/apr/APRAcceptor.cpp
+++ b/cpp/src/qpid/sys/apr/APRAcceptor.cpp
@@ -18,6 +18,7 @@
  * under the License.
  *
  */
+#include "qpid/log/Statement.h"
 #include "qpid/sys/Acceptor.h"
 #include "qpid/sys/ConnectionInputHandlerFactory.h"
 #include "qpid/sys/Mutex.h"
@@ -80,7 +81,7 @@ uint16_t APRAcceptor::getPort() const {
 void APRAcceptor::run(ConnectionInputHandlerFactory* factory) {
     running = true;
     processor.start();
-    std::cout << "Listening on port " << getPort() << "..." << std::endl;
+    QPID_LOG(info, "Listening on port " << getPort());
     while(running) {
             apr_socket_t* client;
             apr_status_t status = apr_socket_accept(&client, socket, APRPool::get());
@@ -97,7 +98,7 @@ void APRAcceptor::run(ConnectionInputHandlerFactory* factory) {
             Mutex::ScopedLock locker(shutdownLock);                
             if(running) {
                 if(status != APR_EINTR){
-                    std::cout << "ERROR: " << get_desc(status) << std::endl;
+                    QPID_LOG(error, get_desc(status));
                 }
                 shutdownImpl();
             }
diff --git a/cpp/src/qpid/sys/apr/APRBase.cpp b/cpp/src/qpid/sys/apr/APRBase.cpp
index ba7dfc08d4..f527e0d0b2 100644
--- a/cpp/src/qpid/sys/apr/APRBase.cpp
+++ b/cpp/src/qpid/sys/apr/APRBase.cpp
@@ -19,6 +19,7 @@
  *
  */
 #include <iostream>
+#include "qpid/log/Statement.h"
 #include "qpid/QpidError.h"
 #include "APRBase.h"
 
@@ -73,9 +74,8 @@ void APRBase::_decrement(){
 
 void APRBase::increment(){
     int count = 0;
-    while(count++ < 2 && !getInstance()->_increment()){
-        std::cout << "WARNING: APR initialization triggered concurrently with termination." << std::endl;
-    }
+    while(count++ < 2 && !getInstance()->_increment())
+        QPID_LOG(warning, "APR initialization triggered concurrently with termination.");
 }
 
 void APRBase::decrement(){
diff --git a/cpp/src/qpid/sys/apr/APRSocket.cpp b/cpp/src/qpid/sys/apr/APRSocket.cpp
index 96dbd132a1..3086bafc7c 100644
--- a/cpp/src/qpid/sys/apr/APRSocket.cpp
+++ b/cpp/src/qpid/sys/apr/APRSocket.cpp
@@ -20,6 +20,7 @@
  */
 #include "APRBase.h"
 #include "APRSocket.h"
+#include "qpid/log/Statement.h"
 #include <assert.h>
 #include <iostream>
 
@@ -53,7 +54,7 @@ void APRSocket::write(qpid::framing::Buffer& buffer){
 
 void APRSocket::close(){
     if(!closed){
-        std::cout << "Closing socket " << socket << "@" << this << std::endl;
+        QPID_LOG(warning, "Closing socket " << socket << "@" << this);
         CHECK_APR_SUCCESS(apr_socket_close(socket));
         closed = true;
     }
diff --git a/cpp/src/qpid/sys/apr/LFProcessor.cpp b/cpp/src/qpid/sys/apr/LFProcessor.cpp
index 9e139c874c..bb53e45a83 100644
--- a/cpp/src/qpid/sys/apr/LFProcessor.cpp
+++ b/cpp/src/qpid/sys/apr/LFProcessor.cpp
@@ -19,6 +19,7 @@
  *
  */
 #include <sstream>
+#include "qpid/log/Statement.h"
 #include "qpid/QpidError.h"
 #include "qpid/sys/Mutex.h"
 #include "LFProcessor.h"
@@ -136,7 +137,7 @@ void LFProcessor::run(){
             }
         }
     }catch(std::exception e){
-	std::cout << e.what() << std::endl;
+	QPID_LOG(error,  e.what());
     }
 }
 
diff --git a/cpp/src/qpid/sys/apr/LFSessionContext.cpp b/cpp/src/qpid/sys/apr/LFSessionContext.cpp
index 4f5fcb269e..2672b168e5 100644
--- a/cpp/src/qpid/sys/apr/LFSessionContext.cpp
+++ b/cpp/src/qpid/sys/apr/LFSessionContext.cpp
@@ -21,6 +21,7 @@
 #include "LFSessionContext.h"
 #include "APRBase.h"
 #include "qpid/QpidError.h"
+#include "qpid/log/Statement.h"
 #include <assert.h>
 
 using namespace qpid::sys;
@@ -60,20 +61,18 @@ void LFSessionContext::read(){
         AMQFrame frame;
         try{
             while(frame.decode(in)){
-                if(debug) log("RECV", &frame);
+                QPID_LOG(debug, "RECV: " << frame);
                 handler->received(&frame);
             }
-        }catch(QpidError error){
-            std::cout << "Error [" << error.code << "] " << error.msg
-                      << " (" << error.loc.file << ":" << error.loc.line
-                      << ")" << std::endl;
+        }catch(const std::exception& e){
+            QPID_LOG(error, e.what());
         }
     }else{
         ProtocolInitiation protocolInit;
         if(protocolInit.decode(in)){
             handler->initiated(protocolInit);
             initiated = true;
-            if(debug) std::cout << "INIT [" << &socket << "]" << std::endl;
+            QPID_LOG(debug, "INIT [" << &socket << "]");
         }
     }
     in.compact();
@@ -99,7 +98,7 @@ void LFSessionContext::write(){
                 while(frame && out.available() >= frame->size()){
                     encoded = true;
                     frame->encode(out);
-                    if(debug) log("SENT", frame);
+                    QPID_LOG(debug, "SENT: " << frame);
                     delete frame;
                     framesToWrite.pop();
                     frame = framesToWrite.empty() ? 0 : framesToWrite.front();
@@ -156,7 +155,7 @@ void LFSessionContext::close(){
 
 void LFSessionContext::handleClose(){
     handler->closed();
-    std::cout << "Session closed [" << &socket << "]" << std::endl;
+    QPID_LOG(info, "Session closed [" << &socket << "]");
     delete handler;
     delete this;
 }
@@ -171,9 +170,3 @@ void LFSessionContext::init(ConnectionInputHandler* _handler){
     processor->add(&fd);
 }
 
-void LFSessionContext::log(const std::string& desc, AMQFrame* const frame){
-    Mutex::ScopedLock l(logLock);
-    std::cout << desc << " [" << &socket << "]: " << *frame << std::endl;
-}
-
-Mutex LFSessionContext::logLock;
diff --git a/cpp/src/qpid/sys/apr/LFSessionContext.h b/cpp/src/qpid/sys/apr/LFSessionContext.h
index 3c90c4a381..5248d8f5bd 100644
--- a/cpp/src/qpid/sys/apr/LFSessionContext.h
+++ b/cpp/src/qpid/sys/apr/LFSessionContext.h
@@ -61,11 +61,6 @@ class LFSessionContext : public virtual qpid::sys::ConnectionOutputHandler
     bool processing;
     bool closing;
 
-    static qpid::sys::Mutex logLock;
-    void log(const std::string& desc,
-             qpid::framing::AMQFrame* const frame);
-        
-
   public:
     LFSessionContext(apr_pool_t* pool, apr_socket_t* socket, 
                      LFProcessor* const processor, 
diff --git a/cpp/src/qpid/sys/apr/Module.h b/cpp/src/qpid/sys/apr/Module.h
index d77cc0f388..ff93a0eaf0 100644
--- a/cpp/src/qpid/sys/apr/Module.h
+++ b/cpp/src/qpid/sys/apr/Module.h
@@ -21,7 +21,7 @@
  * under the License.
  *
  */
-
+#include "qpid/log/Statement.h"
 #include "qpid/QpidError.h"
 #include "APRBase.h"
 #include "APRPool.h"
@@ -85,7 +85,7 @@ template <class T> Module<T>::~Module() throw()
         }
         if (handle) unload();
     } catch (std::exception& e) {
-        std::cout << "Error while destroying module: " << e.what() << std::endl;
+        QPID_LOG(error, "Error while destroying module: " << e.what());
     }
     destroy = 0;
     handle = 0;
diff --git a/cpp/src/qpid/sys/apr/Thread.h b/cpp/src/qpid/sys/apr/Thread.h
index ce876efbdf..8cbbc0456e 100644
--- a/cpp/src/qpid/sys/apr/Thread.h
+++ b/cpp/src/qpid/sys/apr/Thread.h
@@ -37,6 +37,12 @@ class Thread
 {
   public:
     inline static Thread current();
+
+    /** ID of current thread for logging.
+     * Workaround for broken Thread::current() in APR 
+     */
+    inline static long logId();
+
     inline static void yield();
 
     inline Thread();
@@ -46,7 +52,7 @@ class Thread
     inline void join();
 
     inline long id();
-        
+
   private:
     static void* APR_THREAD_FUNC runRunnable(apr_thread_t* thread, void *data);
     inline Thread(apr_thread_t* t);
@@ -75,6 +81,13 @@ long Thread::id() {
     return long(thread);
 }
 
+/** ID of current thread for logging.
+ * Workaround for broken Thread::current() in APR
+ */
+long Thread::logId() {
+    return static_cast<long>(apr_os_thread_current());
+}
+
 Thread::Thread(apr_thread_t* t) : thread(t) {}
 
 Thread Thread::current(){