In chat(), check for failed delivery of request headers and body separately
[privoxy.git] / jcc.c
diff --git a/jcc.c b/jcc.c
index 6661b34..9fc9d95 100644 (file)
--- a/jcc.c
+++ b/jcc.c
@@ -1,4 +1,4 @@
-const char jcc_rcs[] = "$Id: jcc.c,v 1.375 2011/12/10 17:26:11 fabiankeil Exp $";
+const char jcc_rcs[] = "$Id: jcc.c,v 1.393 2012/10/21 12:39:27 fabiankeil Exp $";
 /*********************************************************************
  *
  * File        :  $Source: /cvsroot/ijbswa/current/jcc.c,v $
@@ -6,7 +6,7 @@ const char jcc_rcs[] = "$Id: jcc.c,v 1.375 2011/12/10 17:26:11 fabiankeil Exp $"
  * Purpose     :  Main file.  Contains main() method, main loop, and
  *                the main connection-handling function.
  *
- * Copyright   :  Written by and Copyright (C) 2001-2010 the
+ * Copyright   :  Written by and Copyright (C) 2001-2012 the
  *                Privoxy team. http://www.privoxy.org/
  *
  *                Based on the Internet Junkbuster originally written
@@ -338,7 +338,7 @@ static void sig_handler(int the_signal)
       case SIGINT:
          log_error(LOG_LEVEL_INFO, "exiting by signal %d .. bye", the_signal);
 #if defined(unix)
-         if(pidfile)
+         if (pidfile)
          {
             unlink(pidfile);
          }
@@ -661,6 +661,34 @@ static const char *crunch_reason(const struct http_response *rsp)
 }
 
 
+/*********************************************************************
+ *
+ * Function    :  log_applied_actions
+ *
+ * Description :  Logs the applied actions if LOG_LEVEL_ACTIONS is
+ *                enabled.
+ *
+ * Parameters  :
+ *          1  :  actions = Current action spec to log
+ *
+ * Returns     :  Nothing.
+ *
+ *********************************************************************/
+static void log_applied_actions(const struct current_action_spec *actions)
+{
+   /*
+    * The conversion to text requires lots of memory allocations so
+    * we only do the conversion if the user is actually interested.
+    */
+   if (debug_level_is_enabled(LOG_LEVEL_ACTIONS))
+   {
+      char *actions_as_text = actions_to_line_of_text(actions);
+      log_error(LOG_LEVEL_ACTIONS, "%s", actions_as_text);
+      freez(actions_as_text);
+   }
+}
+
+
 /*********************************************************************
  *
  * Function    :  send_crunch_response
@@ -705,6 +733,7 @@ static void send_crunch_response(const struct client_state *csp, struct http_res
       status_code[3] = '\0';
 
       /* Log that the request was crunched and why. */
+      log_applied_actions(csp->action);
       log_error(LOG_LEVEL_CRUNCH, "%s: %s", crunch_reason(rsp), http->url);
       log_error(LOG_LEVEL_CLF, "%s - - [%T] \"%s\" %s %u",
          csp->ip_addr_str, http->ocmd, status_code, rsp->content_length);
@@ -827,12 +856,7 @@ static void build_request_line(struct client_state *csp, const struct forward_sp
      && (!strcmpic(http->ver, "HTTP/1.1")))
    {
       freez(http->ver);
-      http->ver = strdup("HTTP/1.0");
-
-      if (http->ver == NULL)
-      {
-         log_error(LOG_LEVEL_FATAL, "Out of memory downgrading HTTP version");
-      }
+      http->ver = strdup_or_die("HTTP/1.0");
    }
 
    /*
@@ -891,12 +915,7 @@ static jb_err change_request_destination(struct client_state *csp)
    else
    {
       /* XXX: ocmd is a misleading name */
-      http->ocmd = strdup(http->cmd);
-      if (http->ocmd == NULL)
-      {
-         log_error(LOG_LEVEL_FATAL,
-            "Out of memory copying rewritten HTTP request line");
-      }
+      http->ocmd = strdup_or_die(http->cmd);
    }
 
    return err;
