Increase socks5_connect()'s optimism
[privoxy.git] / gateway.c
index 0a77e04..60f2aa2 100644 (file)
--- a/gateway.c
+++ b/gateway.c
@@ -1,4 +1,4 @@
-const char gateway_rcs[] = "$Id: gateway.c,v 1.62 2009/09/22 11:35:52 fabiankeil Exp $";
+const char gateway_rcs[] = "$Id: gateway.c,v 1.93 2012/12/07 12:45:20 fabiankeil Exp $";
 /*********************************************************************
  *
  * File        :  $Source: /cvsroot/ijbswa/current/gateway.c,v $
@@ -66,9 +66,12 @@ const char gateway_rcs[] = "$Id: gateway.c,v 1.62 2009/09/22 11:35:52 fabiankeil
 #include "jbsockets.h"
 #include "gateway.h"
 #include "miscutil.h"
+#include "list.h"
+#include "parsers.h"
+
 #ifdef FEATURE_CONNECTION_KEEP_ALIVE
 #ifdef HAVE_POLL
-#ifdef __GLIBC__ 
+#ifdef __GLIBC__
 #include <sys/poll.h>
 #else
 #include <poll.h>
@@ -88,21 +91,24 @@ static jb_socket socks5_connect(const struct forward_spec *fwd,
                                 int target_port,
                                 struct client_state *csp);
 
+enum {
+   SOCKS4_REQUEST_GRANTED        =  90,
+   SOCKS4_REQUEST_REJECT         =  91,
+   SOCKS4_REQUEST_IDENT_FAILED   =  92,
+   SOCKS4_REQUEST_IDENT_CONFLICT =  93
+};
 
-#define SOCKS_REQUEST_GRANTED          90
-#define SOCKS_REQUEST_REJECT           91
-#define SOCKS_REQUEST_IDENT_FAILED     92
-#define SOCKS_REQUEST_IDENT_CONFLICT   93
-
-#define SOCKS5_REQUEST_GRANTED             0
-#define SOCKS5_REQUEST_FAILED              1
-#define SOCKS5_REQUEST_DENIED              2
-#define SOCKS5_REQUEST_NETWORK_UNREACHABLE 3
-#define SOCKS5_REQUEST_HOST_UNREACHABLE    4
-#define SOCKS5_REQUEST_CONNECTION_REFUSED  5
-#define SOCKS5_REQUEST_TTL_EXPIRED         6
-#define SOCKS5_REQUEST_PROTOCOL_ERROR      7
-#define SOCKS5_REQUEST_BAD_ADDRESS_TYPE    8
+enum {
+   SOCKS5_REQUEST_GRANTED             = 0,
+   SOCKS5_REQUEST_FAILED              = 1,
+   SOCKS5_REQUEST_DENIED              = 2,
+   SOCKS5_REQUEST_NETWORK_UNREACHABLE = 3,
+   SOCKS5_REQUEST_HOST_UNREACHABLE    = 4,
+   SOCKS5_REQUEST_CONNECTION_REFUSED  = 5,
+   SOCKS5_REQUEST_TTL_EXPIRED         = 6,
+   SOCKS5_REQUEST_PROTOCOL_ERROR      = 7,
+   SOCKS5_REQUEST_BAD_ADDRESS_TYPE    = 8
+};
 
 /* structure of a socks client operation */
 struct socks_op {
@@ -169,22 +175,20 @@ extern void initialize_reusable_connections(void)
  *
  * Function    :  remember_connection
  *
- * Description :  Remembers a connection for reuse later on.
+ * Description :  Remembers a server connection for reuse later on.
  *
  * Parameters  :
- *          1  :  csp = Current client state (buffers, headers, etc...)
- *          2  :  fwd = The forwarder settings used.
+ *          1  :  connection = The server connection to remember.
  *
  * Returns     : void
  *
  *********************************************************************/
-void remember_connection(const struct client_state *csp, const struct forward_spec *fwd)
+void remember_connection(const struct reusable_connection *connection)
 {
    unsigned int slot = 0;
    int free_slot_found = FALSE;
-   const struct reusable_connection *connection = &csp->server_connection;
-   const struct http_request *http = csp->http;
 
+   assert(NULL != connection);
    assert(connection->sfd != JB_INVALID_SOCKET);
 
    if (mark_connection_unused(connection))
@@ -202,7 +206,7 @@ void remember_connection(const struct client_state *csp, const struct forward_sp
          assert(reusable_connection[slot].in_use == 0);
          log_error(LOG_LEVEL_CONNECT,
             "Remembering socket %d for %s:%d in slot %d.",
-            connection->sfd, http->host, http->port, slot);
+            connection->sfd, connection->host, connection->port, slot);
          free_slot_found = TRUE;
          break;
       }
@@ -211,69 +215,56 @@ void remember_connection(const struct client_state *csp, const struct forward_sp
    if (!free_slot_found)
    {
       log_error(LOG_LEVEL_CONNECT,
-        "No free slots found to remembering socket for %s:%d. Last slot %d.",
-        http->host, http->port, slot);
+        "No free slots found to remember socket for %s:%d. Last slot %d.",
+        connection->host, connection->port, slot);
       privoxy_mutex_unlock(&connection_reuse_mutex);
       close_socket(connection->sfd);
       return;
    }
 
-   assert(NULL != http->host);
-   reusable_connection[slot].host = strdup(http->host);
-   if (NULL == reusable_connection[slot].host)
-   {
-      log_error(LOG_LEVEL_FATAL, "Out of memory saving socket.");
-   }
+   assert(NULL != connection->host);
+   reusable_connection[slot].host = strdup_or_die(connection->host);
    reusable_connection[slot].sfd = connection->sfd;
-   reusable_connection[slot].port = http->port;
+   reusable_connection[slot].port = connection->port;
    reusable_connection[slot].in_use = 0;
    reusable_connection[slot].timestamp = connection->timestamp;
-   reusable_connection->request_sent = connection->request_sent;
-   reusable_connection->response_received = connection->response_received;
+   reusable_connection[slot].request_sent = connection->request_sent;
+   reusable_connection[slot].response_received = connection->response_received;
    reusable_connection[slot].keep_alive_timeout = connection->keep_alive_timeout;
+   reusable_connection[slot].requests_sent_total = connection->requests_sent_total;
 
-   assert(NULL != fwd);
    assert(reusable_connection[slot].gateway_host == NULL);
    assert(reusable_connection[slot].gateway_port == 0);
    assert(reusable_connection[slot].forwarder_type == SOCKS_NONE);
    assert(reusable_connection[slot].forward_host == NULL);
    assert(reusable_connection[slot].forward_port == 0);
 
-   reusable_connection[slot].forwarder_type = fwd->type;
-   if (NULL != fwd->gateway_host)
+   reusable_connection[slot].forwarder_type = connection->forwarder_type;
+   if (NULL != connection->gateway_host)
    {
-      reusable_connection[slot].gateway_host = strdup(fwd->gateway_host);
-      if (NULL == reusable_connection[slot].gateway_host)
-      {
-         log_error(LOG_LEVEL_FATAL, "Out of memory saving gateway_host.");
-      }
+      reusable_connection[slot].gateway_host = strdup_or_die(connection->gateway_host);
    }
    else
    {
       reusable_connection[slot].gateway_host = NULL;
    }
-   reusable_connection[slot].gateway_port = fwd->gateway_port;
+   reusable_connection[slot].gateway_port = connection->gateway_port;
 
-   if (NULL != fwd->forward_host)
+   if (NULL != connection->forward_host)
    {
-      reusable_connection[slot].forward_host = strdup(fwd->forward_host);
-      if (NULL == reusable_connection[slot].forward_host)
-      {
-         log_error(LOG_LEVEL_FATAL, "Out of memory saving forward_host.");
-      }
+      reusable_connection[slot].forward_host = strdup_or_die(connection->forward_host);
    }
    else
    {
       reusable_connection[slot].forward_host = NULL;
    }
-   reusable_connection[slot].forward_port = fwd->forward_port;
+   reusable_connection[slot].forward_port = connection->forward_port;
 
    privoxy_mutex_unlock(&connection_reuse_mutex);
 }
 #endif /* def FEATURE_CONNECTION_SHARING */
 
 
