]> git.ipfire.org Git - thirdparty/squid.git/blobdiff - src/format/Format.cc
Fix logged request size (%http::>st) and other size-related %codes.
[thirdparty/squid.git] / src / format / Format.cc
index 6f929779a6cdb4c95b4eb6054747c6d844fe2df2..f007e982c975eaa7007c609c42c8d30a1017f0c0 100644 (file)
@@ -1,5 +1,5 @@
 /*
- * Copyright (C) 1996-2015 The Squid Software Foundation and contributors
+ * Copyright (C) 1996-2016 The Squid Software Foundation and contributors
  *
  * Squid software is distributed under GPLv2+ license and includes
  * contributions from numerous individuals and organizations.
 #include "format/Quoting.h"
 #include "format/Token.h"
 #include "fqdncache.h"
+#include "http/Stream.h"
 #include "HttpRequest.h"
 #include "MemBuf.h"
 #include "rfc1738.h"
+#include "security/CertError.h"
+#include "security/NegotiationHistory.h"
 #include "SquidTime.h"
 #include "Store.h"
 #include "tools.h"
@@ -32,6 +35,8 @@
 /// Convert a string to NULL pointer if it is ""
 #define strOrNull(s) ((s)==NULL||(s)[0]=='\0'?NULL:(s))
 
+const SBuf Format::Dash("-");
+
 Format::Format::Format(const char *n) :
     format(NULL),
     next(NULL)
@@ -316,6 +321,34 @@ log_quoted_string(const char *str, char *out)
     *p = '\0';
 }
 
+#if USE_OPENSSL
+static char *
+sslErrorName(Security::ErrorCode err, char *buf, size_t size)
+{
+    snprintf(buf, size, "SSL_ERR=%d", err);
+    return buf;
+}
+#endif
+
+static const HttpMsg *
+actualReplyHeader(const AccessLogEntry::Pointer &al)
+{
+    const HttpMsg *msg = al->reply;
+    if (!msg && al->icap.reqMethod == Adaptation::methodReqmod)
+        msg = al->adapted_request;
+    return msg;
+}
+
+static const HttpMsg *
+actualRequestHeader(const AccessLogEntry::Pointer &al)
+{
+    if (al->icap.reqMethod == Adaptation::methodRespmod) {
+        // XXX: for now AccessLogEntry lacks virgin response headers
+        return nullptr;
+    }
+    return al->request;
+}
+
 void
 Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logSequenceNumber) const
 {
@@ -579,9 +612,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
             break;
 
         case LFT_REQUEST_HEADER:
-
-            if (al->request)
-                sb = al->request->header.getByName(fmt->data.header.header);
+            if (const HttpMsg *msg = actualRequestHeader(al))
+                sb = msg->header.getByName(fmt->data.header.header);
 
             out = sb.termedBuf();
 
@@ -600,15 +632,15 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
 
             break;
 
-        case LFT_REPLY_HEADER:
-            if (al->reply)
-                sb = al->reply->header.getByName(fmt->data.header.header);
+        case LFT_REPLY_HEADER: {
+            if (const HttpMsg *msg = actualReplyHeader(al))
+                sb = msg->header.getByName(fmt->data.header.header);
 
             out = sb.termedBuf();
 
             quote = 1;
-
-            break;
+        }
+        break;
 
 #if USE_ADAPTATION
         case LFT_ADAPTATION_SUM_XACT_TIMES:
@@ -790,8 +822,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
             break;
 #endif
         case LFT_REQUEST_HEADER_ELEM:
-            if (al->request)
-                sb = al->request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
+            if (const HttpMsg *msg = actualRequestHeader(al))
+                sb = msg->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 
             out = sb.termedBuf();
 
@@ -809,18 +841,24 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
 
             break;
 
-        case LFT_REPLY_HEADER_ELEM:
-            if (al->reply)
-                sb = al->reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
+        case LFT_REPLY_HEADER_ELEM: {
+            if (const HttpMsg *msg = actualReplyHeader(al))
+                sb = msg->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
 
             out = sb.termedBuf();
 
             quote = 1;
-
-            break;
+        }
+        break;
 
         case LFT_REQUEST_ALL_HEADERS:
-            out = al->headers.request;
+            if (al->icap.reqMethod == Adaptation::methodRespmod) {
+                // XXX: since AccessLogEntry::Headers lacks virgin response
+                // headers, do nothing for now
+                out = nullptr;
+            } else {
+                out = al->headers.request;
+            }
 
             quote = 1;
 
@@ -835,6 +873,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
 
         case LFT_REPLY_ALL_HEADERS:
             out = al->headers.reply;
+            if (!out && al->icap.reqMethod == Adaptation::methodReqmod)
+                out = al->headers.adapted_request;
 
             quote = 1;
 
@@ -845,8 +885,14 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
             if (al->request && al->request->auth_user_request != NULL)
                 out = strOrNull(al->request->auth_user_request->username());
 #endif
+            if (!out && al->request && al->request->extacl_user.size()) {
+                if (const char *t = al->request->extacl_user.termedBuf())
+                    out = t;
+            }
+
             if (!out)
                 out = strOrNull(al->cache.extuser);
+
 #if USE_OPENSSL
             if (!out)
                 out = strOrNull(al->cache.ssluser);
@@ -867,8 +913,10 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
             break;
 
         case LFT_USER_EXTERNAL:
-            if (al->request && al->request->extacl_user.size())
-                out = al->request->extacl_user.termedBuf();
+            if (al->request && al->request->extacl_user.size()) {
+                if (const char *t = al->request->extacl_user.termedBuf())
+                    out = t;
+            }
 
             if (!out)
                 out = strOrNull(al->cache.extuser);
@@ -922,10 +970,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
         case LFT_SQUID_ERROR_DETAIL:
 #if USE_OPENSSL
             if (al->request && al->request->errType == ERR_SECURE_CONNECT_FAIL) {
-                if (! (out = Ssl::GetErrorName(al->request->errDetail))) {
-                    snprintf(tmp, sizeof(tmp), "SSL_ERR=%d", al->request->errDetail);
-                    out = tmp;
-                }
+                if (! (out = Ssl::GetErrorName(al->request->errDetail)))
+                    out = sslErrorName(al->request->errDetail, tmp, sizeof(tmp));
             } else
 #endif
                 if (al->request && al->request->errDetail != ERR_DETAIL_NONE) {
@@ -977,7 +1023,9 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
 
         case LFT_CLIENT_REQ_URLSCHEME:
             if (al->request) {
-                out = al->request->url.getScheme().c_str();
+                const SBuf s(al->request->url.getScheme().image());
+                sb.append(s.rawContent(), s.length());
+                out = sb.termedBuf();
                 quote = 1;
             }
             break;
@@ -1013,20 +1061,22 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
             break;
 
         case LFT_REQUEST_METHOD:
-            if (al->_private.method_str) // ICP, HTCP method code
-                out = al->_private.method_str;
-            else {
-                const SBuf &s = al->http.method.image();
+        {
+            const SBuf s(al->getLogMethod());
+            sb.append(s.rawContent(), s.length());
+            out = sb.termedBuf();
+            quote = 1;
+        }
+        break;
+
+        case LFT_REQUEST_URI:
+            if (!al->url.isEmpty()) {
+                const SBuf &s = al->url;
                 sb.append(s.rawContent(), s.length());
                 out = sb.termedBuf();
-                quote = 1;
             }
             break;
 
-        case LFT_REQUEST_URI:
-            out = al->url;
-            break;
-
         case LFT_REQUEST_VERSION_OLD_2X:
         case LFT_REQUEST_VERSION:
             snprintf(tmp, sizeof(tmp), "%d.%d", (int) al->http.version.major, (int) al->http.version.minor);
@@ -1054,7 +1104,9 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
 
         case LFT_SERVER_REQ_URLSCHEME:
             if (al->adapted_request) {
-                out = al->adapted_request->url.getScheme().c_str();
+                const SBuf s(al->adapted_request->url.getScheme().image());
+                sb.append(s.rawContent(), s.length());
+                out = sb.termedBuf();
                 quote = 1;
             }
             break;
@@ -1163,13 +1215,13 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
             // for Ssl::bumpEnd, Ssl::bumpMode() returns NULL and we log '-'
             out = Ssl::bumpMode(mode);
         }
-            break;
+        break;
 
         case LFT_EXT_ACL_USER_CERT_RAW:
             if (al->request) {
                 ConnStateData *conn = al->request->clientConnectionManager.get();
-                if (conn != NULL && Comm::IsConnOpen(conn->clientConnection)) {
-                    if (SSL *ssl = fd_table[conn->clientConnection->fd].ssl)
+                if (conn && Comm::IsConnOpen(conn->clientConnection)) {
+                    if (auto ssl = fd_table[conn->clientConnection->fd].ssl.get())
                         out = sslGetUserCertificatePEM(ssl);
                 }
             }
@@ -1178,8 +1230,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
         case LFT_EXT_ACL_USER_CERTCHAIN_RAW:
             if (al->request) {
                 ConnStateData *conn = al->request->clientConnectionManager.get();
-                if (conn != NULL && Comm::IsConnOpen(conn->clientConnection)) {
-                    if (SSL *ssl = fd_table[conn->clientConnection->fd].ssl)
+                if (conn && Comm::IsConnOpen(conn->clientConnection)) {
+                    if (auto ssl = fd_table[conn->clientConnection->fd].ssl.get())
                         out = sslGetUserCertificatePEM(ssl);
                 }
             }
@@ -1188,8 +1240,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
         case LFT_EXT_ACL_USER_CERT:
             if (al->request) {
                 ConnStateData *conn = al->request->clientConnectionManager.get();
-                if (conn != NULL && Comm::IsConnOpen(conn->clientConnection)) {
-                    if (SSL *ssl = fd_table[conn->clientConnection->fd].ssl)
+                if (conn && Comm::IsConnOpen(conn->clientConnection)) {
+                    if (auto ssl = fd_table[conn->clientConnection->fd].ssl.get())
                         out = sslGetUserAttribute(ssl, format->data.header.header);
                 }
             }
@@ -1198,9 +1250,9 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
         case LFT_EXT_ACL_USER_CA_CERT:
             if (al->request) {
                 ConnStateData *conn = al->request->clientConnectionManager.get();
-                if (conn != NULL && Comm::IsConnOpen(conn->clientConnection)) {
-                    if (SSL *ssl = fd_table[conn->clientConnection->fd].ssl)
-                       out = sslGetCAAttribute(ssl, format->data.header.header);
+                if (conn && Comm::IsConnOpen(conn->clientConnection)) {
+                    if (auto ssl = fd_table[conn->clientConnection->fd].ssl.get())
+                        out = sslGetCAAttribute(ssl, format->data.header.header);
                 }
             }
             break;
@@ -1232,9 +1284,80 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
             }
             break;
 
+        case LFT_SSL_SERVER_CERT_ERRORS:
+            if (al->request && al->request->clientConnectionManager.valid()) {
+                if (Ssl::ServerBump * srvBump = al->request->clientConnectionManager->serverBump()) {
+                    const char *separator = fmt->data.string ? fmt->data.string : ":";
+                    for (const Security::CertErrors *sslError = srvBump->sslErrors(); sslError != nullptr; sslError = sslError->next) {
+                        if (sb.size())
+                            sb.append(separator);
+                        if (const char *errorName = Ssl::GetErrorName(sslError->element.code))
+                            sb.append(errorName);
+                        else
+                            sb.append(sslErrorName(sslError->element.code, tmp, sizeof(tmp)));
+                        if (sslError->element.depth >= 0) {
+                            snprintf(tmp, sizeof(tmp), "@depth=%d", sslError->element.depth);
+                            sb.append(tmp);
+                        }
+                    }
+                    if (sb.size())
+                        out = sb.termedBuf();
+                }
+            }
+            break;
+
         case LFT_SSL_SERVER_CERT_ISSUER:
         case LFT_SSL_SERVER_CERT_SUBJECT:
-            // Not implemented
+            if (al->request && al->request->clientConnectionManager.valid()) {
+                if (Ssl::ServerBump * srvBump = al->request->clientConnectionManager->serverBump()) {
+                    if (X509 *serverCert = srvBump->serverCert.get()) {
+                        if (fmt->type == LFT_SSL_SERVER_CERT_SUBJECT)
+                            out = Ssl::GetX509UserAttribute(serverCert, "DN");
+                        else
+                            out = Ssl::GetX509CAAttribute(serverCert, "DN");
+                    }
+                }
+            }
+            break;
+
+        case LFT_TLS_CLIENT_NEGOTIATED_VERSION:
+            if (al->tcpClient != nullptr && al->tcpClient->hasTlsNegotiations())
+                out = al->tcpClient->hasTlsNegotiations()->negotiatedVersion();
+            break;
+
+        case LFT_TLS_SERVER_NEGOTIATED_VERSION:
+            if (al->hier.tcpServer != nullptr && al->hier.tcpServer->hasTlsNegotiations())
+                out = al->hier.tcpServer->hasTlsNegotiations()->negotiatedVersion();
+            break;
+
+        case LFT_TLS_CLIENT_RECEIVED_HELLO_VERSION:
+            if (al->tcpClient != nullptr && al->tcpClient->hasTlsNegotiations())
+                out = al->tcpClient->hasTlsNegotiations()->helloVersion();
+            break;
+
+        case LFT_TLS_SERVER_RECEIVED_HELLO_VERSION:
+            if (al->hier.tcpServer != nullptr && al->hier.tcpServer->hasTlsNegotiations())
+                out = al->hier.tcpServer->hasTlsNegotiations()->helloVersion();
+            break;
+
+        case LFT_TLS_CLIENT_SUPPORTED_VERSION:
+            if (al->tcpClient != nullptr && al->tcpClient->hasTlsNegotiations())
+                out = al->tcpClient->hasTlsNegotiations()->supportedVersion();
+            break;
+
+        case LFT_TLS_SERVER_SUPPORTED_VERSION:
+            if (al->hier.tcpServer != nullptr && al->hier.tcpServer->hasTlsNegotiations())
+                out = al->hier.tcpServer->hasTlsNegotiations()->supportedVersion();
+            break;
+
+        case LFT_TLS_CLIENT_NEGOTIATED_CIPHER:
+            if (al->tcpClient != nullptr && al->tcpClient->hasTlsNegotiations())
+                out = al->tcpClient->hasTlsNegotiations()->cipherName();
+            break;
+
+        case LFT_TLS_SERVER_NEGOTIATED_CIPHER:
+            if (al->hier.tcpServer != nullptr && al->hier.tcpServer->hasTlsNegotiations())
+                out = al->hier.tcpServer->hasTlsNegotiations()->cipherName();
             break;
 #endif
 
@@ -1295,7 +1418,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
             break;
 
         case LFT_EXT_ACL_DATA:
-            out = al->lastAclData;
+            if (!al->lastAclData.isEmpty())
+                out = al->lastAclData.c_str();
             break;
         }
 
@@ -1358,7 +1482,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
                     newout = mbq.content();
                     mbq.stolen = 1;
                     newfree = 1;
-                    } break;
+                }
+                break;
 
                 case LOG_QUOTE_RAW:
                     break;