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 f2fa2cf..9fc9d95 100644 (file)
--- a/jcc.c
+++ b/jcc.c
@@ -1,4 +1,4 @@
-const char jcc_rcs[] = "$Id: jcc.c,v 1.379 2012/07/23 12:39:12 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.379 2012/07/23 12:39:12 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
@@ -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);
@@ -1050,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))
@@ -1064,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);
@@ -1080,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")
@@ -1102,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
@@ -1196,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));
 
@@ -1293,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)
       {
@@ -1323,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
@@ -1425,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);
@@ -1455,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;
 
 }
@@ -1602,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)
@@ -1673,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)
       {
@@ -1685,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
    {
@@ -1714,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);
@@ -2115,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;
@@ -2179,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();
@@ -2214,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;
                }
             }
@@ -2430,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);
@@ -2478,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;
@@ -2575,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)
@@ -2630,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;
@@ -3032,12 +3076,7 @@ int main(int argc, char **argv)
       basedir = strdup_or_die(cwd);
       /* XXX: why + 5? */
       abs_file_size = strlen(cwd) + strlen(configfile) + 5;
-      abs_file = malloc(abs_file_size);
-      if (NULL == abs_file)
-      {
-         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);
@@ -3526,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;