diff --git a/AUTHORS.md b/AUTHORS.md index a0f6c55..67e928f 100644 --- a/AUTHORS.md +++ b/AUTHORS.md @@ -7,6 +7,7 @@ If you would like to become a contributor to the official repository, please fol * Jerald Paul Abraham * Alexander Afanasyev * Jing Guan +* Alexander Lane * Spencer Lee * Eric Newberry * Davide Pesavento diff --git a/README.md b/README.md index 3b77b9b..ef34ee5 100644 --- a/README.md +++ b/README.md @@ -29,30 +29,40 @@ sudo ./waf install ### `ndn-traffic-server` Usage: ndn-traffic-server [options] + Respond to Interests as per provided Traffic_Configuration_File. Multiple prefixes can be configured for handling. Set the environment variable NDN_TRAFFIC_LOGFOLDER to redirect output to a log file. + Options: - -h [ --help ] print this help message and exit - -c [ --count ] arg maximum number of Interests to respond to - -d [ --delay ] arg (=0) wait this amount of milliseconds before responding to each Interest - -q [ --quiet ] turn off logging of Interest reception/Data generation + -h [ --help ] print this help message and exit + -c [ --count ] arg maximum number of Interests to respond to + -d [ --delay ] arg (=0) wait this amount of milliseconds before responding to each Interest + -t [ --timestamp-format ] arg format string for timestamp output (see below) + -q [ --quiet ] turn off logging of Interest reception and Data generation ### `ndn-traffic-client` Usage: ndn-traffic-client [options] + Generate Interest traffic as per provided Traffic_Configuration_File. Interests are continuously generated unless a total number is specified. Set the environment variable NDN_TRAFFIC_LOGFOLDER to redirect output to a log file. + Options: -h [ --help ] print this help message and exit -c [ --count ] arg total number of Interests to be generated -i [ --interval ] arg (=1000) Interest generation interval in milliseconds - -q [ --quiet ] turn off logging of Interest generation/Data reception + -t [ --timestamp-format ] arg format string for timestamp output (see below) + -q [ --quiet ] turn off logging of Interest generation and Data reception + -v [ --verbose ] log additional per-packet information * These tools need not be used together and can be used individually as well. * Please refer to the sample configuration files provided for details on how to create your own. * Use the command line options shown above to adjust traffic configuration. +* By default, timestamps are logged in Unix epoch format with microsecond granularity. + For custom output, the `--timestamp-format` option expects a format string using the syntax given in the + [Boost.Date_Time documentation](https://www.boost.org/doc/libs/1_71_0/doc/html/date_time/date_time_io.html#date_time.format_flags). ## Example diff --git a/src/logger.hpp b/src/logger.hpp index 7952b1c..d9be745 100644 --- a/src/logger.hpp +++ b/src/logger.hpp @@ -1,6 +1,6 @@ /* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */ /* - * Copyright (c) 2014-2022, Arizona Board of Regents. + * Copyright (c) 2014-2023, Arizona Board of Regents. * * This program is free software: you can redistribute it and/or modify * it under the terms of the GNU General Public License as published by @@ -24,9 +24,14 @@ #include #include #include +#include -#include +#include #include +#include +#include + +#include namespace ndntg { @@ -34,40 +39,56 @@ class Logger { public: explicit - Logger(const std::string& module) + Logger(std::string_view module) : m_module(module) { } void - log(const std::string& logLine, bool printTime, bool printToConsole) + log(std::string_view logLine, bool printTimestamp, bool printToConsole) { - if (m_logLocation.length() > 0) { - if (printTime) - m_logFile << getTimestamp() << " - "; - m_logFile << logLine << std::endl; - m_logFile.flush(); - if (printToConsole) { - if (printTime) - std::cout << getTimestamp() << " - "; - std::cout << logLine << std::endl; + boost::container::static_vector, 2> destinations; + if (!m_logLocation.empty()) { + destinations.emplace_back(m_logFile); + } + if (m_logLocation.empty() || printToConsole) { + destinations.emplace_back(std::cout); + } + + if (printTimestamp) { + if (m_wantUnixTime) { + using namespace ndn::time; + auto now = std::to_string(toUnixTimestamp(system_clock::now()).count() / 1e6); + for (auto dest : destinations) { + dest.get() << '[' << now << "] "; + } + } + else { + auto now = boost::posix_time::microsec_clock::local_time(); + for (auto dest : destinations) { + dest.get() << '[' << now << "] "; + } } } - else { - if (printTime) - std::cout << getTimestamp() << " - "; - std::cout << logLine << std::endl; + + for (auto dest : destinations) { + dest.get() << logLine << std::endl; } } void - initializeLog(const std::string& instanceId) + initialize(const std::string& instanceId, const std::string& timestampFormat) { - m_logLocation = ""; - const char* envVar = std::getenv("NDN_TRAFFIC_LOGFOLDER"); - if (envVar != nullptr) - m_logLocation = envVar; + m_wantUnixTime = timestampFormat.empty(); + if (!timestampFormat.empty()) { + std::cout.imbue(std::locale(std::cout.getloc(), + new boost::posix_time::time_facet(timestampFormat.data()))); + } + m_logLocation = ""; + if (const char* envVar = std::getenv("NDN_TRAFFIC_LOGFOLDER"); envVar != nullptr) { + m_logLocation = envVar; + } if (m_logLocation.empty()) { std::cout << "Environment variable NDN_TRAFFIC_LOGFOLDER not set.\n" << "Using default output for logging." << std::endl; @@ -80,16 +101,20 @@ public: auto logfile = logdir / (m_module + '_' + instanceId + ".log"); m_logFile.open(logfile.string(), std::ofstream::out | std::ofstream::trunc); if (m_logFile.is_open()) { + if (!timestampFormat.empty()) { + m_logFile.imbue(std::locale(m_logFile.getloc(), + new boost::posix_time::time_facet(timestampFormat.data()))); + } std::cout << "Log file initialized: " << logfile << std::endl; } else { - std::cout << "ERROR: Unable to initialize a log file at: " << m_logLocation << std::endl + std::cout << "ERROR: Unable to initialize a log file at: " << m_logLocation << "\n" << "Using default output for logging." << std::endl; m_logLocation = ""; } } else { - std::cout << "NDN_TRAFFIC_LOGFOLDER should be a directory.\n" + std::cout << "NDN_TRAFFIC_LOGFOLDER is not a directory.\n" << "Using default output for logging." << std::endl; m_logLocation = ""; } @@ -102,17 +127,10 @@ public: } private: - static std::string - getTimestamp() - { - auto now = boost::posix_time::second_clock::local_time(); - return to_simple_string(now); - } - -private: - std::string m_module; + const std::string m_module; std::string m_logLocation; std::ofstream m_logFile; + bool m_wantUnixTime = true; }; } // namespace ndntg diff --git a/src/ndn-traffic-client.cpp b/src/ndn-traffic-client.cpp index fd5d1ed..c9e9f34 100644 --- a/src/ndn-traffic-client.cpp +++ b/src/ndn-traffic-client.cpp @@ -30,15 +30,14 @@ #include #include #include -#include #include #include #include #include +#include #include #include -#include #include #include #include @@ -54,11 +53,8 @@ class NdnTrafficClient : boost::noncopyable { public: explicit - NdnTrafficClient(const std::string& configFile) - : m_signalSet(m_ioService, SIGINT, SIGTERM) - , m_logger("NdnTrafficClient") - , m_face(m_ioService) - , m_configurationFile(configFile) + NdnTrafficClient(std::string configFile) + : m_configurationFile(std::move(configFile)) { } @@ -75,16 +71,28 @@ public: m_interestInterval = interval; } + void + setTimestampFormat(std::string format) + { + m_timestampFormat = std::move(format); + } + void setQuietLogging() { m_wantQuiet = true; } + void + setVerboseLogging() + { + m_wantVerbose = true; + } + int run() { - m_logger.initializeLog(std::to_string(ndn::random::generateWord32())); + m_logger.initialize(std::to_string(ndn::random::generateWord32()), m_timestampFormat); if (!readConfigurationFile(m_configurationFile, m_trafficPatterns, m_logger)) { return 2; @@ -95,7 +103,7 @@ public: return 2; } - m_logger.log("Traffic configuration file processing completed.\n", true, false); + m_logger.log("Traffic configuration file processing completed\n", true, false); for (std::size_t i = 0; i < m_trafficPatterns.size(); i++) { m_logger.log("Traffic Pattern Type #" + std::to_string(i + 1), false, false); m_trafficPatterns[i].printTrafficConfiguration(m_logger); @@ -246,7 +254,7 @@ private: { using std::to_string; - m_logger.log("\n\n== Interest Traffic Report ==\n", false, true); + m_logger.log("\n\n== Traffic Report ==\n", false, true); m_logger.log("Total Traffic Pattern Types = " + to_string(m_trafficPatterns.size()), false, true); m_logger.log("Total Interests Sent = " + to_string(m_nInterestsSent), false, true); m_logger.log("Total Responses Received = " + to_string(m_nInterestsReceived), false, true); @@ -380,6 +388,7 @@ private: onData(const ndn::Interest&, const ndn::Data& data, int globalRef, int localRef, std::size_t patternId, const time::steady_clock::time_point& sentTime) { + auto now = time::steady_clock::now(); auto logLine = "Data Received - PatternType=" + std::to_string(patternId + 1) + ", GlobalID=" + std::to_string(globalRef) + ", LocalID=" + std::to_string(localRef) + @@ -406,7 +415,12 @@ private: m_logger.log(logLine, true, false); } - double roundTripTime = (time::steady_clock::now() - sentTime).count() / 1000000.0; + double roundTripTime = (now - sentTime).count() / 1000000.0; + if (m_wantVerbose) { + auto rttLine = "RTT - Name=" + data.getName().toUri() + + ", RTT=" + std::to_string(roundTripTime) + "ms"; + m_logger.log(rttLine, true, false); + } if (m_minimumInterestRoundTripTime > roundTripTime) m_minimumInterestRoundTripTime = roundTripTime; if (m_maximumInterestRoundTripTime < roundTripTime) @@ -506,6 +520,7 @@ private: break; } } + if (patternId == m_trafficPatterns.size()) { timer.expires_at(timer.expires_at() + boost::posix_time::millisec(m_interestInterval.count())); timer.async_wait([this, &timer] (auto&&...) { generateTraffic(timer); }); @@ -525,12 +540,13 @@ private: } private: + Logger m_logger{"NdnTrafficClient"}; boost::asio::io_service m_ioService; - boost::asio::signal_set m_signalSet; - Logger m_logger; - ndn::Face m_face; + boost::asio::signal_set m_signalSet{m_ioService, SIGINT, SIGTERM}; + ndn::Face m_face{m_ioService}; std::string m_configurationFile; + std::string m_timestampFormat; std::optional m_nMaximumInterests; time::milliseconds m_interestInterval = 1_s; @@ -547,6 +563,7 @@ private: double m_totalInterestRoundTripTime = 0; bool m_wantQuiet = false; + bool m_wantVerbose = false; bool m_hasError = false; }; @@ -570,14 +587,17 @@ int main(int argc, char* argv[]) { std::string configFile; + std::string timestampFormat; po::options_description visibleOptions("Options"); visibleOptions.add_options() ("help,h", "print this help message and exit") - ("count,c", po::value(), "total number of Interests to be generated") + ("count,c", po::value(), "total number of Interests to be generated") ("interval,i", po::value()->default_value(1000), "Interest generation interval in milliseconds") - ("quiet,q", po::bool_switch(), "turn off logging of Interest generation/Data reception") + ("timestamp-format,t", po::value(×tampFormat), "format string for timestamp output") + ("quiet,q", po::bool_switch(), "turn off logging of Interest generation and Data reception") + ("verbose,v", po::bool_switch(), "log additional per-packet information") ; po::options_description hiddenOptions; @@ -615,12 +635,12 @@ main(int argc, char* argv[]) return 2; } - ndntg::NdnTrafficClient client(configFile); + ndntg::NdnTrafficClient client(std::move(configFile)); if (vm.count("count") > 0) { - int count = vm["count"].as(); + auto count = vm["count"].as(); if (count < 0) { - std::cerr << "ERROR: the argument for option '--count' cannot be negative" << std::endl; + std::cerr << "ERROR: the argument for option '--count' cannot be negative\n"; return 2; } client.setMaximumInterests(static_cast(count)); @@ -629,15 +649,27 @@ main(int argc, char* argv[]) if (vm.count("interval") > 0) { ndn::time::milliseconds interval(vm["interval"].as()); if (interval <= 0_ms) { - std::cerr << "ERROR: the argument for option '--interval' must be positive" << std::endl; + std::cerr << "ERROR: the argument for option '--interval' must be positive\n"; return 2; } client.setInterestInterval(interval); } + if (!timestampFormat.empty()) { + client.setTimestampFormat(std::move(timestampFormat)); + } + if (vm["quiet"].as()) { + if (vm["verbose"].as()) { + std::cerr << "ERROR: cannot set both '--quiet' and '--verbose'\n"; + return 2; + } client.setQuietLogging(); } + if (vm["verbose"].as()) { + client.setVerboseLogging(); + } + return client.run(); } diff --git a/src/ndn-traffic-server.cpp b/src/ndn-traffic-server.cpp index 6525b7a..3556efe 100644 --- a/src/ndn-traffic-server.cpp +++ b/src/ndn-traffic-server.cpp @@ -1,6 +1,6 @@ /* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */ /* - * Copyright (c) 2014-2022, Arizona Board of Regents. + * Copyright (c) 2014-2023, Arizona Board of Regents. * * This program is free software: you can redistribute it and/or modify * it under the terms of the GNU General Public License as published by @@ -31,18 +31,16 @@ #include #include #include -#include #include #include #include -#include +#include #include #include #include #include -namespace po = boost::program_options; using namespace ndn::time_literals; using namespace std::string_literals; @@ -54,11 +52,8 @@ class NdnTrafficServer : boost::noncopyable { public: explicit - NdnTrafficServer(const std::string& configFile) - : m_signalSet(m_ioService, SIGINT, SIGTERM) - , m_logger("NdnTrafficServer") - , m_face(m_ioService) - , m_configurationFile(configFile) + NdnTrafficServer(std::string configFile) + : m_configurationFile(std::move(configFile)) { } @@ -75,6 +70,12 @@ public: m_contentDelay = delay; } + void + setTimestampFormat(std::string format) + { + m_timestampFormat = std::move(format); + } + void setQuietLogging() { @@ -84,7 +85,7 @@ public: int run() { - m_logger.initializeLog(std::to_string(ndn::random::generateWord32())); + m_logger.initialize(std::to_string(ndn::random::generateWord32()), m_timestampFormat); if (!readConfigurationFile(m_configurationFile, m_trafficPatterns, m_logger)) { return 2; @@ -95,7 +96,7 @@ public: return 2; } - m_logger.log("Traffic configuration file processing completed.\n", true, false); + m_logger.log("Traffic configuration file processing completed\n", true, false); for (std::size_t i = 0; i < m_trafficPatterns.size(); i++) { m_logger.log("Traffic Pattern Type #" + std::to_string(i + 1), false, false); m_trafficPatterns[i].printTrafficConfiguration(m_logger); @@ -223,17 +224,19 @@ private: void logStatistics() { - m_logger.log("\n\n== Interest Traffic Report ==\n", false, true); - m_logger.log("Total Traffic Pattern Types = " + - std::to_string(m_trafficPatterns.size()), false, true); - m_logger.log("Total Interests Received = " + - std::to_string(m_nInterestsReceived), false, true); + using std::to_string; + + m_logger.log("\n\n== Traffic Report ==\n", false, true); + m_logger.log("Total Traffic Pattern Types = " + to_string(m_trafficPatterns.size()), false, true); + m_logger.log("Total Interests Received = " + to_string(m_nInterestsReceived) + "\n", false, true); for (std::size_t patternId = 0; patternId < m_trafficPatterns.size(); patternId++) { - m_logger.log("\nTraffic Pattern Type #" + std::to_string(patternId + 1), false, true); - m_trafficPatterns[patternId].printTrafficConfiguration(m_logger); + const auto& pattern = m_trafficPatterns[patternId]; + + m_logger.log("Traffic Pattern Type #" + to_string(patternId + 1), false, true); + pattern.printTrafficConfiguration(m_logger); m_logger.log("Total Interests Received = " + - std::to_string(m_trafficPatterns[patternId].m_nInterestsReceived) + "\n", false, true); + to_string(pattern.m_nInterestsReceived) + "\n", false, true); } } @@ -286,10 +289,10 @@ private: pattern.m_nInterestsReceived++; if (!m_wantQuiet) { - auto logLine = "Interest received - PatternType=" + std::to_string(patternId + 1) + + auto logLine = "Interest Received - PatternType=" + std::to_string(patternId + 1) + ", GlobalID=" + std::to_string(m_nInterestsReceived) + ", LocalID=" + std::to_string(pattern.m_nInterestsReceived) + - ", Name=" + pattern.m_name; + ", Name=" + interest.getName().toUri(); m_logger.log(logLine, true, false); } @@ -332,13 +335,14 @@ private: } private: + Logger m_logger{"NdnTrafficServer"}; boost::asio::io_service m_ioService; - boost::asio::signal_set m_signalSet; - Logger m_logger; - ndn::Face m_face; + boost::asio::signal_set m_signalSet{m_ioService, SIGINT, SIGTERM}; + ndn::Face m_face{m_ioService}; ndn::KeyChain m_keyChain; std::string m_configurationFile; + std::string m_timestampFormat; std::optional m_nMaximumInterests; time::milliseconds m_contentDelay = 0_ms; @@ -353,6 +357,8 @@ private: } // namespace ndntg +namespace po = boost::program_options; + static void usage(std::ostream& os, std::string_view programName, const po::options_description& desc) { @@ -369,14 +375,16 @@ int main(int argc, char* argv[]) { std::string configFile; + std::string timestampFormat; po::options_description visibleOptions("Options"); visibleOptions.add_options() ("help,h", "print this help message and exit") - ("count,c", po::value(), "maximum number of Interests to respond to") + ("count,c", po::value(), "maximum number of Interests to respond to") ("delay,d", po::value()->default_value(0), "wait this amount of milliseconds before responding to each Interest") - ("quiet,q", po::bool_switch(), "turn off logging of Interest reception/Data generation") + ("timestamp-format,t", po::value(×tampFormat), "format string for timestamp output") + ("quiet,q", po::bool_switch(), "turn off logging of Interest reception and Data generation") ; po::options_description hiddenOptions; @@ -414,12 +422,12 @@ main(int argc, char* argv[]) return 2; } - ndntg::NdnTrafficServer server(configFile); + ndntg::NdnTrafficServer server(std::move(configFile)); if (vm.count("count") > 0) { - int count = vm["count"].as(); + auto count = vm["count"].as(); if (count < 0) { - std::cerr << "ERROR: the argument for option '--count' cannot be negative" << std::endl; + std::cerr << "ERROR: the argument for option '--count' cannot be negative\n"; return 2; } server.setMaximumInterests(static_cast(count)); @@ -428,12 +436,16 @@ main(int argc, char* argv[]) if (vm.count("delay") > 0) { ndn::time::milliseconds delay(vm["delay"].as()); if (delay < 0_ms) { - std::cerr << "ERROR: the argument for option '--delay' cannot be negative" << std::endl; + std::cerr << "ERROR: the argument for option '--delay' cannot be negative\n"; return 2; } server.setContentDelay(delay); } + if (!timestampFormat.empty()) { + server.setTimestampFormat(std::move(timestampFormat)); + } + if (vm["quiet"].as()) { server.setQuietLogging(); }