@@ -1003,11 +1022,7 @@ void save_connection_destination(jb_socket sfd,
    assert(NULL != http->host);
 
    server_connection->sfd = sfd;
-   server_connection->host = strdup(http->host);
-   if (NULL == server_connection->host)
-   {
-      log_error(LOG_LEVEL_FATAL, "Out of memory saving socket.");
-   }
+   server_connection->host = strdup_or_die(http->host);
    server_connection->port = http->port;
 
    assert(NULL != fwd);
@@ -1020,11 +1035,7 @@ void save_connection_destination(jb_socket sfd,
    server_connection->forwarder_type = fwd->type;
    if (NULL != fwd->gateway_host)
    {
-      server_connection->gateway_host = strdup(fwd->gateway_host);
-      if (NULL == server_connection->gateway_host)
-      {
-         log_error(LOG_LEVEL_FATAL, "Out of memory saving gateway_host.");
-      }
+      server_connection->gateway_host = strdup_or_die(fwd->gateway_host);
    }
    else
    {
@@ -1034,11 +1045,7 @@ void save_connection_destination(jb_socket sfd,
 
    if (NULL != fwd->forward_host)
    {
-      server_connection->forward_host = strdup(fwd->forward_host);
-      if (NULL == server_connection->forward_host)
-      {
-         log_error(LOG_LEVEL_FATAL, "Out of memory saving forward_host.");
-      }
+      server_connection->forward_host = strdup_or_die(fwd->forward_host);
    }
    else
    {
@@ -1072,7 +1079,7 @@ void save_connection_destination(jb_socket sfd,
 static void verify_request_length(struct client_state *csp)
 {
    unsigned long long buffered_request_bytes =
-      (unsigned long long)(csp->iob->eod - csp->iob->cur);
+      (unsigned long long)(csp->client_iob->eod - csp->client_iob->cur);
 
    if ((csp->expected_client_content_length != 0)
       && (buffered_request_bytes != 0))
@@ -1086,8 +1093,8 @@ static void verify_request_length(struct client_state *csp)
       }
       else
       {
-         assert(csp->iob->eod > csp->iob->cur + csp->expected_client_content_length);
-         csp->iob->eod = csp->iob->cur + csp->expected_client_content_length;
+         assert(csp->client_iob->eod > csp->client_iob->cur + csp->expected_client_content_length);
+         csp->client_iob->eod = csp->client_iob->cur + csp->expected_client_content_length;
          log_error(LOG_LEVEL_CONNECT, "Reducing expected bytes to 0. "
             "Marking the server socket tainted after throwing %llu bytes away.",
             buffered_request_bytes - csp->expected_client_content_length);
@@ -1102,7 +1109,7 @@ static void verify_request_length(struct client_state *csp)
    }
 
    if (!(csp->flags & CSP_FLAG_CLIENT_REQUEST_COMPLETELY_READ)
-    && ((csp->iob->cur[0] != '\0') || (csp->expected_client_content_length != 0)))
+    && ((csp->client_iob->cur[0] != '\0') || (csp->expected_client_content_length != 0)))
    {
       csp->flags |= CSP_FLAG_SERVER_SOCKET_TAINTED;
       if (strcmpic(csp->http->gpc, "GET")
@@ -1124,8 +1131,8 @@ static void verify_request_length(struct client_state *csp)
             "Possible pipeline attempt detected. The connection will not "
             "be kept alive and we will only serve the first request.");
          /* Nuke the pipelined requests from orbit, just to be sure. */
-         csp->iob->buf[0] = '\0';
-         csp->iob->eod = csp->iob->cur = csp->iob->buf;
+         csp->client_iob->buf[0] = '\0';
+         csp->client_iob->eod = csp->client_iob->cur = csp->client_iob->buf;
       }
    }
    else
@@ -1193,11 +1200,20 @@ static char *get_request_line(struct client_state *csp)
    {
       if (!data_is_available(csp->cfd, csp->config->socket_timeout))
       {
-         log_error(LOG_LEVEL_CONNECT,
-            "Stopped waiting for the request line. Timeout: %d.",
-            csp->config->socket_timeout);
-         write_socket(csp->cfd, CLIENT_CONNECTION_TIMEOUT_RESPONSE,
-            strlen(CLIENT_CONNECTION_TIMEOUT_RESPONSE));
+         if (socket_is_still_alive(csp->cfd))
+         {
+            log_error(LOG_LEVEL_CONNECT,
+               "No request line on socket %d received in time. Timeout: %d.",
+               csp->cfd, csp->config->socket_timeout);
+            write_socket(csp->cfd, CLIENT_CONNECTION_TIMEOUT_RESPONSE,
+               strlen(CLIENT_CONNECTION_TIMEOUT_RESPONSE));
+         }
+         else
+         {
+            log_error(LOG_LEVEL_CONNECT,
+               "The client side of the connection on socket %d got "
+               "closed without sending a complete request line.", csp->cfd);
+         }
          return NULL;
       }
 
@@ -1209,12 +1225,12 @@ static char *get_request_line(struct client_state *csp)
        * If there is no memory left for buffering the
        * request, there is nothing we can do but hang up
        */
-      if (add_to_iob(csp, buf, len))
+      if (add_to_iob(csp->client_iob, csp->config->buffer_limit, buf, len))
       {
          return NULL;
       }
 
-      request_line = get_header(csp->iob);
+      request_line = get_header(csp->client_iob);
 
    } while ((NULL != request_line) && ('\0' == *request_line));
 
@@ -1306,7 +1322,7 @@ static jb_err receive_client_request(struct client_state *csp)
    init_list(headers);
    for (;;)
    {
-      p = get_header(csp->iob);
+      p = get_header(csp->client_iob);
 
       if (p == NULL)
       {
@@ -1336,7 +1352,7 @@ static jb_err receive_client_request(struct client_state *csp)
             return JB_ERR_PARSE;
          }
 
-         if (add_to_iob(csp, buf, len))
+         if (add_to_iob(csp->client_iob, csp->config->buffer_limit, buf, len))
          {
             /*
              * If there is no memory left for buffering the
@@ -1396,12 +1412,7 @@ static jb_err receive_client_request(struct client_state *csp)
    /*
     * Save a copy of the original request for logging
     */
-   http->ocmd = strdup(http->cmd);
-   if (http->ocmd == NULL)
-   {
-      log_error(LOG_LEVEL_FATAL,
-         "Out of memory copying HTTP request line");
-   }
+   http->ocmd = strdup_or_die(http->cmd);
    enlist(csp->headers, http->cmd);
 
    /* Append the previously read headers */
@@ -1443,6 +1454,12 @@ static jb_err parse_client_request(struct client_state *csp)
       /* Assume persistence until further notice */
       csp->flags |= CSP_FLAG_CLIENT_CONNECTION_KEEP_ALIVE;
    }
+
+   if (csp->http->ssl == 0)
+   {
+      csp->expected_client_content_length = get_expected_content_length(csp->headers);
+      verify_request_length(csp);
+   }
 #endif /* def FEATURE_CONNECTION_KEEP_ALIVE */
 
    err = sed(csp, FILTER_CLIENT_HEADERS);
@@ -1473,13 +1490,6 @@ static jb_err parse_client_request(struct client_state *csp)
       return JB_ERR_PARSE;
    }
 
-#ifdef FEATURE_CONNECTION_KEEP_ALIVE
-   if (csp->http->ssl == 0)
-   {
-      verify_request_length(csp);
-   }
-#endif /* def FEATURE_CONNECTION_KEEP_ALIVE */
-
    return JB_ERR_OK;
 
 }
@@ -1620,6 +1630,7 @@ static void chat(struct client_state *csp)
       return;
    }
 
+   log_applied_actions(csp->action);
    log_error(LOG_LEVEL_GPC, "%s%s", http->hostport, http->path);
 
    if (fwd->forward_host)
@@ -1691,6 +1702,7 @@ static void chat(struct client_state *csp)
 
    if (fwd->forward_host || (http->ssl == 0))
    {
+      int write_failure;
       hdr = list_to_text(csp->headers);
       if (hdr == NULL)
       {
@@ -1703,22 +1715,30 @@ static void chat(struct client_state *csp)
        * Write the client's (modified) header to the server
        * (along with anything else that may be in the buffer)
        */
-      if (write_socket(csp->server_connection.sfd, hdr, strlen(hdr))
-       || (flush_socket(csp->server_connection.sfd, csp->iob) <  0))
+      write_failure = 0 != write_socket(csp->server_connection.sfd, hdr, strlen(hdr));
+      freez(hdr);
+
+      if (write_failure)
+      {
+         log_error(LOG_LEVEL_CONNECT,
+            "Failed sending request headers to: %s: %E", http->hostport);
+      }
+      else if (flush_socket(csp->server_connection.sfd, csp->client_iob) <  0))
       {
+         write_failure = 1;
          log_error(LOG_LEVEL_CONNECT,
-            "write header to: %s failed: %E", http->hostport);
+            "Failed sending request body to: %s: %E", http->hostport);
+      }
 
+      if (write_failure)
+      {
          rsp = error_response(csp, "connect-failed");
          if (rsp)
          {
             send_crunch_response(csp, rsp);
          }
-
-         freez(hdr);
          return;
       }
-      freez(hdr);
    }
    else
    {
@@ -1732,7 +1752,7 @@ static void chat(struct client_state *csp)
       {
          return;
       }
-      IOB_RESET(csp);
+      IOB_RESET(csp->client_iob);
    }
 
    log_error(LOG_LEVEL_CONNECT, "to %s successful", http->hostport);
@@ -1861,8 +1881,9 @@ static void chat(struct client_state *csp)
                 */
                watch_client_socket = 0;
                log_error(LOG_LEVEL_CONNECT,
-                  "Stopping to watch the client socket. "
-                  "There's already another request waiting.");
+                  "Stopping to watch the client socket %d. "
+                  "There's already another request waiting.",
+                  csp->cfd);
                continue;
             }
             /*
@@ -2132,7 +2153,7 @@ static void chat(struct client_state *csp)
                 * has been reached, switch to non-filtering mode, i.e. make & write the
                 * header, flush the iob and buf, and get out of the way.
                 */
