From: Amos Jeffries Date: Tue, 29 Oct 2013 02:24:29 +0000 (-0700) Subject: Cleanup transaction message size logging X-Git-Tag: SQUID_3_5_0_1~571 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=d6df21d2b7df823e96a2e4ec58b68de2b3768a92;p=thirdparty%2Fsquid.git Cleanup transaction message size logging - Add class MessageCounters to track all size properties of a transaction message. HTTP-centric for now. - replaced AccessLogEntry::cache.requestHeadersSize with AccessLogEntry::http.clientRequest.headerSz - replaced AccessLogEntry::cache.requestSize with AccessLogEntry::http.clientRequest (total() of all counters) - replaced AccessLogEntry::cache.replyHeadersSize with AccessLogEntry::http.adaptedReply.headerSz - replaced AccessLogEntry::cache.replySize with AccessLogEntry::http.adaptedReply (total() of all counters) - Rename the logformat byte codes for message size counters to form a logical set of details by message type - reorganize and document logformat option codes more clearly There are no logic changes in this patch. Several accounting bugs have been identified and marked for fixing later. --- diff --git a/src/AccessLogEntry.h b/src/AccessLogEntry.h index b3c4908ae3..2ee4b73d34 100644 --- a/src/AccessLogEntry.h +++ b/src/AccessLogEntry.h @@ -40,6 +40,7 @@ #include "icp_opcode.h" #include "ip/Address.h" #include "LogTags.h" +#include "MessageCounters.h" #include "Notes.h" #if ICAP_CLIENT #include "adaptation/icap/Elements.h" @@ -84,7 +85,10 @@ public: public: HttpDetails() : method(Http::METHOD_NONE), code(0), content_type(NULL), - timedout(false), aborted(false) {} + timedout(false), + aborted(false), + clientRequest() + {} HttpRequestMethod method; int code; @@ -97,6 +101,17 @@ public: const char *statusSfx() const { return timedout ? "_TIMEDOUT" : (aborted ? "_ABORTED" : ""); } + + /// counters for the original request received from client + // TODO calculate header and payload better (by parser) + // XXX payload encoding overheads not calculated at all yet. + MessageCounters clientRequest; + + /// counters for the response sent to client + // TODO calculate header and payload better (by parser) + // XXX payload encoding overheads not calculated at all yet. + MessageCounters adaptedReply; + } http; /** \brief This subclass holds log info for ICP protocol @@ -144,10 +159,6 @@ public: public: CacheDetails() : caddr(), - requestSize(0), - replySize(0), - requestHeadersSize(0), - replyHeadersSize(0), highOffset(0), objectSize(0), code (LOG_TAG_NONE), @@ -162,10 +173,6 @@ public: } Ip::Address caddr; - int64_t requestSize; - int64_t replySize; - int requestHeadersSize; ///< received, including request line - int replyHeadersSize; ///< sent, including status line int64_t highOffset; int64_t objectSize; LogTags code; diff --git a/src/Makefile.am b/src/Makefile.am index 2a04e3437e..8f8d528470 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -427,6 +427,7 @@ squid_SOURCES = \ MemBuf.cc \ MemObject.cc \ MemObject.h \ + MessageCounters.h \ mime.h \ mime.cc \ mime_header.h \ diff --git a/src/MessageCounters.h b/src/MessageCounters.h new file mode 100644 index 0000000000..b1b86efd35 --- /dev/null +++ b/src/MessageCounters.h @@ -0,0 +1,29 @@ +#ifndef SQUID_SRC_MESSAGECOUNTERS_H +#define SQUID_SRC_MESSAGECOUNTERS_H + +/** + * Counters used to collate the traffic size measurements + * for a transaction message. + */ +class MessageCounters +{ +public: + MessageCounters() : headerSz(0), payloadDataSz(0), payloadTeSz(0) {} + + /// size of message header block (if any) + uint64_t headerSz; + + /// total size of payload block(s) excluding transfer encoding overheads + uint64_t payloadDataSz; + + /// total size of extra bytes added by transfer encoding + uint64_t payloadTeSz; + + // total message size + uint64_t total() const {return headerSz + payloadDataSz + payloadTeSz;} + + /// total payload size including transfer encoding overheads + uint64_t payloadTotal() const {return payloadDataSz + payloadTeSz;} +}; + +#endif /* SQUID_SRC_MESSAGECOUNTERS_H */ diff --git a/src/adaptation/icap/ModXact.cc b/src/adaptation/icap/ModXact.cc index 71203b4dbd..fc038df289 100644 --- a/src/adaptation/icap/ModXact.cc +++ b/src/adaptation/icap/ModXact.cc @@ -1289,7 +1289,8 @@ void Adaptation::Icap::ModXact::finalizeLogInfo() al.cache.ssluser = h->ssluser.termedBuf(); #endif al.cache.code = h->logType; - al.cache.requestSize = h->req_sz; + // XXX: should use icap-specific counters instead ? + al.http.clientRequest.payloadDataSz = h->req_sz; // leave al.icap.bodyBytesRead negative if no body if (replyHttpHeaderSize >= 0 || replyHttpBodySize >= 0) { @@ -1302,7 +1303,9 @@ void Adaptation::Icap::ModXact::finalizeLogInfo() al.http.code = reply_->sline.status(); al.http.content_type = reply_->content_type.termedBuf(); if (replyHttpBodySize >= 0) { - al.cache.replySize = replyHttpBodySize + reply_->hdr_sz; + // XXX: should use icap-specific counters instead ? + al.http.adaptedReply.payloadDataSz = replyHttpBodySize; + al.http.adaptedReply.headerSz = reply_->hdr_sz; al.cache.highOffset = replyHttpBodySize; } //don't set al.cache.objectSize because it hasn't exist yet diff --git a/src/cf.data.pre b/src/cf.data.pre index 19418e8a26..6fe072bc3c 100644 --- a/src/cf.data.pre +++ b/src/cf.data.pre @@ -3710,6 +3710,21 @@ DOC_START HTTP related format codes: + REQUEST + + [http::]rm Request method (GET/POST etc) + [http::]>rm Request method from client + [http::]ru Request URL from client + [http::]rp Request URL-Path excluding hostname from client + [http::]rv Request protocol version from client + [http::]h Original received request header. Usually differs from the request header sent by Squid, although most fields are often preserved. @@ -3720,37 +3735,41 @@ DOC_START Usually differs from the request header sent by Squid, although most fields are often preserved. Optional header name argument as for >h + + + RESPONSE + + [http::]Hs HTTP status code sent to the client + [http::]h - [http::]>Hs HTTP status code sent to the client - [http::]st Total size of request received from client. + Excluding chunked encoding bytes. + [http::]sh Size of request headers received from client + [http::]rm Request method from client - [http::]ru Request URL from client - [http::]rp Request URL-Path excluding hostname from client - [http::]rv Request protocol version from client - [http::]st Received request size including HTTP headers. In the - case of chunked requests the chunked encoding metadata - are not included - [http::]>sh Received HTTP request headers size - [http::]http.version = request->http_ver; aLogEntry->hier = request->hier; if (request->content_length > 0) // negative when no body or unknown length - aLogEntry->cache.requestSize += request->content_length; + aLogEntry->http.clientRequest.payloadDataSz += request->content_length; // XXX: actually adaptedRequest payload size ?? aLogEntry->cache.extuser = request->extacl_user.termedBuf(); // Adapted request, if any, inherits and then collects all the stats, but @@ -631,7 +631,7 @@ ClientHttpRequest::logRequest() debugs(33, 9, "clientLogRequest: http.code='" << al->http.code << "'"); if (loggingEntry() && loggingEntry()->mem_obj) - al->cache.objectSize = loggingEntry()->contentLen(); + al->cache.objectSize = loggingEntry()->contentLen(); // payload duplicate ?? with or without TE ? al->cache.caddr.setNoAddr(); @@ -640,11 +640,10 @@ ClientHttpRequest::logRequest() al->cache.port = cbdataReference(getConn()->port); } - al->cache.requestSize = req_sz; - al->cache.requestHeadersSize = req_sz; - - al->cache.replySize = out.size; - al->cache.replyHeadersSize = out.headers_sz; + al->http.clientRequest.headerSz = req_sz; + al->http.adaptedReply.headerSz = out.headers_sz; + // XXX: calculate without payload encoding or headers !! + al->http.adaptedReply.payloadDataSz = out.size - out.headers_sz; // pretend its all un-encoded data for now. al->cache.highOffset = out.offset; diff --git a/src/format/ByteCode.h b/src/format/ByteCode.h index 81e33a836f..d32227d6e4 100644 --- a/src/format/ByteCode.h +++ b/src/format/ByteCode.h @@ -88,9 +88,8 @@ typedef enum { LFT_SERVER_REQ_VERSION, /* request meta details */ - LFT_REQUEST_SIZE_TOTAL, - /*LFT_REQUEST_SIZE_LINE, */ - LFT_REQUEST_SIZE_HEADERS, + LFT_CLIENT_REQUEST_SIZE_TOTAL, + LFT_CLIENT_REQUEST_SIZE_HEADERS, /*LFT_REQUEST_SIZE_BODY, */ /*LFT_REQUEST_SIZE_BODY_NO_TE, */ @@ -118,14 +117,15 @@ typedef enum { /* LFT_ADAPTED_REPLY_ALL_HEADERS, */ /* response meta details */ - LFT_REPLY_SIZE_TOTAL, + LFT_ADAPTED_REPLY_SIZE_TOTAL, LFT_REPLY_HIGHOFFSET, LFT_REPLY_OBJECTSIZE, - /*LFT_REPLY_SIZE_LINE, */ - LFT_REPLY_SIZE_HEADERS, + LFT_ADAPTED_REPLY_SIZE_HEADERS, /*LFT_REPLY_SIZE_BODY, */ /*LFT_REPLY_SIZE_BODY_NO_TE, */ + LFT_CLIENT_IO_SIZE_TOTAL, + /* client credentials */ LFT_USER_NAME, /* any source will do */ LFT_USER_LOGIN, @@ -155,7 +155,6 @@ typedef enum { LFT_MIME_TYPE, LFT_TAG, - LFT_IO_SIZE_TOTAL, LFT_EXT_LOG, LFT_SEQUENCE_NUMBER, diff --git a/src/format/Format.cc b/src/format/Format.cc index e737280e8e..353d7119a7 100644 --- a/src/format/Format.cc +++ b/src/format/Format.cc @@ -982,21 +982,21 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS } break; - case LFT_REQUEST_SIZE_TOTAL: - outoff = al->cache.requestSize; + case LFT_CLIENT_REQUEST_SIZE_TOTAL: + outoff = al->http.clientRequest.total(); dooff = 1; break; - /*case LFT_REQUEST_SIZE_LINE: */ - case LFT_REQUEST_SIZE_HEADERS: - outoff = al->cache.requestHeadersSize; + case LFT_CLIENT_REQUEST_SIZE_HEADERS: + outoff = al->http.clientRequest.headerSz; dooff =1; break; + /*case LFT_REQUEST_SIZE_BODY: */ /*case LFT_REQUEST_SIZE_BODY_NO_TE: */ - case LFT_REPLY_SIZE_TOTAL: - outoff = al->cache.replySize; + case LFT_ADAPTED_REPLY_SIZE_TOTAL: + outoff = al->http.adaptedReply.total(); dooff = 1; break; @@ -1014,14 +1014,20 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS break; - /*case LFT_REPLY_SIZE_LINE: */ - case LFT_REPLY_SIZE_HEADERS: - outint = al->cache.replyHeadersSize; + case LFT_ADAPTED_REPLY_SIZE_HEADERS: + outint = al->http.adaptedReply.headerSz; doint = 1; break; + /*case LFT_REPLY_SIZE_BODY: */ /*case LFT_REPLY_SIZE_BODY_NO_TE: */ + case LFT_CLIENT_IO_SIZE_TOTAL: + outint = al->http.clientRequest.total() + al->http.adaptedReply.total(); + doint = 1; + break; + /*case LFT_SERVER_IO_SIZE_TOTAL: */ + case LFT_TAG: if (al->request) out = al->request->tag.termedBuf(); @@ -1030,11 +1036,6 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS break; - case LFT_IO_SIZE_TOTAL: - outint = al->cache.requestSize + al->cache.replySize; - doint = 1; - break; - case LFT_EXT_LOG: if (al->request) out = al->request->extacl_log.termedBuf(); diff --git a/src/format/Token.cc b/src/format/Token.cc index 1dd60e6c50..af80f95baa 100644 --- a/src/format/Token.cc +++ b/src/format/Token.cc @@ -96,22 +96,22 @@ static TokenTableEntry TokenTable2C[] = { /*{"st", LFT_REQUEST_SIZE_TOTAL }, - /*{ ">sl", LFT_REQUEST_SIZE_LINE }, * / / * the request line "GET ... " */ - {">sh", LFT_REQUEST_SIZE_HEADERS }, + {">st", LFT_CLIENT_REQUEST_SIZE_TOTAL }, + {">sh", LFT_CLIENT_REQUEST_SIZE_HEADERS }, /*{ ">sb", LFT_REQUEST_SIZE_BODY }, */ /*{ ">sB", LFT_REQUEST_SIZE_BODY_NO_TE }, */ - {"cache.caddr = caddr; - al->cache.replySize = len; + // XXX: move to use icp.clientReply instead + al->http.adaptedReply.payloadDataSz = len; al->cache.code = logcode; diff --git a/src/log/FormatHttpdCombined.cc b/src/log/FormatHttpdCombined.cc index b63dc62132..efb1a5e344 100644 --- a/src/log/FormatHttpdCombined.cc +++ b/src/log/FormatHttpdCombined.cc @@ -77,7 +77,7 @@ Log::Format::HttpdCombined(const AccessLogEntry::Pointer &al, Logfile * logfile) AnyP::ProtocolType_str[al->http.version.protocol], al->http.version.major, al->http.version.minor, al->http.code, - al->cache.replySize, + al->http.adaptedReply.total(), referer, agent, LogTags_str[al->cache.code], diff --git a/src/log/FormatHttpdCommon.cc b/src/log/FormatHttpdCommon.cc index f1c6e9a94f..590882f5a6 100644 --- a/src/log/FormatHttpdCommon.cc +++ b/src/log/FormatHttpdCommon.cc @@ -64,7 +64,7 @@ Log::Format::HttpdCommon(const AccessLogEntry::Pointer &al, Logfile * logfile) AnyP::ProtocolType_str[al->http.version.protocol], al->http.version.major, al->http.version.minor, al->http.code, - al->cache.replySize, + al->http.adaptedReply.total(), LogTags_str[al->cache.code], al->http.statusSfx(), hier_code_str[al->hier.code], diff --git a/src/log/FormatSquidNative.cc b/src/log/FormatSquidNative.cc index 4fafb6fe51..e10a84f866 100644 --- a/src/log/FormatSquidNative.cc +++ b/src/log/FormatSquidNative.cc @@ -78,7 +78,7 @@ Log::Format::SquidNative(const AccessLogEntry::Pointer &al, Logfile * logfile) LogTags_str[al->cache.code], al->http.statusSfx(), al->http.code, - al->cache.replySize, + al->http.adaptedReply.total(), al->_private.method_str, al->url, user ? user : dash_str,