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 d2dca0cfe5b631217d5e0423a4a1e2f0fd9dc482..4dd4de1dd11fe84453681fc5b46ee0734344b63c 100644 (file)
--- 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 4e9fc88770ea97d7a6dc15bcc3688ab7863343a1..df2e8f8a688193ee771099a9a3c755fb205a1568 100644 (file)
--- 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 1eda02dbe4c7b5f922ed0330625db7af2952f32e..66573a8a6f789f1aa6c9bbe0fbb1bf935934cb9e 100644 (file)
--- 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 66913cf3c41680ee2289b19752a5b8786d409221..594e204b26e8ad29798a77e9e9a9fc66eb7e24a5 100644 (file)
--- 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<Ssl::BumpMode>(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 845bc412786829b43fc3905e7462aa0d1fa78438..ca5e1b25fdf019ba1407d9ef40d88a39f43f90e4 100644 (file)
--- 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 8fb7dacd66a63da7d04f122f6e5b2f151e67c5d4..c27598f93d80f62a715e76e99b60df4bb188d562 100644 (file)
--- 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<Ssl::BumpMode>(answer.kind));
-    else
-        http->sslBumpNeeded(Ssl::bumpNone);
+    const Ssl::BumpMode bumpMode = answer == ACCESS_ALLOWED ?
+        static_cast<Ssl::BumpMode>(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 13dc6bbc8052ea1c5cfbab1227eab4a7b9513550..f89b69b7cc8f8c1f42995142cadc7fd69a757a14 100644 (file)
--- 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 8e345dfcdd46d9e810a8b5a5df3c5d10132e40e3..b79369321525d4ef52e36b247d286ab41fdb80d6 100644 (file)
--- 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 18348e8148a9e7dec893004b8097a479fc8fff00..ba24d1a0c203925bee197509f21e07e03d5bbd27 100644 (file)
--- 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<Ssl::BumpMode>(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 37c665f06b5a9437ec6ba1e439b6d88309f5bb6c..163405684fee5dc3ee9c13f026ebea22b1f3a604 100644 (file)
--- 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