]> git.ipfire.org Git - thirdparty/squid.git/blobdiff - src/log/access_log.cc
Source Format Enforcement (#763)
[thirdparty/squid.git] / src / log / access_log.cc
index 019c3ca2a611c9e8278d0a5e2e7d37cf5c4699f4..a35bdee646091b3b1c8da47a15912c1048d2d289 100644 (file)
@@ -1,41 +1,21 @@
 /*
- * DEBUG: section 46    Access Log
- * AUTHOR: Duane Wessels
- *
- * SQUID Web Proxy Cache          http://www.squid-cache.org/
- * ----------------------------------------------------------
- *
- *  Squid is the result of efforts by numerous individuals from
- *  the Internet community; see the CONTRIBUTORS file for full
- *  details.   Many organizations have provided support for Squid's
- *  development; see the SPONSORS file for full details.  Squid is
- *  Copyrighted (C) 2001 by the Regents of the University of
- *  California; see the COPYRIGHT file for full details.  Squid
- *  incorporates software developed and/or copyrighted by other
- *  sources; see the CREDITS file for full details.
- *
- *  This program is free software; you can redistribute it and/or modify
- *  it under the terms of the GNU General Public License as published by
- *  the Free Software Foundation; either version 2 of the License, or
- *  (at your option) any later version.
- *
- *  This program is distributed in the hope that it will be useful,
- *  but WITHOUT ANY WARRANTY; without even the implied warranty of
- *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
- *  GNU General Public License for more details.
- *
- *  You should have received a copy of the GNU General Public License
- *  along with this program; if not, write to the Free Software
- *  Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
+ * Copyright (C) 1996-2021 The Squid Software Foundation and contributors
  *
+ * Squid software is distributed under GPLv2+ license and includes
+ * contributions from numerous individuals and organizations.
+ * Please see the COPYING and CONTRIBUTORS files for details.
  */
 
+/* DEBUG: section 46    Access Log */
+
 #include "squid.h"
 #include "AccessLogEntry.h"
 #include "acl/Checklist.h"
+#if USE_ADAPTATION
+#include "adaptation/Config.h"
+#endif
 #include "CachePeer.h"
-#include "err_detail_type.h"
-#include "errorpage.h"
+#include "error/Detail.h"
 #include "errorpage.h"
 #include "format/Token.h"
 #include "globals.h"
@@ -44,6 +24,7 @@
 #include "HttpRequest.h"
 #include "log/access_log.h"
 #include "log/Config.h"
+#include "log/CustomLog.h"
 #include "log/File.h"
 #include "log/Formats.h"
 #include "MemBuf.h"
@@ -90,29 +71,26 @@ static void fvdbRegisterWithCacheManager();
 int LogfileStatus = LOG_DISABLE;
 
 void
-accessLogLogTo(customlog* log, AccessLogEntry::Pointer &al, ACLChecklist * checklist)
+accessLogLogTo(CustomLog* log, AccessLogEntry::Pointer &al, ACLChecklist * checklist)
 {
 
-    if (al->url == NULL)
-        al->url = dash_str;
+    if (al->url.isEmpty())
+        al->url = Format::Dash;
 
     if (!al->http.content_type || *al->http.content_type == '\0')
         al->http.content_type = dash_str;
 
-    if (al->icp.opcode)
-        al->_private.method_str = icp_opcode_str[al->icp.opcode];
-    else if (al->htcp.opcode)
-        al->_private.method_str = al->htcp.opcode;
-    else
-        al->_private.method_str = RequestMethodStr(al->http.method);
-
     if (al->hier.host[0] == '\0')
         xstrncpy(al->hier.host, dash_str, SQUIDHOSTNAMELEN);
 
     for (; log; log = log->next) {
-        if (log->aclList && checklist && checklist->fastCheck(log->aclList) != ACCESS_ALLOWED)
+        if (log->aclList && checklist && !checklist->fastCheck(log->aclList).allowed())
             continue;
 
+        // The special-case "none" type has no logfile object set
+        if (log->type == Log::Format::CLF_NONE)
+            return;
+
         if (log->logfile) {
             logfileLineStart(log->logfile);
 
@@ -148,9 +126,6 @@ accessLogLogTo(customlog* log, AccessLogEntry::Pointer &al, ACLChecklist * check
                 break;
 #endif
 
-            case Log::Format::CLF_NONE:
-                return; // abort!
-
             default:
                 fatalf("Unknown log format %d\n", log->type);
                 break;
@@ -183,8 +158,8 @@ accessLogLog(AccessLogEntry::Pointer &al, ACLChecklist * checklist)
     else {
         unsigned int ibuf[365];
         size_t isize;
-        xstrncpy((char *) ibuf, al->url, 364 * sizeof(int));
-        isize = ((strlen(al->url) + 8) / 8) * 2;
+        xstrncpy((char *) ibuf, al->url.c_str(), 364 * sizeof(int));
+        isize = ((al->url.length() + 8) / 8) * 2;
 
         if (isize > 364)
             isize = 364;
@@ -203,7 +178,7 @@ accessLogLog(AccessLogEntry::Pointer &al, ACLChecklist * checklist)
 void
 accessLogRotate(void)
 {
-    customlog *log;
+    CustomLog *log;
 #if USE_FORW_VIA_DB
 
     fvdbClear();
@@ -211,13 +186,14 @@ accessLogRotate(void)
 
     for (log = Config.Log.accesslogs; log; log = log->next) {
         if (log->logfile) {
-            logfileRotate(log->logfile);
+            int16_t rc = (log->rotateCount >= 0 ? log->rotateCount : Config.Log.rotateNumber);
+            logfileRotate(log->logfile, rc);
         }
     }
 
 #if HEADERS_LOG
 
-    logfileRotate(headerslog);
+    logfileRotate(headerslog, Config.Log.rotateNumber);
 
 #endif
 }
@@ -225,7 +201,7 @@ accessLogRotate(void)
 void
 accessLogClose(void)
 {
-    customlog *log;
+    CustomLog *log;
 
     for (log = Config.Log.accesslogs; log; log = log->next) {
         if (log->logfile) {
@@ -244,15 +220,13 @@ accessLogClose(void)
 }
 
 HierarchyLogEntry::HierarchyLogEntry() :
-        code(HIER_NONE),
-        cd_lookup(LOOKUP_NONE),
-        n_choices(0),
-        n_ichoices(0),
-        peer_reply_status(HTTP_STATUS_NONE),
-        peer_response_time(-1),
-        total_response_time(-1),
-        tcpServer(NULL),
-        bodyBytesRead(-1)
+    code(HIER_NONE),
+    cd_lookup(LOOKUP_NONE),
+    n_choices(0),
+    n_ichoices(0),
+    peer_reply_status(Http::scNone),
+    tcpServer(NULL),
+    bodyBytesRead(-1)
 {
     memset(host, '\0', SQUIDHOSTNAMELEN);
     memset(cd_host, '\0', SQUIDHOSTNAMELEN);
@@ -263,16 +237,20 @@ HierarchyLogEntry::HierarchyLogEntry() :
     store_complete_stop.tv_sec =0;
     store_complete_stop.tv_usec =0;
 
-    peer_http_request_sent.tv_sec = 0;
-    peer_http_request_sent.tv_usec = 0;
+    clearPeerNotes();
+
+    totalResponseTime_.tv_sec = -1;
+    totalResponseTime_.tv_usec = 0;
 
-    first_conn_start.tv_sec = 0;
-    first_conn_start.tv_usec = 0;
+    firstConnStart_.tv_sec = 0;
+    firstConnStart_.tv_usec = 0;
 }
 
 void
-HierarchyLogEntry::note(const Comm::ConnectionPointer &server, const char *requestedHost)
+HierarchyLogEntry::resetPeerNotes(const Comm::ConnectionPointer &server, const char *requestedHost)
 {
+    clearPeerNotes();
+
     tcpServer = server;
     if (tcpServer == NULL) {
         code = HIER_NONE;
@@ -289,6 +267,91 @@ HierarchyLogEntry::note(const Comm::ConnectionPointer &server, const char *reque
     }
 }
 
+/// forget previous notePeerRead() and notePeerWrite() calls (if any)
+void
+HierarchyLogEntry::clearPeerNotes()
+{
+    peer_last_read_.tv_sec = 0;
+    peer_last_read_.tv_usec = 0;
+
+    peer_last_write_.tv_sec = 0;
+    peer_last_write_.tv_usec = 0;
+
+    bodyBytesRead = -1;
+}
+
+void
+HierarchyLogEntry::notePeerRead()
+{
+    peer_last_read_ = current_time;
+}
+
+void
+HierarchyLogEntry::notePeerWrite()
+{
+    peer_last_write_ = current_time;
+}
+
+void
+HierarchyLogEntry::startPeerClock()
+{
+    if (!firstConnStart_.tv_sec)
+        firstConnStart_ = current_time;
+}
+
+void
+HierarchyLogEntry::stopPeerClock(const bool force)
+{
+    debugs(46, 5, "First connection started: " << firstConnStart_ <<
+           ", current total response time value: " << (totalResponseTime_.tv_sec * 1000 +  totalResponseTime_.tv_usec/1000) <<
+           (force ? ", force fixing" : ""));
+    if (!force && totalResponseTime_.tv_sec != -1)
+        return;
+
+    if (firstConnStart_.tv_sec)
+        tvSub(totalResponseTime_, firstConnStart_, current_time);
+}
+
+bool
+HierarchyLogEntry::peerResponseTime(struct timeval &responseTime)
+{
+    // no I/O whatsoever
+    if (peer_last_write_.tv_sec <= 0 && peer_last_read_.tv_sec <= 0)
+        return false;
+
+    // accommodate read without (completed) write
+    const auto last_write = peer_last_write_.tv_sec > 0 ?
+                            peer_last_write_ : peer_last_read_;
+
+    // accommodate write without (completed) read
+    const auto last_read = peer_last_read_.tv_sec > 0 ?
+                           peer_last_read_ : peer_last_write_;
+
+    tvSub(responseTime, last_write, last_read);
+    // The peer response time (%<pt) stopwatch is currently defined to start
+    // when we wrote the entire request. Thus, if we wrote something after the
+    // last read, report zero peer response time.
+    if (responseTime.tv_sec < 0) {
+        responseTime.tv_sec = 0;
+        responseTime.tv_usec = 0;
+    }
+
+    return true;
+}
+
+bool
+HierarchyLogEntry::totalResponseTime(struct timeval &responseTime)
+{
+    // This should not really happen, but there may be rare code
+    // paths that lead to FwdState discarded (or transaction logged)
+    // without (or before) a stopPeerClock() call.
+    if (firstConnStart_.tv_sec && totalResponseTime_.tv_sec == -1)
+        stopPeerClock(false);
+
+    responseTime = totalResponseTime_;
+    return responseTime.tv_sec >= 0 && responseTime.tv_usec >= 0;
+}
+
 static void
 accessLogRegisterWithCacheManager(void)
 {
@@ -300,7 +363,7 @@ accessLogRegisterWithCacheManager(void)
 void
 accessLogInit(void)
 {
-    customlog *log;
+    CustomLog *log;
 
     accessLogRegisterWithCacheManager();
 
@@ -315,7 +378,7 @@ accessLogInit(void)
         if (log->type == Log::Format::CLF_NONE)
             continue;
 
-        log->logfile = logfileOpen(log->filename, MAX_URL << 2, 1);
+        log->logfile = logfileOpen(log->filename, log->bufferSize, log->fatal);
 
         LogfileStatus = LOG_ENABLE;
 
@@ -325,7 +388,8 @@ accessLogInit(void)
                     curr_token->type == Format::LFT_ADAPTATION_ALL_XACT_TIMES ||
                     curr_token->type == Format::LFT_ADAPTATION_LAST_HEADER ||
                     curr_token->type == Format::LFT_ADAPTATION_LAST_HEADER_ELEM ||
-                    curr_token->type == Format::LFT_ADAPTATION_LAST_ALL_HEADERS) {
+                    curr_token->type == Format::LFT_ADAPTATION_LAST_ALL_HEADERS||
+                    (curr_token->type == Format::LFT_NOTE && !Adaptation::Config::metaHeaders.empty())) {
                 Log::TheConfig.hasAdaptToken = true;
             }
 #if ICAP_CLIENT
@@ -525,7 +589,6 @@ headersLog(int cs, int pq, const HttpRequestMethod& method, void *data)
     HttpRequest *req;
     unsigned short magic = 0;
     unsigned char M = (unsigned char) m;
-    unsigned short S;
     char *hmask;
     int ccmask = 0;
 
@@ -560,10 +623,9 @@ headersLog(int cs, int pq, const HttpRequestMethod& method, void *data)
     magic = htons(magic);
     ccmask = htonl(ccmask);
 
+    unsigned short S = 0;
     if (0 == pq)
-        S = (unsigned short) rep->sline.status;
-    else
-        S = (unsigned short) HTTP_STATUS_NONE;
+        S = static_cast<unsigned short>(rep->sline.status());
 
     logfileWrite(headerslog, &magic, sizeof(magic));
     logfileWrite(headerslog, &M, sizeof(M));
@@ -574,31 +636,3 @@ headersLog(int cs, int pq, const HttpRequestMethod& method, void *data)
 
 #endif
 
-int
-logTypeIsATcpHit(log_type code)
-{
-    /* this should be a bitmap for better optimization */
-
-    if (code == LOG_TCP_HIT)
-        return 1;
-
-    if (code == LOG_TCP_IMS_HIT)
-        return 1;
-
-    if (code == LOG_TCP_REFRESH_FAIL_OLD)
-        return 1;
-
-    if (code == LOG_TCP_REFRESH_UNMODIFIED)
-        return 1;
-
-    if (code == LOG_TCP_NEGATIVE_HIT)
-        return 1;
-
-    if (code == LOG_TCP_MEM_HIT)
-        return 1;
-
-    if (code == LOG_TCP_OFFLINE_HIT)
-        return 1;
-
-    return 0;
-}