You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@qpid.apache.org by ac...@apache.org on 2007/05/30 18:14:02 UTC

svn commit: r542855 [2/2] - in /incubator/qpid/trunk/qpid/cpp: docs/man/ src/ src/qpid/ src/qpid/broker/ src/qpid/client/ src/qpid/log/ src/qpid/sys/ src/qpid/sys/apr/ src/qpid/sys/posix/ src/tests/ src/tests/unit/

Added: incubator/qpid/trunk/qpid/cpp/src/tests/unit/logging.cpp
URL: http://svn.apache.org/viewvc/incubator/qpid/trunk/qpid/cpp/src/tests/unit/logging.cpp?view=auto&rev=542855
==============================================================================
--- incubator/qpid/trunk/qpid/cpp/src/tests/unit/logging.cpp (added)
+++ incubator/qpid/trunk/qpid/cpp/src/tests/unit/logging.cpp Wed May 30 09:13:58 2007
@@ -0,0 +1,373 @@
+/*
+ *
+ * Copyright (c) 2006 The Apache Software Foundation
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ *
+ */
+
+#include "test_tools.h"
+#include "qpid/log/Logger.h"
+#include "qpid/log/Options.h"
+#include "qpid/memory.h"
+#include "qpid/CommonOptions.h"
+#include <boost/test/floating_point_comparison.hpp>
+#include <boost/format.hpp>
+#include <exception>
+#include <time.h>
+#include <fstream>
+
+
+using namespace std;
+using namespace boost;
+using namespace qpid::log;
+
+BOOST_AUTO_TEST_CASE(testStatementInit) {
+    Statement s=QPID_LOG_STATEMENT_INIT(debug); int line=__LINE__;
+    BOOST_CHECK(!s.enabled);
+    BOOST_CHECK_EQUAL(string(__FILE__), s.file);
+    BOOST_CHECK_EQUAL(line, s.line);
+    BOOST_CHECK_EQUAL(string("void testStatementInit()"), s.function);
+    BOOST_CHECK_EQUAL(debug, s.level);
+}
+
+
+BOOST_AUTO_TEST_CASE(testSelector_enable) {
+    Selector s;
+    // Simple enable
+    s.enable(debug,"foo");
+    BOOST_CHECK(s.isEnabled(debug,"foo"));
+    BOOST_CHECK(!s.isEnabled(error,"foo"));
+    BOOST_CHECK(!s.isEnabled(error,"bar"));
+
+    // Substring match
+    BOOST_CHECK(s.isEnabled(debug, "bazfoobar"));
+    BOOST_CHECK(!s.isEnabled(debug, "bazbar"));
+
+    // Different levels for different substrings.
+    s.enable(info, "bar");
+    BOOST_CHECK(s.isEnabled(debug, "foobar"));
+    BOOST_CHECK(s.isEnabled(info, "foobar"));
+    BOOST_CHECK(!s.isEnabled(debug, "bar"));
+    BOOST_CHECK(!s.isEnabled(info, "foo"));
+
+    // Enable-strings
+    s.enable("notice:blob");
+    BOOST_CHECK(s.isEnabled(notice, "blob"));
+    s.enable("error+:oops");
+    BOOST_CHECK(s.isEnabled(error, "oops"));
+    BOOST_CHECK(s.isEnabled(critical, "oops"));
+}
+
+Logger& clearLogger() {
+    Logger::instance().clear();
+    return Logger::instance();
+}
+
+BOOST_AUTO_TEST_CASE(testStatementEnabled) {
+    // Verify that the logger enables and disables log statements.
+    Logger& l=clearLogger();
+    l.select(Selector(debug));
+    Statement s=QPID_LOG_STATEMENT_INIT(debug);
+    BOOST_CHECK(!s.enabled);
+    Statement::Initializer init(s);
+    BOOST_CHECK(s.enabled);
+
+    Statement s2=QPID_LOG_STATEMENT_INIT(warning);
+    Statement::Initializer init2(s2);
+    BOOST_CHECK(!s2.enabled);
+
+    l.select(Selector(warning));
+    BOOST_CHECK(!s.enabled);
+    BOOST_CHECK(s2.enabled);
+}
+
+struct TestOutput : public Logger::Output {
+    vector<string> msg;
+    vector<Statement> stmt;
+
+    TestOutput() {
+        Logger::instance().output(qpid::make_auto_ptr<Logger::Output>(this));
+    }
+    void log(const Statement& s, const string& m) {
+        msg.push_back(m);
+        stmt.push_back(s);
+    }
+    string last() { return msg.back(); }
+};
+
+using boost::assign::list_of;
+
+BOOST_AUTO_TEST_CASE(testLoggerOutput) {
+    Logger& l=clearLogger();
+    l.select(Selector(debug));
+    Statement s=QPID_LOG_STATEMENT_INIT(debug);
+    TestOutput* out=new TestOutput();
+
+    // Verify message is output.
+    l.log(s, "foo");
+    vector<string> expect=list_of("foo\n");
+    BOOST_CHECK_EQUAL(expect, out->msg);
+
+    // Verify multiple outputs
+    TestOutput* out2=new TestOutput();
+    l.log(Statement(), "baz");
+    expect.push_back("baz\n");
+    BOOST_CHECK_EQUAL(expect, out->msg);
+    expect.erase(expect.begin());
+    BOOST_CHECK_EQUAL(expect, out2->msg);
+}
+
+BOOST_AUTO_TEST_CASE(testMacro) {
+    Logger& l = clearLogger();
+    l.select(Selector(info));
+    TestOutput* out=new TestOutput();
+    QPID_LOG(info, "foo");
+    vector<string> expect=list_of("foo\n");
+    BOOST_CHECK_EQUAL(expect, out->msg);
+    BOOST_CHECK_EQUAL(__FILE__, out->stmt.front().file);
+    BOOST_CHECK_EQUAL("void testMacro()", out->stmt.front().function);
+
+    // Not enabled:
+    QPID_LOG(debug, "bar");
+    BOOST_CHECK_EQUAL(expect, out->msg);
+
+    QPID_LOG(info, 42 << " bingo");
+    expect.push_back("42 bingo\n");
+    BOOST_CHECK_EQUAL(expect, out->msg);
+}
+
+BOOST_AUTO_TEST_CASE(testLoggerFormat) {
+    Logger& l=clearLogger();
+    l.select(Selector(critical));
+    TestOutput* out=new TestOutput();
+
+    // Time format is YYY-Month-dd hh:mm:ss
+    l.format(Logger::TIME);
+    QPID_LOG(critical, "foo");
+    string re("\\d\\d\\d\\d-[A-Z][a-z]+-\\d\\d \\d\\d:\\d\\d:\\d\\d foo\n");
+    BOOST_CHECK_REGEX(re, out->last());
+
+    l.format(Logger::FILE);
+    QPID_LOG(critical, "foo");
+    BOOST_CHECK_EQUAL(out->last(), string(__FILE__)+": foo\n");
+
+    l.format(Logger::FILE|Logger::LINE);
+    QPID_LOG(critical, "foo");
+    BOOST_CHECK_REGEX(string(__FILE__)+":\\d+: foo\n", out->last());
+
+    l.format(Logger::FUNCTION);
+    QPID_LOG(critical, "foo");
+    BOOST_CHECK_EQUAL("void testLoggerFormat(): foo\n", out->last());
+    
+    l.format(Logger::LEVEL);
+    QPID_LOG(critical, "foo");
+    BOOST_CHECK_EQUAL("critical foo\n", out->last());
+
+    l.format(~0);               // Everything
+    QPID_LOG(critical, "foo");
+    re=".* critical \\[[0-9a-f]*] "+string(__FILE__)+":\\d+:void testLoggerFormat\\(\\): foo\n";
+    BOOST_CHECK_REGEX(re, out->last());
+}
+
+BOOST_AUTO_TEST_CASE(testOstreamOutput) {
+    Logger& l=clearLogger();
+    l.select(Selector(error));
+    ostringstream os;
+    l.output(os);
+    QPID_LOG(error, "foo");
+    QPID_LOG(error, "bar");
+    QPID_LOG(error, "baz");
+    BOOST_CHECK_EQUAL("foo\nbar\nbaz\n", os.str());
+    l.clear();
+}
+
+#if 0 // This test requires manual intervention. Normally disabled.
+BOOST_AUTO_TEST_CASE(testSyslogOutput) {
+    Logger& l = clearLogger();
+    l.select(Selector(info));
+    l.syslog("qpid_test");
+    QPID_LOG(info, "Testing QPID");
+    BOOST_ERROR("Manually verify that /var/log/messages contains a recent line 'Testing QPID'");
+}
+#endif // 0
+
+int count() {
+    static int n = 0;
+    return n++;
+}
+
+int loggedCount() {
+    static int n = 0;
+    QPID_LOG(debug, "counting: " << n);
+    return n++;
+}
+
+
+using namespace qpid::sys;
+
+// Measure CPU time.
+clock_t timeLoop(int times, int (*fp)()) {
+    clock_t start=clock();
+    while (times-- > 0)
+        (*fp)();
+    return clock() - start;
+}
+
+// Overhead test disabled because it consumes a ton of CPU and takes
+// forever under valgrind. Not friendly for regular test runs.
+// 
+#if 0
+BOOST_AUTO_TEST_CASE(testOverhead) {
+    // Ensure that the ratio of CPU time for an incrementing loop
+    // with and without disabled log statements is in  acceptable limits.
+    // 
+    int times=100000000;
+    clock_t noLog=timeLoop(times, count);
+    clock_t withLog=timeLoop(times, loggedCount);
+    double ratio=double(withLog)/double(noLog);
+
+    // NB: in initial tests the ratio was consistently below 1.5,
+    // 2.5 is reasonable and should avoid spurios failures
+    // due to machine load.
+    // 
+    BOOST_CHECK_SMALL(ratio, 2.5); 
+}    
+#endif // 0
+
+Statement statement(
+    Level level, const char* file="", int line=0, const char* fn=0)
+{
+    Statement s={0, file, line, fn, level};
+    return s;
+}
+
+
+struct TestOptions : public Options {
+    TestOptions(int argc, char** argv) {
+        qpid::po::options_description desc;
+        addTo(desc);
+        qpid::parseOptions(desc, argc, argv);
+    }
+};
+
+#define ARGC(argv) (sizeof(argv)/sizeof(char*))
+
+BOOST_AUTO_TEST_CASE(testOptionsParse) {
+    char* argv[]={
+        0,
+        "--log.enable", "error+:foo",
+        "--log.enable", "debug:bar",
+        "--log.enable", "info",
+        "--log.output", "x",
+        "--log.output", "y",
+        "--log.level", "yes",
+        "--log.source", "1",
+        "--log.thread", "true",
+        "--log.function", "YES"
+    };
+    TestOptions opts(ARGC(argv), argv);
+    vector<string> expect=list_of("error+:foo")("debug:bar")("info");
+    BOOST_CHECK_EQUAL(expect, opts.selectors);
+    expect=list_of("x")("y");
+    BOOST_CHECK_EQUAL(expect, opts.outputs);
+    BOOST_CHECK(opts.level);
+    BOOST_CHECK(opts.source);
+    BOOST_CHECK(opts.function);
+    BOOST_CHECK(opts.thread);
+}
+
+BOOST_AUTO_TEST_CASE(testOptionsDefault) {
+    Options opts;
+    vector<string> expect=list_of("stderr");
+    BOOST_CHECK_EQUAL(expect, opts.outputs);
+    expect=list_of("error+");
+    BOOST_CHECK_EQUAL(expect, opts.selectors);
+    BOOST_CHECK(opts.time && opts.level);
+    BOOST_CHECK(!(opts.source || opts.function || opts.thread));
+}
+
+BOOST_AUTO_TEST_CASE(testSelectorFromOptions) {
+    char* argv[]={
+        0,
+        "--log.enable", "error+:foo",
+        "--log.enable", "debug:bar",
+        "--log.enable", "info"
+    };
+    TestOptions opts(ARGC(argv), argv);
+    vector<string> expect=list_of("error+:foo")("debug:bar")("info");
+    BOOST_CHECK_EQUAL(expect, opts.selectors);
+    Selector s(opts);
+    BOOST_CHECK(!s.isEnabled(warning, "x"));
+    BOOST_CHECK(!s.isEnabled(debug, "x"));
+    BOOST_CHECK(s.isEnabled(debug, "bar"));
+    BOOST_CHECK(s.isEnabled(error, "foo"));
+    BOOST_CHECK(s.isEnabled(critical, "foo"));
+}
+
+BOOST_AUTO_TEST_CASE(testOptionsFormat) {
+    Logger& l = clearLogger();
+    Options opts;
+    BOOST_CHECK_EQUAL(Logger::TIME|Logger::LEVEL, l.format(opts));
+    char* argv[]={
+        0,
+        "--log.time", "no", 
+        "--log.level", "no",
+        "--log.source", "1",
+        "--log.thread",  "1"
+    };
+    qpid::po::options_description desc;
+    opts.addTo(desc);
+    qpid::parseOptions(desc, ARGC(argv), argv);
+    BOOST_CHECK_EQUAL(
+        Logger::FILE|Logger::LINE|Logger::THREAD, l.format(opts));
+    opts = Options();           // Clear.
+    char* argv2[]={
+        0,
+        "--log.level", "no",
+        "--log.thread", "true",
+        "--log.function", "YES",
+        "--log.time", "YES"
+    };
+    qpid::po::options_description desc2;
+    opts.addTo(desc2);
+    qpid::parseOptions(desc2, ARGC(argv2), argv2);
+    BOOST_CHECK_EQUAL(
+        Logger::THREAD|Logger::FUNCTION|Logger::TIME,
+        l.format(opts));
+}
+
+
+BOOST_AUTO_TEST_CASE(testLoggerConfigure) {
+    Logger& l = clearLogger();
+    Options opts;
+    char* argv[]={
+        0,
+        "--log.time", "no", 
+        "--log.source", "yes",
+        "--log.output", "logging.tmp",
+        "--log.enable", "critical"
+    };
+    qpid::po::options_description desc;
+    opts.addTo(desc);
+    qpid::parseOptions(desc, ARGC(argv), argv);
+    l.configure(opts, "test");
+    QPID_LOG(critical, "foo"); int srcline=__LINE__;
+    ifstream log("logging.tmp");
+    string line;
+    getline(log, line);
+    string expect=(format("critical %s:%d: foo")%__FILE__%srcline).str();
+    BOOST_CHECK_EQUAL(expect, line);
+    log.close();
+    unlink("logging.tmp");
+}

