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
18 using isc::dhcp::DHO_DHCP_CLIENT_IDENTIFIER;
19 using isc::dhcp::DUID;
20 using isc::dhcp::Option6IAAddr;
21 using isc::dhcp::Option6IAAddrPtr;
22 using isc::dhcp::Option6IAPrefix;
23 using isc::dhcp::Option6IAPrefixPtr;
24 using isc::dhcp::OptionPtr;
25 using isc::dhcp::Pkt4;
26 using isc::dhcp::Pkt4Ptr;
27 using isc::dhcp::PktPtr;
28
29 namespace isc {
30 namespace perfdhcp {
31
dhcpVersion(ExchangeType const exchange_type)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:
45 isc_throw(BadValue,
46 "unrecognized exchange type '" << exchange_type << "'");
47 }
48 }
49
operator <<(std::ostream & os,ExchangeType xchg_type)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
ExchangeStats(const ExchangeType xchg_type,const double drop_time,const bool archive_enabled,const boost::posix_time::ptime boot_time)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
updateDelays(const PktPtr & sent_packet,const PktPtr & rcvd_packet)104 ExchangeStats::updateDelays(const PktPtr& sent_packet,
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()) {
118 isc_throw(Unexpected,
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
matchPackets(const PktPtr & rcvd_packet)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
printTimestamps()302 ExchangeStats::printTimestamps() {
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_) {
306 isc_throw(isc::InvalidOperation,
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;
320 PktListTransidHashIndex& idx =
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()) {
339 isc_throw(InvalidOperation,
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
StatsMgr(CommandOptions & options)357 StatsMgr::StatsMgr(CommandOptions& options) :
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) {
367 addExchangeStats(ExchangeType::DO, options.getDropTime()[0]);
368 if (options.getExchangeMode() == CommandOptions::DORA_SARR) {
369 addExchangeStats(ExchangeType::RA, options.getDropTime()[1]);
370 }
371 if (options.getRenewRate() != 0) {
372 addExchangeStats(ExchangeType::RNA);
373 }
374 if (options.getReleaseRate() != 0) {
375 addExchangeStats(ExchangeType::RLA);
376 }
377 } else if (options.getIpVersion() == 6) {
378 addExchangeStats(ExchangeType::SA, options.getDropTime()[0]);
379 if (options.getExchangeMode() == CommandOptions::DORA_SARR) {
380 addExchangeStats(ExchangeType::RR, options.getDropTime()[1]);
381 }
382 if (options.getRenewRate() != 0) {
383 addExchangeStats(ExchangeType::RN);
384 }
385 if (options.getReleaseRate() != 0) {
386 addExchangeStats(ExchangeType::RL);
387 }
388 }
389 if (options.testDiags('i')) {
390 addCustomCounter("shortwait", "Short waits for packets");
391 }
392 }
393
394 std::string
receivedLeases() const395 ExchangeStats::receivedLeases() const {
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
printLeases() const457 ExchangeStats::printLeases() const {
458 std::cout << receivedLeases() << std::endl;
459 }
460
printLeases() const461 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
470 int ExchangeStats::malformed_pkts_{0};
471
472 } // namespace perfdhcp
473 } // namespace isc
474