-               if (add_to_iob(csp, buf, len))
+               if (add_to_iob(csp->iob, csp->config->buffer_limit, buf, len))
                {
                   size_t hdrlen;
                   long flushed;
@@ -2196,7 +2217,7 @@ static void chat(struct client_state *csp)
              * Buffer up the data we just read.  If that fails, there's
              * little we can do but send our static out-of-memory page.
              */
-            if (add_to_iob(csp, buf, len))
+            if (add_to_iob(csp->iob, csp->config->buffer_limit, buf, len))
             {
                log_error(LOG_LEVEL_ERROR, "Out of memory while looking for end of server headers.");
                rsp = cgi_error_memory();
@@ -2231,8 +2252,8 @@ static void chat(struct client_state *csp)
                    * we can parse the headers we just continue here.
                    */
                   log_error(LOG_LEVEL_CONNECT,
-                     "Continuing buffering headers. Bytes most recently read: %d.",
-                     len);
+                     "Continuing buffering server headers from socket %d. "
+                     "Bytes most recently read: %d.", csp->cfd, len);
                   continue;
                }
             }
@@ -2447,8 +2468,7 @@ static void prepare_csp_for_next_request(struct client_state *csp)
    csp->expected_content_length = 0;
    csp->expected_client_content_length = 0;
    list_remove_all(csp->headers);
