access_log.cc
Go to the documentation of this file.
1/*
2 * Copyright (C) 1996-2023 The Squid Software Foundation and contributors
3 *
4 * Squid software is distributed under GPLv2+ license and includes
5 * contributions from numerous individuals and organizations.
6 * Please see the COPYING and CONTRIBUTORS files for details.
7 */
8
9/* DEBUG: section 46 Access Log */
10
11#include "squid.h"
12#include "AccessLogEntry.h"
13#include "acl/Checklist.h"
14#include "sbuf/Algorithms.h"
15#if USE_ADAPTATION
16#include "adaptation/Config.h"
17#endif
18#include "base/PackableStream.h"
19#include "CachePeer.h"
20#include "error/Detail.h"
21#include "errorpage.h"
22#include "format/Token.h"
23#include "globals.h"
24#include "hier_code.h"
25#include "HttpReply.h"
26#include "HttpRequest.h"
27#include "log/access_log.h"
28#include "log/Config.h"
29#include "log/CustomLog.h"
30#include "log/File.h"
31#include "log/Formats.h"
32#include "MemBuf.h"
33#include "mgr/Registration.h"
34#include "rfc1738.h"
35#include "sbuf/SBuf.h"
36#include "SquidConfig.h"
37#include "Store.h"
38
39#if USE_SQUID_EUI
40#include "eui/Eui48.h"
41#include "eui/Eui64.h"
42#endif
43
44#include <unordered_map>
45
46#if USE_FORW_VIA_DB
47
48using HeaderValueCountsElement = std::pair<const SBuf, uint64_t>;
50using HeaderValueCounts = std::unordered_map<SBuf, uint64_t, std::hash<SBuf>, std::equal_to<SBuf>, PoolingAllocator<HeaderValueCountsElement> >;
51
53static HeaderValueCounts TheViaCounts;
55static HeaderValueCounts TheForwardedCounts;
56
57static OBJH fvdbDumpVia;
58static OBJH fvdbDumpForwarded;
59static void fvdbClear(void);
60static void fvdbRegisterWithCacheManager();
61#endif
62
64
65void
67{
68
69 if (al->url.isEmpty())
70 al->url = Format::Dash;
71
72 if (!al->http.content_type || *al->http.content_type == '\0')
74
75 if (al->hier.host[0] == '\0')
77
78 for (; log; log = log->next) {
79 if (log->aclList && checklist && !checklist->fastCheck(log->aclList).allowed())
80 continue;
81
82 // The special-case "none" type has no logfile object set
83 if (log->type == Log::Format::CLF_NONE)
84 return;
85
86 if (log->logfile) {
87 logfileLineStart(log->logfile);
88
89 switch (log->type) {
90
92 Log::Format::SquidNative(al, log->logfile);
93 break;
94
96 Log::Format::HttpdCombined(al, log->logfile);
97 break;
98
100 Log::Format::HttpdCommon(al, log->logfile);
101 break;
102
104 Log::Format::SquidReferer(al, log->logfile);
105 break;
106
108 Log::Format::SquidUserAgent(al, log->logfile);
109 break;
110
113 break;
114
115#if ICAP_CLIENT
117 Log::Format::SquidIcap(al, log->logfile);
118 break;
119#endif
120
121 default:
122 fatalf("Unknown log format %d\n", log->type);
123 break;
124 }
125
126 logfileLineEnd(log->logfile);
127 }
128
129 // NP: WTF? if _any_ log line has no checklist ignore the following ones?
130 if (!checklist)
131 break;
132 }
133}
134
135void
137{
139 return;
140
141 accessLogLogTo(Config.Log.accesslogs, al, checklist);
142}
143
144void
146{
147 CustomLog *log;
148#if USE_FORW_VIA_DB
149
150 fvdbClear();
151#endif
152
153 for (log = Config.Log.accesslogs; log; log = log->next) {
154 log->rotate();
155 }
156}
157
158void
160{
161 CustomLog *log;
162
163 for (log = Config.Log.accesslogs; log; log = log->next) {
164 if (log->logfile) {
165 logfileClose(log->logfile);
166 log->logfile = nullptr;
167 }
168 }
169}
170
173 cd_lookup(LOOKUP_NONE),
174 n_choices(0),
175 n_ichoices(0),
176 peer_reply_status(Http::scNone),
177 tcpServer(nullptr),
178 bodyBytesRead(-1)
179{
180 memset(host, '\0', SQUIDHOSTNAMELEN);
181 memset(cd_host, '\0', SQUIDHOSTNAMELEN);
182
183 peer_select_start.tv_sec =0;
184 peer_select_start.tv_usec =0;
185
186 store_complete_stop.tv_sec =0;
187 store_complete_stop.tv_usec =0;
188
190
191 totalResponseTime_.tv_sec = -1;
192 totalResponseTime_.tv_usec = 0;
193
194 firstConnStart_.tv_sec = 0;
195 firstConnStart_.tv_usec = 0;
196}
197
198void
200{
202
204 if (tcpServer == nullptr) {
205 code = HIER_NONE;
206 xstrncpy(host, requestedHost, sizeof(host));
207 } else {
209
210 if (tcpServer->getPeer()) {
211 // went to peer, log peer host name
212 xstrncpy(host, tcpServer->getPeer()->name, sizeof(host));
213 } else {
214 xstrncpy(host, requestedHost, sizeof(host));
215 }
216 }
217}
218
220void
222{
223 peer_last_read_.tv_sec = 0;
224 peer_last_read_.tv_usec = 0;
225
226 peer_last_write_.tv_sec = 0;
227 peer_last_write_.tv_usec = 0;
228
229 bodyBytesRead = -1;
230}
231
232void
234{
236}
237
238void
240{
242}
243
244void
246{
247 if (!firstConnStart_.tv_sec)
249}
250
251void
253{
254 debugs(46, 5, "First connection started: " << firstConnStart_ <<
255 ", current total response time value: " << (totalResponseTime_.tv_sec * 1000 + totalResponseTime_.tv_usec/1000) <<
256 (force ? ", force fixing" : ""));
257 if (!force && totalResponseTime_.tv_sec != -1)
258 return;
259
260 if (firstConnStart_.tv_sec)
262}
263
264bool
265HierarchyLogEntry::peerResponseTime(struct timeval &responseTime)
266{
267 // no I/O whatsoever
268 if (peer_last_write_.tv_sec <= 0 && peer_last_read_.tv_sec <= 0)
269 return false;
270
271 // accommodate read without (completed) write
272 const auto last_write = peer_last_write_.tv_sec > 0 ?
274
275 // accommodate write without (completed) read
276 const auto last_read = peer_last_read_.tv_sec > 0 ?
278
279 tvSub(responseTime, last_write, last_read);
280 // The peer response time (%<pt) stopwatch is currently defined to start
281 // when we wrote the entire request. Thus, if we wrote something after the
282 // last read, report zero peer response time.
283 if (responseTime.tv_sec < 0) {
284 responseTime.tv_sec = 0;
285 responseTime.tv_usec = 0;
286 }
287
288 return true;
289}
290
291bool
292HierarchyLogEntry::totalResponseTime(struct timeval &responseTime)
293{
294 // This should not really happen, but there may be rare code
295 // paths that lead to FwdState discarded (or transaction logged)
296 // without (or before) a stopPeerClock() call.
297 if (firstConnStart_.tv_sec && totalResponseTime_.tv_sec == -1)
298 stopPeerClock(false);
299
300 responseTime = totalResponseTime_;
301 return responseTime.tv_sec >= 0 && responseTime.tv_usec >= 0;
302}
303
304static void
306{
307#if USE_FORW_VIA_DB
308 fvdbRegisterWithCacheManager();
309#endif
310}
311
312void
314{
315 CustomLog *log;
316
318
319#if USE_ADAPTATION
321#endif
322#if ICAP_CLIENT
324#endif
325
326 for (log = Config.Log.accesslogs; log; log = log->next) {
327 if (log->type == Log::Format::CLF_NONE)
328 continue;
329
330 log->logfile = logfileOpen(log->filename, log->bufferSize, log->fatal);
331
333
334#if USE_ADAPTATION
335 for (Format::Token * curr_token = (log->logFormat?log->logFormat->format:nullptr); curr_token; curr_token = curr_token->next) {
336 if (curr_token->type == Format::LFT_ADAPTATION_SUM_XACT_TIMES ||
337 curr_token->type == Format::LFT_ADAPTATION_ALL_XACT_TIMES ||
338 curr_token->type == Format::LFT_ADAPTATION_LAST_HEADER ||
339 curr_token->type == Format::LFT_ADAPTATION_LAST_HEADER_ELEM ||
340 curr_token->type == Format::LFT_ADAPTATION_LAST_ALL_HEADERS||
341 (curr_token->type == Format::LFT_NOTE && !Adaptation::Config::metaHeaders.empty())) {
343 }
344#if ICAP_CLIENT
345 if (curr_token->type == Format::LFT_ICAP_TOTAL_TIME) {
347 }
348#endif
349 }
350#endif
351 }
352}
353
354#if USE_FORW_VIA_DB
355
356static void
357fvdbRegisterWithCacheManager(void)
358{
359 Mgr::RegisterAction("via_headers", "Via Request Headers", fvdbDumpVia, 0, 1);
360 Mgr::RegisterAction("forw_headers", "X-Forwarded-For Request Headers",
361 fvdbDumpForwarded, 0, 1);
362}
363
364void
365fvdbCountVia(const SBuf &headerValue)
366{
367 ++TheViaCounts[headerValue];
368}
369
370void
371fvdbCountForwarded(const SBuf &key)
372{
373 ++TheForwardedCounts[key];
374}
375
376static void
377fvdbDumpCounts(StoreEntry &e, const HeaderValueCounts &counts)
378{
379 PackableStream os(e);
380 for (const auto &i : counts)
381 os << std::setw(9) << i.second << ' ' << i.first << "\n";
382}
383
384static void
385fvdbDumpVia(StoreEntry * e)
386{
387 assert(e);
388 fvdbDumpCounts(*e, TheViaCounts);
389}
390
391static void
392fvdbDumpForwarded(StoreEntry * e)
393{
394 assert(e);
395 fvdbDumpCounts(*e, TheForwardedCounts);
396}
397
398static void
399fvdbClear(void)
400{
401 TheViaCounts.clear();
402 TheForwardedCounts.clear();
403}
404
405#endif
406
class SquidConfig Config
Definition: SquidConfig.cc:12
void accessLogInit(void)
Definition: access_log.cc:313
void accessLogLog(const AccessLogEntryPointer &al, ACLChecklist *checklist)
Definition: access_log.cc:136
void accessLogClose(void)
Definition: access_log.cc:159
void accessLogLogTo(CustomLog *log, const AccessLogEntryPointer &al, ACLChecklist *checklist)
Definition: access_log.cc:66
static void accessLogRegisterWithCacheManager(void)
Definition: access_log.cc:305
int LogfileStatus
Definition: access_log.cc:63
void accessLogRotate(void)
Definition: access_log.cc:145
void fvdbCountVia(const SBuf &)
void fvdbCountForwarded(const SBuf &)
count occurrences of the given X-Forwarded-For header value
void log(char *format,...)
#define assert(EX)
Definition: assert.h:17
static char server[MAXLINE]
Acl::Answer const & fastCheck()
Definition: Checklist.cc:332
HierarchyLogEntry hier
class AccessLogEntry::HttpDetails http
bool allowed() const
Definition: Acl.h:156
static Notes metaHeaders
The list of configured meta headers.
Definition: Config.h:58
char * name
Definition: CachePeer.h:60
hier_code peerType
Definition: Connection.h:152
CachePeer * getPeer() const
Definition: Connection.cc:124
Token * next
Definition: Token.h:71
char host[SQUIDHOSTNAMELEN]
struct timeval peer_select_start
void clearPeerNotes()
forget previous notePeerRead() and notePeerWrite() calls (if any)
Definition: access_log.cc:221
struct timeval peer_last_write_
time of the last write to the last peer
bool totalResponseTime(struct timeval &responseTime)
Definition: access_log.cc:292
struct timeval store_complete_stop
int64_t bodyBytesRead
number of body bytes received from the next hop or -1
Comm::ConnectionPointer tcpServer
TCP/IP level details of the last peer/server connection.
timeval firstConnStart_
first connection use among all peers
char cd_host[SQUIDHOSTNAMELEN]
bool peerResponseTime(struct timeval &responseTime)
Definition: access_log.cc:265
struct timeval totalResponseTime_
cumulative for all peers
struct timeval peer_last_read_
time of the last read from the last peer
void startPeerClock()
Start recording total time spent communicating with peers.
Definition: access_log.cc:245
void stopPeerClock(const bool force)
Definition: access_log.cc:252
void resetPeerNotes(const Comm::ConnectionPointer &server, const char *requestedHost)
Definition: access_log.cc:199
bool hasIcapToken
Definition: Config.h:53
bool hasAdaptToken
Definition: Config.h:49
bool empty() const
Definition: Notes.h:139
STL Allocator that uses Squid memory pools for memory management.
Definition: SBuf.h:94
bool isEmpty() const
Definition: SBuf.h:431
CustomLog * accesslogs
Definition: SquidConfig.h:186
struct SquidConfig::@98 Log
#define debugs(SECTION, LEVEL, CONTENT)
Definition: Stream.h:194
#define LOG_DISABLE
Definition: defines.h:63
#define LOG_ENABLE
Definition: defines.h:62
void fatalf(const char *fmt,...)
Definition: fatal.cc:68
const char * dash_str
@ HIER_NONE
Definition: hier_code.h:13
void logfileLineEnd(Logfile *lf)
Definition: File.cc:132
void logfileLineStart(Logfile *lf)
Definition: File.cc:126
void logfileClose(Logfile *lf)
Definition: File.cc:92
Logfile * logfileOpen(const char *path, size_t bufsz, int fatal_flag)
Definition: File.cc:40
@ LOOKUP_NONE
Definition: lookup_t.h:13
void OBJH(StoreEntry *)
Definition: forward.h:44
const SBuf Dash
@ LFT_ICAP_TOTAL_TIME
Definition: ByteCode.h:194
@ LFT_NOTE
Definition: ByteCode.h:238
@ LFT_ADAPTATION_SUM_XACT_TIMES
Definition: ByteCode.h:185
@ LFT_ADAPTATION_LAST_HEADER
Definition: ByteCode.h:187
@ LFT_ADAPTATION_LAST_ALL_HEADERS
Definition: ByteCode.h:189
@ LFT_ADAPTATION_LAST_HEADER_ELEM
Definition: ByteCode.h:188
@ LFT_ADAPTATION_ALL_XACT_TIMES
Definition: ByteCode.h:186
Definition: forward.h:18
@ scNone
Definition: StatusCode.h:21
void HttpdCombined(const AccessLogEntryPointer &al, Logfile *logfile)
Log with Apache httpd combined format.
void SquidCustom(const AccessLogEntryPointer &al, CustomLog *log)
Log with a local custom format.
void SquidIcap(const AccessLogEntryPointer &al, Logfile *logfile)
Display log details in Squid ICAP format.
void SquidUserAgent(const AccessLogEntryPointer &al, Logfile *logfile)
Display log details in useragent format.
@ CLF_COMBINED
Definition: Formats.h:28
@ CLF_ICAP_SQUID
Definition: Formats.h:32
@ CLF_COMMON
Definition: Formats.h:29
@ CLF_USERAGENT
Definition: Formats.h:36
@ CLF_SQUID
Definition: Formats.h:35
@ CLF_REFERER
Definition: Formats.h:34
@ CLF_NONE
Definition: Formats.h:37
@ CLF_CUSTOM
Definition: Formats.h:30
void HttpdCommon(const AccessLogEntryPointer &al, Logfile *logfile)
Log with Apache httpd common format.
void SquidNative(const AccessLogEntryPointer &al, Logfile *logfile)
Native Squid Format Display.
void SquidReferer(const AccessLogEntryPointer &al, Logfile *logfile)
Display log details in Squid old refererlog format.
LogConfig TheConfig
Definition: Config.cc:15
void RegisterAction(char const *action, char const *desc, OBJH *handler, int pw_req_flag, int atomic)
Definition: Registration.cc:16
#define SQUIDHOSTNAMELEN
Definition: rfc2181.h:30
int code
Definition: smb-errors.c:145
static StoreRebuildData counts
void tvSub(struct timeval &res, struct timeval const &t1, struct timeval const &t2)
Definition: gadgets.cc:58
struct timeval current_time
the current UNIX time in timeval {seconds, microseconds} format
Definition: gadgets.cc:17
char * xstrncpy(char *dst, const char *src, size_t n)
Definition: xstring.cc:37

 

Introduction

Documentation

Support

Miscellaneous

Web Site Translations

Mirrors