receive_client_request(): Improve error message
[privoxy.git] / jcc.c
diff --git a/jcc.c b/jcc.c
index bb6a8fa..780969c 100644 (file)
--- a/jcc.c
+++ b/jcc.c
@@ -995,12 +995,35 @@ static void build_request_line(struct client_state *csp, const struct forward_sp
     * Rebuild the request line.
     */
    freez(*request_line);
-   *request_line = strdup(http->gpc);
-   string_append(request_line, " ");
+#ifdef FEATURE_HTTPS_INSPECTION
+   if (fwd != NULL && fwd->forward_host &&
+       fwd->type != FORWARD_WEBSERVER && client_use_ssl(csp))
+   {
+      *request_line = strdup("CONNECT ");
+   }
+   else
+#endif
+   {
+      *request_line = strdup(http->gpc);
+      string_append(request_line, " ");
+   }
 
    if (fwd != NULL && fwd->forward_host && fwd->type != FORWARD_WEBSERVER)
    {
-      string_append(request_line, http->url);
+#ifdef FEATURE_HTTPS_INSPECTION
+      if (client_use_ssl(csp))
+      {
+         char port_string[10];
+
+         string_append(request_line, http->host);
+         snprintf(port_string, sizeof(port_string), ":%d", http->port);
+         string_append(request_line, port_string);
+      }
+      else
+#endif
+      {
+         string_append(request_line, http->url);
+      }
    }
    else
    {
@@ -1503,6 +1526,12 @@ static enum chunk_status chunked_body_is_complete(struct iob *iob, size_t *lengt
       /* Move beyond the chunkdata. */
       p += 2 + chunksize;
 
+      /* Make sure we're still within the buffer and have two bytes left */
+      if (p + 2 > iob->eod)
+      {
+         return CHUNK_STATUS_MISSING_DATA;
+      }
+
       /* There should be another "\r\n" to skip */
       if (memcmp(p, "\r\n", 2))
       {
@@ -1806,7 +1835,8 @@ static jb_err receive_client_request(struct client_state *csp)
          if (!data_is_available(csp->cfd, csp->config->socket_timeout))
          {
             log_error(LOG_LEVEL_ERROR,
-               "Stopped grabbing the client headers.");
+               "Client headers did not arrive in time. Timeout: %d",
+               csp->config->socket_timeout);
             destroy_list(headers);
             return JB_ERR_PARSE;
          }
@@ -2051,12 +2081,13 @@ static int read_http_request_body(struct client_state *csp)
 
    if (to_read != 0)
    {
-      log_error(LOG_LEVEL_CONNECT, "Not enough request body has been read: expected %llu more bytes",
-         csp->expected_client_content_length);
+      log_error(LOG_LEVEL_CONNECT,
+         "Not enough request body has been read: expected %lu more bytes",
+         to_read);
       return 1;
    }
-   log_error(LOG_LEVEL_CONNECT, "The last %llu bytes of the request body have been read",
-      csp->expected_client_content_length);
+   log_error(LOG_LEVEL_CONNECT,
+      "The last %d bytes of the request body have been read", len);
    return 0;
 }
 
@@ -2129,7 +2160,7 @@ static int can_filter_request_body(const struct client_state *csp)
    {
       log_error(LOG_LEVEL_INFO,
          "Not filtering request body from %s: buffer limit %lu will be exceeded "
-         "(content length %lluu)", csp->ip_addr_str, csp->config->buffer_limit,
+         "(content length %llu)", csp->ip_addr_str, csp->config->buffer_limit,
          csp->expected_client_content_length);
       return FALSE;
    }
@@ -2176,6 +2207,7 @@ static int send_http_request(struct client_state *csp)
          update_client_headers(csp, to_send_len))
       {
          log_error(LOG_LEVEL_HEADER, "Error updating client headers");
+         freez(to_send);
          return 1;
       }
       csp->expected_client_content_length = 0;
@@ -2200,6 +2232,10 @@ static int send_http_request(struct client_state *csp)
    {
       log_error(LOG_LEVEL_CONNECT, "Failed sending request headers to: %s: %E",
          csp->http->hostport);
+      if (filter_client_body)
+      {
+         freez(to_send);
+      }
       return 1;
    }
 
@@ -2491,9 +2527,10 @@ static int send_https_request(struct client_state *csp)
 
 /*********************************************************************
  *
- * Function    :  receive_encrypted_request
+ * Function    :  receive_encrypted_request_headers
  *
- * Description :  Receives an encrypted request.
+ * Description :  Receives the encrypted request headers when
+ *                https-inspecting.
  *
  * Parameters  :
  *          1  :  csp = Current client state (buffers, headers, etc...)
@@ -2502,7 +2539,7 @@ static int send_https_request(struct client_state *csp)
  *                JB_ERR_PARSE or JB_ERR_MEMORY otherwise
  *
  *********************************************************************/
-static jb_err receive_encrypted_request(struct client_state *csp)
+static jb_err receive_encrypted_request_headers(struct client_state *csp)
 {
    char buf[BUFFER_SIZE];
    int len;
@@ -2510,7 +2547,7 @@ static jb_err receive_encrypted_request(struct client_state *csp)
 
    do
    {
-      log_error(LOG_LEVEL_HEADER, "Reading encrypted headers");
+      log_error(LOG_LEVEL_HEADER, "Waiting for encrypted client headers");
       if (!is_ssl_pending(&(csp->ssl_client_attr)) &&
           !data_is_available(csp->cfd, csp->config->socket_timeout))
       {
@@ -2646,9 +2683,10 @@ static jb_err change_encrypted_request_destination(struct client_state *csp)
 
 /*********************************************************************
  *
- * Function    :  process_encrypted_request
+ * Function    :  process_encrypted_request_headers
  *
- * Description :  Receives and parses an encrypted request.
+ * Description :  Receives and parses the encrypted headers send
+ *                by the client when https-inspecting.
  *
  * Parameters  :
  *          1  :  csp = Current client state (buffers, headers, etc...)
@@ -2657,7 +2695,7 @@ static jb_err change_encrypted_request_destination(struct client_state *csp)
  *                JB_ERR_PARSE or JB_ERR_MEMORY otherwise
  *
  *********************************************************************/
-static jb_err process_encrypted_request(struct client_state *csp)
+static jb_err process_encrypted_request_headers(struct client_state *csp)
 {
    char *p;
    char *request_line;
@@ -2674,7 +2712,7 @@ static jb_err process_encrypted_request(struct client_state *csp)
       csp->flags |= CSP_FLAG_CLIENT_CONNECTION_KEEP_ALIVE;
    }
 #endif
-   err = receive_encrypted_request(csp);
+   err = receive_encrypted_request_headers(csp);
    if (err != JB_ERR_OK)
    {
       if (csp->client_iob->cur == NULL ||
@@ -2769,6 +2807,8 @@ static jb_err process_encrypted_request(struct client_state *csp)
          "Failed to get the encrypted request destination");
       ssl_send_data_delayed(&(csp->ssl_client_attr),
          (const unsigned char *)CHEADER, strlen(CHEADER), get_write_delay(csp));
+      destroy_list(headers);
+
       return JB_ERR_PARSE;
    }
 
@@ -2841,8 +2881,7 @@ static jb_err process_encrypted_request(struct client_state *csp)
       return JB_ERR_PARSE;
    }
 
-   log_error(LOG_LEVEL_HEADER, "Encrypted request processed");
-   log_applied_actions(csp->action);
+   log_error(LOG_LEVEL_HEADER, "Encrypted request headers processed");
    log_error(LOG_LEVEL_REQUEST, "https://%s%s", csp->http->hostport,
       csp->http->path);
 
@@ -2908,7 +2947,7 @@ static void continue_https_chat(struct client_state *csp)
 {
    const struct forward_spec *fwd;
 
-   if (JB_ERR_OK != process_encrypted_request(csp))
+   if (JB_ERR_OK != process_encrypted_request_headers(csp))
    {
       csp->flags &= ~CSP_FLAG_CLIENT_CONNECTION_KEEP_ALIVE;
       return;
@@ -2948,6 +2987,8 @@ static void continue_https_chat(struct client_state *csp)
       return;
    }
 
+   log_applied_actions(csp->action);
+
    log_error(LOG_LEVEL_CONNECT,
       "Reusing server socket %d connected to %s. Requests already sent: %u.",
       csp->server_connection.sfd, csp->server_connection.host,
@@ -2966,6 +3007,7 @@ static void continue_https_chat(struct client_state *csp)
          csp->cfd);
       return;
    }
+   csp->server_connection.request_sent = time(NULL);
    csp->server_connection.requests_sent_total++;
    handle_established_connection(csp);
    freez(csp->receive_buffer);
@@ -2979,7 +3021,8 @@ static void continue_https_chat(struct client_state *csp)
  * Function    :  handle_established_connection
  *
  * Description :  Shuffle data between client and server once the
- *                connection has been established.
+ *                connection has been established and the request
+ *                has been sent.
  *
  * Parameters  :
  *          1  :  csp = Current client state (buffers, headers, etc...)
@@ -3055,6 +3098,18 @@ static void handle_established_connection(struct client_state *csp)
 
    for (;;)
    {
+#ifdef FEATURE_HTTPS_INSPECTION
+      if (server_use_ssl(csp) && is_ssl_pending(&(csp->ssl_server_attr)))
+      {
+         /*
+          * It's possible that the TLS library already consumed all the
+          * data the server intends to send. If that happens poll() and
+          * select() will no longer see the data as available so we have
+          * to skip the calls.
+          */
+         goto server_wants_to_talk;
+      }
+#endif
 #ifndef HAVE_POLL
       FD_ZERO(&rfds);
 #ifdef FEATURE_CONNECTION_KEEP_ALIVE
@@ -3141,7 +3196,7 @@ static void handle_established_connection(struct client_state *csp)
       n = select((int)maxfd + 1, &rfds, NULL, NULL, &timeout);
 #endif /* def HAVE_POLL */
 
-      /*server or client not responding in timeout */
+      /* Server or client not responding in timeout */
       if (n == 0)
       {
          log_error(LOG_LEVEL_CONNECT, "Socket timeout %d reached: %s",
@@ -3328,6 +3383,9 @@ static void handle_established_connection(struct client_state *csp)
       if (FD_ISSET(csp->server_connection.sfd, &rfds))
 #endif /* HAVE_POLL */
       {
+#ifdef FEATURE_HTTPS_INSPECTION
+         server_wants_to_talk:
+#endif
 #ifdef FEATURE_CONNECTION_KEEP_ALIVE
          /*
           * If we are buffering content, we don't want to eat up to
@@ -3532,8 +3590,8 @@ static void handle_established_connection(struct client_state *csp)
                               (const unsigned char *) ((p != NULL) ? p : csp->iob->cur),
                               csp->content_length, get_write_delay(csp)) < 0))
                      {
-                        log_error(LOG_LEVEL_ERROR, "write modified content to "
-                           "client over TLS/SSL failed");
+                        log_error(LOG_LEVEL_ERROR,
+                           "Failed to send the modified content to the client over TLS");
                         freez(hdr);
                         freez(p);
                         mark_server_socket_tainted(csp);
@@ -3564,8 +3622,8 @@ static void handle_established_connection(struct client_state *csp)
             }
 
             /*
-             * This is NOT the body, so
-             * Let's pretend the server just sent us a blank line.
+             * This is not the body, so let's pretend the server just sent
+             * us a blank line.
              */
             snprintf(csp->receive_buffer, csp->receive_buffer_size, "\r\n");
             len = (int)strlen(csp->receive_buffer);
@@ -3858,6 +3916,18 @@ static void handle_established_connection(struct client_state *csp)
                return;
             }
 
+            /*
+             * Disable redirect checkers, so that they will be only run
+             * again if the user also enables them through tags.
+             *
+             * From a performance point of view it doesn't matter,
+             * but it prevents duplicated log messages.
+             */
+#ifdef FEATURE_FAST_REDIRECTS
+            csp->action->flags &= ~ACTION_FAST_REDIRECTS;
+#endif
+            csp->action->flags &= ~ACTION_REDIRECT;
+
             /*
              * We have now received the entire server header,
              * filter it and send the result to the client
@@ -4113,9 +4183,6 @@ static void chat(struct client_state *csp)
       return;
    }
 
-   /* decide how to route the HTTP request */
-   fwd = forward_url(csp, http);
-
 #ifdef FEATURE_HTTPS_INSPECTION
    /*
     * Setting flags to use old solution with SSL tunnel and to disable
@@ -4218,10 +4285,6 @@ static void chat(struct client_state *csp)
 #endif
    }
 
-
-   freez(csp->headers->first->str);
-   build_request_line(csp, fwd, &csp->headers->first->str);
-
    /*
     * We have a request. Check if one of the crunchers wants it
     * unless the client wants to use TLS/SSL in which case we
@@ -4240,7 +4303,60 @@ static void chat(struct client_state *csp)
       return;
    }
 
+#ifdef FEATURE_HTTPS_INSPECTION
+   if (client_use_ssl(csp) && !use_ssl_tunnel)
+   {
+      int ret;
+      /*
+       * Creating a SSL proxy.
+       *
+       * By sending the CSUCCEED message we're lying to the client as
+       * the connection hasn't actually been established yet. We don't
+       * establish the connection until we have seen and parsed the
+       * encrypted client headers.
+       */
+      if (write_socket_delayed(csp->cfd, CSUCCEED,
+            strlen(CSUCCEED), get_write_delay(csp)) != 0)
+      {
+         log_error(LOG_LEVEL_ERROR, "Sending SUCCEED to client failed");
+         return;
+      }
+
+      ret = create_client_ssl_connection(csp);
+      if (ret != 0)
+      {
+         log_error(LOG_LEVEL_ERROR,
+            "Failed to open a secure connection with the client");
+         return;
+      }
+      if (JB_ERR_OK != process_encrypted_request_headers(csp))
+      {
+         close_client_ssl_connection(csp);
+         return;
+      }
+      /*
+       * We have an encrypted request. Check if one of the crunchers now
+       * wants it (for example because the previously invisible path was
+       * required to match).
+       */
+      if (crunch_response_triggered(csp, crunchers_all))
+      {
+         /*
+          * Yes. The client got the crunch response and we're done here.
+          */
+         return;
+      }
+   }
+#endif
+
    log_applied_actions(csp->action);
+
+   /* decide how to route the HTTP request */
+   fwd = forward_url(csp, http);
+
+   freez(csp->headers->first->str);
+   build_request_line(csp, fwd, &csp->headers->first->str);
+
    if (fwd->forward_host)
    {
       log_error(LOG_LEVEL_CONNECT, "via [%s]:%d to: %s",
@@ -4288,51 +4404,7 @@ static void chat(struct client_state *csp)
          mark_connection_closed(&csp->server_connection);
       }
 #endif /* def FEATURE_CONNECTION_KEEP_ALIVE */
-#ifdef FEATURE_HTTPS_INSPECTION
-      if (client_use_ssl(csp) && !use_ssl_tunnel)
-      {
-         int ret;
-         /*
-          * Creating a SSL proxy.
-          *
-          * By sending the CSUCCEED message we're lying to the client as
-          * the connection hasn't actually been established yet. We don't
-          * establish the connection until we have seen and parsed the
-          * encrypted client headers.
-          */
-         if (write_socket_delayed(csp->cfd, CSUCCEED,
-               strlen(CSUCCEED), get_write_delay(csp)) != 0)
-         {
-            log_error(LOG_LEVEL_ERROR, "Sending SUCCEED to client failed");
-            return;
-         }
 
-         ret = create_client_ssl_connection(csp);
-         if (ret != 0)
-         {
-            log_error(LOG_LEVEL_ERROR,
-               "Failed to open a secure connection with the client");
-            return;
-         }
-         if (JB_ERR_OK != process_encrypted_request(csp))
-         {
-            close_client_ssl_connection(csp);
-            return;
-         }
-         /*
-          * We have an encrypted request. Check if one of the crunchers now
-          * wants it (for example because the previously invisible path was
-          * required to match).
-          */
-         if (crunch_response_triggered(csp, crunchers_all))
-         {
-            /*
-             * Yes. The client got the crunch response and we're done here.
-             */
-            return;
-         }
-      }
-#endif
       /*
        * Connecting to destination server
        */
@@ -4828,6 +4900,22 @@ static void serve(struct client_state *csp)
 #endif
             close_socket(csp->server_connection.sfd);
             mark_connection_closed(&csp->server_connection);
+#ifdef FEATURE_HTTPS_INSPECTION
+            if (continue_chatting && client_use_ssl(csp))
+            {
+               /*
+                * Close the client socket as well as Privoxy currently
+                * can't establish a new server connection when the client
+                * socket is reused and would drop the connection in
+                * continue_https_chat() anyway.
+                */
+               continue_chatting = 0;
+               csp->flags &= ~CSP_FLAG_CLIENT_CONNECTION_KEEP_ALIVE;
+               log_error(LOG_LEVEL_CONNECT,
+                  "Client socket %d is no longer usable. "
+                  "The server socket has been closed.", csp->cfd);
+            }
+#endif
          }
       }
 
@@ -5745,15 +5833,18 @@ static jb_socket bind_port_helper(const char *haddr, int hport, int backlog)
                "can't bind to %s:%d: There may be another Privoxy "
                "or some other proxy running on port %d",
                bind_address, hport, hport);
+            exit(-1);
 
          case -2:
             log_error(LOG_LEVEL_FATAL,
                "can't bind to %s:%d: The hostname is not resolvable",
                bind_address, hport);
+            exit(-1);
 
          default:
             log_error(LOG_LEVEL_FATAL, "can't bind to %s:%d: %E",
                bind_address, hport);
+            exit(-1);
       }
 
       /* shouldn't get here */
@@ -6023,7 +6114,7 @@ static void listen_loop(void)
       if ((0 != config->max_client_connections)
          && (active_threads >= config->max_client_connections))
       {
-         log_error(LOG_LEVEL_CONNECT,
+         log_error(LOG_LEVEL_ERROR,
             "Rejecting connection from %s. Maximum number of connections reached.",
             csp->ip_addr_str);
          write_socket_delayed(csp->cfd, TOO_MANY_CONNECTIONS_RESPONSE,
@@ -6059,7 +6150,7 @@ static void listen_loop(void)
          }
 #endif
 
-#if defined(_WIN32) && !defined(_CYGWIN) && !defined(SELECTED_ONE_OPTION)
+#if defined(_WIN32) && !defined(SELECTED_ONE_OPTION)
 #define SELECTED_ONE_OPTION
          child_id = _beginthread(
             (void (*)(void *))serve,
@@ -6193,6 +6284,8 @@ static void listen_loop(void)
 
    log_error(LOG_LEVEL_INFO, "Graceful termination requested.");
 
+   close_ports_helper(bfds);
+
    unload_current_config_file();
    unload_current_actions_file();
    unload_current_re_filterfile();