From: Alex Rousskov Date: Sun, 1 Jul 2012 03:55:21 +0000 (-0600) Subject: Added ssl::bump_mode logformat code to log SslBump decisions. X-Git-Tag: BumpSslServerFirst.take10~1 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=08097970848a2d57a67a0ff3fe5d5d3bd7d04f41;p=thirdparty%2Fsquid.git Added ssl::bump_mode logformat code to log SslBump decisions. Reshuffled (a little) how the bumping decision for CONNECT is made to streamline the code. This was necessary to consistently distinguish '-' from 'none' logged modes. Do not evaluate ssl_bump when we are going to respond to a CONNECT request with an HTTP 407 (Proxy Authentication Required) or with a redirect response. Such evaluation was pointless because the code never bumps in such cases because, unlike regular errors, these responses cannot be delayed and served later inside the bumped tunnel. --- diff --git a/src/AccessLogEntry.cc b/src/AccessLogEntry.cc index d2dca0cfe5..4dd4de1dd1 100644 --- a/src/AccessLogEntry.cc +++ b/src/AccessLogEntry.cc @@ -1,6 +1,12 @@ #include "squid.h" #include "AccessLogEntry.h" #include "HttpRequest.h" +#include "ssl/support.h" + +AccessLogEntry::Ssl::Ssl(): user(NULL), bumpMode(::Ssl::bumpEnd) +{ +} + void AccessLogEntry::getLogClientIp(char *buf, size_t bufsz) const diff --git a/src/AccessLogEntry.h b/src/AccessLogEntry.h index 4e9fc88770..df2e8f8a68 100644 --- a/src/AccessLogEntry.h +++ b/src/AccessLogEntry.h @@ -111,6 +111,17 @@ public: const char *opcode; } htcp; +#if USE_SSL + /// logging information specific to the SSL protocol + class Ssl { + public: + Ssl(); + + const char *user; ///< emailAddress from the SSL client certificate + int bumpMode; ///< whether and how the request was SslBumped + } ssl; +#endif + /** \brief This subclass holds log info for Squid internal stats * \todo Inner class declarations should be moved outside * \todo some details relevant to particular protocols need shuffling to other sub-classes diff --git a/src/cf.data.pre b/src/cf.data.pre index 1eda02dbe4..66573a8a6f 100644 --- a/src/cf.data.pre +++ b/src/cf.data.pre @@ -3338,6 +3338,24 @@ DOC_START Ss Squid request status (TCP_MISS etc) Sh Squid hierarchy status (DEFAULT_PARENT etc) + SSL-related format codes: + + ssl::bump_mode SslBump decision for the transaction: + + For CONNECT requests that initiated bumping of + a connection and for any request received on + an already bumped connection, Squid logs the + corresponding SslBump mode ("server-first" or + "client-first"). See the ssl_bump option for + more information about these modes. + + A "none" token is logged for requests that + triggered "ssl_bump" ACL evaluation matching + either a "none" rule or no rules at all. + + In all other cases, a single dash ("-") is + logged. + If ICAP is enabled, the following code becomes available (as well as ICAP log codes documented with the icap_log option): diff --git a/src/client_side.cc b/src/client_side.cc index 66913cf3c4..594e204b26 100644 --- a/src/client_side.cc +++ b/src/client_side.cc @@ -3592,12 +3592,14 @@ httpsSslBumpAccessCheckDone(allow_t answer, void *data) // Require both a match and a positive bump mode to work around exceptional // cases where ACL code may return ACCESS_ALLOWED with zero answer.kind. if (answer == ACCESS_ALLOWED && answer.kind != Ssl::bumpNone) { - debugs(33, 2, HERE << "sslBump done data: " << connState->clientConnection); + debugs(33, 2, HERE << "sslBump needed for " << connState->clientConnection); + connState->sslBumpMode = static_cast(answer.kind); httpsEstablish(connState, NULL, (Ssl::BumpMode)answer.kind); } else { - // fake a CONNECT request to force connState to tunnel + debugs(33, 2, HERE << "sslBump not needed for " << connState->clientConnection); + connState->sslBumpMode = Ssl::bumpNone; - debugs(33, 2, HERE << " SslBump denied: " << connState->clientConnection << " revert to tunnel mode"); + // fake a CONNECT request to force connState to tunnel static char ip[MAX_IPSTRLEN]; static char reqStr[MAX_IPSTRLEN + 80]; connState->clientConnection->local.NtoA(ip, sizeof(ip)); @@ -4245,6 +4247,7 @@ CBDATA_CLASS_INIT(ConnStateData); ConnStateData::ConnStateData() : AsyncJob("ConnStateData"), #if USE_SSL + sslBumpMode(Ssl::bumpEnd), switchedToHttps_(false), sslServerBump(NULL), #endif diff --git a/src/client_side.h b/src/client_side.h index 845bc41278..ca5e1b25fd 100644 --- a/src/client_side.h +++ b/src/client_side.h @@ -352,6 +352,9 @@ public: /// Otherwise, writes the error to the client and returns true. Also checks /// for SQUID_X509_V_ERR_DOMAIN_MISMATCH on bumped requests. bool serveDelayedError(ClientSocketContext *context); + + Ssl::BumpMode sslBumpMode; ///< ssl_bump decision (Ssl::bumpEnd if n/a). + #else bool switchedToHttps() const { return false; } #endif diff --git a/src/client_side_request.cc b/src/client_side_request.cc index 8fb7dacd66..c27598f93d 100644 --- a/src/client_side_request.cc +++ b/src/client_side_request.cc @@ -187,7 +187,7 @@ ClientHttpRequest::ClientHttpRequest(ConnStateData * aConn) : request_satisfaction_mode = false; #endif #if USE_SSL - sslBumpNeed = Ssl::bumpEnd; + sslBumpNeed_ = Ssl::bumpEnd; #endif } @@ -1277,18 +1277,40 @@ ClientRequestContext::checkNoCacheDone(const allow_t &answer) bool ClientRequestContext::sslBumpAccessCheck() { - if (http->request->method == METHOD_CONNECT && - !http->request->flags.spoof_client_ip && // not a fake bumped request from an https port - Config.accessList.ssl_bump && http->getConn()->port->sslBump) { - debugs(85, 5, HERE << "SslBump possible, checking ACL"); + // If SSL connection tunneling or bumping decision has been made, obey it. + const Ssl::BumpMode bumpMode = http->getConn()->sslBumpMode; + if (bumpMode != Ssl::bumpEnd) { + debugs(85, 5, HERE << "SslBump already decided (" << bumpMode << + "), " << "ignoring ssl_bump for " << http->getConn()); + http->al.ssl.bumpMode = bumpMode; // inherited from bumped connection + return false; + } - ACLFilledChecklist *acl_checklist = clientAclChecklistCreate(Config.accessList.ssl_bump, http); - acl_checklist->nonBlockingCheck(sslBumpAccessCheckDoneWrapper, this); - return true; - } else { - http->sslBumpNeeded(Ssl::bumpNone); + // If we have not decided yet, decide whether to bump now. + + // Bumping here can only start with a CONNECT request on a bumping port + // (bumping of intercepted SSL conns is decided before we get 1st request). + // We also do not bump redirected CONNECT requests. + if (http->request->method != METHOD_CONNECT || http->redirect.status || + !Config.accessList.ssl_bump || !http->getConn()->port->sslBump) { + http->al.ssl.bumpMode = Ssl::bumpEnd; // SslBump does not apply; log - + debugs(85, 5, HERE << "cannot SslBump this request"); return false; } + + // Do not bump during authentication: clients would not proxy-authenticate + // if we delay a 407 response and respond with 200 OK to CONNECT. + if (error && error->httpStatus == HTTP_PROXY_AUTHENTICATION_REQUIRED) { + http->al.ssl.bumpMode = Ssl::bumpEnd; // SslBump does not apply; log - + debugs(85, 5, HERE << "no SslBump during proxy authentication"); + return false; + } + + debugs(85, 5, HERE << "SslBump possible, checking ACL"); + + ACLFilledChecklist *acl_checklist = clientAclChecklistCreate(Config.accessList.ssl_bump, http); + acl_checklist->nonBlockingCheck(sslBumpAccessCheckDoneWrapper, this); + return true; } /** @@ -1311,10 +1333,10 @@ ClientRequestContext::sslBumpAccessCheckDone(const allow_t &answer) if (!httpStateIsValid()) return; - if (answer == ACCESS_ALLOWED) - http->sslBumpNeeded(static_cast(answer.kind)); - else - http->sslBumpNeeded(Ssl::bumpNone); + const Ssl::BumpMode bumpMode = answer == ACCESS_ALLOWED ? + static_cast(answer.kind) : Ssl::bumpNone; + http->sslBumpNeed(bumpMode); // for processRequest() to bump if needed + http->al.ssl.bumpMode = bumpMode; // for logging http->doCallouts(); } @@ -1363,18 +1385,11 @@ ClientHttpRequest::httpStart() #if USE_SSL -Ssl::BumpMode -ClientHttpRequest::sslBumpNeeded() const -{ - assert(sslBumpNeed != Ssl::bumpEnd); - return sslBumpNeed; -} - void -ClientHttpRequest::sslBumpNeeded(Ssl::BumpMode mode) +ClientHttpRequest::sslBumpNeed(Ssl::BumpMode mode) { debugs(83, 3, HERE << "sslBump required: "<< Ssl::bumpMode(mode)); - sslBumpNeed = mode; + sslBumpNeed_ = mode; } // called when comm_write has completed @@ -1411,16 +1426,18 @@ ClientHttpRequest::sslBumpEstablish(comm_err_t errflag) getConn()->auth_user_request = request->auth_user_request; #endif - getConn()->switchToHttps(request, sslBumpNeeded()); + assert(sslBumpNeeded()); + getConn()->switchToHttps(request, sslBumpNeed_); } void ClientHttpRequest::sslBumpStart() { - debugs(85, 5, HERE << "Confirming CONNECT tunnel on FD " << getConn()->clientConnection); - // send an HTTP 200 response to kick client SSL negotiation - debugs(33, 7, HERE << "Confirming CONNECT tunnel on FD " << getConn()->clientConnection); + debugs(85, 5, HERE << "Confirming " << Ssl::bumpMode(sslBumpNeed_) << + "-bumped CONNECT tunnel on FD " << getConn()->clientConnection); + getConn()->sslBumpMode = sslBumpNeed_; + // send an HTTP 200 response to kick client SSL negotiation // TODO: Unify with tunnel.cc and add a Server(?) header static const char *const conn_established = "HTTP/1.1 200 Connection established\r\n\r\n"; AsyncCall::Pointer call = commCbCall(85, 5, "ClientSocketContext::sslBumpEstablish", @@ -1605,8 +1622,7 @@ ClientHttpRequest::doCallouts() const char *uri = urlCanonical(request); StoreEntry *e= storeCreateEntry(uri, uri, request->flags, request->method); #if USE_SSL - if (sslBumpNeeded() && - calloutContext->error->httpStatus != HTTP_PROXY_AUTHENTICATION_REQUIRED) { + if (sslBumpNeeded()) { // set final error but delay sending until we bump Ssl::ServerBump *srvBump = new Ssl::ServerBump(request, e); errorAppendEntry(e, calloutContext->error); diff --git a/src/client_side_request.h b/src/client_side_request.h index 13dc6bbc80..f89b69b7cc 100644 --- a/src/client_side_request.h +++ b/src/client_side_request.h @@ -156,13 +156,15 @@ private: #if USE_SSL /// whether (and how) the request needs to be bumped - Ssl::BumpMode sslBumpNeed; + Ssl::BumpMode sslBumpNeed_; public: - /// return true if the request needs to be bumped - Ssl::BumpMode sslBumpNeeded() const; + /// returns raw sslBump mode value + Ssl::BumpMode sslBumpNeed() const { return sslBumpNeed_; } + /// returns true if and only if the request needs to be bumped + bool sslBumpNeeded() const { return sslBumpNeed_ == Ssl::bumpServerFirst || sslBumpNeed_ == Ssl::bumpClientFirst; } /// set the sslBumpNeeded state - void sslBumpNeeded(Ssl::BumpMode mode); + void sslBumpNeed(Ssl::BumpMode mode); void sslBumpStart(); void sslBumpEstablish(comm_err_t errflag); #endif diff --git a/src/format/ByteCode.h b/src/format/ByteCode.h index 8e345dfcdd..b793693215 100644 --- a/src/format/ByteCode.h +++ b/src/format/ByteCode.h @@ -190,6 +190,10 @@ typedef enum { LFT_ICAP_STATUS_CODE, #endif +#if USE_SSL + LFT_SSL_BUMP_MODE, +#endif + LFT_PERCENT /* special string cases for escaped chars */ } ByteCode_t; diff --git a/src/format/Format.cc b/src/format/Format.cc index 18348e8148..ba24d1a0c2 100644 --- a/src/format/Format.cc +++ b/src/format/Format.cc @@ -1004,6 +1004,15 @@ Format::Format::assemble(MemBuf &mb, AccessLogEntry *al, int logSequenceNumber) dooff = 1; break; +#if USE_SSL + case LFT_SSL_BUMP_MODE: { + const Ssl::BumpMode mode = static_cast(al->ssl.bumpMode); + // for Ssl::bumpEnd, Ssl::bumpMode() returns NULL and we log '-' + out = Ssl::bumpMode(mode); + break; + } +#endif + case LFT_PERCENT: out = "%"; diff --git a/src/format/Token.cc b/src/format/Token.cc index 37c665f06b..163405684f 100644 --- a/src/format/Token.cc +++ b/src/format/Token.cc @@ -186,6 +186,13 @@ static TokenTableEntry TokenTableIcap[] = { }; #endif +#if USE_SSL +// SSL (ssl::) tokens +static TokenTableEntry TokenTableSsl[] = { + {"bump_mode", LFT_SSL_BUMP_MODE}, + {NULL, LFT_NONE} +}; +#endif } // namespace Format /// Register all components custom format tokens @@ -201,8 +208,9 @@ Format::Token::Init() #if ICAP_CLIENT TheConfig.registerTokens(String("icap"),::Format::TokenTableIcap); #endif - - // TODO tokens for OpenSSL errors in "ssl::" +#if USE_SSL + TheConfig.registerTokens(String("ssl"),::Format::TokenTableSsl); +#endif } /// Scans a token table to see if the next token exists there