extern pid_t radius_pid;
extern int dont_fork;
extern int check_config;
-extern void force_log_reopen(void);
extern char *debug_condition;
/*
static int proxy_fds[32];
static rad_listen_t *proxy_listeners[32];
static void check_for_zombie_home_server(REQUEST *request);
+static void remove_from_proxy_hash(REQUEST *request);
#else
#define remove_from_proxy_hash(foo)
#endif
}
+static void ev_request_free(REQUEST **prequest)
+{
+ REQUEST *request;
+
+ if (!prequest || !*prequest) return;
+
+ request = *prequest;
+
+#ifdef WITH_COA
+ if (request->coa) {
+ /*
+ * Divorce the child from the parent first,
+ * then clean up the child.
+ */
+ request->coa->parent = NULL;
+ ev_request_free(&request->coa);
+ }
+
+ /*
+ * Divorce the parent from the child, and leave the
+ * parent still alive.
+ */
+ if (request->parent && (request->parent->coa == request)) {
+ request->parent->coa = NULL;
+ }
+#endif
+
+ if (request->ev) fr_event_delete(el, &request->ev);
+#ifdef WITH_PROXY
+ if (request->in_proxy_hash) remove_from_proxy_hash(request);
+#endif
+ if (request->in_request_hash) remove_from_request_hash(request);
+
+ request_free(prequest);
+}
+
#ifdef WITH_PROXY
static REQUEST *lookup_in_proxy_hash(RADIUS_PACKET *reply)
{
PTHREAD_MUTEX_UNLOCK(&proxy_mutex);
}
-static void ev_request_free(REQUEST **prequest)
+static int proxy_add_fds(rad_listen_t *proxy_listener)
{
- REQUEST *request;
-
- if (!prequest || !*prequest) return;
-
- request = *prequest;
+ int i, proxy, found = -1;
-#ifdef WITH_COA
- if (request->coa) {
+ proxy = proxy_listener->fd;
+ for (i = 0; i < 32; i++) {
/*
- * Divorce the child from the parent first,
- * then clean up the child.
+ * Found a free entry. Save the socket,
+ * and remember where we saved it.
*/
- request->coa->parent = NULL;
- ev_request_free(&request->coa);
- }
-
- /*
- * Divorce the parent from the child, and leave the
- * parent still alive.
- */
- if (request->parent && (request->parent->coa == request)) {
- request->parent->coa = NULL;
+ if (proxy_fds[(proxy + i) & 0x1f] == -1) {
+ found = (proxy + i) & 0x1f;
+ proxy_fds[found] = proxy;
+ proxy_listeners[found] = proxy_listener;
+ break;
+ }
}
-#endif
-
- if (request->ev) fr_event_delete(el, &request->ev);
- if (request->in_proxy_hash) remove_from_proxy_hash(request);
- if (request->in_request_hash) remove_from_request_hash(request);
- request_free(prequest);
+ return found;
}
static int proxy_id_alloc(REQUEST *request, RADIUS_PACKET *packet)
{
- int i, proxy, found;
rad_listen_t *proxy_listener;
if (fr_packet_list_id_alloc(proxy_list, packet)) return 1;
/*
* Cache it locally.
*/
- found = -1;
- proxy = proxy_listener->fd;
- for (i = 0; i < 32; i++) {
- /*
- * Found a free entry. Save the socket,
- * and remember where we saved it.
- */
- if (proxy_fds[(proxy + i) & 0x1f] == -1) {
- found = (proxy + i) & 0x1f;
- proxy_fds[found] = proxy;
- proxy_listeners[found] = proxy_listener;
- break;
- }
- }
- if (found < 0) {
+ if (proxy_add_fds(proxy_listener) < 0) {
proxy_all_used = TRUE;
listen_free(&proxy_listener);
radlog(L_ERR, "Failed creating new proxy socket: server is too busy and home servers appear to be down");
if (!fr_packet_list_insert(proxy_list, &request->proxy)) {
fr_packet_list_id_free(proxy_list, request->proxy);
PTHREAD_MUTEX_UNLOCK(&proxy_mutex);
- RDEBUG2("ERROR: Failed to insert entry into proxy list");
+ RDEBUG2("ERROR: Failed to insert entry into proxy list.");
return 0;
}
if ((request->num_proxied_requests == request->num_proxied_responses) ||
timercmp(&now, &request->when, >)) {
if (request->packet) {
- RDEBUG2("Cleaning up request %d ID %d with timestamp +%d",
+ RDEBUG2("Cleaning up request %u ID %d with timestamp +%d",
request->number, request->packet->id,
(unsigned int) (request->timestamp - fr_start_time));
} else {
- RDEBUG2("Cleaning up request %d with timestamp +%d",
+ RDEBUG2("Cleaning up request %u with timestamp +%d",
request->number,
(unsigned int) (request->timestamp - fr_start_time));
}
REQUEST *request = ctx;
rad_assert(request->magic == REQUEST_MAGIC);
+ remove_from_request_hash(request);
/*
* If it's still queued (waiting for a thread to pick it
(pthread_equal(request->child_pid, NO_SUCH_CHILD_PID) == 0))) {
/*
- * Cap delay at five minutes.
+ * Cap delay at max_request_time
*/
- if (request->delay < (USEC * 60 * 5)) {
+ if (request->delay < (USEC * request->root->max_request_time)) {
request->delay += (request->delay >> 1);
- radlog(L_INFO, "WARNING: Child is hung for request %d.",
- request->number);
+ radlog(L_INFO, "WARNING: Child is hung for request %u in component %s module %s.",
+ request->number, request->component, request->module);
} else {
- RDEBUG2("Child is still stuck for request %d",
+ request->delay = USEC * request->root->max_request_time;
+ RDEBUG2("WARNING: Child is hung after \"max_request_time\" for request %u",
request->number);
}
tv_add(&request->when, request->delay);
return;
}
- RDEBUG2("Child is finally responsive for request %d", request->number);
- remove_from_request_hash(request);
+ RDEBUG2("Child is finally responsive for request %u", request->number);
#ifdef WITH_PROXY
if (request->proxy) {
}
#endif
- RDEBUG2("Cleaning up request %d ID %d with timestamp +%d",
+ RDEBUG2("Cleaning up request %u ID %d with timestamp +%d",
request->number, request->packet->id,
(unsigned int) (request->timestamp - fr_start_time));
rad_assert(request->magic == REQUEST_MAGIC);
rad_assert(request->child_state == REQUEST_REJECT_DELAY);
- RDEBUG2("Sending delayed reject for request %d", request->number);
+ RDEBUG2("Sending delayed reject for request %u", request->number);
DEBUG_PACKET(request, request->reply, 1);
rad_assert(request->proxy_listener == NULL);
if (!insert_into_proxy_hash(request, FALSE)) {
- RDEBUG2("ERROR: Failed inserting status check %d into proxy hash. Discarding it.",
+ RDEBUG2("ERROR: Failed to insert status check %d into proxy list. Discarding it.",
request->number);
ev_request_free(&request);
return;
* well.
*/
if (home->no_response_fail) {
- radlog(L_ERR, "Rejecting request %d (proxy Id %d) due to lack of any response from home server %s port %d",
+ radlog(L_ERR, "Rejecting request %u (proxy Id %d) due to lack of any response from home server %s port %d",
request->number, request->proxy->id,
inet_ntop(request->proxy->dst_ipaddr.af,
&request->proxy->dst_ipaddr.ipaddr,
/*
* Don't touch request due to race conditions
*/
- if (home->state == HOME_STATE_IS_DEAD) {
- rad_assert(home->ev != NULL); /* or it will never wake up */
- return;
- }
/*
- * Enable the zombie period when we notice that the home
- * server hasn't responded. We do NOT back-date the start
- * of the zombie period.
+ * If it's not alive, don't try to make it a zombie.
*/
- if (home->state == HOME_STATE_ALIVE) {
- home->state = HOME_STATE_ZOMBIE;
- home->zombie_period_start = now;
-
- radlog(L_PROXY, "Marking home server %s port %d as zombie (it looks like it is dead).",
- inet_ntop(home->ipaddr.af, &home->ipaddr.ipaddr,
- buffer, sizeof(buffer)),
- home->port);
-
+ if (home->state != HOME_STATE_ALIVE) {
/*
- * Start pinging the home server.
+ * Don't check home->ev due to race conditions.
*/
- ping_home_server(home);
+ return;
+ }
+
+ /*
+ * We've received a real packet recently. Don't mark the
+ * server as zombie until we've received NO packets for a
+ * while. The "1/4" of zombie period was chosen rather
+ * arbitrarily. It's a balance between too short, which
+ * gives quick fail-over and fail-back, or too long,
+ * where the proxy still sends packets to an unresponsive
+ * home server.
+ */
+ if ((home->last_packet + ((home->zombie_period + 3) / 4)) >= now.tv_sec) {
+ return;
}
+
+ /*
+ * Enable the zombie period when we notice that the home
+ * server hasn't responded for a while. We back-date the
+ * zombie period to when we last received a response from
+ * the home server.
+ */
+ home->state = HOME_STATE_ZOMBIE;
+
+ home->zombie_period_start.tv_sec = home->last_packet;
+ home->zombie_period_start.tv_sec = USEC / 2;
+
+ fr_event_delete(el, &home->ev);
+ home->currently_outstanding = 0;
+ home->num_received_pings = 0;
+
+ radlog(L_PROXY, "Marking home server %s port %d as zombie (it looks like it is dead).",
+ inet_ntop(home->ipaddr.af, &home->ipaddr.ipaddr,
+ buffer, sizeof(buffer)),
+ home->port);
+
+ /*
+ * Start pinging the home server.
+ */
+ ping_home_server(home);
}
#endif
switch (request->child_state) {
case REQUEST_QUEUED:
case REQUEST_RUNNING:
+ /*
+ * If we're not thread-capable, OR we're capable,
+ * but have been told to run without threads,
+ * complain when the requests is queued for a
+ * thread, or running in a child thread.
+ */
+#ifdef HAVE_PTHREAD_H
+ if (!have_children)
+#endif
+ {
+ rad_assert("We do not have threads, but the request is marked as queued or running in a child thread" == NULL);
+ break;
+ }
+
+#ifdef HAVE_PTHREAD_H
+ /*
+ * If we have threads, wait for the child thread
+ * to stop.
+ */
when = request->received;
when.tv_sec += request->root->max_request_time;
* Request still has more time. Continue
* waiting.
*/
- if (timercmp(&now, &when, <) ||
- ((request->listener->type == RAD_LISTEN_DETAIL) &&
- (request->child_state == REQUEST_QUEUED))) {
+ if (timercmp(&now, &when, <)) {
if (request->delay < (USEC / 10)) {
request->delay = USEC / 10;
}
request->delay += request->delay >> 1;
-#ifdef WITH_DETAIL
/*
- * Cap wait at some sane value for detail
- * files.
+ * Cap delays at something reasonable.
*/
- if ((request->listener->type == RAD_LISTEN_DETAIL) &&
- (request->delay > (request->root->max_request_time * USEC))) {
+ if (request->delay > (request->root->max_request_time * USEC)) {
request->delay = request->root->max_request_time * USEC;
}
-#endif
request->when = now;
tv_add(&request->when, request->delay);
break;
}
- stop_processing:
-#if defined(HAVE_PTHREAD_H) || defined(WITH_PROXY)
+ request->master_state = REQUEST_STOP_PROCESSING;
+
/*
* A child thread MAY still be running on the
* request. Ask the thread to stop working on
*/
if (have_children &&
(pthread_equal(request->child_pid, NO_SUCH_CHILD_PID) == 0)) {
- request->master_state = REQUEST_STOP_PROCESSING;
-
- radlog(L_ERR, "WARNING: Unresponsive child for request %d, in module %s component %s",
+ radlog(L_ERR, "WARNING: Unresponsive child for request %u, in component %s module %s",
request->number,
- request->module ? request->module : "<server core>",
- request->component ? request->component : "<server core>");
-
- request->delay = USEC / 4;
- tv_add(&request->when, request->delay);
- callback = wait_for_child_to_die;
- break;
+ request->component ? request->component : "<server core>",
+ request->module ? request->module : "<server core>");
+
}
+
+ request->delay = USEC;
+ tv_add(&request->when, request->delay);
+ callback = wait_for_child_to_die;
+ break;
#endif
/*
- * Else no child thread is processing the
- * request. We probably should have just marked
- * the request as 'done' elsewhere, like in the
- * post-proxy-fail handler. But doing that would
- * involve checking for max_request_time in
- * multiple places, so this may be simplest.
- */
- request->child_state = REQUEST_DONE;
- /* FALL-THROUGH */
-
- /*
* Mark the request as no longer running,
* and clean it up.
*/
request->child_pid = NO_SUCH_CHILD_PID;
#endif
-#ifdef WTH_COA
+#ifdef WITH_COA
/*
* This is a CoA request. It's been divorced
* from everything else, so we clean it up now.
* mode, with no threads...
*/
if (!callback) {
- RDEBUG("WARNING: Internal sanity check failed in event handler for request %d: Discarding the request!", request->number);
+ RDEBUG("WARNING: Internal sanity check failed in event handler for request %u: Discarding the request!", request->number);
ev_request_free(&request);
return;
}
if (update_event_timestamp(request->proxy, now.tv_sec)) {
if (!insert_into_proxy_hash(request, TRUE)) {
- DEBUG("ERROR: Failed re-inserting CoA request into proxy hash.");
+ DEBUG("ERROR: Failed to insert retransmission of CoA request into proxy list.");
return;
}
coa->proxy->dst_port = coa->home_server->port;
if (!insert_into_proxy_hash(coa, FALSE)) {
- DEBUG("ERROR: Failed inserting CoA request into proxy hash.");
+ DEBUG("ERROR: Failed to insert CoA request into proxy list.");
goto fail;
}
*/
request->num_proxied_requests = 1;
request->num_proxied_responses = 0;
+#ifdef HAVE_PTHREAD_H
request->child_pid = NO_SUCH_CHILD_PID;
+#endif
update_event_timestamp(request->proxy, request->proxy_when.tv_sec);
#ifdef WITH_PROXY
if (request->proxy) {
return process_proxy_reply(request);
-#endif
}
+#endif
return 1;
}
struct timeval when;
char buffer[128];
+#ifdef WITH_COA
+ if (request->coa) {
+ RDEBUG("WARNING: Cannot proxy and originate CoA packets at the same time. Cancelling CoA request");
+ ev_request_free(&request->coa);
+ }
+#endif
+
if (request->home_server->server) {
- RDEBUG("ERROR: Cannot perform real proxying to a virtual server.");
+ RDEBUG("ERROR: Cannot proxy to a virtual server.");
return 0;
}
if (!insert_into_proxy_hash(request, FALSE)) {
- RDEBUG("ERROR: Failed inserting request into proxy hash.");
+ RDEBUG("ERROR: Failed to insert entry into proxy list.");
return 0;
}
}
request->next_callback = no_response_to_proxied_request;
- RDEBUG2("Proxying request %d to home server %s port %d",
+ RDEBUG2("Proxying request %u to home server %s port %d",
request->number,
inet_ntop(request->proxy->dst_ipaddr.af,
&request->proxy->dst_ipaddr.ipaddr,
}
if (!proxy_request(request)) {
- RDEBUG("ERROR: Failed to proxy request %d", request->number);
+ RDEBUG("ERROR: Failed to proxy request %u", request->number);
return -1;
}
if ((request->master_state == REQUEST_STOP_PROCESSING) ||
(request->parent &&
(request->parent->master_state == REQUEST_STOP_PROCESSING))) {
- RDEBUG2("Request %d was cancelled.", request->number);
+ RDEBUG2("request %u was cancelled.", request->number);
#ifdef HAVE_PTHREAD_H
request->child_pid = NO_SUCH_CHILD_PID;
#endif
* OR we proxied it internally to a virutal server.
*/
}
+
+#ifdef WITH_COA
+ else if (request->proxy && request->coa) {
+ RDEBUG("WARNING: Cannot proxy and originate CoA packets at the same time. Cancelling CoA request");
+ ev_request_free(&request->coa);
+ }
+#endif
#endif
/*
vp = pairfind(request->config_items,
PW_RESPONSE_PACKET_TYPE);
if (!vp) {
- RDEBUG2("There was no response configured: rejecting request %d",
+ RDEBUG2("There was no response configured: rejecting request %u",
request->number);
request->reply->code = PW_AUTHENTICATION_REJECT;
} else if (vp->vp_integer == 256) {
- RDEBUG2("Not responding to request %d",
+ RDEBUG2("Not responding to request %u",
request->number);
/*
when.tv_sec += request->root->reject_delay;
if (timercmp(&when, &request->next_when, >)) {
- RDEBUG2("Delaying reject of request %d for %d seconds",
+ RDEBUG2("Delaying reject of request %u for %d seconds",
request->number,
request->root->reject_delay);
request->next_when = when;
#ifdef WITH_COA
/*
* Now that we've completely processed the request,
- * see if we need to originate a CoA request.
- */
- if (request->coa ||
- (pairfind(request->config_items, PW_SEND_COA_REQUEST) != NULL)) {
+ * see if we need to originate a CoA request. But ONLY
+ * if it wasn't proxied.
+ */
+ if (!request->proxy &&
+ (request->packet->code != PW_COA_REQUEST) &&
+ (request->packet->code != PW_DISCONNECT_REQUEST) &&
+ (request->coa ||
+ (pairfind(request->config_items, PW_SEND_COA_REQUEST) != NULL))) {
if (!originated_coa_request(request)) {
RDEBUG2("Do CoA Fail handler here");
}
}
#endif
- RDEBUG2("Finished request %d.", request->number);
+ RDEBUG2("Finished request %u.", request->number);
rad_assert(child_state >= 0);
request->child_state = child_state;
discard:
#endif
radlog(L_ERR, "Discarding duplicate request from "
- "client %s port %d - ID: %d due to unfinished request %d",
+ "client %s port %d - ID: %d due to unfinished request %u",
client->shortname,
request->packet->src_port,request->packet->id,
request->number);
home = home_server_ldb(NULL, request->home_pool, request);
if (!home) {
- RDEBUG2("Failed to find live home server for request %d", request->number);
+ RDEBUG2("ERROR: Failed to find live home server for request %u", request->number);
no_home_servers:
/*
* Do post-request processing,
* Try to proxy the request.
*/
if (!proxy_request(request)) {
- RDEBUG("ERROR: Failed to re-proxy request %d", request->number);
+ RDEBUG("ERROR: Failed to re-proxy request %u", request->number);
goto no_home_servers;
}
const RADCLIENT *client)
{
radlog(L_ERR, "Received conflicting packet from "
- "client %s port %d - ID: %d due to unfinished request %d. Giving up on old request.",
+ "client %s port %d - ID: %d due to unfinished request %u. Giving up on old request.",
client->shortname,
request->packet->src_port, request->packet->id,
request->number);
*/
if ((request->reply->code != 0) &&
request->reply->data) {
- radlog(L_INFO, "WARNING: Allowing fast client %s port %d - ID: %d for recent request %d.",
+ radlog(L_INFO, "WARNING: Allowing fast client %s port %d - ID: %d for recent request %u.",
client->shortname,
packet->src_port, packet->id,
request->number);
*/
if (timercmp(&when, &request->received, <)) {
radlog(L_ERR, "Discarding conflicting packet from "
- "client %s port %d - ID: %d due to recent request %d.",
+ "client %s port %d - ID: %d due to recent request %u.",
client->shortname,
packet->src_port, packet->id,
request->number);
* Remember the request in the list.
*/
if (!fr_packet_list_insert(pl, &request->packet)) {
- radlog(L_ERR, "Failed to insert request %d in the list of live requests: discarding", request->number);
+ radlog(L_ERR, "Failed to insert request %u in the list of live requests: discarding", request->number);
ev_request_free(&request);
return 0;
}
if (memcmp(request->proxy_reply->vector,
packet->vector,
sizeof(request->proxy_reply->vector)) == 0) {
- RDEBUG2("Discarding duplicate reply from host %s port %d - ID: %d for request %d",
+ RDEBUG2("Discarding duplicate reply from host %s port %d - ID: %d for request %u",
inet_ntop(packet->src_ipaddr.af,
&packet->src_ipaddr.ipaddr,
buffer, sizeof(buffer)),
gettimeofday(&now, NULL);
/*
+ * "ping" packets have a different algorithm for marking
+ * a home server alive. They also skip all of the CoA,
+ * etc. checks.
+ */
+ if (!request->packet) {
+ request->proxy_reply = packet;
+ received_response_to_ping(request);
+ request->proxy_reply = NULL; /* caller will free it */
+ ev_request_free(&request);
+ return NULL;
+ }
+
+ /*
* Maybe move this earlier in the decision process?
* Having it here means that late or duplicate proxy
* replies no longer get the home server marked as
* receive a packet? Setting this here means that we
* mark it alive on *any* packet, even if it's lost all
* of the *other* packets in the last 10s.
+ *
+ * This behavior could be configurable.
*/
- if (request->proxy->code != PW_STATUS_SERVER) {
- request->home_server->state = HOME_STATE_ALIVE;
- }
+ request->home_server->state = HOME_STATE_ALIVE;
+ request->home_server->last_packet = now.tv_sec;
#ifdef WITH_COA
/*
request->parent->coa = NULL;
request->parent = NULL;
+ /*
+ * The proxied packet was different from the
+ * original packet, AND the proxied packet was
+ * a CoA: allow it.
+ */
+ } else if ((request->packet->code != request->proxy->code) &&
+ ((request->proxy->code == PW_COA_REQUEST) ||
+ (request->proxy->code == PW_DISCONNECT_REQUEST))) {
+ /*
+ * It's already divorced: do nothing.
+ */
+
} else
/*
* Skip the next set of checks, as the original
RDEBUG2("Ignoring proxy reply that arrived after we sent a reply to the NAS");
return NULL;
}
-
+
#ifdef WITH_STATS
/*
* The average includes our time to receive packets and
case REQUEST_REJECT_DELAY:
case REQUEST_CLEANUP_DELAY:
case REQUEST_DONE:
- radlog(L_ERR, "Reply from home server %s port %d - ID: %d arrived too late for request %d. Try increasing 'retry_delay' or 'max_request_time'",
+ radlog(L_ERR, "Reply from home server %s port %d - ID: %d arrived too late for request %u. Try increasing 'retry_delay' or 'max_request_time'",
inet_ntop(packet->src_ipaddr.af,
&packet->src_ipaddr.ipaddr,
buffer, sizeof(buffer)),
}
#endif
- /*
- * There's no incoming request, so it's a proxied packet
- * we originated.
- */
- if (!request->packet) {
- received_response_to_ping(request);
- request->proxy_reply = NULL; /* caller will free it */
- ev_request_free(&request);
- return NULL;
- }
-
request->child_state = REQUEST_QUEUED;
request->when = now;
request->delay = USEC;
time_t when;
static time_t last_hup = 0;
- radlog(L_INFO, "Received HUP signal.");
-
when = time(NULL);
if ((int) (when - last_hup) < 5) {
radlog(L_INFO, "Ignoring HUP (less than 5s since last one)");
return;
}
+
+ radlog(L_INFO, "Received HUP signal.");
+
last_hup = when;
fr_event_loop_exit(el, 0x80);
}
#endif
- /*
- * Just before we spawn the child threads, force the log
- * subsystem to re-open the log file for every write.
- */
- if (spawn_flag) force_log_reopen();
-
#ifdef HAVE_PTHREAD_H
#ifndef __MINGW32__
NO_SUCH_CHILD_PID = (pthread_t ) (0);
if (check_config) {
DEBUG("%s: #### Skipping IP addresses and Ports ####",
mainconfig.name);
+ if (listen_init(cs, &head) < 0) {
+ fflush(NULL);
+ exit(1);
+ }
return 1;
}
#ifdef WITH_PROXY
case RAD_LISTEN_PROXY:
- rad_assert(proxy_fds[this->fd & 0x1f] == -1);
- rad_assert(proxy_listeners[this->fd & 0x1f] == NULL);
-
- proxy_fds[this->fd & 0x1f] = this->fd;
- proxy_listeners[this->fd & 0x1f] = this;
+ if (proxy_add_fds(this) < 0) {
+ radlog(L_ERR, "Failed creating new proxy socket");
+ return 0;
+ }
+
if (!fr_packet_list_socket_add(proxy_list,
this->fd)) {
rad_assert(0 == 1);