-   freez(csp->iob->buf);
-   memset(csp->iob, 0, sizeof(csp->iob));
+   IOB_RESET(csp->iob);
    freez(csp->error_message);
    free_http_request(csp->http);
    destroy_list(csp->headers);
@@ -2495,6 +2515,9 @@ static void serve(struct client_state *csp)
 #endif /* def FEATURE_CONNECTION_SHARING */
    int continue_chatting = 0;
 
+   log_error(LOG_LEVEL_CONNECT, "Accepted connection from %s on socket %d",
+      csp->ip_addr_str, csp->cfd);
+
    do
    {
       unsigned int latency;
@@ -2592,7 +2615,7 @@ static void serve(struct client_state *csp)
 
                remember_connection(&csp->server_connection);
                csp->server_connection.sfd = JB_INVALID_SOCKET;
-               close_socket(csp->cfd);
+               drain_and_close_socket(csp->cfd);
                csp->cfd = JB_INVALID_SOCKET;
                privoxy_mutex_lock(&connection_reuse_mutex);
                if (!monitor_thread_running)
@@ -2647,7 +2670,11 @@ static void serve(struct client_state *csp)
 
    if (csp->cfd != JB_INVALID_SOCKET)
    {
-      close_socket(csp->cfd);
+      log_error(LOG_LEVEL_CONNECT, "Closing client socket %d. "
+         "Keep-alive: %u, Socket alive: %u. Data available: %u.",
+         csp->cfd, 0 != (csp->flags & CSP_FLAG_CLIENT_CONNECTION_KEEP_ALIVE),
+         socket_is_still_alive(csp->cfd), data_is_available(csp->cfd, 0));
+      drain_and_close_socket(csp->cfd);
    }
 
    csp->flags &= ~CSP_FLAG_ACTIVE;
@@ -2948,7 +2975,7 @@ int main(int argc, char **argv)
          usage(argv[0]);
       }
 
