read_http_request_body(): End more log messages with periods.
[privoxy.git] / jcc.c
diff --git a/jcc.c b/jcc.c
index 19b2f49..3322574 100644 (file)
--- a/jcc.c
+++ b/jcc.c
@@ -1653,6 +1653,14 @@ extern int fuzz_chunked_transfer_encoding(struct client_state *csp, char *fuzz_i
    {
       log_error(LOG_LEVEL_INFO, "Chunked body is incomplete or invalid");
    }
+   if (get_bytes_missing_from_chunked_data(csp->iob->cur, size, 0) == 0)
+   {
+      if (CHUNK_STATUS_BODY_COMPLETE != status)
+      {
+         log_error(LOG_LEVEL_ERROR,
+            "There's disagreement about whether or not the chunked body is complete.");
+      }
+   }
 
    return (JB_ERR_OK == remove_chunked_transfer_coding(csp->iob->cur, &size));
 
@@ -2114,12 +2122,12 @@ 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 %lu more bytes",
+         "Not enough request body has been read: expected %lu more bytes.",
          to_read);
       return 1;
    }
    log_error(LOG_LEVEL_CONNECT,
-      "The last %d bytes of the request body have been read", len);
+      "The last %d bytes of the request body have been read.", len);
    return 0;
 }
 
@@ -2363,7 +2371,7 @@ static int receive_and_send_encrypted_post_data(struct client_state *csp)
          /* XXX: Does this actually happen? */
          break;
       }
-      log_error(LOG_LEVEL_CONNECT, "Forwarding %d bytes of encrypted request body",
+      log_error(LOG_LEVEL_CONNECT, "Forwarding %d bytes of encrypted request body.",
          len);
       len = ssl_send_data(&(csp->ssl_server_attr), buf, (size_t)len);
       if (len == -1)
@@ -2378,13 +2386,13 @@ static int receive_and_send_encrypted_post_data(struct client_state *csp)
          }
          if (csp->expected_client_content_length == 0)
          {
-            log_error(LOG_LEVEL_CONNECT, "Forwarded the last %d bytes", len);
+            log_error(LOG_LEVEL_CONNECT, "Forwarded the last %d bytes.", len);
             break;
          }
       }
    }
 
-   log_error(LOG_LEVEL_CONNECT, "Done forwarding encrypted request body");
+   log_error(LOG_LEVEL_CONNECT, "Done forwarding encrypted request body.");
 
    return 0;
 
@@ -2414,7 +2422,7 @@ static int send_https_request(struct client_state *csp)
    if (hdr == NULL)
    {
       /* FIXME Should handle error properly */
-      log_error(LOG_LEVEL_FATAL, "Out of memory parsing client header");
+      log_error(LOG_LEVEL_FATAL, "Out of memory parsing client header.");
    }
    list_remove_all(csp->https_headers);
 
@@ -2451,14 +2459,14 @@ static int send_https_request(struct client_state *csp)
          if (csp->expected_client_content_length < flushed)
          {
             log_error(LOG_LEVEL_ERROR,
-               "Flushed %ld bytes of request body while only expecting %llu",
+               "Flushed %ld bytes of request body while only expecting %llu.",
                flushed, csp->expected_client_content_length);
             csp->expected_client_content_length = 0;
          }
          else
          {
             log_error(LOG_LEVEL_CONNECT,
-               "Flushed %ld bytes of request body while expecting %llu",
+               "Flushed %ld bytes of request body while expecting %llu.",
                flushed, csp->expected_client_content_length);
             csp->expected_client_content_length -= (unsigned)flushed;
             if (receive_and_send_encrypted_post_data(csp))
@@ -2470,11 +2478,11 @@ static int send_https_request(struct client_state *csp)
       else
       {
          log_error(LOG_LEVEL_CONNECT,
-            "Flushed %ld bytes of request body", flushed);
+            "Flushed %ld bytes of request body.", flushed);
       }
    }
 
-   log_error(LOG_LEVEL_CONNECT, "Encrypted request sent");
+   log_error(LOG_LEVEL_CONNECT, "Encrypted request sent.");
 
    return 0;
 
