Make error messages more consistent
[freeradius.git] / src / main / event.c
index 4973d9a..b4ffbd5 100644 (file)
@@ -101,6 +101,7 @@ static int          proxy_all_used = FALSE;
 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
@@ -147,6 +148,42 @@ static void remove_from_request_hash(REQUEST *request)
 }
 
 
+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)
 {
@@ -242,40 +279,6 @@ static void remove_from_proxy_hash(REQUEST *request)
        PTHREAD_MUTEX_UNLOCK(&proxy_mutex);
 }
 
-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);
-       if (request->in_proxy_hash) remove_from_proxy_hash(request);
-       if (request->in_request_hash) remove_from_request_hash(request);
-
-       request_free(prequest);
-}
-
 static int proxy_id_alloc(REQUEST *request, RADIUS_PACKET *packet)
 {
        int i, proxy, found;
@@ -410,7 +413,7 @@ static int insert_into_proxy_hash(REQUEST *request, int retransmit)
        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;
        }
 
@@ -476,6 +479,7 @@ static void wait_for_child_to_die(void *ctx)
        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
@@ -487,14 +491,15 @@ static void wait_for_child_to_die(void *ctx)
             (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 %u in component %s module %s.",
                               request->number, request->component, request->module);
                } else {
-                       RDEBUG2("Child is still stuck for request %u",
+                       request->delay = USEC * request->root->max_request_time;
+                       RDEBUG2("WARNING: Child is still stuck for request %u",
                                request->number);
                }
                tv_add(&request->when, request->delay);
@@ -504,7 +509,6 @@ static void wait_for_child_to_die(void *ctx)
        }
 
        RDEBUG2("Child is finally responsive for request %u", request->number);
-       remove_from_request_hash(request);
 
 #ifdef WITH_PROXY
        if (request->proxy) {
@@ -789,7 +793,7 @@ static void ping_home_server(void *ctx)
        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;
@@ -1137,6 +1141,25 @@ static void wait_a_bit(void *ctx)
        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;
 
@@ -1153,24 +1176,18 @@ static void wait_a_bit(void *ctx)
                 *      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);
@@ -1178,7 +1195,8 @@ static void wait_a_bit(void *ctx)
                        break;
                }
 
-#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
@@ -1186,32 +1204,19 @@ static void wait_a_bit(void *ctx)
                 */
                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 %u, in module %s component %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->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.
                 */
@@ -1402,7 +1407,7 @@ static void retransmit_coa_request(void *ctx)
        
        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;
                }
 
@@ -1596,7 +1601,7 @@ static int originated_coa_request(REQUEST *request)
        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;
        }
 
@@ -1647,7 +1652,9 @@ static int originated_coa_request(REQUEST *request)
         */
        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);
 
@@ -1818,8 +1825,8 @@ static int request_pre_handler(REQUEST *request)
 #ifdef WITH_PROXY
        if (request->proxy) {
                return process_proxy_reply(request);
-#endif
        }
+#endif
 
        return 1;
 }
@@ -1842,12 +1849,12 @@ static int proxy_request(REQUEST *request)
 #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;
        }
 
@@ -2464,6 +2471,8 @@ static void request_post_handler(REQUEST *request)
         *      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)) {
@@ -2580,7 +2589,7 @@ static void received_retransmit(REQUEST *request, const RADCLIENT *client)
 
                        home = home_server_ldb(NULL, request->home_pool, request);
                        if (!home) {
-                               RDEBUG2("Failed to find live home server for request %u", request->number);
+                               RDEBUG2("ERROR: Failed to find live home server for request %u", request->number);
                        no_home_servers:
                                /*
                                 *      Do post-request processing,
@@ -3033,6 +3042,19 @@ REQUEST *received_proxy_response(RADIUS_PACKET *packet)
        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
@@ -3043,9 +3065,7 @@ REQUEST *received_proxy_response(RADIUS_PACKET *packet)
         *      mark it alive on *any* packet, even if it's lost all
         *      of the *other* packets in the last 10s.
         */
-       if (request->proxy->code != PW_STATUS_SERVER) {
-               request->home_server->state = HOME_STATE_ALIVE;
-       }
+       request->home_server->state = HOME_STATE_ALIVE;
        
 #ifdef WITH_COA
        /*
@@ -3094,7 +3114,7 @@ REQUEST *received_proxy_response(RADIUS_PACKET *packet)
                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
@@ -3170,17 +3190,6 @@ REQUEST *received_proxy_response(RADIUS_PACKET *packet)
        }
 #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;
@@ -3537,6 +3546,10 @@ int radius_event_init(CONF_SECTION *cs, int spawn_flag)
        if (check_config) {
                DEBUG("%s: #### Skipping IP addresses and Ports ####",
                       mainconfig.name);
+               if (listen_init(cs, &head) < 0) {
+                       fflush(NULL);
+                       exit(1);
+               }
                return 1;
        }