From: Amos Jeffries Date: Fri, 2 Sep 2011 12:35:57 +0000 (+1200) Subject: Bug 3319: Inconsistencies in error messages pt2 X-Git-Tag: take08~33^2 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=48e7baac8b556ff8d6c8218d27fb3897b6b36985;p=thirdparty%2Fsquid.git Bug 3319: Inconsistencies in error messages pt2 --- diff --git a/src/auth/basic/UserRequest.cc b/src/auth/basic/UserRequest.cc index bad3a2b16b..bdad042093 100644 --- a/src/auth/basic/UserRequest.cc +++ b/src/auth/basic/UserRequest.cc @@ -140,7 +140,7 @@ AuthBasicUserRequest::HandleReply(void *data, char *reply) BasicAuthQueueNode *tmpnode; char *t = NULL; void *cbdata; - debugs(29, 9, HERE << "{" << (reply ? reply : "") << "}"); + debugs(29, 5, HERE << "{" << (reply ? reply : "") << "}"); if (reply) { if ((t = strchr(reply, ' '))) diff --git a/src/client_side_request.cc b/src/client_side_request.cc index 08a38ad3a5..f81481c74f 100644 --- a/src/client_side_request.cc +++ b/src/client_side_request.cc @@ -873,7 +873,7 @@ clientRedirectAccessCheckDone(allow_t answer, void *data) void ClientRequestContext::clientRedirectStart() { - debugs(33, 5, "clientRedirectStart: '" << http->uri << "'"); + debugs(33, 5, HERE << "'" << http->uri << "'"); if (Config.accessList.redirector) { acl_checklist = clientAclChecklistCreate(Config.accessList.redirector, http); diff --git a/src/comm/ModDevPoll.cc b/src/comm/ModDevPoll.cc index 614ac85416..8db2585e74 100644 --- a/src/comm/ModDevPoll.cc +++ b/src/comm/ModDevPoll.cc @@ -247,13 +247,9 @@ void Comm::SetSelect(int fd, unsigned int type, PF * handler, void *client_data, time_t timeout) { assert(fd >= 0); - debugs( - 5, - DEBUG_DEVPOLL ? 0 : 8, - HERE << "FD " << fd << ",type=" << type - << ",handler=" << handler << ",client_data=" << client_data - << ",timeout=" << timeout << ")" - ); + debugs(5, 5, HERE << "FD " << fd << ", type=" << type << + ", handler=" << handler << ", client_data=" << client_data << + ", timeout=" << timeout); /* POLLIN/POLLOUT are defined in */ fde *F = &fd_table[fd]; diff --git a/src/comm/ModEpoll.cc b/src/comm/ModEpoll.cc index af9790ace8..f19df2f2c7 100644 --- a/src/comm/ModEpoll.cc +++ b/src/comm/ModEpoll.cc @@ -132,7 +132,7 @@ Comm::SetSelect(int fd, unsigned int type, PF * handler, void *client_data, time struct epoll_event ev; assert(fd >= 0); - debugs(5, DEBUG_EPOLL ? 0 : 8, HERE << "FD " << fd << ", type=" << type << + debugs(5, 5, HERE << "FD " << fd << ", type=" << type << ", handler=" << handler << ", client_data=" << client_data << ", timeout=" << timeout); diff --git a/src/comm/ModKqueue.cc b/src/comm/ModKqueue.cc index 3364853d34..de3616cf17 100644 --- a/src/comm/ModKqueue.cc +++ b/src/comm/ModKqueue.cc @@ -194,6 +194,9 @@ Comm::SetSelect(int fd, unsigned int type, PF * handler, void *client_data, time fde *F = &fd_table[fd]; assert(fd >= 0); assert(F->flags.open); + debugs(5, 5, HERE << "FD " << fd << ", type=" << type << + ", handler=" << handler << ", client_data=" << client_data << + ", timeout=" << timeout); if (type & COMM_SELECT_READ) { kq_update_events(fd, EVFILT_READ, handler); diff --git a/src/comm/ModPoll.cc b/src/comm/ModPoll.cc index 0d80fb4713..cbb00bc971 100644 --- a/src/comm/ModPoll.cc +++ b/src/comm/ModPoll.cc @@ -144,7 +144,9 @@ Comm::SetSelect(int fd, unsigned int type, PF * handler, void *client_data, time fde *F = &fd_table[fd]; assert(fd >= 0); assert(F->flags.open); - debugs(5, 5, "commSetSelect: FD " << fd << " type " << type); + debugs(5, 5, HERE << "FD " << fd << ", type=" << type << + ", handler=" << handler << ", client_data=" << client_data << + ", timeout=" << timeout); if (type & COMM_SELECT_READ) { F->read_handler = handler; @@ -513,7 +515,7 @@ Comm::DoSelect(int msec) } if (revents & (POLLWRNORM | POLLOUT | POLLHUP | POLLERR)) { - debugs(5, 5, "comm_poll: FD " << fd << " ready for writing"); + debugs(5, 6, "comm_poll: FD " << fd << " ready for writing"); if ((hdl = F->write_handler)) { PROF_start(comm_write_handler); diff --git a/src/comm/ModSelect.cc b/src/comm/ModSelect.cc index d7c773393c..d18feef2a7 100644 --- a/src/comm/ModSelect.cc +++ b/src/comm/ModSelect.cc @@ -139,7 +139,9 @@ Comm::SetSelect(int fd, unsigned int type, PF * handler, void *client_data, time fde *F = &fd_table[fd]; assert(fd >= 0); assert(F->flags.open); - debugs(5, 5, HERE << "FD " << fd << " type " << type); + debugs(5, 5, HERE << "FD " << fd << ", type=" << type << + ", handler=" << handler << ", client_data=" << client_data << + ", timeout=" << timeout); if (type & COMM_SELECT_READ) { F->read_handler = handler; @@ -585,7 +587,7 @@ Comm::DoSelect(int msec) } F = &fd_table[fd]; - debugs(5, 5, "comm_select: FD " << fd << " ready for writing"); + debugs(5, 6, "comm_select: FD " << fd << " ready for writing"); if ((hdl = F->write_handler)) { F->write_handler = NULL; diff --git a/src/comm/ModSelectWin32.cc b/src/comm/ModSelectWin32.cc index 2e190904fa..4763437949 100644 --- a/src/comm/ModSelectWin32.cc +++ b/src/comm/ModSelectWin32.cc @@ -138,7 +138,9 @@ Comm::SetSelect(int fd, unsigned int type, PF * handler, void *client_data, time fde *F = &fd_table[fd]; assert(fd >= 0); assert(F->flags.open); - debugs(5, 5, "commSetSelect: FD " << fd << " type " << type); + debugs(5, 5, HERE << "FD " << fd << ", type=" << type << + ", handler=" << handler << ", client_data=" << client_data << + ", timeout=" << timeout); if (type & COMM_SELECT_READ) { F->read_handler = handler; @@ -608,7 +610,7 @@ Comm::DoSelect(int msec) } F = &fd_table[fd]; - debugs(5, 5, "comm_select: FD " << fd << " ready for writing"); + debugs(5, 6, "comm_select: FD " << fd << " ready for writing"); if ((hdl = F->write_handler)) { F->write_handler = NULL; diff --git a/src/filemap.cc b/src/filemap.cc index d6d41ad1c9..10bcb0091f 100644 --- a/src/filemap.cc +++ b/src/filemap.cc @@ -76,6 +76,7 @@ file_map_grow(fileMap * fm) assert(fm->max_n_files <= (1 << 24)); /* swap_filen is 25 bits, signed */ fm->nwords = fm->max_n_files >> LONG_BIT_SHIFT; debugs(8, 3, "file_map_grow: creating space for " << fm->max_n_files << " files"); + debugs(8, 5, "--> " << fm->nwords << " words of " << sizeof(*fm->file_map) << " bytes each"); fm->file_map = (unsigned long *)xcalloc(fm->nwords, sizeof(*fm->file_map)); debugs(8, 3, "copying " << old_sz << " old bytes"); memcpy(fm->file_map, old_map, old_sz); diff --git a/src/ftp.cc b/src/ftp.cc index 150c4edaad..2e34f30cec 100644 --- a/src/ftp.cc +++ b/src/ftp.cc @@ -3232,7 +3232,7 @@ ftpReadRetr(FtpStateData * ftpState) if (code == 125 || (code == 150 && Comm::IsConnOpen(ftpState->data.conn))) { /* Begin data transfer */ - debugs(9, 3, HERE << "reading data channel"); + debugs(9, 3, HERE << "begin data transfer from " << ftpState->data.conn->remote << " (" << ftpState->data.conn->local << ")"); ftpState->switchTimeoutToDataChannel(); ftpState->maybeReadVirginBody(); ftpState->state = READING_DATA; diff --git a/src/helper.cc b/src/helper.cc index ae56fe7cb2..6a1ce2aca4 100644 --- a/src/helper.cc +++ b/src/helper.cc @@ -1093,6 +1093,7 @@ GetFirstAvailable(helper * hlp) dlink_node *n; helper_server *srv; helper_server *selected = NULL; + debugs(84, 5, "GetFirstAvailable: Running servers " << hlp->childs.n_running); if (hlp->childs.n_running == 0) return NULL; @@ -1119,12 +1120,17 @@ GetFirstAvailable(helper * hlp) } /* Check for overload */ - if (!selected) + if (!selected) { + debugs(84, 5, "GetFirstAvailable: None available."); return NULL; + } - if (selected->stats.pending >= (hlp->childs.concurrency ? hlp->childs.concurrency : 1)) + if (selected->stats.pending >= (hlp->childs.concurrency ? hlp->childs.concurrency : 1)) { + debugs(84, 3, "GetFirstAvailable: Least-loaded helper is overloaded!"); return NULL; + } + debugs(84, 5, "GetFirstAvailable: returning srv-" << selected->index); return selected; } diff --git a/src/htcp.cc b/src/htcp.cc index 5c5fbd90dd..1e2d0a6cd9 100644 --- a/src/htcp.cc +++ b/src/htcp.cc @@ -1171,7 +1171,6 @@ htcpHandleTstResponse(htcpDataHeader * hdr, char *buf, int sz, Ip::Address &from } static void - htcpHandleTstRequest(htcpDataHeader * dhdr, char *buf, int sz, Ip::Address &from) { /* buf should be a SPECIFIER */ @@ -1193,27 +1192,27 @@ htcpHandleTstRequest(htcpDataHeader * dhdr, char *buf, int sz, Ip::Address &from s->setDataHeader(dhdr); if (NULL == s) { - debugs(31, 2, "htcpHandleTstRequest: htcpUnpackSpecifier failed"); + debugs(31, 3, "htcpHandleTstRequest: htcpUnpackSpecifier failed"); htcpLogHtcp(from, dhdr->opcode, LOG_UDP_INVALID, dash_str); return; } if (!s->request) { - debugs(31, 2, "htcpHandleTstRequest: failed to parse request"); + debugs(31, 3, "htcpHandleTstRequest: failed to parse request"); htcpLogHtcp(from, dhdr->opcode, LOG_UDP_INVALID, dash_str); htcpFreeSpecifier(s); return; } if (!htcpAccessAllowed(Config.accessList.htcp, s, from)) { - debugs(31, 2, "htcpHandleTstRequest: Access denied"); + debugs(31, 3, "htcpHandleTstRequest: Access denied"); htcpLogHtcp(from, dhdr->opcode, LOG_UDP_DENIED, s->uri); htcpFreeSpecifier(s); return; } - debugs(31, 3, "htcpHandleTstRequest: " << s->method << " " << s->uri << " " << s->version); - debugs(31, 3, "htcpHandleTstRequest: " << s->req_hdrs); + debugs(31, 2, "HTCP TST request: " << s->method << " " << s->uri << " " << s->version); + debugs(31, 2, "HTCP TST headers: " << s->req_hdrs); s->checkHit(); } @@ -1251,7 +1250,7 @@ htcpHandleClr(htcpDataHeader * hdr, char *buf, int sz, Ip::Address &from) htcpSpecifier *s; /* buf[0/1] is reserved and reason */ int reason = buf[1] << 4; - debugs(31, 3, "htcpHandleClr: reason=" << reason); + debugs(31, 2, "HTCP CLR reason: " << reason); buf += 2; sz -= 2; @@ -1272,21 +1271,21 @@ htcpHandleClr(htcpDataHeader * hdr, char *buf, int sz, Ip::Address &from) } if (!s->request) { - debugs(31, 2, "htcpHandleTstRequest: failed to parse request"); + debugs(31, 3, "htcpHandleTstRequest: failed to parse request"); htcpLogHtcp(from, hdr->opcode, LOG_UDP_INVALID, dash_str); htcpFreeSpecifier(s); return; } if (!htcpAccessAllowed(Config.accessList.htcp_clr, s, from)) { - debugs(31, 2, "htcpHandleClr: Access denied"); + debugs(31, 3, "htcpHandleClr: Access denied"); htcpLogHtcp(from, hdr->opcode, LOG_UDP_DENIED, s->uri); htcpFreeSpecifier(s); return; } - debugs(31, 5, "htcpHandleClr: " << s->method << " " << s->uri << " " << s->version); - debugs(31, 5, "htcpHandleClr: request headers: " << s->req_hdrs); + debugs(31, 2, "HTCP CLR request: " << s->method << " " << s->uri << " " << s->version); + debugs(31, 2, "HTCP CLR headers: " << s->req_hdrs); /* Release objects from cache * analog to clientPurgeRequest in client_side.c diff --git a/src/ipcache.cc b/src/ipcache.cc index ed538e6465..ce69f12572 100644 --- a/src/ipcache.cc +++ b/src/ipcache.cc @@ -487,6 +487,7 @@ ipcacheParse(ipcache_entry *i, rfc1035_rr * answers, int nr, const char *error_m return -1; } + debugs(14, 3, "ipcacheParse: " << nr << " answers for '" << name << "'"); assert(answers); for (k = 0; k < nr; k++) { diff --git a/src/peer_digest.cc b/src/peer_digest.cc index 84089c1b57..3ddf4df286 100644 --- a/src/peer_digest.cc +++ b/src/peer_digest.cc @@ -917,7 +917,7 @@ peerDigestFetchFinish(DigestFetchState * fetch, int err) assert(fetch->entry && fetch->request); if (fetch->old_entry) { - debugs(72, 2, "peerDigestFetchFinish: deleting old entry"); + debugs(72, 3, "peerDigestFetchFinish: deleting old entry"); storeUnregister(fetch->old_sc, fetch->old_entry, fetch); fetch->old_entry->releaseRequest(); fetch->old_entry->unlock(); diff --git a/src/ssl/support.cc b/src/ssl/support.cc index 17191716c0..cfdb05b851 100644 --- a/src/ssl/support.cc +++ b/src/ssl/support.cc @@ -654,7 +654,7 @@ sslCreateServerContext(const char *certfile, const char *keyfile, int version, c debugs(83, 5, "Using SSLv2."); method = SSLv2_server_method(); #else - debugs(83, 1, "SSLv2 is not available in this Proxy."); + debugs(83, DBG_IMPORTANT, "SSLv2 is not available in this Proxy."); return NULL; #endif break; @@ -711,31 +711,33 @@ sslCreateServerContext(const char *certfile, const char *keyfile, int version, c } } - debugs(83, 1, "Using certificate in " << certfile); + debugs(83, DBG_IMPORTANT, "Using certificate in " << certfile); if (!SSL_CTX_use_certificate_chain_file(sslContext, certfile)) { ssl_error = ERR_get_error(); - debugs(83, 0, "Failed to acquire SSL certificate '" << certfile << "': " << ERR_error_string(ssl_error, NULL) ); - goto error; + debugs(83, DBG_CRITICAL, "ERROR: Failed to acquire SSL certificate '" << certfile << "': " << ERR_error_string(ssl_error, NULL)); + SSL_CTX_free(sslContext); + return NULL; } - debugs(83, 1, "Using private key in " << keyfile); + debugs(83, DBG_IMPORTANT, "Using private key in " << keyfile); ssl_ask_password(sslContext, keyfile); if (!SSL_CTX_use_PrivateKey_file(sslContext, keyfile, SSL_FILETYPE_PEM)) { ssl_error = ERR_get_error(); - debugs(83, 0, "Failed to acquire SSL private key '" << keyfile << "': " << ERR_error_string(ssl_error, NULL) ); - goto error; + debugs(83, DBG_CRITICAL, "ERROR: Failed to acquire SSL private key '" << keyfile << "': " << ERR_error_string(ssl_error, NULL)); + SSL_CTX_free(sslContext); + return NULL; } debugs(83, 5, "Comparing private and public SSL keys."); if (!SSL_CTX_check_private_key(sslContext)) { ssl_error = ERR_get_error(); - debugs(83, 0, "SSL private key '" << - certfile << "' does not match public key '" << - keyfile << "': " << ERR_error_string(ssl_error, NULL) ); - goto error; + debugs(83, DBG_CRITICAL, "ERROR: SSL private key '" << certfile << "' does not match public key '" << + keyfile << "': " << ERR_error_string(ssl_error, NULL)); + SSL_CTX_free(sslContext); + return NULL; } debugs(83, 9, "Setting RSA key generation callback."); @@ -745,15 +747,13 @@ sslCreateServerContext(const char *certfile, const char *keyfile, int version, c if ((CAfile || CApath) && !SSL_CTX_load_verify_locations(sslContext, CAfile, CApath)) { ssl_error = ERR_get_error(); - debugs(83, 1, "Error setting CA certificate locations: " << ERR_error_string(ssl_error, NULL) ); - debugs(83, 1, "continuing anyway..." ); + debugs(83, DBG_IMPORTANT, "WARNING: Ignoring error setting CA certificate locations: " << ERR_error_string(ssl_error, NULL)); } if (!(fl & SSL_FLAG_NO_DEFAULT_CA) && !SSL_CTX_set_default_verify_paths(sslContext)) { ssl_error = ERR_get_error(); - debugs(83, 1, "Error setting default CA certificate location: " << ERR_error_string(ssl_error, NULL) ); - debugs(83, 1, "continuing anyway..." ); + debugs(83, DBG_IMPORTANT, "WARNING: Ignoring error setting default CA certificate location: " << ERR_error_string(ssl_error, NULL)); } if (clientCA) { @@ -762,8 +762,9 @@ sslCreateServerContext(const char *certfile, const char *keyfile, int version, c cert_names = SSL_load_client_CA_file(clientCA); if (cert_names == NULL) { - debugs(83, 1, "Error loading the client CA certificates from '" << clientCA << "\': " << ERR_error_string(ERR_get_error(),NULL) ); - goto error; + debugs(83, DBG_IMPORTANT, "ERROR: loading the client CA certificates from '" << clientCA << "\': " << ERR_error_string(ERR_get_error(),NULL)); + SSL_CTX_free(sslContext); + return NULL; } ERR_clear_error(); @@ -806,10 +807,10 @@ sslCreateServerContext(const char *certfile, const char *keyfile, int version, c } if (!dh) - debugs(83, 1, "WARNING: Failed to read DH parameters '" << dhfile << "'"); + debugs(83, DBG_IMPORTANT, "WARNING: Failed to read DH parameters '" << dhfile << "'"); else if (dh && DH_check(dh, &codes) == 0) { if (codes) { - debugs(83, 1, "WARNING: Failed to verify DH parameters '" << dhfile << "' (" << std::hex << codes << ")"); + debugs(83, DBG_IMPORTANT, "WARNING: Failed to verify DH parameters '" << dhfile << "' (" << std::hex << codes << ")"); DH_free(dh); dh = NULL; } @@ -823,11 +824,6 @@ sslCreateServerContext(const char *certfile, const char *keyfile, int version, c SSL_CTX_set_ex_data(sslContext, ssl_ctx_ex_index_dont_verify_domain, (void *) -1); return sslContext; - -error: - SSL_CTX_free(sslContext); - - return NULL; } SSL_CTX * @@ -857,7 +853,7 @@ sslCreateClientContext(const char *certfile, const char *keyfile, int version, c debugs(83, 5, "Using SSLv2."); method = SSLv2_client_method(); #else - debugs(83, 1, "SSLv2 is not available in this Proxy."); + debugs(83, DBG_IMPORTANT, "SSLv2 is not available in this Proxy."); return NULL; #endif break; @@ -931,7 +927,7 @@ sslCreateClientContext(const char *certfile, const char *keyfile, int version, c SSL_CTX_set_tmp_rsa_callback(sslContext, ssl_temp_rsa_cb); if (fl & SSL_FLAG_DONT_VERIFY_PEER) { - debugs(83, 1, "NOTICE: Peer certificates are not verified for validity!"); + debugs(83, 2, "NOTICE: Peer certificates are not verified for validity!"); SSL_CTX_set_verify(sslContext, SSL_VERIFY_NONE, NULL); } else { debugs(83, 9, "Setting certificate verification callback."); @@ -942,8 +938,7 @@ sslCreateClientContext(const char *certfile, const char *keyfile, int version, c if ((CAfile || CApath) && !SSL_CTX_load_verify_locations(sslContext, CAfile, CApath)) { ssl_error = ERR_get_error(); - debugs(83, 1, "Error setting CA certificate locations: " << ERR_error_string(ssl_error, NULL)); - debugs(83, 1, "continuing anyway..." ); + debugs(83, DBG_IMPORTANT, "WARNING: Ignoring error setting CA certificate locations: " << ERR_error_string(ssl_error, NULL)); } if (CRLfile) { @@ -962,8 +957,7 @@ sslCreateClientContext(const char *certfile, const char *keyfile, int version, c if (!(fl & SSL_FLAG_NO_DEFAULT_CA) && !SSL_CTX_set_default_verify_paths(sslContext)) { ssl_error = ERR_get_error(); - debugs(83, 1, "Error setting default CA certificate location: " << ERR_error_string(ssl_error, NULL) ); - debugs(83, 1, "continuing anyway..."); + debugs(83, DBG_IMPORTANT, "WARNING: Ignoring error setting default CA certificate location: " << ERR_error_string(ssl_error, NULL)); } return sslContext;