@@ -3018,6 +3026,67 @@ static void continue_https_chat(struct client_state *csp)
 #endif
 
 
+/*********************************************************************
+ *
+ * Function    :  send_server_headers
+ *
+ * Description :  Sends the server headers to the client.
+ *
+ * Parameters  :
+ *          1  :  csp = Current client state (buffers, headers, etc...)
+ *
+ * Returns     :  0 on succes, -1 on error.
+ *
+ *********************************************************************/
+static int send_server_headers(struct client_state *csp)
+{
+   char *server_headers;
+   int ret;
+
+   server_headers = list_to_text(csp->headers);
+   if (server_headers == NULL)
+   {
+      /*
+       * Memory is too tight to even generate the header.
+       * Send our static "Out-of-memory" page.
+       */
+      log_error(LOG_LEVEL_ERROR,
+         "Out of memory while trying to send server headers.");
+      send_crunch_response(csp, cgi_error_memory());
+      mark_server_socket_tainted(csp);
+#ifdef FEATURE_HTTPS_INSPECTION
+      close_client_and_server_ssl_connections(csp);
+#endif
+      return -1;
+   }
+#ifdef FEATURE_HTTPS_INSPECTION
+   if (client_use_ssl(csp))
+   {
+      ret = ssl_send_data_delayed(&(csp->ssl_client_attr),
+         (const unsigned char *)server_headers, strlen(server_headers),
+         get_write_delay(csp));
+   }
+   else
+#endif
+   {
+      ret = write_socket_delayed(csp->cfd, server_headers, strlen(server_headers),
+         get_write_delay(csp));
+   }
+   freez(server_headers);
+   if (ret < 0)
+   {
+      log_error(LOG_LEVEL_ERROR, "Failed to send server headers to the client.");
+      mark_server_socket_tainted(csp);
+#ifdef FEATURE_HTTPS_INSPECTION
+      close_client_and_server_ssl_connections(csp);
+#endif
+      return -1;
+   }
+
+   return 0;
+
+}
+
 /*********************************************************************
  *
  * Function    :  handle_established_connection
@@ -3034,7 +3103,6 @@ static void continue_https_chat(struct client_state *csp)
  *********************************************************************/
 static void handle_established_connection(struct client_state *csp)
 {
-   char *hdr;
    char *p;
    int n;
 #ifdef HAVE_POLL
@@ -3051,6 +3119,7 @@ static void handle_established_connection(struct client_state *csp)
    long len = 0; /* for buffer sizes (and negative error codes) */
    int buffer_and_filter_content = 0;
    unsigned int write_delay;
+   size_t chunk_offset = 0;
 #ifdef FEATURE_HTTPS_INSPECTION
    int ret = 0;
    int use_ssl_tunnel = 0;
@@ -3139,23 +3208,6 @@ static void handle_established_connection(struct client_state *csp)
 #endif /* ndef HAVE_POLL */
 
 #ifdef FEATURE_CONNECTION_KEEP_ALIVE
-      if ((csp->flags & CSP_FLAG_CHUNKED)
-         && !(csp->flags & CSP_FLAG_CONTENT_LENGTH_SET)
-         && ((csp->iob->eod - csp->iob->cur) >= 5)
-         && !memcmp(csp->iob->eod-5, "0\r\n\r\n", 5))
-      {
-         /*
-          * XXX: This check should be obsolete now,
-          *      but let's wait a while to be sure.
-          */
-         log_error(LOG_LEVEL_CONNECT,
-            "Looks like we got the last chunk together with "
-            "the server headers but didn't detect it earlier. "
-            "We better stop reading.");
-         byte_count = (unsigned long long)(csp->iob->eod - csp->iob->cur);
-         csp->expected_content_length = byte_count;
-         csp->flags |= CSP_FLAG_CONTENT_LENGTH_SET;
-      }
       if (server_body && server_response_is_complete(csp, byte_count))
       {
          if (csp->expected_content_length == byte_count)
@@ -3392,8 +3444,6 @@ static void handle_established_connection(struct client_state *csp)
 
       /*
        * The server wants to talk. It could be the header or the body.
-       * If `hdr' is null, then it's the header otherwise it's the body.
-       * FIXME: Does `hdr' really mean `host'? No.
        */
 #ifdef HAVE_POLL
       if (poll_fds[1].revents != 0)
@@ -3489,18 +3539,6 @@ static void handle_established_connection(struct client_state *csp)
          }
 
 #ifdef FEATURE_CONNECTION_KEEP_ALIVE
-         if (csp->flags & CSP_FLAG_CHUNKED)
-         {
-            if ((len >= 5) && !memcmp(csp->receive_buffer+len-5, "0\r\n\r\n", 5))
-            {
-               /* XXX: this is a temporary hack */
-               log_error(LOG_LEVEL_CONNECT,
-                  "Looks like we reached the end of the last chunk. "
-                  "We better stop reading.");
-               csp->expected_content_length = byte_count + (unsigned long long)len;
-               csp->flags |= CSP_FLAG_CONTENT_LENGTH_SET;
-            }
-         }
          reading_done:
 #endif  /* FEATURE_CONNECTION_KEEP_ALIVE */
 
@@ -3588,11 +3626,9 @@ static void handle_established_connection(struct client_state *csp)
                         "Failed to update server headers. after filtering.");
                   }
 
