From b8b931c5017db2d54aabf26fafcffa3f0b986757 Mon Sep 17 00:00:00 2001 From: Shawn Routhier Date: Thu, 19 May 2016 21:56:18 -0700 Subject: [PATCH 1/3] [4480] Add debug logging for evaluation of classification expressions This patch adds a set of log messages to indicate what values are being popped from or pushed to the classification value stack. This is meant to be used by an administrator when debugging the expression statements. --- ChangeLog | 4 + doc/guide/classify.xml | 58 ++++ src/lib/eval/eval_log.h | 8 +- src/lib/eval/eval_messages.mes | 103 +++++- src/lib/eval/tests/token_unittest.cc | 480 ++++++++++++++++++++++++++- src/lib/eval/token.cc | 156 ++++++++- src/lib/eval/token.h | 2 +- 7 files changed, 787 insertions(+), 24 deletions(-) diff --git a/ChangeLog b/ChangeLog index 6fa8b29adc..dcf4170310 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,7 @@ +11XX. [func] sar + Add debug logging to the classification tokens. + (Trac #4480, git TBD) + 1114. [bug] stephen Adjusted variable type in a MySQL-related file to overcome a type mismatch problem reported by one particular compiler. diff --git a/doc/guide/classify.xml b/doc/guide/classify.xml index ba746272f5..d9d85ea03e 100644 --- a/doc/guide/classify.xml +++ b/doc/guide/classify.xml @@ -625,4 +625,62 @@ +
+ Debugging Expressions + + While you are constructing your classification expressions you may + find it useful to enable logging see for + a more complete description of the logging facility. + + + + To enable the debug statements in the classifciaton system you will + need to set the severity to "DEBUG" and the debug level to at least 55. + The specific loggers are "kea-dhcp4.eval" and "kea-dhcp6.eval". + + + + When debug logging is enabled each time a token is evaluated it will + emit a log line indicating the values of any objects that were popped + off of the value stack and any objects that were pushed onto the value + stack. + + + + The values will be displayed as either text if the command is known + to use text values or hex if the command either uses binary values or + can manipulate either text or binary values. For expressions that + pop multiple values off the stack the values will be displayed in + the order they were popped. For most expressions this won't matter + but for the concat expression the values are displayed in reverse + order from how they are written in the expression. + + + + Let us assume that the following test has been entered into the configuration. + This example skips most of the configuration to concentrate on the test. + + "test": "substring(option[61].hex,0,3) == 'foo'", + + The logging might then resemble this: + + 2016-05-19 13:35:04.163 DEBUG [kea.eval/44478] EVAL_DEBUG_OPTION Pushing option 61 with value 0x666F6F626172 + 2016-05-19 13:35:04.164 DEBUG [kea.eval/44478] EVAL_DEBUG_STRING Pushing text string "0" + 2016-05-19 13:35:04.165 DEBUG [kea.eval/44478] EVAL_DEBUG_STRING Pushing text string "3" + 2016-05-19 13:35:04.166 DEBUG [kea.eval/44478] EVAL_DEBUG_SUBSTRING Popping length 3, start 0, + string 0x666F6F626172 pushing result 0x666F6F + 2016-05-19 13:35:04.167 DEBUG [kea.eval/44478] EVAL_DEBUG_STRING Pushing text string "foo" + 2016-05-19 13:35:04.168 DEBUG [kea.eval/44478] EVAL_DEBUG_EQUAL Popping 0x666F6F and 0x666F6F pushing result "true" + + + + + The debug logging may be quite verbose if you have a number of expressions + to evaluate. It is intended as an aide in helping you create and debug + your expressions. You should plan to disable debug logging when you have your + expressions working correctly. You also may wish to debug only one set of + expressions at a time to limit the log statements. + +
+ diff --git a/src/lib/eval/eval_log.h b/src/lib/eval/eval_log.h index a85e459f1f..20205ea0ad 100644 --- a/src/lib/eval/eval_log.h +++ b/src/lib/eval/eval_log.h @@ -1,4 +1,4 @@ -// Copyright (C) 2015 Internet Systems Consortium, Inc. ("ISC") +// Copyright (C) 2015-2016 Internet Systems Consortium, Inc. ("ISC") // // This Source Code Form is subject to the terms of the Mozilla Public // License, v. 2.0. If a copy of the MPL was not distributed with this @@ -21,11 +21,11 @@ namespace dhcp { // The first level traces normal operations, const int EVAL_DBG_TRACE = DBGLVL_TRACE_BASIC; -// The next level traces each call to hook code. +// The next level traces each call to eval code. const int EVAL_DBG_CALLS = DBGLVL_TRACE_BASIC_DATA; -// Additional information on the calls. Report each call to a callout (even -// if there are multiple callouts on a hook) and each status return. +// Additional information on the calls. Report the values that were +// popped from or pushed to the value stack. const int EVAL_DBG_EXTENDED_CALLS = DBGLVL_TRACE_DETAIL_DATA; /// @brief Eval Logger diff --git a/src/lib/eval/eval_messages.mes b/src/lib/eval/eval_messages.mes index 9d23293581..3ee2da1306 100644 --- a/src/lib/eval/eval_messages.mes +++ b/src/lib/eval/eval_messages.mes @@ -1,4 +1,4 @@ -# Copyright (C) 2015 Internet Systems Consortium, Inc. ("ISC") +# Copyright (C) 2015-2016 Internet Systems Consortium, Inc. ("ISC") # # This Source Code Form is subject to the terms of the Mozilla Public # License, v. 2.0. If a copy of the MPL was not distributed with this @@ -6,6 +6,107 @@ $NAMESPACE isc::dhcp + +# For use with TokenAnd +% EVAL_DEBUG_AND Popping %1 and %2 pushing %3 +This debug message indicates that two values are popped from +the value stack. Then are then combined via logical and and +the result is pushed onto the value stack. + +# For use with TokenConcat +% EVAL_DEBUG_CONCAT Popping %1 and %2 pushing %3 +This debug message indicates that the two strings are being popped off +of the stack. They are then concatenated and the resulting string is +pushed onto the stack. The strings are displayed in hex. + +# For use with TokenEqual +# Start with binary for the inputs for now, we may add text in the future. +% EVAL_DEBUG_EQUAL Popping %1 and %2 pushing result %3 +This debug message indicates that the two strings are being popped off +of the value stack and the result of comparing them is being pushed onto +the value stack. The strings are displayed in hex. + +# For use with TokenHexString +% EVAL_DEBUG_HEXSTRING Pushing hex string %1 +This debug message indicates that the given binary string is being pushed +onto the value stack. The string is displayed in hex. + +# For use with TokenIpAddress +% EVAL_DEBUG_IPADDRESS Pushing IPAddress %1 +This debug message indicates that the given binary string is being pushed +onto the value stack. This represents either an IPv4 or IPv6 address. +The string is displayed in hex. + +# For use with TokenNot +% EVAL_DEBUG_NOT Popping %1 pushing %2 +This debug message indicates that the first value is popped from +the value stack, negated and then pushed onto the value stack. +The string is displayed in text. + +# For use with TokenOption based classes. These include TokenOpton, +# TokenRelay4Option and TokenRelay6Option. +% EVAL_DEBUG_OPTION Pushing option %1 with value %2 +This debug message indicates that the given string representing the +value of the requested option is being pushed onto the value stack. +The string may be the text or binary value of the string based on the +representation type requested (.text or .hex) or "true" or "false" if +the requested type is .exists. The option code may be for either an +option or a sub-option as requested in the classification statement. + +# For use with TokenOr +% EVAL_DEBUG_OR Popping %1 and %2 pushing %3 +This debug message indicates that two values are popped from +the value stack. Then are then combined via logical or and +the result is pushed onto the value stack. The string is displayed +in text. + +# For use with TokenPkt4 +% EVAL_DEBUG_PKT4 Pushing PKT4 field %1 with value %2 +This debug message indicates that the given binary string representing +the value of the requested fied is being pushed onto the value stack. +The string is displayed in hex. + +# For use with TokenPkt6 +% EVAL_DEBUG_PKT6 Pushing PKT6 field %1 with value %2 +This debug message indicates that the given binary string representing +the value of the requested fied is being pushed onto the value stack. +The string is displayed in hex. + +# For use with TokenRelay6Field +% EVAL_DEBUG_RELAY6 Pushing PKT6 relay field %1 nest %2 with value %3 +This debug message indicates that the given binary string representing +the value of the requested fied is being pushed onto the value stack. +The string is displayed in hex. + +% EVAL_DEBUG_RELAY6_RANGE Pushing PKT6 relay field %1 nest %2 with value %3 +This debug message is generated if the nest field is out of range. The +empty string will always be the value pushed onto the stack. + +# For use with TokenString +% EVAL_DEBUG_STRING Pushing text string %1 +This debug message indicates that the given text string is being pushed +onto the value stack. The string is displayed in text. + +# For use with TokenSubstring +# Start with binary for the strings for now, we may add text in the future. +% EVAL_DEBUG_SUBSTRING Popping length %1, start %2, string %3 pushing result %4 +This debug message indicates that three values are being popped from +the value stack and a result is being pushed onto the value stack. The +values being popped are the starting point and length of a substring to +extract from the given string. The resulting string is pushed onto +the stack. The strings are displayed in hex. + +% EVAL_DEBUG_SUBSTRING_EMPTY Popping length %1, start %2, string %3 pushing result %4 +This debug message indicates that the string popped from the stack was empty +and so the result will also be empty. The start, length and string are +still popped from the stack and the result is still pushed. + +% EVAL_DEBUG_SUBSTRING_RANGE Popping length %1, start %2, string %3 pushing result %4 +This debug message indicates that the value of start is outside of the +string and an empty result will be pushed onto the stack. The start, +length and string are still popped from the stack and the result is +still pushed. The strings are displayed in hex. + % EVAL_RESULT Expression %1 evaluated to %2 This debug message indicates that the expression has been evaluated to said value. This message is mostly useful during debugging of the diff --git a/src/lib/eval/tests/token_unittest.cc b/src/lib/eval/tests/token_unittest.cc index 80af7c3c12..1d3543334b 100644 --- a/src/lib/eval/tests/token_unittest.cc +++ b/src/lib/eval/tests/token_unittest.cc @@ -5,12 +5,16 @@ // file, You can obtain one at http://mozilla.org/MPL/2.0/. #include +#include #include #include #include #include #include #include +#include +#include +#include #include #include @@ -21,6 +25,7 @@ using namespace std; using namespace isc::dhcp; using namespace isc::asiolink; +using namespace isc::log; namespace { @@ -28,6 +33,7 @@ namespace { /// /// This class provides several convenience objects to be used during testing /// of the Token family of classes. + class TokenTest : public ::testing::Test { public: @@ -43,6 +49,54 @@ public: pkt4_->addOption(option_str4_); pkt6_->addOption(option_str6_); + + // Set up the logger for use in checking the debug statements. + // We send the debug statements to a file which we can + // check after the evaluations have completed. We also + // set the log severity and debug levels so that the log + // statements are executed. + LoggerSpecification spec(getRootLoggerName(), + keaLoggerSeverity(isc::log::DEBUG), + keaLoggerDbglevel(isc::log::MAX_DEBUG_LEVEL)); + OutputOption option; + option.destination = OutputOption::DEST_FILE; + option.filename = string(TokenTest::LOG_FILE); + spec.addOutputOption(option); + LoggerManager manager; + manager.process(spec); + } + + /// @brief check that the requested strings are in the + /// test log file in the requested order. + /// + /// @param exp_strings vector of strings to match + /// @return true if all of the strings match + bool checkFile(const vector& exp_strings) { + ifstream file(LOG_FILE); + EXPECT_TRUE(file.is_open()); + string line, exp_line; + int i = 0; + bool found = true; + + while (getline(file, line) && (i != exp_strings.size())) { + exp_line = exp_strings[i]; + i++; + if (string::npos == line.find(exp_line)) { + found = false; + } + } + + file.close(); + + if ((i != exp_strings.size()) || (found == false)) + return (false); + + return (true); + } + + /// @brief remove the test log file + void remFile() { + static_cast(remove(LOG_FILE)); } /// @brief Inserts RAI option with several suboptions @@ -229,8 +283,15 @@ public: } /// @todo: Add more option types here + + /// Name of the log file used during tests + static const char * LOG_FILE; }; +// Set up the name of the LOG_FILE for use in checking +// the debug statements +const char *TokenTest::LOG_FILE = "test.log"; + // This tests the toBool() conversions TEST_F(TokenTest, toBool) { @@ -262,6 +323,14 @@ TEST_F(TokenTest, string4) { // Check that the evaluation put its value on the values stack. ASSERT_EQ(1, values_.size()); EXPECT_EQ("foo", values_.top()); + + // Check that the debug output was correct, we create a vector + // of all the strings we expect (in this case only 1) and send + // it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_STRING Pushing text string \"foo\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This simple test checks that a TokenString, representing a constant string, @@ -277,6 +346,14 @@ TEST_F(TokenTest, string6) { // Check that the evaluation put its value on the values stack. ASSERT_EQ(1, values_.size()); EXPECT_EQ("foo", values_.top()); + + // Check that the debug output was correct, we create a vector + // of all the strings we expect (in this case only 1) and send + // it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_STRING Pushing text string \"foo\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This simple test checks that a TokenHexString, representing a constant @@ -306,7 +383,8 @@ TEST_F(TokenTest, hexstring4) { // Store constant hexstring "0x63825363" (DHCP_OPTIONS_COOKIE). ASSERT_NO_THROW(cookie.reset(new TokenHexString("0x63825363"))); - // Make sure that tokens can be evaluated without exceptions. + // Make sure that tokens can be evaluated without exceptions, + // and verify the debug output ASSERT_NO_THROW(empty->evaluate(*pkt4_, values_)); ASSERT_NO_THROW(bad->evaluate(*pkt4_, values_)); ASSERT_NO_THROW(nodigit->evaluate(*pkt4_, values_)); @@ -332,6 +410,19 @@ TEST_F(TokenTest, hexstring4) { EXPECT_EQ("", values_.top()); values_.pop(); EXPECT_EQ("", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x07"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x666F6F"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x63825363"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This simple test checks that a TokenHexString, representing a constant @@ -387,6 +478,19 @@ TEST_F(TokenTest, hexstring6) { EXPECT_EQ("", values_.top()); values_.pop(); EXPECT_EQ("", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x07"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x666F6F"); + exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x63825363"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks that a TokenIpAddress, representing an IP address as @@ -432,6 +536,17 @@ TEST_F(TokenTest, ipaddress) { uint8_t expected4[] = { 10, 0, 0, 1 }; EXPECT_EQ(4, values_.top().size()); EXPECT_EQ(0, memcmp(expected4, &values_.top()[0], 4)); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x0A000001"); + exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress " + "0x20010DB8000000000000000000000001"); + exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x"); + exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an option value is able to extract @@ -460,6 +575,14 @@ TEST_F(TokenTest, optionString4) { // Then the content of the option 100. EXPECT_EQ("hundred4", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"hundred4\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing option value is able to extract @@ -489,6 +612,15 @@ TEST_F(TokenTest, optionHexString4) { // Then the content of the option 100. EXPECT_EQ("hundred4", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value " + "0x68756E6472656434"); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value 0x"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an option value is able to check @@ -511,6 +643,14 @@ TEST_F(TokenTest, optionExistsString4) { EXPECT_EQ("false", values_.top()); values_.pop(); EXPECT_EQ("true", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"true\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"false\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an option value is able to extract @@ -539,6 +679,14 @@ TEST_F(TokenTest, optionString6) { // Then the content of the option 100. EXPECT_EQ("hundred6", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"hundred6\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an option value is able to extract @@ -568,6 +716,15 @@ TEST_F(TokenTest, optionHexString6) { // Then the content of the option 100. EXPECT_EQ("hundred6", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value " + "0x68756E6472656436"); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value 0x"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an option value is able to check @@ -590,6 +747,14 @@ TEST_F(TokenTest, optionExistsString6) { EXPECT_EQ("false", values_.top()); values_.pop(); EXPECT_EQ("true", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"true\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"false\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks that the existing relay4 option can be found. @@ -610,6 +775,13 @@ TEST_F(TokenTest, relay4Option) { // The option should be found and relay4[13] should evaluate to the // content of that sub-option, i.e. "thirteen" EXPECT_EQ("thirteen", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 13 with value \"thirteen\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks that the code properly handles cases when @@ -631,6 +803,13 @@ TEST_F(TokenTest, relay4OptionNoSuboption) { // The option should NOT be found (there is no sub-option 15), // so the expression should evaluate to "" EXPECT_EQ("", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 15 with value \"\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks that the code properly handles cases when @@ -651,6 +830,13 @@ TEST_F(TokenTest, relay4OptionNoRai) { // The option should NOT be found (there is no sub-option 13), // so the expression should evaluate to "" EXPECT_EQ("", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 13 with value \"\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks that only the RAI is searched for the requested @@ -707,6 +893,17 @@ TEST_F(TokenTest, relay4RAIOnly) { EXPECT_NO_THROW(t_->evaluate(*pkt4_, values_)); ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 13 with value \"thirteen\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 1 with value \"one\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 70 with value \"\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 1 with value \"true\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 70 with value \"false\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Verifies if the DHCPv4 packet fields can be extracted. @@ -787,6 +984,26 @@ TEST_F(TokenTest, pkt4Fields) { clearStack(); ASSERT_NO_THROW(t_.reset(new TokenPkt4(TokenPkt4::HLEN))); EXPECT_THROW(t_->evaluate(*pkt6_, values_), EvalTypeError); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field mac " + "with value 0x01020304050607"); + exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field hlen " + "with value 0x00000007"); + exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field htype " + "with value 0x0000007B"); + exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field giaddr " + "with value 0xC0000201"); + exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field ciaddr " + "with value 0xC0000202"); + exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field yiaddr " + "with value 0xC0000203"); + exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field siaddr " + "with value 0xC0000204"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an == operator is able to @@ -818,6 +1035,14 @@ TEST_F(TokenTest, optionEqualFalse) { // result of "foo" == "bar" comparision. ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x626172 and 0x666F6F " + "pushing result \"false\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an == operator is able to @@ -834,6 +1059,14 @@ TEST_F(TokenTest, optionEqualTrue) { // result of "foo" == "foo" comparision. ASSERT_EQ(1, values_.size()); EXPECT_EQ("true", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x666F6F and 0x666F6F " + "pushing result \"true\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing a not is able to @@ -867,6 +1100,14 @@ TEST_F(TokenTest, operatorNot) { EXPECT_NO_THROW(t_->evaluate(*pkt4_, values_)); ASSERT_EQ(1, values_.size()); EXPECT_EQ("true", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_NOT Popping \"true\" pushing \"false\""); + exp_strings.push_back("EVAL_DEBUG_NOT Popping \"false\" pushing \"true\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an and is able to @@ -907,7 +1148,7 @@ TEST_F(TokenTest, operatorAndFalse) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); - // After true and false, checks false and true + // After true and false, check false and true values_.push("true"); EXPECT_NO_THROW(t_->evaluate(*pkt4_, values_)); ASSERT_EQ(1, values_.size()); @@ -918,6 +1159,15 @@ TEST_F(TokenTest, operatorAndFalse) { EXPECT_NO_THROW(t_->evaluate(*pkt4_, values_)); ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_AND Popping \"false\" and \"true\" pushing \"false\""); + exp_strings.push_back("EVAL_DEBUG_AND Popping \"true\" and \"false\" pushing \"false\""); + exp_strings.push_back("EVAL_DEBUG_AND Popping \"false\" and \"false\" pushing \"false\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an and is able to @@ -933,6 +1183,13 @@ TEST_F(TokenTest, operatorAndTrue) { // After evaluation there should be a single "true" value ASSERT_EQ(1, values_.size()); EXPECT_EQ("true", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_AND Popping \"true\" and \"true\" pushing \"true\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an or is able to @@ -972,6 +1229,13 @@ TEST_F(TokenTest, operatorOrFalse) { // After evaluation there should be a single "false" value ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OR Popping \"false\" and \"false\" pushing \"false\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing an == operator is able to @@ -999,9 +1263,16 @@ TEST_F(TokenTest, operatorOrTrue) { EXPECT_NO_THROW(t_->evaluate(*pkt4_, values_)); ASSERT_EQ(1, values_.size()); EXPECT_EQ("true", values_.top()); -} -}; + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OR Popping \"true\" and \"false\" pushing \"true\""); + exp_strings.push_back("EVAL_DEBUG_OR Popping \"false\" and \"true\" pushing \"true\""); + exp_strings.push_back("EVAL_DEBUG_OR Popping \"true\" and \"true\" pushing \"true\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); +} // This test checks if a token representing a substring request // throws an exception if there aren't enough values on the stack. @@ -1028,6 +1299,14 @@ TEST_F(TokenTest, substringNotEnoughValues) { // one after the evaluate ASSERT_EQ(1, values_.size()); EXPECT_EQ("", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_EMPTY Popping length 0, start 0, " + "string 0x pushing result 0x"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Test getting the whole string in different ways @@ -1043,6 +1322,20 @@ TEST_F(TokenTest, substringWholeString) { // Get the whole string counting from the back verifySubstringEval("foobar", "-6", "all", "foobar"); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 6, start 0, " + "string 0x666F6F626172 pushing result 0x666F6F626172"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start 0, " + "string 0x666F6F626172 pushing result 0x666F6F626172"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 123456, start 0, " + "string 0x666F6F626172 pushing result 0x666F6F626172"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start -6, " + "string 0x666F6F626172 pushing result 0x666F6F626172"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Test getting a suffix, in this case the last 3 characters @@ -1051,6 +1344,20 @@ TEST_F(TokenTest, substringTrailer) { verifySubstringEval("foobar", "3", "all", "bar"); verifySubstringEval("foobar", "-3", "all", "bar"); verifySubstringEval("foobar", "-3", "123", "bar"); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 3, start 3, " + "string 0x666F6F626172 pushing result 0x626172"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start 3, " + "string 0x666F6F626172 pushing result 0x626172"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start -3, " + "string 0x666F6F626172 pushing result 0x626172"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 123, start -3, " + "string 0x666F6F626172 pushing result 0x626172"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Test getting the middle of the string in different ways @@ -1059,6 +1366,20 @@ TEST_F(TokenTest, substringMiddle) { verifySubstringEval("foobar", "-5", "4", "ooba"); verifySubstringEval("foobar", "-1", "-4", "ooba"); verifySubstringEval("foobar", "5", "-4", "ooba"); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start -5, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start -1, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 5, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Test getting the last letter in different ways @@ -1069,6 +1390,24 @@ TEST_F(TokenTest, substringLastLetter) { verifySubstringEval("foobar", "-1", "all", "r"); verifySubstringEval("foobar", "-1", "1", "r"); verifySubstringEval("foobar", "-1", "5", "r"); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start 5, " + "string 0x666F6F626172 pushing result 0x72"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 1, start 5, " + "string 0x666F6F626172 pushing result 0x72"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 5, start 5, " + "string 0x666F6F626172 pushing result 0x72"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start -1, " + "string 0x666F6F626172 pushing result 0x72"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 1, start -1, " + "string 0x666F6F626172 pushing result 0x72"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 5, start -1, " + "string 0x666F6F626172 pushing result 0x72"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Test we get only what is available if we ask for a longer string @@ -1084,6 +1423,28 @@ TEST_F(TokenTest, substringLength) { verifySubstringEval("foobar", "4", "4", "ar"); verifySubstringEval("foobar", "5", "4", "r"); verifySubstringEval("foobar", "6", "4", ""); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 0, " + "string 0x666F6F626172 pushing result 0x"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 1, " + "string 0x666F6F626172 pushing result 0x66"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 2, " + "string 0x666F6F626172 pushing result 0x666F"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 3, " + "string 0x666F6F626172 pushing result 0x666F6F"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 3, " + "string 0x666F6F626172 pushing result 0x626172"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 4, " + "string 0x666F6F626172 pushing result 0x6172"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 5, " + "string 0x666F6F626172 pushing result 0x72"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length 4, start 6, " + "string 0x666F6F626172 pushing result 0x"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Test that we get nothing if the starting postion is out of the string @@ -1097,6 +1458,24 @@ TEST_F(TokenTest, substringStartingPosition) { verifySubstringEval("foobar", "6", "1", ""); verifySubstringEval("foobar", "6", "-11", ""); verifySubstringEval("foobar", "6", "all", ""); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length 1, start -7, " + "string 0x666F6F626172 pushing result 0x"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length -11, start -7, " + "string 0x666F6F626172 pushing result 0x"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length all, start -7, " + "string 0x666F6F626172 pushing result 0x"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length 1, start 6, " + "string 0x666F6F626172 pushing result 0x"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length -11, start 6, " + "string 0x666F6F626172 pushing result 0x"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length all, start 6, " + "string 0x666F6F626172 pushing result 0x"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Check what happens if we use strings that aren't numbers for start or length @@ -1109,6 +1488,10 @@ TEST_F(TokenTest, substringBadParams) { verifySubstringEval("foobar", "0", "0ick", "", true); verifySubstringEval("foobar", "0", "ick0", "", true); verifySubstringEval("foobar", "0", "allaboard", "", true); + + // These should result in a throw which should generate it's own + // log entry + remFile(); } // lastly check that we don't get anything if the string is empty or @@ -1116,6 +1499,16 @@ TEST_F(TokenTest, substringBadParams) { TEST_F(TokenTest, substringReturnEmpty) { verifySubstringEval("", "0", "all", ""); verifySubstringEval("foobar", "0", "0", ""); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING_EMPTY Popping length all, start 0, " + "string 0x pushing result 0x"); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 0, start 0, " + "string 0x666F6F626172 pushing result 0x"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Check if we can use the substring and equal tokens together @@ -1137,8 +1530,6 @@ TEST_F(TokenTest, substringEquals) { values_.push("ooba"); // The substring values - // Subsring requires three values on the stack, try - // with 0, 1 and 2 all should throw an exception values_.push("foobar"); values_.push("1"); values_.push("4"); @@ -1160,8 +1551,6 @@ TEST_F(TokenTest, substringEquals) { values_.push("foob"); // The substring values - // Subsring requires three values on the stack, try - // with 0, 1 and 2 all should throw an exception values_.push("foobar"); values_.push("1"); values_.push("4"); @@ -1175,6 +1564,19 @@ TEST_F(TokenTest, substringEquals) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x6F6F6261 and 0x6F6F6261 " + "pushing result \"true\""); + exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x6F6F6261 and 0x666F6F62 " + "pushing result \"false\""); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if a token representing a concat request @@ -1197,6 +1599,14 @@ TEST_F(TokenTest, concat) { // Check the result ASSERT_EQ(1, values_.size()); EXPECT_EQ("foobar", values_.top()); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_CONCAT Popping 0x626172 and 0x666F6F " + "pushing 0x666F6F626172"); + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if we can properly extract the link and peer @@ -1250,6 +1660,30 @@ TEST_F(TokenTest, relay6Field) { // be tidy clearStack(); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 0 " + "with value 0x00000000000000000000000000000000"); + exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field peeraddr nest 0 " + "with value 0x00000000000000000000000000000000"); + exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 1 " + "with value 0x00010000000000000000000000000001"); + exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field peeraddr nest 1 " + "with value 0x00010000000000000000000000000002"); + exp_strings.push_back("EVAL_DEBUG_RELAY6_RANGE Pushing PKT6 relay field linkaddr nest 2 " + "with value 0x"); + + exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 1 " + "with value 0x00010000000000000000000000000001"); + exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress " + "0x00010000000000000000000000000001"); + exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x00010000000000000000000000000001 " + "and 0x00010000000000000000000000000001 pushing result \"true\""); + + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // This test checks if we can properly extract an option @@ -1283,6 +1717,24 @@ TEST_F(TokenTest, relay6Option) { // Level 2, no encapsulation so no options verifyRelay6Option(2, 100, TokenOption::TEXTUAL, ""); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"hundred.zero\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"true\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"hundredone.zero\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 102 with value \"\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 102 with value \"false\""); + + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"hundred.one\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"\""); + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 102 with value \"hundredtwo.one\""); + + exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"\""); + + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } // Verifies if the DHCPv6 packet fields can be extracted. @@ -1309,4 +1761,16 @@ TEST_F(TokenTest, pkt6Fields) { clearStack(); ASSERT_NO_THROW(t_.reset(new TokenPkt6(TokenPkt6::TRANSID))); EXPECT_THROW(t_->evaluate(*pkt4_, values_), EvalTypeError); + + // Check that the debug output was correct, we create a vector of all + // the strings we expect and send it to checkFile for comparison. + vector exp_strings; + exp_strings.push_back("EVAL_DEBUG_PKT6 Pushing PKT6 field msgtype " + "with value 0x00000001"); + exp_strings.push_back("EVAL_DEBUG_PKT6 Pushing PKT6 field transid " + "with value 0x00003039"); + + EXPECT_TRUE(checkFile(exp_strings)); + remFile(); } +}; diff --git a/src/lib/eval/token.cc b/src/lib/eval/token.cc index 7fbe6f2d22..c461786f46 100644 --- a/src/lib/eval/token.cc +++ b/src/lib/eval/token.cc @@ -21,6 +21,10 @@ void TokenString::evaluate(const Pkt& /*pkt*/, ValueStack& values) { // Literals only push, nothing to pop values.push(value_); + + // Log what we pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_STRING) + .arg('"' + value_ + '"'); } TokenHexString::TokenHexString(const string& str) : value_("") { @@ -55,6 +59,11 @@ void TokenHexString::evaluate(const Pkt& /*pkt*/, ValueStack& values) { // Literals only push, nothing to pop values.push(value_); + + // Log what we pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_HEXSTRING) + .arg("0x" + util::encode::encodeHex(std::vector(value_.begin(), + value_.end()))); } TokenIpAddress::TokenIpAddress(const string& addr) : value_("") { @@ -76,6 +85,11 @@ void TokenIpAddress::evaluate(const Pkt& /*pkt*/, ValueStack& values) { // Literals only push, nothing to pop values.push(value_); + + // Log what we pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_IPADDRESS) + .arg("0x" + util::encode::encodeHex(std::vector(value_.begin(), + value_.end()))); } OptionPtr @@ -106,6 +120,20 @@ TokenOption::evaluate(const Pkt& pkt, ValueStack& values) { // Push value of the option or empty string if there was no such option // in the packet. values.push(opt_str); + + // Log what we pushed, both exists and textual are simple text + // and can be output directly. We also include the code number + // of the requested option. + if (representation_type_ == HEXADECIMAL) { + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_OPTION) + .arg(option_code_) + .arg("0x" + util::encode::encodeHex(std::vector(opt_str.begin(), + opt_str.end()))); + } else { + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_OPTION) + .arg(option_code_) + .arg('"' + opt_str + '"'); + } } TokenRelay4Option::TokenRelay4Option(const uint16_t option_code, @@ -129,6 +157,7 @@ void TokenPkt4::evaluate(const Pkt& pkt, ValueStack& values) { vector binary; + string type_str; try { // Check if it's a Pkt4. If it's not, the dynamic_cast will throw // std::bad_cast (failed dynamic_cast returns NULL for pointers and @@ -145,22 +174,27 @@ TokenPkt4::evaluate(const Pkt& pkt, ValueStack& values) { "Packet does not have hardware address"); } binary = hwaddr->hwaddr_; + type_str = "mac"; break; } case GIADDR: binary = pkt4.getGiaddr().toBytes(); + type_str = "giaddr"; break; case CIADDR: binary = pkt4.getCiaddr().toBytes(); + type_str = "ciaddr"; break; case YIADDR: binary = pkt4.getYiaddr().toBytes(); + type_str = "yiaddr"; break; case SIADDR: binary = pkt4.getSiaddr().toBytes(); + type_str = "siaddr"; break; case HLEN: @@ -169,6 +203,7 @@ TokenPkt4::evaluate(const Pkt& pkt, ValueStack& values) { binary.push_back(0); binary.push_back(0); binary.push_back(pkt4.getHlen()); + type_str = "hlen"; break; case HTYPE: @@ -177,6 +212,7 @@ TokenPkt4::evaluate(const Pkt& pkt, ValueStack& values) { binary.push_back(0); binary.push_back(0); binary.push_back(pkt4.getHtype()); + type_str = "htype"; break; default: @@ -194,6 +230,12 @@ TokenPkt4::evaluate(const Pkt& pkt, ValueStack& values) { memmove(&value[0], &binary[0], binary.size()); } values.push(value); + + // Log what we pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_PKT4) + .arg(type_str) + .arg("0x" + util::encode::encodeHex(std::vector(value.begin(), + value.end()))); } void @@ -209,10 +251,21 @@ TokenEqual::evaluate(const Pkt& /*pkt*/, ValueStack& values) { string op2 = values.top(); values.pop(); // Dammit, std::stack interface is awkward. + string result; if (op1 == op2) - values.push("true"); + result = "true"; else - values.push("false"); + result = "false"; + + values.push(result); + + // Log what we popped and pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_EQUAL) + .arg("0x" + util::encode::encodeHex(std::vector(op1.begin(), + op1.end()))) + .arg("0x" + util::encode::encodeHex(std::vector(op2.begin(), + op2.end()))) + .arg('"' + result + '"'); } void @@ -233,6 +286,13 @@ TokenSubstring::evaluate(const Pkt& /*pkt*/, ValueStack& values) { // If we have no string to start with we push an empty string and leave if (string_str.empty()) { values.push(""); + + // Log what we popped and pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_SUBSTRING_EMPTY) + .arg(len_str) + .arg(start_str) + .arg("0x") + .arg("0x"); return; } @@ -266,6 +326,14 @@ TokenSubstring::evaluate(const Pkt& /*pkt*/, ValueStack& values) { // empty string and leave if ((start_pos < -string_length) || (start_pos >= string_length)) { values.push(""); + + // Log what we popped and pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_SUBSTRING_RANGE) + .arg(len_str) + .arg(start_str) + .arg("0x" + util::encode::encodeHex(std::vector(string_str.begin(), + string_str.end()))) + .arg("0x"); return; } @@ -286,8 +354,19 @@ TokenSubstring::evaluate(const Pkt& /*pkt*/, ValueStack& values) { } } + // and finally get the substring - values.push(string_str.substr(start_pos, length)); + string result = string_str.substr(start_pos, length); + values.push(result); + + // Log what we popped and pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_SUBSTRING) + .arg(len_str) + .arg(start_str) + .arg("0x" + util::encode::encodeHex(std::vector(string_str.begin(), + string_str.end()))) + .arg("0x" + util::encode::encodeHex(std::vector(result.begin(), + result.end()))); } void @@ -304,7 +383,17 @@ TokenConcat::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.pop(); // Dammit, std::stack interface is awkward. // The top of the stack was evaluated last so this is the right order - values.push(op2 + op1); + string result = op2 + op1; + values.push(result); + + // Log what we popped and pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_CONCAT) + .arg("0x" + util::encode::encodeHex(std::vector(op1.begin(), + op1.end()))) + .arg("0x" + util::encode::encodeHex(std::vector(op2.begin(), + op2.end()))) + .arg("0x" + util::encode::encodeHex(std::vector(result.begin(), + result.end()))); } void @@ -318,11 +407,18 @@ TokenNot::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.pop(); bool val = toBool(op); + string result; if (!val) { - values.push("true"); + result = "true"; } else { - values.push("false"); + result = "false"; } + values.push(result); + + // Log what we popped and pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_NOT) + .arg('"' + op + '"') + .arg('"' + result + '"'); } void @@ -340,11 +436,19 @@ TokenAnd::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.pop(); // Dammit, std::stack interface is awkward. bool val2 = toBool(op2); + string result; if (val1 && val2) { - values.push("true"); + result = "true"; } else { - values.push("false"); + result = "false"; } + values.push(result); + + // Log what we popped and pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_AND) + .arg('"' + op1 + '"') + .arg("\"" + op2 + "\"") + .arg("\"" + result + "\""); } void @@ -362,11 +466,19 @@ TokenOr::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.pop(); // Dammit, std::stack interface is awkward. bool val2 = toBool(op2); + string result; if (val1 || val2) { - values.push("true"); + result = "true"; } else { - values.push("false"); + result = "false"; } + values.push(result); + + // Log what we popped and pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_OR) + .arg('"' + op1 + '"') + .arg('"' + op2 + '"') + .arg('"' + result + '"'); } OptionPtr TokenRelay6Option::getOption(const Pkt& pkt) { @@ -399,6 +511,7 @@ void TokenRelay6Field::evaluate(const Pkt& pkt, ValueStack& values) { vector binary; + string type_str; try { // Check if it's a Pkt6. If it's not the dynamic_cast will // throw std::bad_cast. @@ -409,9 +522,11 @@ TokenRelay6Field::evaluate(const Pkt& pkt, ValueStack& values) { // Now that we have the right type of packet we can // get the option and return it. case LINKADDR: + type_str = "linkaddr"; binary = pkt6.getRelay6LinkAddress(nest_level_).toBytes(); break; case PEERADDR: + type_str = "peeraddr"; binary = pkt6.getRelay6PeerAddress(nest_level_).toBytes(); break; } @@ -419,6 +534,11 @@ TokenRelay6Field::evaluate(const Pkt& pkt, ValueStack& values) { // The only exception we expect is OutOfRange if the nest // level is invalid. We push "" in that case. values.push(""); + // Log what we pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_RELAY6_RANGE) + .arg(type_str) + .arg(unsigned(nest_level_)) + .arg("0x"); return; } } catch (const std::bad_cast&) { @@ -431,12 +551,20 @@ TokenRelay6Field::evaluate(const Pkt& pkt, ValueStack& values) { memmove(&value[0], &binary[0], binary.size()); } values.push(value); + + // Log what we pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_RELAY6) + .arg(type_str) + .arg(unsigned(nest_level_)) + .arg("0x" + util::encode::encodeHex(std::vector(value.begin(), + value.end()))); } void TokenPkt6::evaluate(const Pkt& pkt, ValueStack& values) { vector binary; + string type_str; try { // Check if it's a Pkt6. If it's not the dynamic_cast will throw // std::bad_cast (failed dynamic_cast returns NULL for pointers and @@ -450,6 +578,7 @@ TokenPkt6::evaluate(const Pkt& pkt, ValueStack& values) { binary.push_back(0); binary.push_back(0); binary.push_back(pkt6.getType()); + type_str = "msgtype"; break; } case TRANSID: { @@ -459,6 +588,7 @@ TokenPkt6::evaluate(const Pkt& pkt, ValueStack& values) { binary.push_back((transid >> 16) & 0xFF); binary.push_back((transid >> 8) & 0xFF); binary.push_back(transid & 0xFF); + type_str = "transid"; break; } default: @@ -474,4 +604,10 @@ TokenPkt6::evaluate(const Pkt& pkt, ValueStack& values) { value.resize(binary.size()); memmove(&value[0], &binary[0], binary.size()); values.push(value); + + // Log what we pushed + LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_PKT6) + .arg(type_str) + .arg("0x" + util::encode::encodeHex(std::vector(value.begin(), + value.end()))); } diff --git a/src/lib/eval/token.h b/src/lib/eval/token.h index 316106e43e..c90d2f25a9 100644 --- a/src/lib/eval/token.h +++ b/src/lib/eval/token.h @@ -650,7 +650,7 @@ public: /// @brief enum value that determines the field. enum FieldType { MSGTYPE, ///< msg type - TRANSID ///< transaction id (integer but manipulated as as string) + TRANSID ///< transaction id (integer but manipulated as a string) }; /// @brief Constructor (does nothing) From cf62ec17c86c7534f3d0c9a865caeb8305f399f0 Mon Sep 17 00:00:00 2001 From: Shawn Routhier Date: Thu, 26 May 2016 21:36:36 -0700 Subject: [PATCH 2/3] [trac4480] Update per review comments Create a LogContentTest class and move the functions to manipulate a test to check on the log output there. This will make it available for other tests in the future. As part of this bundle a bit more work into the class to minimze the calls in the test routines. Where reasonable remove extra copys of the values being pushed onto the stack - instead of generating a copy just for the logging simply use the value from the top of the stack directly. Swtich to using single quotes around text values. Added some more description in the classify document --- ChangeLog | 4 +- doc/guide/classify.xml | 38 +- src/lib/eval/eval_log.h | 5 +- src/lib/eval/tests/Makefile.am | 1 + src/lib/eval/tests/token_unittest.cc | 734 ++++++++++++--------------- src/lib/eval/token.cc | 100 ++-- src/lib/eval/token.h | 2 +- src/lib/testutils/Makefile.am | 1 + src/lib/testutils/log_utils.cc | 74 +++ src/lib/testutils/log_utils.h | 82 +++ 10 files changed, 559 insertions(+), 482 deletions(-) create mode 100644 src/lib/testutils/log_utils.cc create mode 100644 src/lib/testutils/log_utils.h diff --git a/ChangeLog b/ChangeLog index dcf4170310..d55ad1e1ff 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,5 +1,7 @@ 11XX. [func] sar - Add debug logging to the classification tokens. + Add debug logging to the classification tokens. This uses + the loggers "kea-dhcp4.eval" and "kea-dhcp6.eval" to capture + details of the classification expression evaluations. (Trac #4480, git TBD) 1114. [bug] stephen diff --git a/doc/guide/classify.xml b/doc/guide/classify.xml index d9d85ea03e..48ac7e478a 100644 --- a/doc/guide/classify.xml +++ b/doc/guide/classify.xml @@ -639,6 +639,36 @@ The specific loggers are "kea-dhcp4.eval" and "kea-dhcp6.eval". + + In order to understand the logging statements one must understand a + bit about how expressions are evaluated, for a more complete description + refer to the design document at . + In brief there are two structures used during the evaluation of an expression + a list of tokens which represent the expressions and a value stack which + represents the values being manipulated. + + + + The list of tokens is created when the configuration file is processed with + most expressions and values being converted to a token. The list is organized + in reverse polish notation. During execution the list will be traversed + in order. As each token is executed it will be able to pop values + from the top of the stack and eventually push its result on the top of the + stack. Imagine the following expression: + + "test": "substring(option[61].hex,0,3) == 'foo'", + + This will result in the following tokens: + + option, number (0), number (3), substring, text ('foo'), equals + + In this example the first three tokens will simply push values onto the + stack. The substring token will then remove those three values and + compute a result that it places on the stack. The text option also + places a value on the stack and finally the equals token removes the + two tokens on the stack and places its result on the stack. + + When debug logging is enabled each time a token is evaluated it will emit a log line indicating the values of any objects that were popped @@ -678,8 +708,12 @@ The debug logging may be quite verbose if you have a number of expressions to evaluate. It is intended as an aide in helping you create and debug your expressions. You should plan to disable debug logging when you have your - expressions working correctly. You also may wish to debug only one set of - expressions at a time to limit the log statements. + expressions working correctly. You also may wish to include only one set of + expressions at a time in the configuration file while debugging them in order + to limit the log statements. For example when adding a new set of expressions + you might find it more convenient to create a configuration file that only + includes the new expressions until you have them working correctly and then + add the new set to the main configuration file. diff --git a/src/lib/eval/eval_log.h b/src/lib/eval/eval_log.h index 20205ea0ad..c7fa5001fd 100644 --- a/src/lib/eval/eval_log.h +++ b/src/lib/eval/eval_log.h @@ -21,12 +21,9 @@ namespace dhcp { // The first level traces normal operations, const int EVAL_DBG_TRACE = DBGLVL_TRACE_BASIC; -// The next level traces each call to eval code. -const int EVAL_DBG_CALLS = DBGLVL_TRACE_BASIC_DATA; - // Additional information on the calls. Report the values that were // popped from or pushed to the value stack. -const int EVAL_DBG_EXTENDED_CALLS = DBGLVL_TRACE_DETAIL_DATA; +const int EVAL_DBG_STACK = DBGLVL_TRACE_DETAIL_DATA; /// @brief Eval Logger /// diff --git a/src/lib/eval/tests/Makefile.am b/src/lib/eval/tests/Makefile.am index ec42f1d992..a492686eff 100644 --- a/src/lib/eval/tests/Makefile.am +++ b/src/lib/eval/tests/Makefile.am @@ -43,6 +43,7 @@ libeval_unittests_LDADD += $(top_builddir)/src/lib/log/libkea-log.la libeval_unittests_LDADD += $(top_builddir)/src/lib/util/threads/libkea-threads.la libeval_unittests_LDADD += $(top_builddir)/src/lib/util/libkea-util.la libeval_unittests_LDADD += $(top_builddir)/src/lib/exceptions/libkea-exceptions.la +libeval_unittests_LDADD += $(top_builddir)/src/lib/testutils/libkea-testutils.la libeval_unittests_LDADD += $(CRYPTO_LIBS) $(LOG4CPLUS_LIBS) libeval_unittests_LDADD += $(BOOST_LIBS) $(GTEST_LDADD) diff --git a/src/lib/eval/tests/token_unittest.cc b/src/lib/eval/tests/token_unittest.cc index 1d3543334b..c4cbec6003 100644 --- a/src/lib/eval/tests/token_unittest.cc +++ b/src/lib/eval/tests/token_unittest.cc @@ -15,6 +15,7 @@ #include #include #include +#include #include #include @@ -26,6 +27,7 @@ using namespace std; using namespace isc::dhcp; using namespace isc::asiolink; using namespace isc::log; +using namespace isc::dhcp::test; namespace { @@ -34,7 +36,7 @@ namespace { /// This class provides several convenience objects to be used during testing /// of the Token family of classes. -class TokenTest : public ::testing::Test { +class TokenTest : public LogContentTest { public: /// @brief Initializes Pkt4,Pkt6 and options that can be useful for @@ -49,54 +51,6 @@ public: pkt4_->addOption(option_str4_); pkt6_->addOption(option_str6_); - - // Set up the logger for use in checking the debug statements. - // We send the debug statements to a file which we can - // check after the evaluations have completed. We also - // set the log severity and debug levels so that the log - // statements are executed. - LoggerSpecification spec(getRootLoggerName(), - keaLoggerSeverity(isc::log::DEBUG), - keaLoggerDbglevel(isc::log::MAX_DEBUG_LEVEL)); - OutputOption option; - option.destination = OutputOption::DEST_FILE; - option.filename = string(TokenTest::LOG_FILE); - spec.addOutputOption(option); - LoggerManager manager; - manager.process(spec); - } - - /// @brief check that the requested strings are in the - /// test log file in the requested order. - /// - /// @param exp_strings vector of strings to match - /// @return true if all of the strings match - bool checkFile(const vector& exp_strings) { - ifstream file(LOG_FILE); - EXPECT_TRUE(file.is_open()); - string line, exp_line; - int i = 0; - bool found = true; - - while (getline(file, line) && (i != exp_strings.size())) { - exp_line = exp_strings[i]; - i++; - if (string::npos == line.find(exp_line)) { - found = false; - } - } - - file.close(); - - if ((i != exp_strings.size()) || (found == false)) - return (false); - - return (true); - } - - /// @brief remove the test log file - void remFile() { - static_cast(remove(LOG_FILE)); } /// @brief Inserts RAI option with several suboptions @@ -284,14 +238,8 @@ public: /// @todo: Add more option types here - /// Name of the log file used during tests - static const char * LOG_FILE; }; -// Set up the name of the LOG_FILE for use in checking -// the debug statements -const char *TokenTest::LOG_FILE = "test.log"; - // This tests the toBool() conversions TEST_F(TokenTest, toBool) { @@ -324,13 +272,11 @@ TEST_F(TokenTest, string4) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("foo", values_.top()); - // Check that the debug output was correct, we create a vector - // of all the strings we expect (in this case only 1) and send - // it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_STRING Pushing text string \"foo\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_STRING Pushing text string 'foo'"); + EXPECT_TRUE(checkFile()); } // This simple test checks that a TokenString, representing a constant string, @@ -347,13 +293,11 @@ TEST_F(TokenTest, string6) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("foo", values_.top()); - // Check that the debug output was correct, we create a vector - // of all the strings we expect (in this case only 1) and send - // it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_STRING Pushing text string \"foo\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_STRING Pushing text string 'foo'"); + EXPECT_TRUE(checkFile()); } // This simple test checks that a TokenHexString, representing a constant @@ -411,18 +355,17 @@ TEST_F(TokenTest, hexstring4) { values_.pop(); EXPECT_EQ("", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x07"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x666F6F"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x63825363"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x07"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x666F6F"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x63825363"); + EXPECT_TRUE(checkFile()); } // This simple test checks that a TokenHexString, representing a constant @@ -479,18 +422,17 @@ TEST_F(TokenTest, hexstring6) { values_.pop(); EXPECT_EQ("", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x07"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x666F6F"); - exp_strings.push_back("EVAL_DEBUG_HEXSTRING Pushing hex string 0x63825363"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x07"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x666F6F"); + addString("EVAL_DEBUG_HEXSTRING Pushing hex string 0x63825363"); + EXPECT_TRUE(checkFile()); } // This test checks that a TokenIpAddress, representing an IP address as @@ -537,16 +479,15 @@ TEST_F(TokenTest, ipaddress) { EXPECT_EQ(4, values_.top().size()); EXPECT_EQ(0, memcmp(expected4, &values_.top()[0], 4)); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x0A000001"); - exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress " - "0x20010DB8000000000000000000000001"); - exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x"); - exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x0A000001"); + addString("EVAL_DEBUG_IPADDRESS Pushing IPAddress " + "0x20010DB8000000000000000000000001"); + addString("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x"); + addString("EVAL_DEBUG_IPADDRESS Pushing IPAddress 0x"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an option value is able to extract @@ -576,13 +517,12 @@ TEST_F(TokenTest, optionString4) { // Then the content of the option 100. EXPECT_EQ("hundred4", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"hundred4\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 'hundred4'"); + addString("EVAL_DEBUG_OPTION Pushing option 101 with value ''"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing option value is able to extract @@ -613,14 +553,12 @@ TEST_F(TokenTest, optionHexString4) { // Then the content of the option 100. EXPECT_EQ("hundred4", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value " - "0x68756E6472656434"); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value 0x"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 0x68756E6472656434"); + addString("EVAL_DEBUG_OPTION Pushing option 101 with value 0x"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an option value is able to check @@ -644,13 +582,12 @@ TEST_F(TokenTest, optionExistsString4) { values_.pop(); EXPECT_EQ("true", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"true\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"false\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 'true'"); + addString("EVAL_DEBUG_OPTION Pushing option 101 with value 'false'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an option value is able to extract @@ -680,13 +617,12 @@ TEST_F(TokenTest, optionString6) { // Then the content of the option 100. EXPECT_EQ("hundred6", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"hundred6\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 'hundred6'"); + addString("EVAL_DEBUG_OPTION Pushing option 101 with value ''"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an option value is able to extract @@ -717,14 +653,12 @@ TEST_F(TokenTest, optionHexString6) { // Then the content of the option 100. EXPECT_EQ("hundred6", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value " - "0x68756E6472656436"); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value 0x"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 0x68756E6472656436"); + addString("EVAL_DEBUG_OPTION Pushing option 101 with value 0x"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an option value is able to check @@ -748,13 +682,12 @@ TEST_F(TokenTest, optionExistsString6) { values_.pop(); EXPECT_EQ("true", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"true\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"false\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 'true'"); + addString("EVAL_DEBUG_OPTION Pushing option 101 with value 'false'"); + EXPECT_TRUE(checkFile()); } // This test checks that the existing relay4 option can be found. @@ -776,12 +709,11 @@ TEST_F(TokenTest, relay4Option) { // content of that sub-option, i.e. "thirteen" EXPECT_EQ("thirteen", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 13 with value \"thirteen\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 13 with value 'thirteen'"); + EXPECT_TRUE(checkFile()); } // This test checks that the code properly handles cases when @@ -804,12 +736,11 @@ TEST_F(TokenTest, relay4OptionNoSuboption) { // so the expression should evaluate to "" EXPECT_EQ("", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 15 with value \"\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 15 with value ''"); + EXPECT_TRUE(checkFile()); } // This test checks that the code properly handles cases when @@ -831,12 +762,11 @@ TEST_F(TokenTest, relay4OptionNoRai) { // so the expression should evaluate to "" EXPECT_EQ("", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 13 with value \"\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 13 with value ''"); + EXPECT_TRUE(checkFile()); } // This test checks that only the RAI is searched for the requested @@ -894,16 +824,15 @@ TEST_F(TokenTest, relay4RAIOnly) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 13 with value \"thirteen\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 1 with value \"one\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 70 with value \"\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 1 with value \"true\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 70 with value \"false\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 13 with value 'thirteen'"); + addString("EVAL_DEBUG_OPTION Pushing option 1 with value 'one'"); + addString("EVAL_DEBUG_OPTION Pushing option 70 with value ''"); + addString("EVAL_DEBUG_OPTION Pushing option 1 with value 'true'"); + addString("EVAL_DEBUG_OPTION Pushing option 70 with value 'false'"); + EXPECT_TRUE(checkFile()); } // Verifies if the DHCPv4 packet fields can be extracted. @@ -985,25 +914,17 @@ TEST_F(TokenTest, pkt4Fields) { ASSERT_NO_THROW(t_.reset(new TokenPkt4(TokenPkt4::HLEN))); EXPECT_THROW(t_->evaluate(*pkt6_, values_), EvalTypeError); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field mac " - "with value 0x01020304050607"); - exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field hlen " - "with value 0x00000007"); - exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field htype " - "with value 0x0000007B"); - exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field giaddr " - "with value 0xC0000201"); - exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field ciaddr " - "with value 0xC0000202"); - exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field yiaddr " - "with value 0xC0000203"); - exp_strings.push_back("EVAL_DEBUG_PKT4 Pushing PKT4 field siaddr " - "with value 0xC0000204"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_PKT4 Pushing PKT4 field mac with value 0x01020304050607"); + addString("EVAL_DEBUG_PKT4 Pushing PKT4 field hlen with value 0x00000007"); + addString("EVAL_DEBUG_PKT4 Pushing PKT4 field htype with value 0x0000007B"); + addString("EVAL_DEBUG_PKT4 Pushing PKT4 field giaddr with value 0xC0000201"); + addString("EVAL_DEBUG_PKT4 Pushing PKT4 field ciaddr with value 0xC0000202"); + addString("EVAL_DEBUG_PKT4 Pushing PKT4 field yiaddr with value 0xC0000203"); + addString("EVAL_DEBUG_PKT4 Pushing PKT4 field siaddr with value 0xC0000204"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an == operator is able to @@ -1036,13 +957,12 @@ TEST_F(TokenTest, optionEqualFalse) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x626172 and 0x666F6F " - "pushing result \"false\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_EQUAL Popping 0x626172 and 0x666F6F " + "pushing result 'false'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an == operator is able to @@ -1060,13 +980,12 @@ TEST_F(TokenTest, optionEqualTrue) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("true", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x666F6F and 0x666F6F " - "pushing result \"true\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_EQUAL Popping 0x666F6F and 0x666F6F " + "pushing result 'true'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing a not is able to @@ -1101,13 +1020,12 @@ TEST_F(TokenTest, operatorNot) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("true", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_NOT Popping \"true\" pushing \"false\""); - exp_strings.push_back("EVAL_DEBUG_NOT Popping \"false\" pushing \"true\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_NOT Popping 'true' pushing 'false'"); + addString("EVAL_DEBUG_NOT Popping 'false' pushing 'true'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an and is able to @@ -1160,14 +1078,13 @@ TEST_F(TokenTest, operatorAndFalse) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_AND Popping \"false\" and \"true\" pushing \"false\""); - exp_strings.push_back("EVAL_DEBUG_AND Popping \"true\" and \"false\" pushing \"false\""); - exp_strings.push_back("EVAL_DEBUG_AND Popping \"false\" and \"false\" pushing \"false\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_AND Popping 'false' and 'true' pushing 'false'"); + addString("EVAL_DEBUG_AND Popping 'true' and 'false' pushing 'false'"); + addString("EVAL_DEBUG_AND Popping 'false' and 'false' pushing 'false'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an and is able to @@ -1184,12 +1101,11 @@ TEST_F(TokenTest, operatorAndTrue) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("true", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_AND Popping \"true\" and \"true\" pushing \"true\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_AND Popping 'true' and 'true' pushing 'true'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an or is able to @@ -1230,12 +1146,11 @@ TEST_F(TokenTest, operatorOrFalse) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OR Popping \"false\" and \"false\" pushing \"false\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OR Popping 'false' and 'false' pushing 'false'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing an == operator is able to @@ -1264,14 +1179,13 @@ TEST_F(TokenTest, operatorOrTrue) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("true", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OR Popping \"true\" and \"false\" pushing \"true\""); - exp_strings.push_back("EVAL_DEBUG_OR Popping \"false\" and \"true\" pushing \"true\""); - exp_strings.push_back("EVAL_DEBUG_OR Popping \"true\" and \"true\" pushing \"true\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OR Popping 'true' and 'false' pushing 'true'"); + addString("EVAL_DEBUG_OR Popping 'false' and 'true' pushing 'true'"); + addString("EVAL_DEBUG_OR Popping 'true' and 'true' pushing 'true'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing a substring request @@ -1300,13 +1214,12 @@ TEST_F(TokenTest, substringNotEnoughValues) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_EMPTY Popping length 0, start 0, " - "string 0x pushing result 0x"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING_EMPTY Popping length 0, start 0, " + "string 0x pushing result 0x"); + EXPECT_TRUE(checkFile()); } // Test getting the whole string in different ways @@ -1323,19 +1236,18 @@ TEST_F(TokenTest, substringWholeString) { // Get the whole string counting from the back verifySubstringEval("foobar", "-6", "all", "foobar"); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 6, start 0, " - "string 0x666F6F626172 pushing result 0x666F6F626172"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start 0, " - "string 0x666F6F626172 pushing result 0x666F6F626172"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 123456, start 0, " - "string 0x666F6F626172 pushing result 0x666F6F626172"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start -6, " - "string 0x666F6F626172 pushing result 0x666F6F626172"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING Popping length 6, start 0, " + "string 0x666F6F626172 pushing result 0x666F6F626172"); + addString("EVAL_DEBUG_SUBSTRING Popping length all, start 0, " + "string 0x666F6F626172 pushing result 0x666F6F626172"); + addString("EVAL_DEBUG_SUBSTRING Popping length 123456, start 0, " + "string 0x666F6F626172 pushing result 0x666F6F626172"); + addString("EVAL_DEBUG_SUBSTRING Popping length all, start -6, " + "string 0x666F6F626172 pushing result 0x666F6F626172"); + EXPECT_TRUE(checkFile()); } // Test getting a suffix, in this case the last 3 characters @@ -1345,19 +1257,18 @@ TEST_F(TokenTest, substringTrailer) { verifySubstringEval("foobar", "-3", "all", "bar"); verifySubstringEval("foobar", "-3", "123", "bar"); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 3, start 3, " - "string 0x666F6F626172 pushing result 0x626172"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start 3, " - "string 0x666F6F626172 pushing result 0x626172"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start -3, " - "string 0x666F6F626172 pushing result 0x626172"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 123, start -3, " - "string 0x666F6F626172 pushing result 0x626172"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING Popping length 3, start 3, " + "string 0x666F6F626172 pushing result 0x626172"); + addString("EVAL_DEBUG_SUBSTRING Popping length all, start 3, " + "string 0x666F6F626172 pushing result 0x626172"); + addString("EVAL_DEBUG_SUBSTRING Popping length all, start -3, " + "string 0x666F6F626172 pushing result 0x626172"); + addString("EVAL_DEBUG_SUBSTRING Popping length 123, start -3, " + "string 0x666F6F626172 pushing result 0x626172"); + EXPECT_TRUE(checkFile()); } // Test getting the middle of the string in different ways @@ -1367,19 +1278,18 @@ TEST_F(TokenTest, substringMiddle) { verifySubstringEval("foobar", "-1", "-4", "ooba"); verifySubstringEval("foobar", "5", "-4", "ooba"); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " - "string 0x666F6F626172 pushing result 0x6F6F6261"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start -5, " - "string 0x666F6F626172 pushing result 0x6F6F6261"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start -1, " - "string 0x666F6F626172 pushing result 0x6F6F6261"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 5, " - "string 0x666F6F626172 pushing result 0x6F6F6261"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + addString("EVAL_DEBUG_SUBSTRING Popping length 4, start -5, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + addString("EVAL_DEBUG_SUBSTRING Popping length -4, start -1, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + addString("EVAL_DEBUG_SUBSTRING Popping length -4, start 5, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + EXPECT_TRUE(checkFile()); } // Test getting the last letter in different ways @@ -1391,23 +1301,22 @@ TEST_F(TokenTest, substringLastLetter) { verifySubstringEval("foobar", "-1", "1", "r"); verifySubstringEval("foobar", "-1", "5", "r"); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start 5, " - "string 0x666F6F626172 pushing result 0x72"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 1, start 5, " - "string 0x666F6F626172 pushing result 0x72"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 5, start 5, " - "string 0x666F6F626172 pushing result 0x72"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length all, start -1, " - "string 0x666F6F626172 pushing result 0x72"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 1, start -1, " - "string 0x666F6F626172 pushing result 0x72"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 5, start -1, " - "string 0x666F6F626172 pushing result 0x72"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING Popping length all, start 5, " + "string 0x666F6F626172 pushing result 0x72"); + addString("EVAL_DEBUG_SUBSTRING Popping length 1, start 5, " + "string 0x666F6F626172 pushing result 0x72"); + addString("EVAL_DEBUG_SUBSTRING Popping length 5, start 5, " + "string 0x666F6F626172 pushing result 0x72"); + addString("EVAL_DEBUG_SUBSTRING Popping length all, start -1, " + "string 0x666F6F626172 pushing result 0x72"); + addString("EVAL_DEBUG_SUBSTRING Popping length 1, start -1, " + "string 0x666F6F626172 pushing result 0x72"); + addString("EVAL_DEBUG_SUBSTRING Popping length 5, start -1, " + "string 0x666F6F626172 pushing result 0x72"); + EXPECT_TRUE(checkFile()); } // Test we get only what is available if we ask for a longer string @@ -1424,27 +1333,26 @@ TEST_F(TokenTest, substringLength) { verifySubstringEval("foobar", "5", "4", "r"); verifySubstringEval("foobar", "6", "4", ""); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 0, " - "string 0x666F6F626172 pushing result 0x"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 1, " - "string 0x666F6F626172 pushing result 0x66"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 2, " - "string 0x666F6F626172 pushing result 0x666F"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length -4, start 3, " - "string 0x666F6F626172 pushing result 0x666F6F"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 3, " - "string 0x666F6F626172 pushing result 0x626172"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 4, " - "string 0x666F6F626172 pushing result 0x6172"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 5, " - "string 0x666F6F626172 pushing result 0x72"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length 4, start 6, " - "string 0x666F6F626172 pushing result 0x"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING Popping length -4, start 0, " + "string 0x666F6F626172 pushing result 0x"); + addString("EVAL_DEBUG_SUBSTRING Popping length -4, start 1, " + "string 0x666F6F626172 pushing result 0x66"); + addString("EVAL_DEBUG_SUBSTRING Popping length -4, start 2, " + "string 0x666F6F626172 pushing result 0x666F"); + addString("EVAL_DEBUG_SUBSTRING Popping length -4, start 3, " + "string 0x666F6F626172 pushing result 0x666F6F"); + addString("EVAL_DEBUG_SUBSTRING Popping length 4, start 3, " + "string 0x666F6F626172 pushing result 0x626172"); + addString("EVAL_DEBUG_SUBSTRING Popping length 4, start 4, " + "string 0x666F6F626172 pushing result 0x6172"); + addString("EVAL_DEBUG_SUBSTRING Popping length 4, start 5, " + "string 0x666F6F626172 pushing result 0x72"); + addString("EVAL_DEBUG_SUBSTRING_RANGE Popping length 4, start 6, " + "string 0x666F6F626172 pushing result 0x"); + EXPECT_TRUE(checkFile()); } // Test that we get nothing if the starting postion is out of the string @@ -1459,23 +1367,22 @@ TEST_F(TokenTest, substringStartingPosition) { verifySubstringEval("foobar", "6", "-11", ""); verifySubstringEval("foobar", "6", "all", ""); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length 1, start -7, " - "string 0x666F6F626172 pushing result 0x"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length -11, start -7, " - "string 0x666F6F626172 pushing result 0x"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length all, start -7, " - "string 0x666F6F626172 pushing result 0x"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length 1, start 6, " - "string 0x666F6F626172 pushing result 0x"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length -11, start 6, " - "string 0x666F6F626172 pushing result 0x"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_RANGE Popping length all, start 6, " - "string 0x666F6F626172 pushing result 0x"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING_RANGE Popping length 1, start -7, " + "string 0x666F6F626172 pushing result 0x"); + addString("EVAL_DEBUG_SUBSTRING_RANGE Popping length -11, start -7, " + "string 0x666F6F626172 pushing result 0x"); + addString("EVAL_DEBUG_SUBSTRING_RANGE Popping length all, start -7, " + "string 0x666F6F626172 pushing result 0x"); + addString("EVAL_DEBUG_SUBSTRING_RANGE Popping length 1, start 6, " + "string 0x666F6F626172 pushing result 0x"); + addString("EVAL_DEBUG_SUBSTRING_RANGE Popping length -11, start 6, " + "string 0x666F6F626172 pushing result 0x"); + addString("EVAL_DEBUG_SUBSTRING_RANGE Popping length all, start 6, " + "string 0x666F6F626172 pushing result 0x"); + EXPECT_TRUE(checkFile()); } // Check what happens if we use strings that aren't numbers for start or length @@ -1491,7 +1398,6 @@ TEST_F(TokenTest, substringBadParams) { // These should result in a throw which should generate it's own // log entry - remFile(); } // lastly check that we don't get anything if the string is empty or @@ -1500,15 +1406,14 @@ TEST_F(TokenTest, substringReturnEmpty) { verifySubstringEval("", "0", "all", ""); verifySubstringEval("foobar", "0", "0", ""); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING_EMPTY Popping length all, start 0, " - "string 0x pushing result 0x"); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 0, start 0, " - "string 0x666F6F626172 pushing result 0x"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING_EMPTY Popping length all, start 0, " + "string 0x pushing result 0x"); + addString("EVAL_DEBUG_SUBSTRING Popping length 0, start 0, " + "string 0x666F6F626172 pushing result 0x"); + EXPECT_TRUE(checkFile()); } // Check if we can use the substring and equal tokens together @@ -1564,19 +1469,18 @@ TEST_F(TokenTest, substringEquals) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("false", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " - "string 0x666F6F626172 pushing result 0x6F6F6261"); - exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x6F6F6261 and 0x6F6F6261 " - "pushing result \"true\""); - exp_strings.push_back("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " - "string 0x666F6F626172 pushing result 0x6F6F6261"); - exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x6F6F6261 and 0x666F6F62 " - "pushing result \"false\""); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + addString("EVAL_DEBUG_EQUAL Popping 0x6F6F6261 and 0x6F6F6261 " + "pushing result 'true'"); + addString("EVAL_DEBUG_SUBSTRING Popping length 4, start 1, " + "string 0x666F6F626172 pushing result 0x6F6F6261"); + addString("EVAL_DEBUG_EQUAL Popping 0x6F6F6261 and 0x666F6F62 " + "pushing result 'false'"); + EXPECT_TRUE(checkFile()); } // This test checks if a token representing a concat request @@ -1600,13 +1504,12 @@ TEST_F(TokenTest, concat) { ASSERT_EQ(1, values_.size()); EXPECT_EQ("foobar", values_.top()); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_CONCAT Popping 0x626172 and 0x666F6F " - "pushing 0x666F6F626172"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_CONCAT Popping 0x626172 and 0x666F6F " + "pushing 0x666F6F626172"); + EXPECT_TRUE(checkFile()); } // This test checks if we can properly extract the link and peer @@ -1661,29 +1564,28 @@ TEST_F(TokenTest, relay6Field) { // be tidy clearStack(); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 0 " - "with value 0x00000000000000000000000000000000"); - exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field peeraddr nest 0 " - "with value 0x00000000000000000000000000000000"); - exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 1 " - "with value 0x00010000000000000000000000000001"); - exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field peeraddr nest 1 " - "with value 0x00010000000000000000000000000002"); - exp_strings.push_back("EVAL_DEBUG_RELAY6_RANGE Pushing PKT6 relay field linkaddr nest 2 " - "with value 0x"); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 0 " + "with value 0x00000000000000000000000000000000"); + addString("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field peeraddr nest 0 " + "with value 0x00000000000000000000000000000000"); + addString("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 1 " + "with value 0x00010000000000000000000000000001"); + addString("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field peeraddr nest 1 " + "with value 0x00010000000000000000000000000002"); + addString("EVAL_DEBUG_RELAY6_RANGE Pushing PKT6 relay field linkaddr nest 2 " + "with value 0x"); - exp_strings.push_back("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 1 " - "with value 0x00010000000000000000000000000001"); - exp_strings.push_back("EVAL_DEBUG_IPADDRESS Pushing IPAddress " - "0x00010000000000000000000000000001"); - exp_strings.push_back("EVAL_DEBUG_EQUAL Popping 0x00010000000000000000000000000001 " - "and 0x00010000000000000000000000000001 pushing result \"true\""); + addString("EVAL_DEBUG_RELAY6 Pushing PKT6 relay field linkaddr nest 1 " + "with value 0x00010000000000000000000000000001"); + addString("EVAL_DEBUG_IPADDRESS Pushing IPAddress " + "0x00010000000000000000000000000001"); + addString("EVAL_DEBUG_EQUAL Popping 0x00010000000000000000000000000001 " + "and 0x00010000000000000000000000000001 pushing result 'true'"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + EXPECT_TRUE(checkFile()); } // This test checks if we can properly extract an option @@ -1718,23 +1620,22 @@ TEST_F(TokenTest, relay6Option) { // Level 2, no encapsulation so no options verifyRelay6Option(2, 100, TokenOption::TEXTUAL, ""); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"hundred.zero\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"true\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"hundredone.zero\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 102 with value \"\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 102 with value \"false\""); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 'hundred.zero'"); + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 'true'"); + addString("EVAL_DEBUG_OPTION Pushing option 101 with value 'hundredone.zero'"); + addString("EVAL_DEBUG_OPTION Pushing option 102 with value ''"); + addString("EVAL_DEBUG_OPTION Pushing option 102 with value 'false'"); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"hundred.one\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 101 with value \"\""); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 102 with value \"hundredtwo.one\""); + addString("EVAL_DEBUG_OPTION Pushing option 100 with value 'hundred.one'"); + addString("EVAL_DEBUG_OPTION Pushing option 101 with value ''"); + addString("EVAL_DEBUG_OPTION Pushing option 102 with value 'hundredtwo.one'"); - exp_strings.push_back("EVAL_DEBUG_OPTION Pushing option 100 with value \"\""); + addString("EVAL_DEBUG_OPTION Pushing option 100 with value ''"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + EXPECT_TRUE(checkFile()); } // Verifies if the DHCPv6 packet fields can be extracted. @@ -1762,15 +1663,12 @@ TEST_F(TokenTest, pkt6Fields) { ASSERT_NO_THROW(t_.reset(new TokenPkt6(TokenPkt6::TRANSID))); EXPECT_THROW(t_->evaluate(*pkt4_, values_), EvalTypeError); - // Check that the debug output was correct, we create a vector of all - // the strings we expect and send it to checkFile for comparison. - vector exp_strings; - exp_strings.push_back("EVAL_DEBUG_PKT6 Pushing PKT6 field msgtype " - "with value 0x00000001"); - exp_strings.push_back("EVAL_DEBUG_PKT6 Pushing PKT6 field transid " - "with value 0x00003039"); + // Check that the debug output was correct. Add the strings + // to the test vector in the class and then call checkFile + // for comparison + addString("EVAL_DEBUG_PKT6 Pushing PKT6 field msgtype with value 0x00000001"); + addString("EVAL_DEBUG_PKT6 Pushing PKT6 field transid with value 0x00003039"); - EXPECT_TRUE(checkFile(exp_strings)); - remFile(); + EXPECT_TRUE(checkFile()); } }; diff --git a/src/lib/eval/token.cc b/src/lib/eval/token.cc index c461786f46..f0e74a04d5 100644 --- a/src/lib/eval/token.cc +++ b/src/lib/eval/token.cc @@ -23,8 +23,8 @@ TokenString::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.push(value_); // Log what we pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_STRING) - .arg('"' + value_ + '"'); + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_STRING) + .arg('\'' + value_ + '\''); } TokenHexString::TokenHexString(const string& str) : value_("") { @@ -61,7 +61,7 @@ TokenHexString::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.push(value_); // Log what we pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_HEXSTRING) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_HEXSTRING) .arg("0x" + util::encode::encodeHex(std::vector(value_.begin(), value_.end()))); } @@ -87,7 +87,7 @@ TokenIpAddress::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.push(value_); // Log what we pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_IPADDRESS) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_IPADDRESS) .arg("0x" + util::encode::encodeHex(std::vector(value_.begin(), value_.end()))); } @@ -125,14 +125,14 @@ TokenOption::evaluate(const Pkt& pkt, ValueStack& values) { // and can be output directly. We also include the code number // of the requested option. if (representation_type_ == HEXADECIMAL) { - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_OPTION) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_OPTION) .arg(option_code_) .arg("0x" + util::encode::encodeHex(std::vector(opt_str.begin(), - opt_str.end()))); + opt_str.end()))); } else { - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_OPTION) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_OPTION) .arg(option_code_) - .arg('"' + opt_str + '"'); + .arg('\'' + opt_str + '\''); } } @@ -232,10 +232,10 @@ TokenPkt4::evaluate(const Pkt& pkt, ValueStack& values) { values.push(value); // Log what we pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_PKT4) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_PKT4) .arg(type_str) .arg("0x" + util::encode::encodeHex(std::vector(value.begin(), - value.end()))); + value.end()))); } void @@ -251,21 +251,18 @@ TokenEqual::evaluate(const Pkt& /*pkt*/, ValueStack& values) { string op2 = values.top(); values.pop(); // Dammit, std::stack interface is awkward. - string result; if (op1 == op2) - result = "true"; + values.push("true"); else - result = "false"; - - values.push(result); + values.push("false"); // Log what we popped and pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_EQUAL) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_EQUAL) .arg("0x" + util::encode::encodeHex(std::vector(op1.begin(), op1.end()))) .arg("0x" + util::encode::encodeHex(std::vector(op2.begin(), op2.end()))) - .arg('"' + result + '"'); + .arg('\'' + values.top() + '\''); } void @@ -288,7 +285,7 @@ TokenSubstring::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.push(""); // Log what we popped and pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_SUBSTRING_EMPTY) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_SUBSTRING_EMPTY) .arg(len_str) .arg(start_str) .arg("0x") @@ -328,7 +325,7 @@ TokenSubstring::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.push(""); // Log what we popped and pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_SUBSTRING_RANGE) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_SUBSTRING_RANGE) .arg(len_str) .arg(start_str) .arg("0x" + util::encode::encodeHex(std::vector(string_str.begin(), @@ -354,19 +351,17 @@ TokenSubstring::evaluate(const Pkt& /*pkt*/, ValueStack& values) { } } - // and finally get the substring - string result = string_str.substr(start_pos, length); - values.push(result); + values.push(string_str.substr(start_pos, length)); // Log what we popped and pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_SUBSTRING) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_SUBSTRING) .arg(len_str) .arg(start_str) .arg("0x" + util::encode::encodeHex(std::vector(string_str.begin(), string_str.end()))) - .arg("0x" + util::encode::encodeHex(std::vector(result.begin(), - result.end()))); + .arg("0x" + util::encode::encodeHex(std::vector(values.top().begin(), + values.top().end()))); } void @@ -383,17 +378,16 @@ TokenConcat::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.pop(); // Dammit, std::stack interface is awkward. // The top of the stack was evaluated last so this is the right order - string result = op2 + op1; - values.push(result); + values.push(op2 + op1); // Log what we popped and pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_CONCAT) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_CONCAT) .arg("0x" + util::encode::encodeHex(std::vector(op1.begin(), op1.end()))) .arg("0x" + util::encode::encodeHex(std::vector(op2.begin(), op2.end()))) - .arg("0x" + util::encode::encodeHex(std::vector(result.begin(), - result.end()))); + .arg("0x" + util::encode::encodeHex(std::vector(values.top().begin(), + values.top().end()))); } void @@ -407,18 +401,16 @@ TokenNot::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.pop(); bool val = toBool(op); - string result; if (!val) { - result = "true"; + values.push("true"); } else { - result = "false"; + values.push("false"); } - values.push(result); // Log what we popped and pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_NOT) - .arg('"' + op + '"') - .arg('"' + result + '"'); + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_NOT) + .arg('\'' + op + '\'') + .arg('\'' + values.top() + '\''); } void @@ -436,19 +428,17 @@ TokenAnd::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.pop(); // Dammit, std::stack interface is awkward. bool val2 = toBool(op2); - string result; if (val1 && val2) { - result = "true"; + values.push("true"); } else { - result = "false"; + values.push("false"); } - values.push(result); // Log what we popped and pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_AND) - .arg('"' + op1 + '"') - .arg("\"" + op2 + "\"") - .arg("\"" + result + "\""); + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_AND) + .arg('\'' + op1 + '\'') + .arg('\'' + op2 + '\'') + .arg('\'' + values.top() + '\''); } void @@ -466,19 +456,17 @@ TokenOr::evaluate(const Pkt& /*pkt*/, ValueStack& values) { values.pop(); // Dammit, std::stack interface is awkward. bool val2 = toBool(op2); - string result; if (val1 || val2) { - result = "true"; + values.push("true"); } else { - result = "false"; + values.push("false"); } - values.push(result); // Log what we popped and pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_OR) - .arg('"' + op1 + '"') - .arg('"' + op2 + '"') - .arg('"' + result + '"'); + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_OR) + .arg('\'' + op1 + '\'') + .arg('\'' + op2 + '\'') + .arg('\'' + values.top() + '\''); } OptionPtr TokenRelay6Option::getOption(const Pkt& pkt) { @@ -535,7 +523,7 @@ TokenRelay6Field::evaluate(const Pkt& pkt, ValueStack& values) { // level is invalid. We push "" in that case. values.push(""); // Log what we pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_RELAY6_RANGE) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_RELAY6_RANGE) .arg(type_str) .arg(unsigned(nest_level_)) .arg("0x"); @@ -553,7 +541,7 @@ TokenRelay6Field::evaluate(const Pkt& pkt, ValueStack& values) { values.push(value); // Log what we pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_RELAY6) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_RELAY6) .arg(type_str) .arg(unsigned(nest_level_)) .arg("0x" + util::encode::encodeHex(std::vector(value.begin(), @@ -606,7 +594,7 @@ TokenPkt6::evaluate(const Pkt& pkt, ValueStack& values) { values.push(value); // Log what we pushed - LOG_DEBUG(eval_logger, EVAL_DBG_EXTENDED_CALLS, EVAL_DEBUG_PKT6) + LOG_DEBUG(eval_logger, EVAL_DBG_STACK, EVAL_DEBUG_PKT6) .arg(type_str) .arg("0x" + util::encode::encodeHex(std::vector(value.begin(), value.end()))); diff --git a/src/lib/eval/token.h b/src/lib/eval/token.h index c90d2f25a9..d51ed6d1ec 100644 --- a/src/lib/eval/token.h +++ b/src/lib/eval/token.h @@ -568,7 +568,7 @@ protected: uint8_t nest_level_; ///< nesting level of the relay block to use }; -/// @breif Token that represents a value of a field within a DHCPv6 relay +/// @brief Token that represents a value of a field within a DHCPv6 relay /// encapsulation /// /// This represents a reference to a field with a given DHCPv6 relay encapsulation. diff --git a/src/lib/testutils/Makefile.am b/src/lib/testutils/Makefile.am index 3d4d8d56ad..8aa2cc2c71 100644 --- a/src/lib/testutils/Makefile.am +++ b/src/lib/testutils/Makefile.am @@ -8,6 +8,7 @@ if HAVE_GTEST noinst_LTLIBRARIES = libkea-testutils.la libkea_testutils_la_SOURCES = io_utils.cc io_utils.h +libkea_testutils_la_SOURCES += log_utils.cc log_utils.h libkea_testutils_la_SOURCES += unix_control_client.h unix_control_client.cc libkea_testutils_la_CPPFLAGS = $(AM_CPPFLAGS) $(GTEST_INCLUDES) libkea_testutils_la_LIBADD = $(top_builddir)/src/lib/asiolink/libkea-asiolink.la diff --git a/src/lib/testutils/log_utils.cc b/src/lib/testutils/log_utils.cc new file mode 100644 index 0000000000..2bfcc78843 --- /dev/null +++ b/src/lib/testutils/log_utils.cc @@ -0,0 +1,74 @@ +// Copyright (C) 2016 Internet Systems Consortium, Inc. ("ISC") +// +// This Source Code Form is subject to the terms of the Mozilla Public +// License, v. 2.0. If a copy of the MPL was not distributed with this +// file, You can obtain one at http://mozilla.org/MPL/2.0/. + +#include + +namespace isc { +namespace dhcp { +namespace test { + +LogContentTest::LogContentTest() { + // Get rid of any old files + remFile(); + + // Set up the logger for use in checking the debug statements. + // We send the debug statements to a file which we can + // check after the evaluations have completed. We also + // set the log severity and debug levels so that the log + // statements are executed. + LoggerSpecification spec(getRootLoggerName(), + keaLoggerSeverity(isc::log::DEBUG), + keaLoggerDbglevel(isc::log::MAX_DEBUG_LEVEL)); + OutputOption option; + option.destination = OutputOption::DEST_FILE; + option.filename = string(LogContentTest::LOG_FILE); + spec.addOutputOption(option); + LoggerManager manager; + manager.process(spec); +} + +LogContentTest:: ~LogContentTest() { + remFile(); +} + +bool LogContentTest::checkFile() { + ifstream file(LOG_FILE); + EXPECT_TRUE(file.is_open()); + string line, exp_line; + int i = 0; + bool found = true; + + while (getline(file, line) && (i != exp_strings_.size())) { + exp_line = exp_strings_[i]; + i++; + if (string::npos == line.find(exp_line)) { + found = false; + } + } + + file.close(); + + if ((i != exp_strings_.size()) || (found == false)) + return (false); + + return (true); +} + +void LogContentTest::remFile() { + static_cast(remove(LOG_FILE)); +} + +void LogContentTest::addString(const string& new_string) { + exp_strings_.push_back(new_string); +} + +// Set up the name of the LOG_FILE for use in checking +// the debug statements +const char *LogContentTest::LOG_FILE = "test.log"; + +}; // end of isc::dhcp::test namespace +}; // end of isc::dhcp namespace +}; // end of isc namespace diff --git a/src/lib/testutils/log_utils.h b/src/lib/testutils/log_utils.h new file mode 100644 index 0000000000..fbfd24cb33 --- /dev/null +++ b/src/lib/testutils/log_utils.h @@ -0,0 +1,82 @@ +// Copyright (C) 2016 Internet Systems Consortium, Inc. ("ISC") +// +// This Source Code Form is subject to the terms of the Mozilla Public +// License, v. 2.0. If a copy of the MPL was not distributed with this +// file, You can obtain one at http://mozilla.org/MPL/2.0/. + +#ifndef TEST_LOG_UTILS_H +#define TEST_LOG_UTILS_H + +#include +#include + +//#include + +#include +#include +#include + +//#include +//#include +#include + +using namespace std; +using namespace isc::log; + +namespace isc { +namespace dhcp { +namespace test { + +/// @brief Test class for testing things that emit log entries +/// +/// This class provides a convenient method for testing out +/// things that emit log entries. The class sets up the logging +/// to log everything into a file and provides a routine to +/// check the expected strings vs the actual log entries. +/// The user needs to call the addString function for each of +/// the strings they expect in the output in the order they +/// will be emitted. + +class LogContentTest : public ::testing::Test { +public: + + /// @brief Initializes the logger setup for using + /// in checking log statements + /// + /// @todo add support to adjust the severity and debug level + /// to allow for better control over the statements that + /// get logged. + LogContentTest(); + + virtual ~LogContentTest(); + + /// @brief check that the requested strings are in the + /// test log file in the requested order. + /// + /// This routine expects that the caller has properly + /// set up the vector of expected strings by calling + /// addString() with the necessary strings. + /// + /// @return true if all of the strings match + bool checkFile(); + + /// @brief remove the test log file + void remFile(); + + /// @brief Add a string to the vector of expected strings + /// + /// @param new_string the string to add to the end of the vector + /// @return void + void addString(const string& new_string); + + vector exp_strings_; + static const char* LOG_FILE; +}; + + + +}; // end of isc::dhcp::test namespace +}; // end of isc::dhcp namespace +}; // end of isc namespace + +#endif // TEST_LOG_UTILS_H From 4014fb39a66be48414eb2414e7e3bd9fd56426bf Mon Sep 17 00:00:00 2001 From: Thomas Markwalder Date: Wed, 1 Jun 2016 09:08:44 -0400 Subject: [PATCH 3/3] [4480] Fixed a few typos Minor corrections to doc/guide/classify.xml --- doc/guide/classify.xml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/doc/guide/classify.xml b/doc/guide/classify.xml index 48ac7e478a..ec640f8d2d 100644 --- a/doc/guide/classify.xml +++ b/doc/guide/classify.xml @@ -643,7 +643,7 @@ In order to understand the logging statements one must understand a bit about how expressions are evaluated, for a more complete description refer to the design document at . - In brief there are two structures used during the evaluation of an expression + In brief there are two structures used during the evaluation of an expression: a list of tokens which represent the expressions and a value stack which represents the values being manipulated. @@ -651,7 +651,7 @@ The list of tokens is created when the configuration file is processed with most expressions and values being converted to a token. The list is organized - in reverse polish notation. During execution the list will be traversed + in reverse Polish notation. During execution the list will be traversed in order. As each token is executed it will be able to pop values from the top of the stack and eventually push its result on the top of the stack. Imagine the following expression: