X-Git-Url: http://www.privoxy.org/gitweb/?p=privoxy.git;a=blobdiff_plain;f=jcc.c;h=07f97de0c41b620b6d8c65bedf3783e051fc547c;hp=b464e46a1d7c7de6892ce3b52c58198da08aa716;hb=bf18b40dd30e0c16392285408cad379c2ead11d7;hpb=a4265a23c9c238d4510ed001fea7301178c68e8a diff --git a/jcc.c b/jcc.c index b464e46a..07f97de0 100644 --- a/jcc.c +++ b/jcc.c @@ -1,4 +1,4 @@ -const char jcc_rcs[] = "$Id: jcc.c,v 1.206 2008/11/23 17:00:11 fabiankeil Exp $"; +const char jcc_rcs[] = "$Id: jcc.c,v 1.229 2009/03/07 11:17:01 fabiankeil Exp $"; /********************************************************************* * * File : $Source: /cvsroot/ijbswa/current/jcc.c,v $ @@ -6,7 +6,7 @@ const char jcc_rcs[] = "$Id: jcc.c,v 1.206 2008/11/23 17:00:11 fabiankeil Exp $" * Purpose : Main file. Contains main() method, main loop, and * the main connection-handling function. * - * Copyright : Written by and Copyright (C) 2001-2008 the SourceForge + * Copyright : Written by and Copyright (C) 2001-2009 the SourceForge * Privoxy team. http://www.privoxy.org/ * * Based on the Internet Junkbuster originally written @@ -33,6 +33,100 @@ const char jcc_rcs[] = "$Id: jcc.c,v 1.206 2008/11/23 17:00:11 fabiankeil Exp $" * * Revisions : * $Log: jcc.c,v $ + * Revision 1.229 2009/03/07 11:17:01 fabiankeil + * Fix compiler warning. + * + * Revision 1.228 2009/03/06 20:30:13 fabiankeil + * Log unsigned values as such. + * + * Revision 1.227 2009/03/02 19:18:11 fabiankeil + * Streamline parse_http_request()'s prototype. As + * cparser pointed out it doesn't actually use csp. + * + * Revision 1.226 2009/03/01 18:28:24 fabiankeil + * Help clang understand that we aren't dereferencing + * NULL pointers here. + * + * Revision 1.225 2009/02/19 18:09:32 fabiankeil + * Unbreak build without FEATURE_CONNECTION_KEEP_ALIVE. + * Noticed by David. + * + * Revision 1.224 2009/02/14 15:32:04 fabiankeil + * Add the request URL to the timeout message in chat(). + * Suggested by Lee. + * + * Revision 1.223 2009/02/09 21:21:16 fabiankeil + * Now that init_log_module() is called earlier, call show_version() + * later on from main() directly so it doesn't get called for --help + * or --version. + * + * Revision 1.222 2009/02/08 12:56:51 fabiankeil + * Call initialize_mutexes() before init_log_module() again. + * Broken since r220, might be the cause of Lee's #2579448. + * + * Revision 1.221 2009/02/06 18:02:58 fabiankeil + * When dropping privileges, also give up membership in supplementary + * groups. Thanks to Matthias Drochner for reporting the problem, + * providing the initial patch and testing the final version. + * + * Revision 1.220 2009/02/04 18:29:07 fabiankeil + * Initialize the log module before parsing arguments. + * Thanks to Matthias Drochner for the report. + * + * Revision 1.219 2009/01/31 16:08:21 fabiankeil + * Remove redundant error check in receive_client_request(). + * + * Revision 1.218 2009/01/31 12:25:54 fabiankeil + * Flatten indentation in receive_client_request(). + * + * Revision 1.217 2009/01/07 19:50:09 fabiankeil + * - If the socket-timeout has been reached and the client + * hasn't received any data yet, send an explanation before + * closing the connection. + * - In get_request_line(), signal timeouts the right way. + * + * Revision 1.216 2008/12/24 22:13:11 ler762 + * fix GCC 3.4.4 warning + * + * Revision 1.215 2008/12/24 17:06:19 fabiankeil + * Keep a thread around to timeout alive connections + * even if no new requests are coming in. + * + * Revision 1.214 2008/12/20 14:53:55 fabiankeil + * Add config option socket-timeout to control the time + * Privoxy waits for data to arrive on a socket. Useful + * in case of stale ssh tunnels or when fuzz-testing. + * + * Revision 1.213 2008/12/15 18:45:51 fabiankeil + * When logging crunches, log the whole URL, so one can easily + * differentiate between vanilla HTTP and CONNECT requests. + * + * Revision 1.212 2008/12/14 15:46:22 fabiankeil + * Give crunched requests their own log level. + * + * Revision 1.211 2008/12/06 10:05:03 fabiankeil + * Downgrade "Received x bytes while expecting y." message to + * LOG_LEVEL_CONNECT as it doesn't necessarily indicate an error. + * + * Revision 1.210 2008/12/02 22:03:18 fabiankeil + * Don't miscalculate byte_count if we don't get all the + * server headers with one read_socket() call. With keep-alive + * support enabled, this caused delays until the server closed + * the connection. + * + * Revision 1.209 2008/11/27 09:44:04 fabiankeil + * Cosmetics for the last commit: Don't watch out for + * the last chunk if the content isn't chunk-encoded or + * if we already determined the content length previously. + * + * Revision 1.208 2008/11/26 18:24:17 fabiankeil + * Recognize that the server response is complete if the + * last chunk is read together with the server headers. + * Reported by Lee. + * + * Revision 1.207 2008/11/25 17:25:16 fabiankeil + * Don't convert the client-header list to text until we need to. + * * Revision 1.206 2008/11/23 17:00:11 fabiankeil * Some more chat() cosmetics. * @@ -1349,6 +1443,14 @@ static const char MESSED_UP_REQUEST_RESPONSE[] = "Connection: close\r\n\r\n" "Bad request. Messed up with header filters.\r\n"; +/* XXX: should be a template */ +static const char CONNECTION_TIMEOUT_RESPONSE[] = + "HTTP/1.0 502 Connection timeout\r\n" + "Proxy-Agent: Privoxy " VERSION "\r\n" + "Content-Type: text/plain\r\n" + "Connection: close\r\n\r\n" + "The connection timed out.\r\n"; + /* A function to crunch a response */ typedef struct http_response *(*crunch_func_ptr)(struct client_state *); @@ -1798,9 +1900,8 @@ static void send_crunch_response(const struct client_state *csp, struct http_res } /* Log that the request was crunched and why. */ - log_error(LOG_LEVEL_GPC, "%s%s crunch! (%s)", - http->hostport, http->path, crunch_reason(rsp)); - log_error(LOG_LEVEL_CLF, "%s - - [%T] \"%s\" %s %d", + 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); /* Clean up and return */ @@ -1857,7 +1958,7 @@ static int request_contains_null_bytes(const struct client_state *csp, char *buf } while (tmp_len < len); log_error(LOG_LEVEL_ERROR, "%s\'s request contains at least one NULL byte " - "(length=%d, strlen=%d).", csp->ip_addr_str, len, c_len); + "(length=%d, strlen=%u).", csp->ip_addr_str, len, c_len); log_error(LOG_LEVEL_HEADER, "Offending request data with NULL bytes turned into \'°\' characters: %s", buf); @@ -2026,7 +2127,7 @@ static jb_err change_request_destination(struct client_state *csp) log_error(LOG_LEVEL_INFO, "Rewrite detected: %s", csp->headers->first->str); free_http_request(http); - err = parse_http_request(csp->headers->first->str, http, csp); + err = parse_http_request(csp->headers->first->str, http); if (JB_ERR_OK != err) { log_error(LOG_LEVEL_ERROR, "Couldn't parse rewritten request: %s.", @@ -2063,9 +2164,10 @@ static jb_err change_request_destination(struct client_state *csp) * FALSE otherwise. * *********************************************************************/ -static int server_response_is_complete(struct client_state *csp, size_t content_length) +static int server_response_is_complete(struct client_state *csp, + unsigned long long content_length) { - int content_length_known = (csp->flags & CSP_FLAG_CONTENT_LENGTH_SET); + int content_length_known = !!(csp->flags & CSP_FLAG_CONTENT_LENGTH_SET); if (!strcmpic(csp->http->gpc, "HEAD")) { @@ -2089,8 +2191,38 @@ static int server_response_is_complete(struct client_state *csp, size_t content_ return (content_length_known && ((0 == csp->expected_content_length) || (csp->expected_content_length <= content_length))); } + + +/********************************************************************* + * + * Function : wait_for_alive_connections + * + * Description : Waits for alive connections to timeout. + * + * Parameters : N/A + * + * Returns : N/A + * + *********************************************************************/ +static void wait_for_alive_connections() +{ + int connections_alive = close_unusable_connections(); + + while (0 < connections_alive) + { + log_error(LOG_LEVEL_CONNECT, + "Waiting for %d connections to timeout.", + connections_alive); + sleep(60); + connections_alive = close_unusable_connections(); + } + + log_error(LOG_LEVEL_CONNECT, "No connections to wait for left."); + +} #endif /* FEATURE_CONNECTION_KEEP_ALIVE */ + /********************************************************************* * * Function : mark_server_socket_tainted @@ -2136,6 +2268,15 @@ static char *get_request_line(struct client_state *csp) do { + if (!data_is_available(csp->cfd, csp->config->socket_timeout)) + { + log_error(LOG_LEVEL_ERROR, + "Stopped waiting for the request line."); + write_socket(csp->cfd, CONNECTION_TIMEOUT_RESPONSE, + strlen(CONNECTION_TIMEOUT_RESPONSE)); + return NULL; + } + len = read_socket(csp->cfd, buf, sizeof(buf) - 1); if (len <= 0) return NULL; @@ -2193,58 +2334,48 @@ static jb_err receive_client_request(struct client_state *csp) memset(buf, 0, sizeof(buf)); req = get_request_line(csp); - - if ((NULL != req) && ('\0' != *req)) + if (req == NULL) { - /* Request received. Validate and parse it. */ + return JB_ERR_PARSE; + } + assert(*req != '\0'); - /* Does the request line look invalid? */ - if (client_protocol_is_unsupported(csp, req)) - { - /* - * Yes. The request has already been - * answered with a error response, the buffers - * were freed and we're done with chatting. - */ - return JB_ERR_PARSE; - } + if (client_protocol_is_unsupported(csp, req)) + { + return JB_ERR_PARSE; + } #ifdef FEATURE_FORCE_LOAD - /* - * If this request contains the FORCE_PREFIX and blocks - * aren't enforced, get rid of it and set the force flag. - */ - if (strstr(req, FORCE_PREFIX)) + /* + * If this request contains the FORCE_PREFIX and blocks + * aren't enforced, get rid of it and set the force flag. + */ + if (strstr(req, FORCE_PREFIX)) + { + if (csp->config->feature_flags & RUNTIME_FEATURE_ENFORCE_BLOCKS) { - if (csp->config->feature_flags & RUNTIME_FEATURE_ENFORCE_BLOCKS) - { - log_error(LOG_LEVEL_FORCE, - "Ignored force prefix in request: \"%s\".", req); - } - else - { - strclean(req, FORCE_PREFIX); - log_error(LOG_LEVEL_FORCE, "Enforcing request: \"%s\".", req); - csp->flags |= CSP_FLAG_FORCED; - } + log_error(LOG_LEVEL_FORCE, + "Ignored force prefix in request: \"%s\".", req); } -#endif /* def FEATURE_FORCE_LOAD */ - - err = parse_http_request(req, http, csp); - if (JB_ERR_OK != err) + else { - log_error(LOG_LEVEL_ERROR, "Couldn't parse request: %s.", jb_err_to_string(err)); + strclean(req, FORCE_PREFIX); + log_error(LOG_LEVEL_FORCE, "Enforcing request: \"%s\".", req); + csp->flags |= CSP_FLAG_FORCED; } - - freez(req); } +#endif /* def FEATURE_FORCE_LOAD */ - if (http->cmd == NULL) + err = parse_http_request(req, http); + freez(req); + if (JB_ERR_OK != err) { write_socket(csp->cfd, CHEADER, strlen(CHEADER)); /* XXX: Use correct size */ log_error(LOG_LEVEL_CLF, "%s - - [%T] \"Invalid request\" 400 0", csp->ip_addr_str); - log_error(LOG_LEVEL_ERROR, "Invalid header received from %s.", csp->ip_addr_str); + log_error(LOG_LEVEL_ERROR, + "Couldn't parse request line received from %s: %s", + csp->ip_addr_str, jb_err_to_string(err)); free_http_request(http); return JB_ERR_PARSE; @@ -2268,6 +2399,13 @@ static jb_err receive_client_request(struct client_state *csp) * We didn't receive a complete header * line yet, get the rest of it. */ + if (!data_is_available(csp->cfd, csp->config->socket_timeout)) + { + log_error(LOG_LEVEL_ERROR, + "Stopped grabbing the client headers."); + return JB_ERR_PARSE; + } + len = read_socket(csp->cfd, buf, sizeof(buf) - 1); if (len <= 0) { @@ -2437,20 +2575,23 @@ static void chat(struct client_state *csp) jb_socket maxfd; int server_body; int ms_iis5_hack = 0; - size_t byte_count = 0; + unsigned long long byte_count = 0; int forwarded_connect_retries = 0; int max_forwarded_connect_retries = csp->config->forwarded_connect_retries; const struct forward_spec *fwd; struct http_request *http; - int len; /* for buffer sizes (and negative error codes) */ + int len = 0; /* for buffer sizes (and negative error codes) */ /* Function that does the content filtering for the current request */ filter_function_ptr content_filter = NULL; /* Skeleton for HTTP response, if we should intercept the request */ struct http_response *rsp; + struct timeval timeout; memset(buf, 0, sizeof(buf)); + memset(&timeout, 0, sizeof(timeout)); + timeout.tv_sec = csp->config->socket_timeout; http = csp->http; @@ -2469,6 +2610,7 @@ static void chat(struct client_state *csp) { log_error(LOG_LEVEL_FATAL, "gateway spec is NULL!?!? This can't happen!"); /* Never get here - LOG_LEVEL_FATAL causes program exit */ + return; } /* @@ -2664,11 +2806,23 @@ static void chat(struct client_state *csp) FD_SET(csp->sfd, &rfds); #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)) + { + log_error(LOG_LEVEL_CONNECT, + "Looks like we read 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; + } if (server_body && server_response_is_complete(csp, byte_count)) { log_error(LOG_LEVEL_CONNECT, - "Done reading from server. Expected content length: %d. " - "Actual content length: %d. Most recently received: %d.", + "Done reading from server. Expected content length: %llu. " + "Actual content length: %llu. Most recently received: %d.", csp->expected_content_length, byte_count, len); len = 0; /* @@ -2679,9 +2833,21 @@ static void chat(struct client_state *csp) } #endif /* FEATURE_CONNECTION_KEEP_ALIVE */ - n = select((int)maxfd+1, &rfds, NULL, NULL, NULL); + n = select((int)maxfd+1, &rfds, NULL, NULL, &timeout); - if (n < 0) + if (n == 0) + { + log_error(LOG_LEVEL_ERROR, + "Didn't receive data in time: %s", http->url); + if ((byte_count == 0) && (http->ssl == 0)) + { + write_socket(csp->cfd, CONNECTION_TIMEOUT_RESPONSE, + strlen(CONNECTION_TIMEOUT_RESPONSE)); + } + mark_server_socket_tainted(csp); + return; + } + else if (n < 0) { log_error(LOG_LEVEL_ERROR, "select() failed!: %E"); mark_server_socket_tainted(csp); @@ -2770,7 +2936,7 @@ static void chat(struct client_state *csp) 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 + (size_t)len; + csp->expected_content_length = byte_count + (unsigned long long)len; csp->flags |= CSP_FLAG_CONTENT_LENGTH_SET; } } @@ -2839,7 +3005,8 @@ static void chat(struct client_state *csp) } if (write_socket(csp->cfd, hdr, strlen(hdr)) - || write_socket(csp->cfd, p != NULL ? p : csp->iob->cur, csp->content_length)) + || write_socket(csp->cfd, + ((p != NULL) ? p : csp->iob->cur), (size_t)csp->content_length)) { log_error(LOG_LEVEL_ERROR, "write modified content to client failed: %E"); freez(hdr); @@ -2923,7 +3090,7 @@ static void chat(struct client_state *csp) * we just flushed. len will be added a few lines below, * hdrlen doesn't matter for LOG_LEVEL_CLF. */ - byte_count = (size_t)flushed; + byte_count = (unsigned long long)flushed; freez(hdr); content_filter = NULL; server_body = 1; @@ -2938,7 +3105,7 @@ static void chat(struct client_state *csp) return; } } - byte_count += (size_t)len; + byte_count += (unsigned long long)len; continue; } else @@ -2980,6 +3147,12 @@ static void chat(struct client_state *csp) * Since we have to wait for more from the server before * we can parse the headers we just continue here. */ + int header_offset = csp->iob->cur - header_start; + assert(csp->iob->cur >= header_start); + byte_count += (unsigned long long)(len - header_offset); + log_error(LOG_LEVEL_CONNECT, "Continuing buffering headers. " + "byte_count: %llu. header_offset: %d. len: %d.", + byte_count, header_offset, len); continue; } } @@ -3078,7 +3251,7 @@ static void chat(struct client_state *csp) return; } - byte_count += (size_t)len; + byte_count += (unsigned long long)len; } else { @@ -3088,7 +3261,7 @@ static void chat(struct client_state *csp) */ int header_length = csp->iob->cur - header_start; assert(csp->iob->cur > header_start); - byte_count += (size_t)(len - header_length); + byte_count += (unsigned long long)(len - header_length); } /* we're finished with the server's header */ @@ -3123,16 +3296,18 @@ static void chat(struct client_state *csp) csp->content_length = byte_count; } +#ifdef FEATURE_CONNECTION_KEEP_ALIVE if ((csp->flags & CSP_FLAG_CONTENT_LENGTH_SET) && (csp->expected_content_length != byte_count)) { - log_error(LOG_LEVEL_ERROR, - "Received %d bytes while expecting %d.", + log_error(LOG_LEVEL_CONNECT, + "Received %llu bytes while expecting %llu.", byte_count, csp->expected_content_length); mark_server_socket_tainted(csp); } +#endif - log_error(LOG_LEVEL_CLF, "%s - - [%T] \"%s\" 200 %d", + log_error(LOG_LEVEL_CLF, "%s - - [%T] \"%s\" 200 %llu", csp->ip_addr_str, http->ocmd, csp->content_length); } @@ -3162,10 +3337,22 @@ static void serve(struct client_state *csp) if (csp->sfd != JB_INVALID_SOCKET) { #ifdef FEATURE_CONNECTION_KEEP_ALIVE + static int monitor_thread_running = 0; + if ((csp->config->feature_flags & RUNTIME_FEATURE_CONNECTION_KEEP_ALIVE) && (csp->flags & CSP_FLAG_SERVER_CONNECTION_KEEP_ALIVE)) { remember_connection(csp->sfd, csp->http, forward_url(csp, csp->http)); + privoxy_mutex_lock(&connection_reuse_mutex); + if (!monitor_thread_running) + { + monitor_thread_running = 1; + privoxy_mutex_unlock(&connection_reuse_mutex); + wait_for_alive_connections(); + privoxy_mutex_lock(&connection_reuse_mutex); + monitor_thread_running = 0; + } + privoxy_mutex_unlock(&connection_reuse_mutex); } else { @@ -3428,6 +3615,12 @@ int main(int argc, const char *argv[]) #endif ; + /* Prepare mutexes if supported and necessary. */ + initialize_mutexes(); + + /* Enable logging until further notice. */ + init_log_module(); + /* * Parse the command line arguments * @@ -3539,6 +3732,8 @@ int main(int argc, const char *argv[]) } /* -END- while (more arguments) */ + show_version(Argv[0]); + #if defined(unix) if ( *configfile != '/' ) { @@ -3581,12 +3776,6 @@ int main(int argc, const char *argv[]) InitWin32(); #endif - /* Prepare mutexes if supported and necessary. */ - initialize_mutexes(); - - /* Enable logging until further notice. */ - init_log_module(Argv[0]); - random_seed = (unsigned int)time(NULL); #ifdef HAVE_RANDOM srandom(random_seed); @@ -3720,6 +3909,17 @@ int main(int argc, const char *argv[]) { log_error(LOG_LEVEL_FATAL, "Cannot setgid(): Insufficient permissions."); } + if (NULL != grp) + { + if (setgroups(1, &grp->gr_gid)) + { + log_error(LOG_LEVEL_FATAL, "setgroups() failed: %E"); + } + } + else if (initgroups(pw->pw_name, pw->pw_gid)) + { + log_error(LOG_LEVEL_FATAL, "initgroups() failed: %E"); + } if (do_chroot) { if (!pw->pw_dir)