Propchange: incubator/qpid/trunk/qpid/cpp/src/tests/unit/logging.cpp
------------------------------------------------------------------------------
    svn:eol-style = native

Propchange: incubator/qpid/trunk/qpid/cpp/src/tests/unit/logging.cpp
------------------------------------------------------------------------------
    svn:keywords = Rev Date

Added: incubator/qpid/trunk/qpid/cpp/src/tests/unit/test_tools.h
URL: http://svn.apache.org/viewvc/incubator/qpid/trunk/qpid/cpp/src/tests/unit/test_tools.h?view=auto&rev=542855
==============================================================================
--- incubator/qpid/trunk/qpid/cpp/src/tests/unit/test_tools.h (added)
+++ incubator/qpid/trunk/qpid/cpp/src/tests/unit/test_tools.h Wed May 30 09:13:58 2007
@@ -0,0 +1,53 @@
+#ifndef TEST_TOOLS_H
+#define TEST_TOOLS_H
+
+/*
+ *
+ * Copyright (c) 2006 The Apache Software Foundation
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ *
+ */
+
+#define BOOST_AUTO_TEST_MAIN    // Must come before #include<boost/test/*>
+#include <boost/test/auto_unit_test.hpp>
+#include <boost/assign/list_of.hpp>
+#include <boost/regex.hpp>
+#include <vector>
+
+/** Stream operator so BOOST_CHECK_EQUALS works on vectors. */
+namespace std {
+template <class T>
+ostream& operator <<(ostream& o, const vector<T>& v) {
+    o << " {";
+    typename vector<T>::const_iterator i = v.begin();
+    if (i != v.end())
+        o << *i++;
+    while (i != v.end())
+        o << ", " << *i++;
+    return o << "}";
+}
+} // namespace std
+
+/** NB: order of parameters is regex first, in line with
+ * CHECK(expected, actual) convention.
+ */
+inline bool regexPredicate(const std::string& re, const std::string& text) {
+    return boost::regex_match(text, boost::regex(re));
+}
+
+/** Check for regular expression match. You must #include <boost/regex.hpp> */
+#define BOOST_CHECK_REGEX(re, text) \
+    BOOST_CHECK_PREDICATE(regexPredicate, (re)(text))
+
+#endif  /*!TEST_TOOLS_H*/

Propchange: incubator/qpid/trunk/qpid/cpp/src/tests/unit/test_tools.h
------------------------------------------------------------------------------
    svn:eol-style = native

Propchange: incubator/qpid/trunk/qpid/cpp/src/tests/unit/test_tools.h
------------------------------------------------------------------------------
    svn:keywords = Rev Date