/src/kea/src/hooks/dhcp/radius/client_exchange.cc
Line | Count | Source |
1 | | // Copyright (C) 2023-2025 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 <asiolink/asio_wrapper.h> |
10 | | #include <asiolink/io_service.h> |
11 | | #include <asiolink/udp_endpoint.h> |
12 | | #include <asiolink/udp_socket.h> |
13 | | #include <cryptolink/crypto_rng.h> |
14 | | #include <util/multi_threading_mgr.h> |
15 | | #include <util/unlock_guard.h> |
16 | | #include <client_exchange.h> |
17 | | #include <radius.h> |
18 | | #include <radius_log.h> |
19 | | |
20 | | #include <cerrno> |
21 | | #include <chrono> |
22 | | #include <limits> |
23 | | #include <sstream> |
24 | | |
25 | | using namespace isc; |
26 | | using namespace isc::asiolink; |
27 | | using namespace isc::data; |
28 | | using namespace isc::util; |
29 | | using namespace std; |
30 | | using namespace std::chrono; |
31 | | namespace ph = std::placeholders; |
32 | | |
33 | | namespace isc { |
34 | | namespace radius { |
35 | | |
36 | | string |
37 | 0 | exchangeRCtoText(const int rc) { |
38 | 0 | ostringstream result; |
39 | 0 | switch (rc) { |
40 | 0 | case BADRESP_RC: |
41 | 0 | return ("bad response"); |
42 | 0 | case ERROR_RC: |
43 | 0 | return ("error"); |
44 | 0 | case OK_RC: |
45 | 0 | return ("ok"); |
46 | 0 | case TIMEOUT_RC: |
47 | 0 | return ("timeout"); |
48 | 0 | case REJECT_RC: |
49 | 0 | return ("reject"); |
50 | 0 | case READBLOCK_RC: |
51 | 0 | return ("temporarily unavailable"); |
52 | 0 | default: |
53 | 0 | result << (rc < 0 ? "error " : "unknown ") << rc; |
54 | 0 | return (result.str()); |
55 | 0 | } |
56 | 0 | } |
57 | | |
58 | | Exchange::Exchange(const asiolink::IOServicePtr io_service, |
59 | | const MessagePtr& request, |
60 | | unsigned maxretries, |
61 | | const Servers& servers, |
62 | | Handler handler) |
63 | 0 | : identifier_(""), io_service_(io_service), sync_(false), |
64 | 0 | started_(false), terminated_(false), rc_(ERROR_RC), |
65 | 0 | start_time_(std::chrono::steady_clock().now()), |
66 | 0 | socket_(), ep_(), timer_(), server_(), idx_(0), |
67 | 0 | request_(request), sent_(), received_(), buffer_(), size_(0), |
68 | 0 | retries_(0), maxretries_(maxretries), servers_(servers), |
69 | 0 | postponed_(), handler_(handler), mutex_(new std::mutex()) { |
70 | 0 | if (!io_service) { |
71 | 0 | isc_throw(BadValue, "null IO service"); |
72 | 0 | } |
73 | 0 | if (!request) { |
74 | 0 | isc_throw(BadValue, "null request"); |
75 | 0 | } |
76 | 0 | if (servers.empty()) { |
77 | 0 | isc_throw(BadValue, "no server"); |
78 | 0 | } |
79 | 0 | if (!handler) { |
80 | 0 | isc_throw(BadValue, "null handler"); |
81 | 0 | } |
82 | 0 | createIdentifier(); |
83 | 0 | } |
84 | | |
85 | | Exchange::Exchange(const MessagePtr& request, |
86 | | unsigned maxretries, |
87 | | const Servers& servers) |
88 | 0 | : identifier_(""), io_service_(new IOService()), sync_(true), |
89 | 0 | started_(false), terminated_(false), rc_(ERROR_RC), |
90 | 0 | start_time_(std::chrono::steady_clock().now()), |
91 | 0 | socket_(), ep_(), timer_(), server_(), idx_(0), |
92 | 0 | request_(request), sent_(), received_(), buffer_(), size_(0), |
93 | 0 | retries_(0), maxretries_(maxretries), servers_(servers), postponed_(), |
94 | 0 | handler_(), mutex_(new std::mutex()) { |
95 | |
|
96 | 0 | if (!request) { |
97 | 0 | isc_throw(BadValue, "null request"); |
98 | 0 | } |
99 | 0 | if (servers.empty()) { |
100 | 0 | isc_throw(BadValue, "no server"); |
101 | 0 | } |
102 | 0 | createIdentifier(); |
103 | 0 | } |
104 | | |
105 | 0 | Exchange::~Exchange() { |
106 | 0 | MultiThreadingLock lock(*mutex_); |
107 | 0 | shutdownInternal(); |
108 | 0 | timer_.reset(); |
109 | 0 | socket_.reset(); |
110 | 0 | if (sync_ && io_service_) { |
111 | | // As a best practice, call any remaining handlers. |
112 | 0 | io_service_->stopAndPoll(); |
113 | 0 | io_service_.reset(); |
114 | 0 | } |
115 | 0 | } |
116 | | |
117 | | void |
118 | 0 | Exchange::createIdentifier() { |
119 | 0 | vector<uint8_t> rv = cryptolink::random(sizeof(uint32_t)); |
120 | 0 | if (rv.size() != sizeof(uint32_t)) { |
121 | 0 | isc_throw(Unexpected, "random failed"); |
122 | 0 | } |
123 | 0 | uint32_t ri; |
124 | 0 | memmove(&ri, &rv[0], sizeof(uint32_t)); |
125 | 0 | ostringstream rs; |
126 | 0 | rs << hex << setfill('0') << setw(8) << ri; |
127 | 0 | identifier_ = rs.str(); |
128 | 0 | } |
129 | | |
130 | | void |
131 | 0 | Exchange::logReplyMessages() const { |
132 | 0 | if (!received_) { |
133 | 0 | return; |
134 | 0 | } |
135 | 0 | const AttributesPtr& attrs = received_->getAttributes(); |
136 | 0 | if (!attrs || (attrs->count(PW_REPLY_MESSAGE) == 0)) { |
137 | 0 | return; |
138 | 0 | } |
139 | 0 | for (const ConstAttributePtr& attr : *attrs) { |
140 | 0 | if (!attr || (attr->getType() != PW_REPLY_MESSAGE)) { |
141 | 0 | continue; |
142 | 0 | } |
143 | 0 | LOG_INFO(radius_logger, RADIUS_REPLY_MESSAGE_ATTRIBUTE) |
144 | 0 | .arg(static_cast<int>(received_->getIdentifier())) |
145 | 0 | .arg(identifier_) |
146 | 0 | .arg(attr->toString()); |
147 | 0 | } |
148 | 0 | } |
149 | | |
150 | | void |
151 | 0 | Exchange::start() { |
152 | 0 | MultiThreadingLock lock(*mutex_); |
153 | |
|
154 | 0 | if (started_) { |
155 | 0 | return; |
156 | 0 | } else { |
157 | 0 | started_ = true; |
158 | 0 | } |
159 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_EXCHANGE_START) |
160 | 0 | .arg(identifier_); |
161 | |
|
162 | 0 | open(); |
163 | |
|
164 | 0 | if (sync_) { |
165 | | // Run() will return when syncHandler will be called. |
166 | 0 | io_service_->run(); |
167 | | |
168 | | // Done. |
169 | 0 | io_service_.reset(); |
170 | |
|
171 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_EXCHANGE_SYNC_RETURN) |
172 | 0 | .arg(identifier_) |
173 | 0 | .arg(rc_); |
174 | 0 | } |
175 | 0 | } |
176 | | |
177 | | void |
178 | 0 | Exchange::shutdown() { |
179 | | // Avoid multiple terminations. |
180 | 0 | MultiThreadingLock lock(*mutex_); |
181 | 0 | shutdownInternal(); |
182 | 0 | } |
183 | | |
184 | | void |
185 | 0 | Exchange::shutdownInternal() { |
186 | 0 | if (terminated_) { |
187 | 0 | return; |
188 | 0 | } else { |
189 | 0 | terminated_ = true; |
190 | 0 | } |
191 | | // Same as terminate but not calling callback. |
192 | 0 | cancelTimer(); |
193 | 0 | if (socket_) { |
194 | 0 | socket_->cancel(); |
195 | 0 | } |
196 | 0 | handler_ = Handler(); |
197 | |
|
198 | 0 | if (io_service_) { |
199 | 0 | if (sync_) { |
200 | 0 | io_service_->stopWork(); |
201 | 0 | } else { |
202 | 0 | io_service_.reset(); |
203 | 0 | } |
204 | 0 | } |
205 | 0 | } |
206 | | |
207 | | void |
208 | 0 | Exchange::buildRequest() { |
209 | 0 | if (!server_) { |
210 | 0 | isc_throw(Unexpected, "no server"); |
211 | 0 | } |
212 | | |
213 | | // Prepare message to send. |
214 | 0 | sent_.reset(new Message(*request_)); |
215 | | |
216 | | // Randomize the identifier. |
217 | 0 | sent_->randomIdentifier(); |
218 | | |
219 | | // Randomize or zero the authenticator. |
220 | 0 | if (sent_->getCode() == PW_ACCESS_REQUEST) { |
221 | 0 | sent_->randomAuth(); |
222 | 0 | } else { |
223 | 0 | sent_->zeroAuth(); |
224 | 0 | } |
225 | | |
226 | | // Set the secret. |
227 | 0 | sent_->setSecret(server_->getSecret()); |
228 | | |
229 | | // Get attributes. |
230 | 0 | AttributesPtr attrs = sent_->getAttributes(); |
231 | 0 | if (!attrs) { |
232 | 0 | attrs.reset(new Attributes()); |
233 | 0 | sent_->setAttributes(attrs); |
234 | 0 | } |
235 | | |
236 | | // Add Acct-Delay-Time to Accounting-Request message. |
237 | 0 | if ((sent_->getCode() == PW_ACCOUNTING_REQUEST) && |
238 | 0 | (attrs->count(PW_ACCT_DELAY_TIME) == 0)) { |
239 | 0 | auto delta = steady_clock().now() - start_time_; |
240 | 0 | seconds secs = duration_cast<seconds>(delta); |
241 | 0 | attrs->add(Attribute::fromInt(PW_ACCT_DELAY_TIME, |
242 | 0 | static_cast<uint32_t>(secs.count()))); |
243 | 0 | } |
244 | | |
245 | | // Add NAS-IP[v6]-Address with the local address. |
246 | 0 | IOAddress local_addr = server_->getLocalAddress(); |
247 | 0 | short family = local_addr.getFamily(); |
248 | 0 | if (family == AF_INET) { |
249 | 0 | if (attrs->count(PW_NAS_IP_ADDRESS) == 0) { |
250 | 0 | attrs->add(Attribute::fromIpAddr(PW_NAS_IP_ADDRESS, local_addr)); |
251 | 0 | } |
252 | 0 | } else if (family == AF_INET6) { |
253 | 0 | if (attrs->count(PW_NAS_IPV6_ADDRESS) == 0) { |
254 | 0 | attrs->add(Attribute::fromIpv6Addr(PW_NAS_IPV6_ADDRESS, |
255 | 0 | local_addr)); |
256 | 0 | } |
257 | 0 | } |
258 | | |
259 | | // Encode the request. |
260 | 0 | sent_->encode(); |
261 | 0 | } |
262 | | |
263 | | void |
264 | 0 | Exchange::open() { |
265 | 0 | if (RadiusImpl::shutdown_) { |
266 | 0 | shutdownInternal(); |
267 | 0 | return; |
268 | 0 | } |
269 | | |
270 | 0 | if (terminated_) { |
271 | 0 | return; |
272 | 0 | } |
273 | | // In order: |
274 | | // - no current server: open the next one. |
275 | | // - last try. |
276 | | // - next try. |
277 | | |
278 | 0 | if (!server_) { |
279 | | // No server: get the next server. |
280 | 0 | if (idx_ < servers_.size()) { |
281 | | // First pass. |
282 | 0 | server_ = servers_[idx_]; |
283 | | // Null pointer (should not happen). |
284 | 0 | if (!server_) { |
285 | 0 | isc_throw(Unexpected, "null server at " << idx_); |
286 | 0 | } |
287 | | // Server still in hold-down: postpone it. |
288 | 0 | if ((server_->getDeadtime() > 0) && |
289 | 0 | (server_->getDeadtimeEnd() > start_time_)) { |
290 | 0 | postponed_.push_back(idx_); |
291 | 0 | ++idx_; |
292 | 0 | io_service_->post(std::bind(&Exchange::openNext, |
293 | 0 | shared_from_this())); |
294 | 0 | return; |
295 | 0 | } |
296 | 0 | } else { |
297 | | // Second pass: try postponed servers. |
298 | 0 | if (postponed_.empty()) { |
299 | 0 | io_service_->post(std::bind(&Exchange::terminate, |
300 | 0 | shared_from_this())); |
301 | 0 | return; |
302 | 0 | } |
303 | 0 | size_t cur_idx = postponed_.front(); |
304 | | // Out-of-range (should not happen). |
305 | 0 | if (cur_idx >= servers_.size()) { |
306 | 0 | isc_throw(Unexpected, "out of range server " << cur_idx |
307 | 0 | << " >= " << servers_.size()); |
308 | 0 | } |
309 | 0 | server_ = servers_[cur_idx]; |
310 | | // Null pointer (should not happen). |
311 | 0 | if (!server_) { |
312 | 0 | isc_throw(Unexpected, "null server at " << cur_idx); |
313 | 0 | } |
314 | 0 | } |
315 | | |
316 | | // Have a new server. |
317 | 0 | try { |
318 | | // Reset error code. |
319 | 0 | rc_ = ERROR_RC; |
320 | | |
321 | | // Build to be send request message. |
322 | 0 | buildRequest(); |
323 | | |
324 | | // Set end-point. |
325 | 0 | ep_.reset(new UDPEndpoint(server_->getPeerAddress(), |
326 | 0 | server_->getPeerPort())); |
327 | | |
328 | | // Set socket. |
329 | 0 | if (socket_) { |
330 | 0 | socket_->close(); |
331 | 0 | } |
332 | 0 | socket_.reset(new RadiusSocket(io_service_)); |
333 | | |
334 | | // Launch timer. |
335 | 0 | setTimer(); |
336 | | |
337 | | // Open socket. |
338 | 0 | socket_->open(ep_.get(), SocketCallback()); |
339 | | |
340 | | // Should bind the socket but it is not (yet) in the API. |
341 | | // Anyway the kernel should choose the same address... |
342 | | |
343 | | // Better to use a connected socket... |
344 | | |
345 | | // Send request message. |
346 | 0 | buffer_ = sent_->getBuffer(); |
347 | 0 | size_ = buffer_.size(); |
348 | |
|
349 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, |
350 | 0 | RADIUS_EXCHANGE_SEND_NEW) |
351 | 0 | .arg(identifier_) |
352 | 0 | .arg(buffer_.size()) |
353 | 0 | .arg(idx_) |
354 | 0 | .arg(ep_->getAddress().toText()) |
355 | 0 | .arg(ep_->getPort()); |
356 | |
|
357 | 0 | socket_->asyncSend(&buffer_[0], buffer_.size(), ep_.get(), |
358 | 0 | std::bind(&Exchange::sentHandler, |
359 | 0 | shared_from_this(), |
360 | 0 | ph::_1, // error_code. |
361 | 0 | ph::_2)); // size. |
362 | 0 | return; |
363 | 0 | } catch (const Exception& exc) { |
364 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_OPEN_FAILED) |
365 | 0 | .arg(identifier_) |
366 | 0 | .arg(exc.what()); |
367 | 0 | cancelTimer(); |
368 | 0 | rc_ = ERROR_RC; |
369 | 0 | if (socket_) { |
370 | 0 | socket_->close(); |
371 | 0 | socket_.reset(); |
372 | 0 | } |
373 | 0 | io_service_->post(std::bind(&Exchange::openNext, |
374 | 0 | shared_from_this())); |
375 | 0 | return; |
376 | 0 | } |
377 | 0 | } |
378 | | |
379 | | // No other try? |
380 | 0 | if (retries_++ >= maxretries_) { |
381 | 0 | if ((rc_ == TIMEOUT_RC) && (idx_ < servers_.size())) { |
382 | | // On timeout hold-down the server. |
383 | 0 | unsigned deadtime = server_->getDeadtime(); |
384 | 0 | if (deadtime > 0) { |
385 | 0 | server_->setDeadtimeEnd(start_time_ + seconds(deadtime)); |
386 | 0 | } |
387 | 0 | } |
388 | 0 | retries_ = 0; |
389 | 0 | server_.reset(); |
390 | 0 | ep_.reset(); |
391 | | // Try postponed servers? |
392 | 0 | if (idx_ == servers_.size()) { |
393 | | // Postponed servers are exhausted. |
394 | 0 | if (postponed_.size() < 2) { |
395 | 0 | io_service_->post(std::bind(&Exchange::terminate, |
396 | 0 | shared_from_this())); |
397 | 0 | return; |
398 | 0 | } |
399 | | // Try next postponed server. |
400 | 0 | postponed_.pop_front(); |
401 | 0 | } else { |
402 | | // Try next server. |
403 | 0 | ++idx_; |
404 | 0 | if ((idx_ == servers_.size()) && (postponed_.empty())) { |
405 | 0 | io_service_->post(std::bind(&Exchange::terminate, |
406 | 0 | shared_from_this())); |
407 | 0 | return; |
408 | 0 | } |
409 | 0 | } |
410 | | // Call again open to try the next server. |
411 | 0 | io_service_->post(std::bind(&Exchange::openNext, |
412 | 0 | shared_from_this())); |
413 | 0 | return; |
414 | 0 | } |
415 | | |
416 | | // Next try. |
417 | 0 | try { |
418 | 0 | if (!ep_) { |
419 | 0 | isc_throw(Unexpected, "endpoint is null"); |
420 | 0 | } |
421 | | |
422 | | // Build to be send request message. |
423 | 0 | buildRequest(); |
424 | | |
425 | | // Set socket. |
426 | 0 | if (socket_) { |
427 | 0 | socket_->close(); |
428 | 0 | } |
429 | 0 | socket_.reset(new RadiusSocket(io_service_)); |
430 | | |
431 | | // Launch timer. |
432 | 0 | setTimer(); |
433 | | |
434 | | // Open socket. |
435 | 0 | socket_->open(ep_.get(), SocketCallback()); |
436 | | |
437 | | // Should bind the socket but it is not (yet) in the API. |
438 | | // Anyway the kernel should choose the same address... |
439 | | |
440 | | // Better to use a connected socket... |
441 | | |
442 | | // Send request message. |
443 | 0 | buffer_ = sent_->getBuffer(); |
444 | 0 | size_ = buffer_.size(); |
445 | |
|
446 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_EXCHANGE_SEND_RETRY) |
447 | 0 | .arg(identifier_) |
448 | 0 | .arg(buffer_.size()) |
449 | 0 | .arg(retries_); |
450 | |
|
451 | 0 | socket_->asyncSend(&buffer_[0], |
452 | 0 | buffer_.size(), |
453 | 0 | ep_.get(), |
454 | 0 | std::bind(&Exchange::sentHandler, |
455 | 0 | shared_from_this(), |
456 | 0 | ph::_1, // error_code. |
457 | 0 | ph::_2)); // size. |
458 | 0 | return; |
459 | 0 | } catch (const Exception& exc) { |
460 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_OPEN_FAILED) |
461 | 0 | .arg(identifier_) |
462 | 0 | .arg(exc.what()); |
463 | 0 | cancelTimer(); |
464 | 0 | rc_ = ERROR_RC; |
465 | 0 | if (socket_) { |
466 | 0 | socket_->close(); |
467 | 0 | socket_.reset(); |
468 | 0 | } |
469 | 0 | io_service_->post(std::bind(&Exchange::openNext, |
470 | 0 | shared_from_this())); |
471 | 0 | return; |
472 | 0 | } |
473 | 0 | } |
474 | | |
475 | | void |
476 | | Exchange::sentHandler(ExchangePtr ex, |
477 | | const boost::system::error_code ec, |
478 | 0 | const size_t size) { |
479 | 0 | if (!ex) { |
480 | 0 | isc_throw(Unexpected, "null exchange in sentHandler"); |
481 | 0 | } |
482 | | |
483 | 0 | if (RadiusImpl::shutdown_) { |
484 | 0 | ex->shutdown(); |
485 | 0 | return; |
486 | 0 | } |
487 | | |
488 | 0 | MultiThreadingLock lock(*ex->mutex_); |
489 | |
|
490 | 0 | if (ex->terminated_) { |
491 | 0 | return; |
492 | 0 | } |
493 | | |
494 | | // Check error code. |
495 | 0 | if (ec) { |
496 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_SEND_FAILED) |
497 | 0 | .arg(ex->identifier_) |
498 | 0 | .arg(ec.message()); |
499 | 0 | ex->cancelTimer(); |
500 | 0 | if (ex->socket_) { |
501 | 0 | ex->socket_->close(); |
502 | 0 | ex->socket_.reset(); |
503 | 0 | } |
504 | 0 | ex->io_service_->post(std::bind(&Exchange::openNext, ex)); |
505 | 0 | return; |
506 | 0 | } |
507 | | |
508 | | // No error: receive response. |
509 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_EXCHANGE_SENT) |
510 | 0 | .arg(ex->identifier_) |
511 | 0 | .arg(size); |
512 | 0 | ex->buffer_.clear(); |
513 | 0 | ex->buffer_.resize(BUF_LEN); |
514 | 0 | ex->size_ = ex->buffer_.size(); |
515 | 0 | ex->socket_->asyncReceive(&(ex->buffer_)[0], ex->size_, 0, ex->ep_.get(), |
516 | 0 | std::bind(&Exchange::receivedHandler, ex, |
517 | 0 | ph::_1, // error_code. |
518 | 0 | ph::_2)); // size. |
519 | 0 | } |
520 | | |
521 | | void |
522 | | Exchange::receivedHandler(ExchangePtr ex, |
523 | | const boost::system::error_code ec, |
524 | 0 | const size_t size) { |
525 | 0 | if (!ex) { |
526 | 0 | isc_throw(Unexpected, "null exchange in receivedHandler"); |
527 | 0 | } |
528 | | |
529 | 0 | if (RadiusImpl::shutdown_) { |
530 | 0 | ex->shutdown(); |
531 | 0 | return; |
532 | 0 | } |
533 | | |
534 | 0 | MultiThreadingLock lock(*ex->mutex_); |
535 | | |
536 | | // This was the action on the socket. |
537 | 0 | ex->cancelTimer(); |
538 | 0 | if (ex->socket_) { |
539 | 0 | ex->socket_->close(); |
540 | 0 | ex->socket_.reset(); |
541 | 0 | } |
542 | |
|
543 | 0 | if (ex->terminated_) { |
544 | 0 | return; |
545 | 0 | } |
546 | | |
547 | | // Check error code. |
548 | 0 | if (ec) { |
549 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_RECEIVE_FAILED) |
550 | 0 | .arg(ex->identifier_) |
551 | 0 | .arg(ec.message()); |
552 | 0 | ex->io_service_->post(std::bind(&Exchange::openNext, ex)); |
553 | 0 | return; |
554 | 0 | } |
555 | | |
556 | | // Remove the server from hold-down. |
557 | 0 | if (ex->server_ && |
558 | 0 | (ex->server_->getDeadtime() > 0) && |
559 | 0 | (ex->server_->getDeadtimeEnd() > ex->start_time_)) { |
560 | 0 | ex->server_->setDeadtimeEnd(ex->start_time_); |
561 | 0 | } |
562 | | |
563 | | // Create message. |
564 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_EXCHANGE_RECEIVED) |
565 | 0 | .arg(ex->identifier_) |
566 | 0 | .arg(size); |
567 | 0 | ex->buffer_.resize(size); |
568 | 0 | ex->received_.reset(new Message(ex->buffer_, ex->sent_->getAuth(), |
569 | 0 | ex->server_->getSecret())); |
570 | | |
571 | | // Decode message. |
572 | 0 | ex->rc_ = OK_RC; |
573 | 0 | try { |
574 | | // In order: |
575 | | // - decode message. |
576 | | // - verify that identifiers match. |
577 | | // - verify that message codes match. |
578 | 0 | ex->received_->decode(); |
579 | 0 | unsigned got = ex->received_->getIdentifier(); |
580 | 0 | unsigned expected = ex->sent_->getIdentifier(); |
581 | 0 | if (got != expected) { |
582 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_RECEIVED_MISMATCH) |
583 | 0 | .arg(ex->identifier_) |
584 | 0 | .arg(got) |
585 | 0 | .arg(expected); |
586 | 0 | ex->rc_ = BADRESP_RC; |
587 | 0 | } else if (ex->request_->getCode() == PW_ACCESS_REQUEST) { |
588 | 0 | if (ex->received_->getCode() == PW_ACCESS_REJECT) { |
589 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, |
590 | 0 | RADIUS_EXCHANGE_RECEIVED_ACCESS_REJECT) |
591 | 0 | .arg(ex->identifier_); |
592 | 0 | ex->rc_ = REJECT_RC; |
593 | 0 | } else if (ex->received_->getCode() != PW_ACCESS_ACCEPT) { |
594 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_RECEIVED_UNEXPECTED) |
595 | 0 | .arg(ex->identifier_) |
596 | 0 | .arg(msgCodeToText(ex->request_->getCode())) |
597 | 0 | .arg(msgCodeToText(ex->received_->getCode())); |
598 | 0 | ex->rc_ = BADRESP_RC; |
599 | 0 | } else { |
600 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, |
601 | 0 | RADIUS_EXCHANGE_RECEIVED_ACCESS_ACCEPT) |
602 | 0 | .arg(ex->identifier_); |
603 | 0 | } |
604 | 0 | } else if (ex->request_->getCode() == PW_ACCOUNTING_REQUEST) { |
605 | 0 | if (ex->received_->getCode() != PW_ACCOUNTING_RESPONSE) { |
606 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_RECEIVED_UNEXPECTED) |
607 | 0 | .arg(ex->identifier_) |
608 | 0 | .arg(msgCodeToText(ex->request_->getCode())) |
609 | 0 | .arg(msgCodeToText(ex->received_->getCode())); |
610 | 0 | ex->rc_ = BADRESP_RC; |
611 | 0 | } else { |
612 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, |
613 | 0 | RADIUS_EXCHANGE_RECEIVED_ACCOUNTING_RESPONSE) |
614 | 0 | .arg(ex->identifier_); |
615 | 0 | } |
616 | 0 | } |
617 | 0 | } catch (const Exception& exc) { |
618 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_RECEIVED_BAD_RESPONSE) |
619 | 0 | .arg(ex->identifier_) |
620 | 0 | .arg(exc.what()); |
621 | 0 | ex->rc_ = BADRESP_RC; |
622 | 0 | } |
623 | |
|
624 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, |
625 | 0 | RADIUS_EXCHANGE_RECEIVED_RESPONSE) |
626 | 0 | .arg(ex->identifier_) |
627 | 0 | .arg(exchangeRCtoText(ex->rc_)); |
628 | | |
629 | | // If bad then retry, if not including reject it is done. |
630 | 0 | if ((ex->rc_ != OK_RC) && ( ex->rc_ != REJECT_RC)) { |
631 | 0 | ex->io_service_->post(std::bind(&Exchange::openNext, ex)); |
632 | 0 | } else { |
633 | 0 | ex->logReplyMessages(); |
634 | 0 | ex->io_service_->post(std::bind(&Exchange::terminate, ex)); |
635 | 0 | } |
636 | 0 | } |
637 | | |
638 | | void |
639 | 0 | Exchange::terminate() { |
640 | | // Avoid multiple terminations. |
641 | 0 | MultiThreadingLock lock(*mutex_); |
642 | |
|
643 | 0 | if (terminated_) { |
644 | 0 | return; |
645 | 0 | } else { |
646 | 0 | terminated_ = true; |
647 | 0 | } |
648 | | |
649 | | // Should have been done before. |
650 | 0 | cancelTimer(); |
651 | 0 | if (socket_) { |
652 | 0 | socket_->close(); |
653 | 0 | socket_.reset(); |
654 | 0 | } |
655 | |
|
656 | 0 | if ((rc_ != OK_RC) && (rc_ != REJECT_RC)) { |
657 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_FAILED) |
658 | 0 | .arg(identifier_) |
659 | 0 | .arg(exchangeRCtoText(rc_)); |
660 | 0 | } else { |
661 | 0 | LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_EXCHANGE_TERMINATE) |
662 | 0 | .arg(identifier_) |
663 | 0 | .arg(exchangeRCtoText(rc_)); |
664 | 0 | } |
665 | |
|
666 | 0 | if (io_service_) { |
667 | 0 | if (sync_) { |
668 | 0 | io_service_->stopWork(); |
669 | 0 | } else { |
670 | 0 | io_service_.reset(); |
671 | 0 | } |
672 | 0 | } |
673 | | |
674 | | // Call handler. |
675 | 0 | if (handler_) { |
676 | 0 | auto handler = handler_; |
677 | | // Avoid to keep a circular reference. |
678 | 0 | handler_ = Handler(); |
679 | 0 | if (MultiThreadingMgr::instance().getMode()) { |
680 | 0 | UnlockGuard<std::mutex> unlock(*mutex_); |
681 | 0 | handler(shared_from_this()); |
682 | 0 | } else { |
683 | 0 | handler(shared_from_this()); |
684 | 0 | } |
685 | 0 | } |
686 | 0 | } |
687 | | |
688 | | void |
689 | 0 | Exchange::setTimer() { |
690 | 0 | cancelTimer(); |
691 | 0 | timer_.reset(new IntervalTimer(io_service_)); |
692 | 0 | timer_->setup(std::bind(&Exchange::timeoutHandler, shared_from_this()), |
693 | 0 | server_->getTimeout() * 1000, IntervalTimer::ONE_SHOT); |
694 | 0 | } |
695 | | |
696 | | void |
697 | 0 | Exchange::cancelTimer() { |
698 | 0 | if (timer_) { |
699 | 0 | timer_->cancel(); |
700 | 0 | timer_.reset(); |
701 | 0 | } |
702 | 0 | } |
703 | | |
704 | | void |
705 | 0 | Exchange::timeoutHandler(ExchangePtr ex) { |
706 | 0 | MultiThreadingLock lock(*ex->mutex_); |
707 | 0 | LOG_ERROR(radius_logger, RADIUS_EXCHANGE_TIMEOUT) |
708 | 0 | .arg(ex->identifier_); |
709 | 0 | ex->rc_ = TIMEOUT_RC; |
710 | 0 | ex->cancelTimer(); |
711 | 0 | if (ex->socket_) { |
712 | 0 | ex->socket_->cancel(); |
713 | 0 | } |
714 | 0 | } |
715 | | |
716 | | } // end of namespace isc::radius |
717 | | } // end of namespace isc |