-      else if(strcmp(argv[argc_pos], "--version") == 0)
+      else if (strcmp(argv[argc_pos], "--version") == 0)
       {
          printf("Privoxy version " VERSION " (" HOME_PAGE_URL ")\n");
          exit(0);
@@ -2965,7 +2992,7 @@ int main(int argc, char **argv)
       else if (strcmp(argv[argc_pos], "--pidfile") == 0)
       {
          if (++argc_pos == argc) usage(argv[0]);
-         pidfile = strdup(argv[argc_pos]);
+         pidfile = strdup_or_die(argv[argc_pos]);
       }
 
       else if (strcmp(argv[argc_pos], "--user") == 0)
@@ -2975,12 +3002,7 @@ int main(int argc, char **argv)
 
          if (++argc_pos == argc) usage(argv[argc_pos]);
 
-         user_arg = strdup(argv[argc_pos]);
-         if (NULL == user_arg)
-         {
-            log_error(LOG_LEVEL_FATAL,
-               "Out of memory splitting --user argument '%s'.", argv[argc_pos]);
-         }
+         user_arg = strdup_or_die(argv[argc_pos]);
          group_name = strchr(user_arg, '.');
          if (NULL != group_name)
          {
@@ -3008,7 +3030,7 @@ int main(int argc, char **argv)
       else if (strcmp(argv[argc_pos], "--pre-chroot-nslookup") == 0)
       {
          if (++argc_pos == argc) usage(argv[0]);
-         pre_chroot_nslookup_to_load_resolver = strdup(argv[argc_pos]);
+         pre_chroot_nslookup_to_load_resolver = strdup_or_die(argv[argc_pos]);
       }
 
       else if (strcmp(argv[argc_pos], "--chroot") == 0)
@@ -3051,16 +3073,10 @@ int main(int argc, char **argv)
          exit(1);
       }
 
+      basedir = strdup_or_die(cwd);
       /* XXX: why + 5? */
       abs_file_size = strlen(cwd) + strlen(configfile) + 5;
-      basedir = strdup(cwd);
-
-      if (NULL == basedir ||
-          NULL == (abs_file = malloc(abs_file_size)))
-      {
-         perror("malloc failed");
-         exit(1);
-      }
+      abs_file = malloc_or_die(abs_file_size);
       strlcpy(abs_file, basedir, abs_file_size);
       strlcat(abs_file, "/", abs_file_size);
       strlcat(abs_file, configfile, abs_file_size);
@@ -3541,7 +3557,7 @@ static void listen_loop(void)
          log_error(LOG_LEVEL_CONNECT, "accept failed: %E");
 
 #ifdef AMIGA
-         if(!childs)
+         if (!childs)
          {
             exit(1);
          }
@@ -3549,12 +3565,6 @@ static void listen_loop(void)
          freez(csp_list);
          continue;
       }
-      else
-      {
-         log_error(LOG_LEVEL_CONNECT,
-            "accepted connection from %s on socket %d",
-            csp->ip_addr_str, csp->cfd);
-      }
 
       csp->flags |= CSP_FLAG_ACTIVE;
       csp->server_connection.sfd = JB_INVALID_SOCKET;
@@ -3700,7 +3710,7 @@ static void listen_loop(void)
                                            NP_StackSize, 200*1024,
                                            TAG_DONE);
 #endif
-         if(0 != child_id)
+         if (0 != child_id)
          {
             childs++;
             ((struct Task *)child_id)->tc_UserData = csp;