/*
- * Copyright (C) 1996-2018 The Squid Software Foundation and contributors
+ * Copyright (C) 1996-2023 The Squid Software Foundation and contributors
*
* Squid software is distributed under GPLv2+ license and includes
* contributions from numerous individuals and organizations.
#include "squid.h"
#include "AccessLogEntry.h"
+#include "base64.h"
#include "client_side.h"
#include "comm/Connection.h"
-#include "err_detail_type.h"
+#include "error/Detail.h"
#include "errorpage.h"
#include "fde.h"
#include "format/Format.h"
#include "format/Quoting.h"
#include "format/Token.h"
-#include "fqdncache.h"
#include "http/Stream.h"
#include "HttpRequest.h"
#include "MemBuf.h"
+#include "proxyp/Header.h"
#include "rfc1738.h"
+#include "sbuf/Stream.h"
#include "sbuf/StringConvert.h"
#include "security/CertError.h"
+#include "security/Certificate.h"
#include "security/NegotiationHistory.h"
-#include "SquidTime.h"
#include "Store.h"
#include "tools.h"
#if USE_OPENSSL
const SBuf Format::Dash("-");
Format::Format::Format(const char *n) :
- format(NULL),
- next(NULL)
+ format(nullptr),
+ next(nullptr)
{
name = xstrdup(n);
}
// unlink the next entry for deletion
Format *temp = next;
next = temp->next;
- temp->next = NULL;
+ temp->next = nullptr;
delete temp;
}
Token *new_lt, *last_lt;
enum Quoting quote = LOG_QUOTE_NONE;
- debugs(46, 2, HERE << "got definition '" << def << "'");
+ debugs(46, 2, "got definition '" << def << "'");
if (format) {
debugs(46, DBG_IMPORTANT, "WARNING: existing format for '" << name << " " << def << "'");
return false;
}
- /* very inefficent parser, but who cares, this needs to be simple */
+ /* very inefficient parser, but who cares, this needs to be simple */
/* First off, let's tokenize, we'll optimize in a second pass.
* A token can either be a %-prefixed sequence (usually a dynamic
* token but it can be an escaped sequence), or a string. */
return true;
}
+size_t
+Format::AssembleOne(const char *token, MemBuf &mb, const AccessLogEntryPointer &ale)
+{
+ Token tkn;
+ enum Quoting quote = LOG_QUOTE_NONE;
+ const auto tokenSize = tkn.parse(token, "e);
+ assert(tokenSize > 0);
+ if (ale != nullptr) {
+ Format fmt("SimpleToken");
+ fmt.format = &tkn;
+ fmt.assemble(mb, ale, 0);
+ fmt.format = nullptr;
+ } else {
+ mb.append("-", 1);
+ }
+ return static_cast<size_t>(tokenSize);
+}
+
void
Format::Format::dump(StoreEntry * entry, const char *directiveName, bool eol) const
{
- debugs(46, 4, HERE);
+ debugs(46, 4, MYNAME);
// loop rather than recursing to conserve stack space.
for (const Format *fmt = this; fmt; fmt = fmt->next) {
- debugs(46, 3, HERE << "Dumping format definition for " << fmt->name);
+ debugs(46, 3, "Dumping format definition for " << fmt->name);
if (directiveName)
storeAppendPrintf(entry, "%s %s ", directiveName, fmt->name);
storeAppendPrintf(entry, "%s", t->data.string);
else {
char argbuf[256];
- char *arg = NULL;
+ char *arg = nullptr;
ByteCode_t type = t->type;
switch (type) {
*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
-
/// XXX: Misnamed. TODO: Split <h (and this function) to distinguish received
/// headers from sent headers rather than failing to distinguish requests from responses.
/// \retval HttpReply sent to the HTTP client (access.log and default context).
static const Http::Message *
actualReplyHeader(const AccessLogEntry::Pointer &al)
{
- const Http::Message *msg = al->reply;
+ const Http::Message *msg = al->reply.getRaw();
#if ICAP_CLIENT
// al->icap.reqMethod is methodNone in access.log context
if (!msg && al->icap.reqMethod == Adaptation::methodReqmod)
int dofree = 0;
int64_t outoff = 0;
int dooff = 0;
- struct timeval outtv = {0, 0};
+ struct timeval outtv = {};
int doMsec = 0;
int doSec = 0;
+ bool doUint64 = false;
+ uint64_t outUint64 = 0;
switch (fmt->type) {
break;
case LFT_CLIENT_FQDN:
- if (al->cache.caddr.isAnyAddr()) // e.g., ICAP OPTIONS lack client
- out = "-";
- else
- out = fqdncache_gethostbyaddr(al->cache.caddr, FQDN_LOOKUP_IF_MISS);
-
- if (!out) {
- out = al->cache.caddr.toStr(tmp, sizeof(tmp));
- }
+ out = al->getLogClientFqdn(tmp, sizeof(tmp));
break;
case LFT_CLIENT_PORT:
}
break;
+ case LFT_TRANSPORT_CLIENT_CONNECTION_ID:
+ if (al->tcpClient) {
+ outUint64 = al->tcpClient->id.value;
+ doUint64 = true;
+ }
+ break;
+
case LFT_CLIENT_LOCAL_NFMARK:
if (al->tcpClient) {
sb.appendf("0x%x", al->tcpClient->nfmark);
break;
case LFT_LOCAL_LISTENING_PORT:
- if (const auto addr = FindListeningPortAddress(nullptr, al.getRaw())) {
- outint = addr->port();
+ if (const auto port = FindListeningPortNumber(nullptr, al.getRaw())) {
+ outint = port;
doint = 1;
}
break;
}
break;
+ case LFT_CLIENT_HANDSHAKE:
+ if (al->request && al->request->clientConnectionManager.valid()) {
+ const auto &handshake = al->request->clientConnectionManager->preservedClientData;
+ if (const auto rawLength = handshake.length()) {
+ // add 1 byte to optimize the c_str() conversion below
+ char *buf = sb.rawAppendStart(base64_encode_len(rawLength) + 1);
+
+ struct base64_encode_ctx ctx;
+ base64_encode_init(&ctx);
+ auto encLength = base64_encode_update(&ctx, buf, rawLength, reinterpret_cast<const uint8_t*>(handshake.rawContent()));
+ encLength += base64_encode_final(&ctx, buf + encLength);
+
+ sb.rawAppendFinish(buf, encLength);
+ out = sb.c_str();
+ }
+ }
+ break;
+
case LFT_TIME_SECONDS_SINCE_EPOCH:
// some platforms store time in 32-bit, some 64-bit...
outoff = static_cast<int64_t>(current_time.tv_sec);
doSec = 1;
break;
+ case LFT_BUSY_TIME: {
+ const auto &stopwatch = al->busyTime;
+ if (stopwatch.ran()) {
+ // make sure total() returns nanoseconds compatible with outoff
+ using nanos = std::chrono::duration<decltype(outoff), std::nano>;
+ const nanos n = stopwatch.total();
+ outoff = n.count();
+ dooff = true;
+ }
+ }
+ break;
+
case LFT_TIME_TO_HANDLE_REQUEST:
outtv = al->cache.trTime;
doMsec = 1;
case LFT_DNS_WAIT_TIME:
if (al->request && al->request->dnsWait >= 0) {
// TODO: microsecond precision for dns wait time.
- // Convert miliseconds to timeval struct:
+ // Convert milliseconds to timeval struct:
outtv.tv_sec = al->request->dnsWait / 1000;
outtv.tv_usec = (al->request->dnsWait % 1000) * 1000;
doMsec = 1;
if (al->request) {
const Adaptation::History::Pointer ah = al->request->adaptHistory();
if (ah) { // XXX: add adapt::<all_h but use lastMeta here
- sb = StringToSBuf(ah->allMeta.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator));
+ sb = ah->allMeta.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
out = sb.c_str();
quote = 1;
}
case LFT_ICAP_REQ_HEADER_ELEM:
if (al->icap.request) {
- sb = StringToSBuf(al->icap.request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator));
+ sb = al->icap.request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
out = sb.c_str();
quote = 1;
}
case LFT_ICAP_REP_HEADER_ELEM:
if (al->icap.reply) {
- sb = StringToSBuf(al->icap.reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator));
+ sb = al->icap.reply->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
out = sb.c_str();
quote = 1;
}
#endif
case LFT_REQUEST_HEADER_ELEM:
if (const Http::Message *msg = actualRequestHeader(al)) {
- sb = StringToSBuf(msg->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator));
+ sb = msg->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
+ out = sb.c_str();
+ quote = 1;
+ }
+ break;
+
+ case LFT_PROXY_PROTOCOL_RECEIVED_HEADER:
+ if (al->proxyProtocolHeader) {
+ sb = al->proxyProtocolHeader->getValues(fmt->data.headerId, fmt->data.header.separator);
+ out = sb.c_str();
+ quote = 1;
+ }
+ break;
+
+ case LFT_PROXY_PROTOCOL_RECEIVED_ALL_HEADERS:
+ if (al->proxyProtocolHeader) {
+ sb = al->proxyProtocolHeader->toMime();
+ out = sb.c_str();
+ quote = 1;
+ }
+ break;
+
+ case LFT_PROXY_PROTOCOL_RECEIVED_HEADER_ELEM:
+ if (al->proxyProtocolHeader) {
+ sb = al->proxyProtocolHeader->getElem(fmt->data.headerId, fmt->data.header.element, fmt->data.header.separator);
out = sb.c_str();
quote = 1;
}
case LFT_ADAPTED_REQUEST_HEADER_ELEM:
if (al->adapted_request) {
- sb = StringToSBuf(al->adapted_request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator));
+ sb = al->adapted_request->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
out = sb.c_str();
quote = 1;
}
case LFT_REPLY_HEADER_ELEM:
if (const Http::Message *msg = actualReplyHeader(al)) {
- sb = StringToSBuf(msg->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator));
+ sb = msg->header.getByNameListMember(fmt->data.header.header, fmt->data.header.element, fmt->data.header.separator);
out = sb.c_str();
quote = 1;
}
} else
#endif
{
+ // just headers without start-line and CRLF
+ // XXX: reconcile with '<h'
out = al->headers.request;
quote = 1;
}
break;
case LFT_ADAPTED_REQUEST_ALL_HEADERS:
+ // just headers without start-line and CRLF
+ // XXX: reconcile with '<h'
out = al->headers.adapted_request;
quote = 1;
break;
- case LFT_REPLY_ALL_HEADERS:
- out = al->headers.reply;
+ case LFT_REPLY_ALL_HEADERS: {
+ MemBuf allHeaders;
+ allHeaders.init();
+ // status-line + headers + CRLF
+ // XXX: reconcile with '>h' and '>ha'
+ al->packReplyHeaders(allHeaders);
+ sb.assign(allHeaders.content(), allHeaders.contentSize());
+ out = sb.c_str();
#if ICAP_CLIENT
if (!out && al->icap.reqMethod == Adaptation::methodReqmod)
out = al->headers.adapted_request;
#endif
quote = 1;
- break;
+ }
+ break;
case LFT_USER_NAME:
#if USE_AUTH
/* case LFT_USER_SCHEME: */
// the fmt->type can not be LFT_HTTP_SENT_STATUS_CODE_OLD_30
- // but compiler complains if ommited
+ // but compiler complains if omitted
case LFT_HTTP_SENT_STATUS_CODE_OLD_30:
case LFT_HTTP_SENT_STATUS_CODE:
outint = al->http.code;
break;
case LFT_SQUID_ERROR:
- if (al->request && al->request->errType != ERR_NONE)
- out = errorPageName(al->request->errType);
+ if (const auto error = al->error())
+ out = errorPageName(error->category);
break;
case LFT_SQUID_ERROR_DETAIL:
-#if USE_OPENSSL
- if (al->request && al->request->errType == ERR_SECURE_CONNECT_FAIL) {
- out = Ssl::GetErrorName(al->request->errDetail);
- if (!out)
- out = sslErrorName(al->request->errDetail, tmp, sizeof(tmp));
- } else
-#endif
- if (al->request && al->request->errDetail != ERR_DETAIL_NONE) {
- if (al->request->errDetail > ERR_DETAIL_START && al->request->errDetail < ERR_DETAIL_MAX)
- out = errorDetailName(al->request->errDetail);
- else {
- if (al->request->errDetail >= ERR_DETAIL_EXCEPTION_START)
- sb.appendf("%s=0x%X",
- errorDetailName(al->request->errDetail), (uint32_t) al->request->errDetail);
- else
- sb.appendf("%s=%d",
- errorDetailName(al->request->errDetail), al->request->errDetail);
- out = sb.c_str();
- }
+ if (const auto error = al->error()) {
+ if (const auto detail = error->detail) {
+ sb = detail->brief();
+ out = sb.c_str();
}
+ }
break;
case LFT_SQUID_HIERARCHY:
out = hier_code_str[al->hier.code];
break;
+ case LFT_SQUID_REQUEST_ATTEMPTS:
+ outint = al->requestAttempts;
+ doint = 1;
+ break;
+
case LFT_MIME_TYPE:
out = al->http.content_type;
break;
break;
case LFT_CLIENT_REQ_URI:
- // original client URI
- if (al->request) {
- sb = al->request->effectiveRequestUri();
+ if (const auto uri = al->effectiveVirginUrl()) {
+ sb = *uri;
out = sb.c_str();
quote = 1;
}
break;
case LFT_REQUEST_METHOD:
- sb = al->getLogMethod();
- out = sb.c_str();
- quote = 1;
+ if (al->hasLogMethod()) {
+ sb = al->getLogMethod();
+ out = sb.c_str();
+ quote = 1;
+ }
break;
case LFT_REQUEST_URI:
if (al->request) {
ConnStateData *conn = al->request->clientConnectionManager.get();
if (conn && Comm::IsConnOpen(conn->clientConnection)) {
- if (auto ssl = fd_table[conn->clientConnection->fd].ssl.get())
- out = sslGetUserCertificatePEM(ssl);
+ if (const auto ssl = fd_table[conn->clientConnection->fd].ssl.get()) {
+ sb = sslGetUserCertificatePEM(ssl);
+ out = sb.c_str();
+ }
}
}
break;
if (al->request) {
ConnStateData *conn = al->request->clientConnectionManager.get();
if (conn && Comm::IsConnOpen(conn->clientConnection)) {
- if (auto ssl = fd_table[conn->clientConnection->fd].ssl.get())
- out = sslGetUserCertificatePEM(ssl);
+ if (const auto ssl = fd_table[conn->clientConnection->fd].ssl.get()) {
+ sb = sslGetUserCertificatePEM(ssl);
+ out = sb.c_str();
+ }
}
}
break;
ConnStateData *conn = al->request->clientConnectionManager.get();
if (conn && Comm::IsConnOpen(conn->clientConnection)) {
if (auto ssl = fd_table[conn->clientConnection->fd].ssl.get())
- out = sslGetUserAttribute(ssl, format->data.header.header);
+ out = sslGetUserAttribute(ssl, fmt->data.header.header);
}
}
break;
ConnStateData *conn = al->request->clientConnectionManager.get();
if (conn && Comm::IsConnOpen(conn->clientConnection)) {
if (auto ssl = fd_table[conn->clientConnection->fd].ssl.get())
- out = sslGetCAAttribute(ssl, format->data.header.header);
+ out = sslGetCAAttribute(ssl, fmt->data.header.header);
}
}
break;
case LFT_SSL_USER_CERT_SUBJECT:
- if (X509 *cert = al->cache.sslClientCert.get()) {
- if (X509_NAME *subject = X509_get_subject_name(cert)) {
- X509_NAME_oneline(subject, tmp, sizeof(tmp));
- out = tmp;
- }
+ if (const auto &cert = al->cache.sslClientCert) {
+ sb = Security::SubjectName(*cert);
+ out = sb.c_str();
}
break;
case LFT_SSL_USER_CERT_ISSUER:
- if (X509 *cert = al->cache.sslClientCert.get()) {
- if (X509_NAME *issuer = X509_get_issuer_name(cert)) {
- X509_NAME_oneline(issuer, tmp, sizeof(tmp));
- out = tmp;
- }
+ if (const auto &cert = al->cache.sslClientCert) {
+ sb = Security::IssuerName(*cert);
+ out = sb.c_str();
}
break;
for (const Security::CertErrors *sslError = srvBump->sslErrors(); sslError; sslError = sslError->next) {
if (!sb.isEmpty())
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)));
+ sb.append(Ssl::GetErrorName(sslError->element.code, true));
if (sslError->element.depth >= 0)
sb.appendf("@depth=%d", sslError->element.depth);
}
case LFT_SSL_SERVER_CERT_ISSUER:
case LFT_SSL_SERVER_CERT_SUBJECT:
+ case LFT_SSL_SERVER_CERT_WHOLE:
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
+ else if (fmt->type == LFT_SSL_SERVER_CERT_ISSUER)
out = Ssl::GetX509CAAttribute(serverCert, "DN");
+ else {
+ assert(fmt->type == LFT_SSL_SERVER_CERT_WHOLE);
+ sb = Ssl::GetX509PEM(serverCert);
+ out = sb.c_str();
+ quote = 1;
+ }
}
}
}
case LFT_REQUEST_URLGROUP_OLD_2X:
assert(LFT_REQUEST_URLGROUP_OLD_2X == 0); // should never happen.
+ break;
case LFT_NOTE:
tmp[0] = fmt->data.header.separator;
if (!al->lastAclData.isEmpty())
out = al->lastAclData.c_str();
break;
+
+ case LFT_MASTER_XACTION:
+ if (al->request) {
+ doUint64 = true;
+ outUint64 = static_cast<uint64_t>(al->request->masterXaction->id.value);
+ break;
+ }
}
if (dooff) {
} else if (doint) {
sb.appendf("%0*ld", fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, outint);
out = sb.c_str();
+ } else if (doUint64) {
+ sb.appendf("%0*" PRIu64, fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, outUint64);
+ out = sb.c_str();
} else if (doMsec) {
if (fmt->widthMax < 0) {
- sb.appendf("%0*ld", fmt->widthMin, tvToMsec(outtv));
+ sb.appendf("%0*ld", fmt->zero && fmt->widthMin >= 0 ? fmt->widthMin : 0, tvToMsec(outtv));
} else {
int precision = fmt->widthMax;
sb.appendf("%0*" PRId64 ".%0*" PRId64 "", fmt->zero && (fmt->widthMin - precision - 1 >= 0) ? fmt->widthMin - precision - 1 : 0, static_cast<int64_t>(outtv.tv_sec * 1000 + outtv.tv_usec / 1000), precision, static_cast<int64_t>((outtv.tv_usec % 1000 )* (1000 / fmt->divisor)));
static_assert(sizeof(quotedOut) > 0, "quotedOut has zero length");
quotedOut[0] = '\0';
- char *newout = NULL;
+ char *newout = nullptr;
int newfree = 0;
switch (fmt->quote) {
}
// enforce width limits if configured
- const bool haveMaxWidth = fmt->widthMax >=0 && !doint && !dooff && !doMsec && !doSec;
+ const bool haveMaxWidth = fmt->widthMax >=0 && !doint && !dooff && !doMsec && !doSec && !doUint64;
if (haveMaxWidth || fmt->widthMin) {
const int minWidth = fmt->widthMin >= 0 ?
fmt->widthMin :0;