-#ifdef FEATURE_CONNECTION_KEEP_ALIVE
 /*********************************************************************
  *
  * Function    :  mark_connection_closed
@@ -296,13 +287,13 @@ void mark_connection_closed(struct reusable_connection *closed_connection)
    closed_connection->request_sent = 0;
    closed_connection->response_received = 0;
    closed_connection->keep_alive_timeout = 0;
+   closed_connection->requests_sent_total = 0;
    closed_connection->forwarder_type = SOCKS_NONE;
    freez(closed_connection->gateway_host);
    closed_connection->gateway_port = 0;
    freez(closed_connection->forward_host);
    closed_connection->forward_port = 0;
 }
-#endif /* def FEATURE_CONNECTION_KEEP_ALIVE */
 
 
 #ifdef FEATURE_CONNECTION_SHARING
@@ -338,16 +329,12 @@ void forget_connection(jb_socket sfd)
             sfd, reusable_connection[slot].host,
             reusable_connection[slot].port, slot);
          mark_connection_closed(&reusable_connection[slot]);
-         privoxy_mutex_unlock(&connection_reuse_mutex);
-
-         return;
+         break;
       }
    }
 
-   log_error(LOG_LEVEL_CONNECT,
-      "Socket %d already forgotten or never remembered.", sfd);
-
    privoxy_mutex_unlock(&connection_reuse_mutex);
+
 }
 #endif /* def FEATURE_CONNECTION_SHARING */
 
@@ -386,7 +373,9 @@ int connection_destination_matches(const struct reusable_connection *connection,
          && strcmpic(connection->gateway_host, fwd->gateway_host))
        && (connection->gateway_host != fwd->gateway_host))
    {
-      log_error(LOG_LEVEL_CONNECT, "Gateway mismatch.");
+      log_error(LOG_LEVEL_CONNECT,
+         "Gateway mismatch. Previous gateway: %s. Current gateway: %s",
+         connection->gateway_host, fwd->gateway_host);
       return FALSE;
    }
 
@@ -395,7 +384,9 @@ int connection_destination_matches(const struct reusable_connection *connection,
          && strcmpic(connection->forward_host, fwd->forward_host))
       && (connection->forward_host != fwd->forward_host))
    {
-      log_error(LOG_LEVEL_CONNECT, "Forwarding proxy mismatch.");
+      log_error(LOG_LEVEL_CONNECT,
+         "Forwarding proxy mismatch. Previous proxy: %s. Current proxy: %s",
+         connection->forward_host, fwd->forward_host);
       return FALSE;
    }
 
@@ -447,7 +438,7 @@ int close_unusable_connections(void)
             close_socket(reusable_connection[slot].sfd);
             mark_connection_closed(&reusable_connection[slot]);
          }
-         else if (!socket_is_still_usable(reusable_connection[slot].sfd))
+         else if (!socket_is_still_alive(reusable_connection[slot].sfd))
          {
             log_error(LOG_LEVEL_CONNECT,
                "The connection to %s:%d in slot %d is no longer usable. "
@@ -506,13 +497,14 @@ static jb_socket get_reusable_connection(const struct http_request *http,
             reusable_connection[slot].in_use = TRUE;
             sfd = reusable_connection[slot].sfd;
             log_error(LOG_LEVEL_CONNECT,
-               "Found reusable socket %d for %s:%d in slot %d. "
-               "Timestamp made %d seconds ago. Timeout: %d. Latency: %d.",
+               "Found reusable socket %d for %s:%d in slot %d. Timestamp made %d "
+               "seconds ago. Timeout: %d. Latency: %d. Requests served: %d",
                sfd, reusable_connection[slot].host, reusable_connection[slot].port,
                slot, time(NULL) - reusable_connection[slot].timestamp,
                reusable_connection[slot].keep_alive_timeout,
                (int)(reusable_connection[slot].response_received -
-               reusable_connection[slot].request_sent));
+               reusable_connection[slot].request_sent),
+               reusable_connection[slot].requests_sent_total);
             break;
          }
       }