-                  hdr = list_to_text(csp->headers);
-                  if (hdr == NULL)
+                  if (send_server_headers(csp))
                   {
-                     /* FIXME Should handle error properly */
-                     log_error(LOG_LEVEL_FATAL, "Out of memory parsing server header");
+                     return;
                   }
 
 #ifdef FEATURE_HTTPS_INSPECTION
@@ -3601,16 +3637,12 @@ static void handle_established_connection(struct client_state *csp)
                    */
                   if (client_use_ssl(csp))
                   {
-                     if ((ssl_send_data_delayed(&(csp->ssl_client_attr),
-                              (const unsigned char *)hdr, strlen(hdr),
-                              get_write_delay(csp)) < 0)
-                        || (ssl_send_data_delayed(&(csp->ssl_client_attr),
+                     if (ssl_send_data_delayed(&(csp->ssl_client_attr),
                               (const unsigned char *) ((p != NULL) ? p : csp->iob->cur),
-                              csp->content_length, get_write_delay(csp)) < 0))
+                              csp->content_length, get_write_delay(csp)) < 0)
                      {
                         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);
                         close_client_and_server_ssl_connections(csp);
@@ -3620,19 +3652,16 @@ static void handle_established_connection(struct client_state *csp)
                   else
 #endif /* def FEATURE_HTTPS_INSPECTION */
                   {
-                     if (write_socket_delayed(csp->cfd, hdr, strlen(hdr), write_delay)
-                      || write_socket_delayed(csp->cfd, ((p != NULL) ? p : csp->iob->cur),
+                     if (write_socket_delayed(csp->cfd, ((p != NULL) ? p : csp->iob->cur),
                          (size_t)csp->content_length, write_delay))
                      {
                         log_error(LOG_LEVEL_ERROR, "write modified content to client failed: %E");
-                        freez(hdr);
                         freez(p);
                         mark_server_socket_tainted(csp);
                         return;
                      }
                   }
 
-                  freez(hdr);
                   freez(p);
                }
 
@@ -3674,29 +3703,15 @@ static void handle_established_connection(struct client_state *csp)
                 */
                if (add_to_iob(csp->iob, csp->config->buffer_limit, csp->receive_buffer, len))
                {
-                  size_t hdrlen;
                   long flushed;
 
                   log_error(LOG_LEVEL_INFO,
                      "Flushing header and buffers. Stepping back from filtering.");
 
-                  hdr = list_to_text(csp->headers);
-                  if (hdr == NULL)
+                  if (send_server_headers(csp))
                   {
-                     /*
-                      * Memory is too tight to even generate the header.
-                      * Send our static "Out-of-memory" page.
-                      */
-                     log_error(LOG_LEVEL_ERROR, "Out of memory while trying to flush.");
-                     rsp = cgi_error_memory();
-                     send_crunch_response(csp, rsp);
-                     mark_server_socket_tainted(csp);
-#ifdef FEATURE_HTTPS_INSPECTION
-                     close_client_and_server_ssl_connections(csp);
-#endif
                      return;
                   }
-                  hdrlen = strlen(hdr);
 
 #ifdef FEATURE_HTTPS_INSPECTION
                   /*
@@ -3704,9 +3719,7 @@ static void handle_established_connection(struct client_state *csp)
                    */
                   if (client_use_ssl(csp))
                   {
-                     if ((ssl_send_data_delayed(&(csp->ssl_client_attr),
-                             (const unsigned char *)hdr, hdrlen, get_write_delay(csp)) < 0)
-                        || ((flushed = ssl_flush_socket(&(csp->ssl_client_attr),
+                     if (((flushed = ssl_flush_socket(&(csp->ssl_client_attr),
                                 csp->iob)) < 0)
                         || (ssl_send_data_delayed(&(csp->ssl_client_attr),
                               (const unsigned char *)csp->receive_buffer, (size_t)len,
@@ -3714,7 +3727,6 @@ static void handle_established_connection(struct client_state *csp)
                      {
                         log_error(LOG_LEVEL_CONNECT,
                            "Flush header and buffers to client failed");
-                        freez(hdr);
                         mark_server_socket_tainted(csp);
                         close_client_and_server_ssl_connections(csp);
                         return;
@@ -3723,26 +3735,43 @@ static void handle_established_connection(struct client_state *csp)
                   else
 #endif /* def FEATURE_HTTPS_INSPECTION */
                   {
-                     if (write_socket_delayed(csp->cfd, hdr, hdrlen, write_delay)
-                      || ((flushed = flush_iob(csp->cfd, csp->iob, write_delay)) < 0)
+                     if (((flushed = flush_iob(csp->cfd, csp->iob, write_delay)) < 0)
                       || write_socket_delayed(csp->cfd, csp->receive_buffer, (size_t)len,
                             write_delay))
                      {
                         log_error(LOG_LEVEL_CONNECT,
                            "Flush header and buffers to client failed: %E");
-                        freez(hdr);
                         mark_server_socket_tainted(csp);
                         return;
                      }
                   }
 
                   /*
-                   * Reset the byte_count to the amount of bytes
-                   * we just flushed. len will be added a few lines below,
-                   * hdrlen doesn't matter for LOG_LEVEL_CLF.
+                   * Reset the byte_count to the amount of bytes we just
+                   * flushed. len will be added a few lines below.
                    */
                   byte_count = (unsigned long long)flushed;
-                  freez(hdr);
+                  if ((csp->flags & CSP_FLAG_CHUNKED) && (chunk_offset != 0))
+                  {
+                     log_error(LOG_LEVEL_CONNECT,
+                        "Reducing chunk offset %lu by %ld to %lu.", chunk_offset, flushed,
+                        (chunk_offset - (unsigned)flushed));
+                     assert(chunk_offset >= flushed); /* XXX: Reachable with malicious input? */
+                     chunk_offset -= (unsigned)flushed;
+
+                     /* Make room in the iob. */
+                     csp->iob->cur = csp->iob->eod = csp->iob->buf;
+
+                     if (add_to_iob(csp->iob, csp->config->buffer_limit,
+                           csp->receive_buffer, len))
+                     {
+                        /* This is not supposed to happen but ... */
+                        csp->flags &= ~CSP_FLAG_CLIENT_CONNECTION_KEEP_ALIVE;
+                        log_error(LOG_LEVEL_ERROR, "Failed to buffer %ld bytes of "
+                           "chunk-encoded data after resetting the buffer.", len);
+                        return;
+                     }
+                  }
                   buffer_and_filter_content = 0;
                   server_body = 1;
                }
@@ -3778,8 +3807,66 @@ static void handle_established_connection(struct client_state *csp)
                      return;
                   }
                }
+               if (csp->flags & CSP_FLAG_CHUNKED)
+               {
+                  /*
+                   * While we don't need the data to filter it, put it in the
+                   * buffer so we can keep track of the offset to the start of
+                   * the next chunk and detect when the response is finished.
+                   */
+                  size_t encoded_bytes = (size_t)(csp->iob->eod - csp->iob->cur);
+
+                  if (csp->config->buffer_limit / 4 < encoded_bytes)
+                  {
+                     /*
+                      * Reset the buffer to reduce the memory footprint.
+                      */
+                     log_error(LOG_LEVEL_CONNECT,
+                        "Reducing the chunk offset from %lu to %lu after "
+                        "discarding %lu bytes to make room in the buffer.",
+                        chunk_offset, (chunk_offset - encoded_bytes),
+                        encoded_bytes);
+                     chunk_offset -= encoded_bytes;
+                     csp->iob->cur = csp->iob->eod = csp->iob->buf;
+                  }
+                  if (add_to_iob(csp->iob, csp->config->buffer_limit,
+                     csp->receive_buffer, len))
+                  {
+                     /* This is not supposed to happen but ... */
+                     csp->flags &= ~CSP_FLAG_CLIENT_CONNECTION_KEEP_ALIVE;
+                     log_error(LOG_LEVEL_ERROR,
+                        "Failed to buffer %ld bytes of chunk-encoded data.",
+                        len);
+                     return;
+                  }
+               }
             }
             byte_count += (unsigned long long)len;
+
+            if (csp->flags & CSP_FLAG_CHUNKED)
+            {
+               int rc;
+               size_t encoded_bytes = (size_t)(csp->iob->eod - csp->iob->cur);
+
+               rc = get_bytes_missing_from_chunked_data(csp->iob->cur, encoded_bytes,
+                  chunk_offset);
+               if (rc >= 0)
+               {
+                  if (rc != 0)
+                  {
+                     chunk_offset = (size_t)rc;
+                  }
+
+                  if (chunked_data_is_complete(csp->iob->cur, encoded_bytes, chunk_offset))
+                  {
+                     log_error(LOG_LEVEL_CONNECT,
+                        "We buffered the last chunk of the response.");
+                     csp->expected_content_length = byte_count;
+                     csp->flags |= CSP_FLAG_CONTENT_LENGTH_SET;
+                  }
+               }
+            }
+
             continue;
          }
          else
@@ -3978,26 +4065,32 @@ static void handle_established_connection(struct client_state *csp)
 #endif
                return;
             }
-            hdr = list_to_text(csp->headers);
-            if (hdr == NULL)
-            {
-               /* FIXME Should handle error properly */
-               log_error(LOG_LEVEL_FATAL, "Out of memory parsing server header");
-            }
 
             if ((csp->flags & CSP_FLAG_CHUNKED)
-               && !(csp->flags & CSP_FLAG_CONTENT_LENGTH_SET)
-               && ((csp->iob->eod - csp->iob->cur) >= 5)
-               && !memcmp(csp->iob->eod-5, "0\r\n\r\n", 5))
+               && !(csp->flags & CSP_FLAG_CONTENT_LENGTH_SET))
             {
-               log_error(LOG_LEVEL_CONNECT,
-                  "Looks like we got the last chunk together with "
-                  "the server headers. We better stop reading.");
-               byte_count = (unsigned long long)(csp->iob->eod - csp->iob->cur);
-               csp->expected_content_length = byte_count;
-               csp->flags |= CSP_FLAG_CONTENT_LENGTH_SET;
-            }
+               int rc;
+               size_t encoded_size = (size_t)(csp->iob->eod - csp->iob->cur);
 
+               rc = get_bytes_missing_from_chunked_data(csp->iob->cur, encoded_size,
+                  chunk_offset);
+               if (rc >= 0)
+               {
+                  if (rc != 0)
+                  {
+                     chunk_offset = (size_t)rc;
+                  }
+                  if (chunked_data_is_complete(csp->iob->cur, encoded_size, chunk_offset))
+                  {
+                     log_error(LOG_LEVEL_CONNECT,
+                        "Looks like we got the last chunk together with "
+                        "the server headers. We better stop reading.");
+                     byte_count = (unsigned long long)(csp->iob->eod - csp->iob->cur);
+                     csp->expected_content_length = byte_count;
+                     csp->flags |= CSP_FLAG_CONTENT_LENGTH_SET;
+                  }
+               }
+            }
             csp->server_connection.response_received = time(NULL);
 
             if (crunch_response_triggered(csp, crunchers_light))
@@ -4008,7 +4101,6 @@ static void handle_established_connection(struct client_state *csp)
                 * delivered the crunch response to the client
                 * and are done here after cleaning up.
                 */
-               freez(hdr);
                mark_server_socket_tainted(csp);
 #ifdef FEATURE_HTTPS_INSPECTION
                close_client_and_server_ssl_connections(csp);
@@ -4027,22 +4119,23 @@ static void handle_established_connection(struct client_state *csp)
                 * may be in the buffer). Use standard or secured
                 * connection.
                 */
+               if (send_server_headers(csp))
+               {
+                  return;
+               }
 #ifdef FEATURE_HTTPS_INSPECTION
                if (client_use_ssl(csp))
                {
-                  if ((ssl_send_data_delayed(&(csp->ssl_client_attr),
-                          (const unsigned char *)hdr, strlen(hdr),
-                          get_write_delay(csp)) < 0)
-                     || ((len = ssl_flush_socket(&(csp->ssl_client_attr),
-                            csp->iob)) < 0))
+                  if ((len = ssl_flush_socket(&(csp->ssl_client_attr),
+                           csp->iob)) < 0)
                   {
-                     log_error(LOG_LEVEL_CONNECT, "Write header to client failed");
+                     log_error(LOG_LEVEL_CONNECT,
+                        "Sending buffered bytes to the client failed");
 
                      /*
                       * The write failed, so don't bother mentioning it
                       * to the client... it probably can't hear us anyway.
                       */
-                     freez(hdr);
                      mark_server_socket_tainted(csp);
 #ifdef FEATURE_HTTPS_INSPECTION
                      close_client_and_server_ssl_connections(csp);
@@ -4053,25 +4146,48 @@ static void handle_established_connection(struct client_state *csp)
                else
 #endif /* def FEATURE_HTTPS_INSPECTION */
                {
-                  if (write_socket_delayed(csp->cfd, hdr, strlen(hdr), write_delay)
-                     || ((len = flush_iob(csp->cfd, csp->iob, write_delay)) < 0))
+                  if ((len = flush_iob(csp->cfd, csp->iob, write_delay)) < 0)
                   {
                      log_error(LOG_LEVEL_ERROR,
-                        "write header to client failed");
+                        "Sending buffered bytes to the client failed.");
                      /*
                       * The write failed, so don't bother mentioning it
                       * to the client... it probably can't hear us anyway.
                       */
-                     freez(hdr);
                      mark_server_socket_tainted(csp);
                      return;
                   }
+               }
+               if (csp->flags & CSP_FLAG_CHUNKED &&
+                 !(csp->flags & CSP_FLAG_CONTENT_LENGTH_SET))
+               {
+                  /*
+                   * In case of valid data we shouldn't flush more
+                   * data than chunk_offset but the data may be invalid.
+                   */
+                  if (chunk_offset >= len)
+                  {
+                     log_error(LOG_LEVEL_CONNECT,
+                        "Reducing chunk offset from %lu to %lu after flushing %ld bytes",
+                        chunk_offset, (chunk_offset - (unsigned)len), len);
+                     chunk_offset = chunk_offset - (unsigned)len;
+                  }
+                  else
+                  {
+                     log_error(LOG_LEVEL_CONNECT,
+                        "Keeping chunk offset at %lu despite flushing %ld bytes",
+                        chunk_offset, len);
+                     /*
+                      * If we can't parse the chunk-encoded data we should
+                      * not reuse the server connection.
+                      */
+                     mark_server_socket_tainted(csp);
+                  }
                }
                                }
 
             /* we're finished with the server's header */
 
-            freez(hdr);
             server_body = 1;
 
             /*