Kea  2.1.7-git
bin/perfdhcp/stats_mgr.cc
Go to the documentation of this file.
1 // Copyright (C) 2012-2021 Internet Systems Consortium, Inc. ("ISC")
2 //
3 // This Source Code Form is subject to the terms of the Mozilla Public
4 // License, v. 2.0. If a copy of the MPL was not distributed with this
5 // file, You can obtain one at http://mozilla.org/MPL/2.0/.
6 
7 #include <config.h>
8 
9 #include <dhcp/dhcp4.h>
10 #include <dhcp/dhcp6.h>
11 #include <dhcp/duid.h>
12 #include <dhcp/option6_iaaddr.h>
13 #include <dhcp/option6_iaprefix.h>
14 #include <dhcp/pkt4.h>
15 #include <perfdhcp/stats_mgr.h>
16 #include <perfdhcp/test_control.h>
17 
19 using isc::dhcp::DUID;
25 using isc::dhcp::Pkt4;
26 using isc::dhcp::Pkt4Ptr;
27 using isc::dhcp::PktPtr;
28 
29 namespace isc {
30 namespace perfdhcp {
31 
32 int dhcpVersion(ExchangeType const exchange_type) {
33  switch (exchange_type) {
34  case ExchangeType::DO:
35  case ExchangeType::RA:
36  case ExchangeType::RNA:
37  case ExchangeType::RLA:
38  return 4;
39  case ExchangeType::SA:
40  case ExchangeType::RR:
41  case ExchangeType::RN:
42  case ExchangeType::RL:
43  return 6;
44  default:
46  "unrecognized exchange type '" << exchange_type << "'");
47  }
48 }
49 
50 std::ostream& operator<<(std::ostream& os, ExchangeType xchg_type)
51 {
52  switch(xchg_type) {
53  case ExchangeType::DO:
54  return(os << "DISCOVER-OFFER");
55  case ExchangeType::RA:
56  return(os << "REQUEST-ACK");
57  case ExchangeType::RNA:
58  return(os << "REQUEST-ACK (renewal)");
59  case ExchangeType::RLA:
60  return(os << "RELEASE");
61  case ExchangeType::SA:
62  return(os << "SOLICIT-ADVERTISE");
63  case ExchangeType::RR:
64  return(os << "REQUEST-REPLY");
65  case ExchangeType::RN:
66  return(os << "RENEW-REPLY");
67  case ExchangeType::RL:
68  return(os << "RELEASE-REPLY");
69  default:
70  return(os << "Unknown exchange type");
71  }
72 }
73 
74 
75 ExchangeStats::ExchangeStats(const ExchangeType xchg_type,
76  const double drop_time,
77  const bool archive_enabled,
78  const boost::posix_time::ptime boot_time)
79  : xchg_type_(xchg_type),
80  sent_packets_(),
81  rcvd_packets_(),
82  archived_packets_(),
83  archive_enabled_(archive_enabled),
84  drop_time_(drop_time),
85  min_delay_(std::numeric_limits<double>::max()),
86  max_delay_(0.),
87  sum_delay_(0.),
88  sum_delay_squared_(0.),
89  orphans_(0),
90  collected_(0),
91  unordered_lookup_size_sum_(0),
92  unordered_lookups_(0),
93  ordered_lookups_(0),
94  sent_packets_num_(0),
95  rcvd_packets_num_(0),
96  non_unique_addr_num_(0),
97  rejected_leases_num_(0),
98  boot_time_(boot_time)
99 {
100  next_sent_ = sent_packets_.begin();
101 }
102 
103 void
105  const PktPtr& rcvd_packet) {
106  if (!sent_packet) {
107  isc_throw(BadValue, "Sent packet is null");
108  }
109  if (!rcvd_packet) {
110  isc_throw(BadValue, "Received packet is null");
111  }
112 
113  boost::posix_time::ptime sent_time = sent_packet->getTimestamp();
114  boost::posix_time::ptime rcvd_time = rcvd_packet->getTimestamp();
115 
116  if (sent_time.is_not_a_date_time() ||
117  rcvd_time.is_not_a_date_time()) {
119  "Timestamp must be set for sent and "
120  "received packet to measure RTT,"
121  << " sent: " << sent_time
122  << " recv: " << rcvd_time);
123  }
124  boost::posix_time::time_period period(sent_time, rcvd_time);
125  // We don't bother calculating deltas in nanoseconds. It is much
126  // more convenient to use seconds instead because we are going to
127  // sum them up.
128  double delta =
129  static_cast<double>(period.length().total_nanoseconds()) / 1e9;
130 
131  if (delta < 0) {
132  isc_throw(Unexpected, "Sent packet's timestamp must not be "
133  "greater than received packet's timestamp in "
134  << xchg_type_ << ".\nTime difference: "
135  << delta << ", sent: " << sent_time << ", rcvd: "
136  << rcvd_time << ".\nTrans ID: " << sent_packet->getTransid()
137  << ".");
138  }
139 
140  // Record the minimum delay between sent and received packets.
141  if (delta < min_delay_) {
142  min_delay_ = delta;
143  }
144  // Record the maximum delay between sent and received packets.
145  if (delta > max_delay_) {
146  max_delay_ = delta;
147  }
148  // Update delay sum and square sum. That will be used to calculate
149  // mean delays.
150  sum_delay_ += delta;
151  sum_delay_squared_ += delta * delta;
152 }
153 
154 PktPtr
155 ExchangeStats::matchPackets(const PktPtr& rcvd_packet) {
156  using namespace boost::posix_time;
157 
158  if (!rcvd_packet) {
159  isc_throw(BadValue, "Received packet is null");
160  }
161 
162  if (sent_packets_.size() == 0) {
163  // List of sent packets is empty so there is no sense
164  // to continue looking fo the packet. It also means
165  // that the received packet we got has no corresponding
166  // sent packet so orphans counter has to be updated.
167  ++orphans_;
168  return(PktPtr());
169  } else if (next_sent_ == sent_packets_.end()) {
170  // Even if there are still many unmatched packets on the
171  // list we might hit the end of it because of unordered
172  // lookups. The next logical step is to reset iterator.
173  next_sent_ = sent_packets_.begin();
174  }
175 
176  // With this variable we will be signalling success or failure
177  // to find the packet.
178  bool packet_found = false;
179  // Most likely responses are sent from the server in the same
180  // order as client's requests to the server. We are caching
181  // next sent packet and first try to match it with the next
182  // incoming packet. We are successful if there is no
183  // packet drop or out of order packets sent. This is actually
184  // the fastest way to look for packets.
185  if ((*next_sent_)->getTransid() == rcvd_packet->getTransid()) {
186  ++ordered_lookups_;
187  packet_found = true;
188  } else {
189  // If we are here, it means that we were unable to match the
190  // next incoming packet with next sent packet so we need to
191  // take a little more expensive approach to look packets using
192  // alternative index (transaction id & 1023).
193  PktListTransidHashIndex& idx = sent_packets_.template get<1>();
194  // Packets are grouped using transaction id masked with value
195  // of 1023. For instance, packets with transaction id equal to
196  // 1, 1024 ... will belong to the same group (a.k.a. bucket).
197  // When using alternative index we don't find the packet but
198  // bucket of packets and we need to iterate through the bucket
199  // to find the one that has desired transaction id.
200  std::pair<PktListTransidHashIterator,PktListTransidHashIterator> p =
201  idx.equal_range(hashTransid(rcvd_packet));
202  // We want to keep statistics of unordered lookups to make
203  // sure that there is a right balance between number of
204  // unordered lookups and ordered lookups. If number of unordered
205  // lookups is high it may mean that many packets are lost or
206  // sent out of order.
207  ++unordered_lookups_;
208  // We also want to keep the mean value of the bucket. The lower
209  // bucket size the better. If bucket sizes appear to big we
210  // might want to increase number of buckets.
211  unordered_lookup_size_sum_ += std::distance(p.first, p.second);
212  bool non_expired_found = false;
213  // Removal can be done only after the loop
214  PktListRemovalQueue to_remove;
215  for (PktListTransidHashIterator it = p.first; it != p.second; ++it) {
216  // If transaction id is matching, we found the original
217  // packet sent to the server. Therefore, we reset the
218  // 'next sent' pointer to point to this location. We
219  // also indicate that the matching packet is found.
220  // Even though the packet has been found, we continue
221  // iterating over the bucket to remove all those packets
222  // that are timed out.
223  if (!packet_found && ((*it)->getTransid() == rcvd_packet->getTransid())) {
224  packet_found = true;
225  next_sent_ = sent_packets_.template project<0>(it);
226  }
227 
228  if (!non_expired_found) {
229  // Check if the packet should be removed due to timeout.
230  // This includes the packet matching the received one.
231  ptime now = microsec_clock::universal_time();
232  ptime packet_time = (*it)->getTimestamp();
233  time_period packet_period(packet_time, now);
234  if (!packet_period.is_null()) {
235  double period_fractional =
236  packet_period.length().total_seconds() +
237  (static_cast<double>(packet_period.length().fractional_seconds())
238  / packet_period.length().ticks_per_second());
239  if (drop_time_ > 0 && (period_fractional > drop_time_)) {
240  // Push the iterator on the removal queue.
241  to_remove.push(it);
242 
243  } else {
244  // We found first non-expired transaction. All other
245  // transactions within this bucket are considered
246  // non-expired because packets are held in the
247  // order of addition within the bucket.
248  non_expired_found = true;
249  }
250  }
251  }
252 
253  // If we found the packet and all expired transactions,
254  // there is nothing more to do.
255  if (non_expired_found && packet_found) {
256  break;
257  }
258  }
259 
260  // Deal with the removal queue.
261  while (!to_remove.empty()) {
262  PktListTransidHashIterator it = to_remove.front();
263  to_remove.pop();
264  // If timed out packet is not the one matching server response,
265  // we simply remove it and keep the pointer to the 'next sent'
266  // packet as it was. If the timed out packet appears to be the
267  // one that is matching the server response, we still want to
268  // remove it, but we need to update the 'next sent' pointer to
269  // point to a valid location.
270  if (sent_packets_.template project<0>(it) != next_sent_) {
271  eraseSent(sent_packets_.template project<0>(it));
272  } else {
273  next_sent_ = eraseSent(sent_packets_.template project<0>(it));
274  // We removed the matching packet because of the timeout. It
275  // means that there is no match anymore.
276  packet_found = false;
277  }
278  ++collected_;
279  }
280  }
281 
282  if (!packet_found) {
283  // If we are here, it means that both ordered lookup and
284  // unordered lookup failed. Searched packet is not on the list.
285  ++orphans_;
286  return(PktPtr());
287  }
288 
289  // Packet is matched so we count it. We don't count unmatched packets
290  // as they are counted as orphans with a separate counter.
291  ++rcvd_packets_num_;
292  PktPtr sent_packet(*next_sent_);
293  // If packet was found, we assume it will be never searched
294  // again. We want to delete this packet from the list to
295  // improve performance of future searches.
296  next_sent_ = eraseSent(next_sent_);
297  return(sent_packet);
298 }
299 
300 
301 void
303  // If archive mode is disabled there is no sense to proceed
304  // because we don't have packets and their timestamps.
305  if (!archive_enabled_) {
307  "packets archive mode is disabled");
308  }
309  if (rcvd_packets_num_ == 0) {
310  std::cout << "Unavailable! No packets received." << std::endl;
311  }
312  // We will be using boost::posix_time extensively here
313  using namespace boost::posix_time;
314 
315  // Iterate through all received packets.
316  for (PktListIterator it = rcvd_packets_.begin();
317  it != rcvd_packets_.end();
318  ++it) {
319  PktPtr rcvd_packet = *it;
321  archived_packets_.template get<1>();
322  std::pair<PktListTransidHashIterator,
323  PktListTransidHashIterator> p =
324  idx.equal_range(hashTransid(rcvd_packet));
325  for (PktListTransidHashIterator it_archived = p.first;
326  it_archived != p.second;
327  ++it_archived) {
328  if ((*it_archived)->getTransid() ==
329  rcvd_packet->getTransid()) {
330  PktPtr sent_packet = *it_archived;
331  // Get sent and received packet times.
332  ptime sent_time = sent_packet->getTimestamp();
333  ptime rcvd_time = rcvd_packet->getTimestamp();
334  // All sent and received packets should have timestamps
335  // set but if there is a bug somewhere and packet does
336  // not have timestamp we want to catch this here.
337  if (sent_time.is_not_a_date_time() ||
338  rcvd_time.is_not_a_date_time()) {
340  "packet time is not set");
341  }
342  // Calculate durations of packets from beginning of epoch.
343  time_period sent_period(boot_time_, sent_time);
344  time_period rcvd_period(boot_time_, rcvd_time);
345  // Print timestamps for sent and received packet.
346  std::cout << "sent / received: "
347  << to_iso_string(sent_period.length())
348  << " / "
349  << to_iso_string(rcvd_period.length())
350  << std::endl;
351  break;
352  }
353  }
354  }
355 }
356 
358  exchanges_(),
359  boot_time_(boost::posix_time::microsec_clock::universal_time())
360 {
361  // Check if packet archive mode is required. If user
362  // requested diagnostics option -x l or -x t we have to enable
363  // it so as StatsMgr preserves all packets.
364  archive_enabled_ = options.testDiags('l') || options.testDiags('t');
365 
366  if (options.getIpVersion() == 4) {
368  if (options.getExchangeMode() == CommandOptions::DORA_SARR) {
370  }
371  if (options.getRenewRate() != 0) {
373  }
374  if (options.getReleaseRate() != 0) {
376  }
377  } else if (options.getIpVersion() == 6) {
379  if (options.getExchangeMode() == CommandOptions::DORA_SARR) {
381  }
382  if (options.getRenewRate() != 0) {
384  }
385  if (options.getReleaseRate() != 0) {
387  }
388  }
389  if (options.testDiags('i')) {
390  addCustomCounter("shortwait", "Short waits for packets");
391  }
392 }
393 
394 std::string
396  // Get DHCP version.
397  int const v(dhcpVersion(xchg_type_));
398 
399  std::stringstream result;
400  // Iterate through all received packets.
401  for (PktPtr const& packet : rcvd_packets_) {
402 
403  // Get client identifier.
404  if (v == 4) {
405  OptionPtr const& client_id_option(
406  packet->getOption(DHO_DHCP_CLIENT_IDENTIFIER));
407  if (client_id_option) {
408  result << TestControl::vector2Hex(client_id_option->getData());
409  }
410  } else if (v == 6) {
411  OptionPtr const& client_id_option(packet->getOption(D6O_CLIENTID));
412  if (client_id_option) {
413  result << DUID(client_id_option->getData()).toText();
414  }
415  } else {
416  isc_throw(BadValue, "unrecognized DHCP version '" << v << "'");
417  }
418  result << ',';
419 
420  // Get address.
421  if (v == 4) {
422  Pkt4Ptr const& packet4(boost::dynamic_pointer_cast<Pkt4>(packet));
423  if (packet4) {
424  result << packet4->getYiaddr().toText();
425  }
426  } else if (v == 6) {
427  OptionPtr const& option(packet->getOption(D6O_IA_NA));
428  if (option) {
429  Option6IAAddrPtr const& iaaddr(
430  boost::dynamic_pointer_cast<Option6IAAddr>(
431  option->getOption(D6O_IAADDR)));
432  if (iaaddr) {
433  result << iaaddr->getAddress().toText();
434  }
435  }
436  }
437  result << ',';
438 
439  // Get prefix.
440  OptionPtr const& option(packet->getOption(D6O_IA_PD));
441  if (option) {
442  Option6IAPrefixPtr const& iaprefix(
443  boost::dynamic_pointer_cast<Option6IAPrefix>(
444  option->getOption(D6O_IAPREFIX)));
445  if (iaprefix) {
446  result << iaprefix->getAddress().toText();
447  }
448  }
449 
450  result << std::endl;
451  }
452 
453  return result.str();
454 }
455 
456 void
458  std::cout << receivedLeases() << std::endl;
459 }
460 
461 void StatsMgr::printLeases() const {
462  for (auto const& exchange : exchanges_) {
463  std::cout << "***Leases for " << exchange.first << "***" << std::endl;
464  std::cout << "client_id,adrress,prefix" << std::endl;
465  exchange.second->printLeases();
466  std::cout << std::endl;
467  }
468 }
469 
471 
472 } // namespace perfdhcp
473 } // namespace isc
DHCPv6 SOLICIT-ADVERTISE.
ExchangeType
DHCP packet exchange types.
static std::string vector2Hex(const std::vector< uint8_t > &vec, const std::string &separator="")
Convert vector in hexadecimal string.
static uint32_t hashTransid(const dhcp::PktPtr &packet)
Hash transaction id of the packet.
std::queue< PktListTransidHashIterator > PktListRemovalQueue
Packet list iterator queue for removal.
boost::shared_ptr< Option > OptionPtr
Definition: option.h:36
STL namespace.
void updateDelays(const dhcp::PktPtr &sent_packet, const dhcp::PktPtr &rcvd_packet)
Update delay counters.
uint8_t getIpVersion() const
Returns IP version.
ExchangeMode getExchangeMode() const
Returns packet exchange mode.
Holds DUID (DHCPv6 Unique Identifier)
Definition: duid.h:27
#define isc_throw(type, stream)
A shortcut macro to insert known values into exception arguments.
A generic exception that is thrown if a parameter given to a method is considered invalid in that con...
StatsMgr(CommandOptions &options)
Constructor.
boost::shared_ptr< Option6IAPrefix > Option6IAPrefixPtr
Pointer to the Option6IAPrefix object.
DHCPv4 REQUEST-ACK (renewal)
int getReleaseRate() const
Returns a rate at which DHCPv6 Release messages are sent.
A generic exception that is thrown when an unexpected error condition occurs.
DHCPv6 RELEASE-REPLY.
int dhcpVersion(ExchangeType const exchange_type)
Get the DHCP version that fits the exchange type.
void printLeases() const
Print the list of received leases.
std::ostream & operator<<(std::ostream &os, ExchangeType xchg_type)
Return name of the exchange.
std::vector< double > getDropTime() const
Returns drop time.
boost::shared_ptr< Pkt4 > Pkt4Ptr
A pointer to Pkt4 object.
Definition: pkt4.h:544
boost::shared_ptr< isc::dhcp::Pkt > PktPtr
A pointer to either Pkt4 or Pkt6 packet.
Definition: pkt.h:797
dhcp::PktPtr matchPackets(const dhcp::PktPtr &rcvd_packet)
Match received packet with the corresponding sent packet.
Defines the logger used by the top-level component of kea-lfc.
PktList::iterator PktListIterator
Packet list iterator for sequential access to elements.
PktList::template nth_index< 1 >::type PktListTransidHashIndex
Packet list index to search packets using transaction id hash.
Represents DHCPv4 packet.
Definition: pkt4.h:37
void addExchangeStats(const ExchangeType xchg_type, const double drop_time=-1)
Specify new exchange type.
DHCPv4 DISCOVER-OFFER.
void printLeases() const
Delegate to all exchanges to print their leases.
PktListTransidHashIndex::const_iterator PktListTransidHashIterator
Packet list iterator to access packets using transaction id hash.
DHCPv6 REQUEST-REPLY.
std::string receivedLeases() const
Return the list of received leases in CSV format as string.
A generic exception that is thrown if a function is called in a prohibited way.
bool testDiags(const char diag)
Find if diagnostic flag has been set.
void addCustomCounter(const std::string &short_name, const std::string &long_name)
Add named custom uint64 counter.
Class that represents IAPREFIX option in DHCPv6.
void printTimestamps()
Print timestamps for sent and received packets.
boost::shared_ptr< Option6IAAddr > Option6IAAddrPtr
A pointer to the isc::dhcp::Option6IAAddr object.
int getRenewRate() const
Returns a rate at which DHCPv6 Renew messages are sent.