@@ -650,12 +642,13 @@ jb_socket forwarded_connect(const struct forward_spec * fwd,
          sfd = socks4_connect(fwd, dest_host, dest_port, csp);
          break;
       case SOCKS_5:
+      case SOCKS_5T:
          sfd = socks5_connect(fwd, dest_host, dest_port, csp);
          break;
       default:
          /* Should never get here */
          log_error(LOG_LEVEL_FATAL,
-            "SOCKS4 impossible internal error - bad SOCKS type.");
+            "Internal error in forwarded_connect(). Bad proxy type: %d", fwd->type);
    }
 
    if (JB_INVALID_SOCKET != sfd)
@@ -724,7 +717,7 @@ static jb_socket socks4_connect(const struct forward_spec * fwd,
    if (err)
    {
       log_error(LOG_LEVEL_CONNECT, "socks4_connect: %s", errstr);
-      csp->error_message = strdup(errstr); 
+      csp->error_message = strdup(errstr);
       errno = EINVAL;
       return(JB_INVALID_SOCKET);
    }
@@ -793,24 +786,20 @@ static jb_socket socks4_connect(const struct forward_spec * fwd,
 
    c->vn          = 4;
    c->cd          = 1;
-   c->dstport[0]  = (unsigned char)((target_port       >> 8  ) & 0xff);
-   c->dstport[1]  = (unsigned char)((target_port             ) & 0xff);
-   c->dstip[0]    = (unsigned char)((web_server_addr   >> 24 ) & 0xff);
-   c->dstip[1]    = (unsigned char)((web_server_addr   >> 16 ) & 0xff);
-   c->dstip[2]    = (unsigned char)((web_server_addr   >>  8 ) & 0xff);
-   c->dstip[3]    = (unsigned char)((web_server_addr         ) & 0xff);
+   c->dstport[0]  = (unsigned char)((target_port       >> 8 ) & 0xff);
+   c->dstport[1]  = (unsigned char)((target_port            ) & 0xff);
+   c->dstip[0]    = (unsigned char)((web_server_addr   >> 24) & 0xff);
+   c->dstip[1]    = (unsigned char)((web_server_addr   >> 16) & 0xff);
+   c->dstip[2]    = (unsigned char)((web_server_addr   >>  8) & 0xff);
+   c->dstip[3]    = (unsigned char)((web_server_addr        ) & 0xff);
 
    /* pass the request to the socks server */
    sfd = connect_to(fwd->gateway_host, fwd->gateway_port, csp);
 
    if (sfd == JB_INVALID_SOCKET)
    {
-      /*
-       * XXX: connect_to should fill in the exact reason.
-       * Most likely resolving the IP of the forwarder failed.
-       */
-      errstr = "connect_to failed: see logfile for details";
-      err = 1;
+      /* The error an its reason have already been logged by connect_to()  */
+      return(JB_INVALID_SOCKET);
    }
    else if (write_socket(sfd, (char *)c, csiz))
    {
@@ -819,6 +808,20 @@ static jb_socket socks4_connect(const struct forward_spec * fwd,
       err = 1;
       close_socket(sfd);
    }
+   else if (!data_is_available(sfd, csp->config->socket_timeout))
+   {
+      if (socket_is_still_alive(sfd))
+      {
+         errstr = "SOCKS4 negotiation timed out";
+      }
+      else
+      {
+         errstr = "SOCKS4 negotiation got aborted by the server";
+      }
+      log_error(LOG_LEVEL_CONNECT, "socks4_connect: %s", errstr);
+      err = 1;
+      close_socket(sfd);
+   }
    else if (read_socket(sfd, buf, sizeof(buf)) != sizeof(*s))
    {
       errstr = "SOCKS4 negotiation read failed.";
@@ -829,24 +832,24 @@ static jb_socket socks4_connect(const struct forward_spec * fwd,
 
    if (err)
    {
-      csp->error_message = strdup(errstr);      
+      csp->error_message = strdup(errstr);
       return(JB_INVALID_SOCKET);
    }
 
    switch (s->cd)
    {
-      case SOCKS_REQUEST_GRANTED:
+      case SOCKS4_REQUEST_GRANTED:
          return(sfd);
-      case SOCKS_REQUEST_REJECT:
+      case SOCKS4_REQUEST_REJECT:
          errstr = "SOCKS request rejected or failed.";
          errno = EINVAL;
          break;
-      case SOCKS_REQUEST_IDENT_FAILED:
+      case SOCKS4_REQUEST_IDENT_FAILED:
          errstr = "SOCKS request rejected because "
             "SOCKS server cannot connect to identd on the client.";
          errno = EACCES;
          break;
-      case SOCKS_REQUEST_IDENT_CONFLICT:
+      case SOCKS4_REQUEST_IDENT_CONFLICT:
          errstr = "SOCKS request rejected because "
             "the client program and identd report "
             "different user-ids.";
@@ -933,7 +936,7 @@ static jb_socket socks5_connect(const struct forward_spec *fwd,
 {
    int err = 0;
    char cbuf[300];
-   char sbuf[30];
+   char sbuf[10];
    size_t client_pos = 0;
    int server_size = 0;
    size_t hostlen = 0;
@@ -965,7 +968,7 @@ static jb_socket socks5_connect(const struct forward_spec *fwd,
       err = 1;
    }
 
-   if (fwd->type != SOCKS_5)
+   if ((fwd->type != SOCKS_5) && (fwd->type != SOCKS_5T))
    {
       /* Should never get here */
       log_error(LOG_LEVEL_FATAL,
@@ -989,6 +992,8 @@ static jb_socket socks5_connect(const struct forward_spec *fwd,
    {
       errstr = "socks5 server unreachable";
       log_error(LOG_LEVEL_CONNECT, "socks5_connect: %s", errstr);
+      /* Free the generic error message provided by connect_to() */
+      freez(csp->error_message);
       csp->error_message = strdup(errstr);
       return(JB_INVALID_SOCKET);
    }
@@ -1007,7 +1012,20 @@ static jb_socket socks5_connect(const struct forward_spec *fwd,
       return(JB_INVALID_SOCKET);
    }
 
-   if (read_socket(sfd, sbuf, sizeof(sbuf)) != 2)
+   if (!data_is_available(sfd, csp->config->socket_timeout))
+   {
+      if (socket_is_still_alive(sfd))
+      {
+         errstr = "SOCKS5 negotiation timed out";
+      }
+      else
+      {
+         errstr = "SOCKS5 negotiation got aborted by the server";
+      }
+      err = 1;
+   }
+
+   if (!err && read_socket(sfd, sbuf, sizeof(sbuf)) != 2)
    {
       errstr = "SOCKS5 negotiation read failed";
       err = 1;
@@ -1056,7 +1074,7 @@ static jb_socket socks5_connect(const struct forward_spec *fwd,
 
    if (write_socket(sfd, cbuf, client_pos))
    {
-      errstr = "SOCKS5 negotiation read failed";
+      errstr = "SOCKS5 negotiation write failed";
       csp->error_message = strdup(errstr);
       log_error(LOG_LEVEL_CONNECT, "%s", errstr);
       close_socket(sfd);
@@ -1064,39 +1082,80 @@ static jb_socket socks5_connect(const struct forward_spec *fwd,
       return(JB_INVALID_SOCKET);
    }
 
-   server_size = read_socket(sfd, sbuf, sizeof(sbuf));
-   if (server_size < 3)
-   {
-      errstr = "SOCKS5 negotiation read failed";
-      err = 1;
-   }
-   else if (server_size > 20)
+   /*
+    * Optimistically send the HTTP request with the initial
+    * SOCKS request if the user enabled the use of Tor extensions,
+    * the CONNECT method isn't being used (in which case the client
+    * doesn't send data until it gets our 200 response) and the
+    * client request has actually been completely read already.
+    */
+   if ((fwd->type == SOCKS_5T) && (csp->http->ssl == 0)
+      && (csp->flags & CSP_FLAG_CLIENT_REQUEST_COMPLETELY_READ))
    {
-      /* This is somewhat unexpected but doesn't realy matter. */
-      log_error(LOG_LEVEL_CONNECT, "socks5_connect: read %d bytes "
-         "from socks server. Would have accepted up to %d.",
-         server_size, sizeof(sbuf));
-   }
+      char *client_headers = list_to_text(csp->headers);
+      size_t header_length;
 
-   if (!err && (sbuf[0] != '\x05'))
-   {
-      errstr = "SOCKS5 negotiation protocol version error";
-      err = 1;
+      if (client_headers == NULL)
+      {
+         log_error(LOG_LEVEL_FATAL, "Out of memory rebuilding client headers");
+      }
+      list_remove_all(csp->headers);
+      header_length= strlen(client_headers);
+
+      log_error(LOG_LEVEL_CONNECT,
+         "Optimistically sending %d bytes of client headers intended for %s",
+         header_length, csp->http->hostport);
+
+      if (write_socket(sfd, client_headers, header_length))
+      {
+         log_error(LOG_LEVEL_CONNECT,
+            "optimistically writing header to: %s failed: %E", csp->http->hostport);
+         freez(client_headers);
+         return(JB_INVALID_SOCKET);
+      }
+      freez(client_headers);
+      if (csp->expected_client_content_length != 0)
+      {
+         unsigned long long buffered_request_bytes =
+            (unsigned long long)(csp->client_iob->eod - csp->client_iob->cur);
+         log_error(LOG_LEVEL_CONNECT,
+            "Optimistically sending %d bytes of client body. Expected %d",
+            csp->expected_client_content_length, buffered_request_bytes);
+         assert(csp->expected_client_content_length == buffered_request_bytes);
+         if (write_socket(sfd, csp->client_iob->cur, buffered_request_bytes))
+         {
+            log_error(LOG_LEVEL_CONNECT,
+               "optimistically writing %d bytes of client body to: %s failed: %E",
+               buffered_request_bytes, csp->http->hostport);
+            return(JB_INVALID_SOCKET);
+         }
+         clear_iob(csp->client_iob);
+      }
    }
 
-   if (!err && (sbuf[2] != '\x00'))
+   server_size = read_socket(sfd, sbuf, sizeof(sbuf));
+   if (server_size != sizeof(sbuf))
    {
-      errstr = "SOCKS5 negotiation protocol error";
-      err = 1;
+      errstr = "SOCKS5 negotiation read failed";
    }
-
-   if (!err)
+   else
    {
-      if (sbuf[1] == SOCKS5_REQUEST_GRANTED)
+      if (sbuf[0] != '\x05')
+      {
+         errstr = "SOCKS5 negotiation protocol version error";
+      }
+      else if (sbuf[2] != '\x00')
+      {
+         errstr = "SOCKS5 negotiation protocol error";
+      }
+      else if (sbuf[1] != SOCKS5_REQUEST_GRANTED)
+      {
+         errstr = translate_socks5_error(sbuf[1]);
+      }
+      else
       {
          return(sfd);
       }
-      errstr = translate_socks5_error(sbuf[1]);
    }
 
    assert(errstr != NULL);