=== modified file 'src/AccessLogEntry.h' --- src/AccessLogEntry.h 2010-05-02 19:32:42 +0000 +++ src/AccessLogEntry.h 2010-08-04 08:03:34 +0000 @@ -195,7 +195,7 @@ class IcapLogEntry { public: - IcapLogEntry():request(NULL),reply(NULL),outcome(Adaptation::Icap::xoUnknown),trTime(0),ioTime(0),resStatus(HTTP_STATUS_NONE) {} + IcapLogEntry():bodyBytesRead(-1),request(NULL),reply(NULL),outcome(Adaptation::Icap::xoUnknown),trTime(0),ioTime(0),resStatus(HTTP_STATUS_NONE) {} Ip::Address hostAddr; ///< ICAP server IP address String serviceName; ///< ICAP service name @@ -203,6 +203,11 @@ Adaptation::Icap::ICAP::Method reqMethod; ///< ICAP request method int64_t bytesSent; ///< number of bytes sent to ICAP server so far int64_t bytesRead; ///< number of bytes read from ICAP server so far + /** + * number of ICAP body bytes read from ICAP server or -1 for no encapsulated + * message data in ICAP reply (eg 204 responses) + */ + int64_t bodyBytesRead; HttpRequest* request; ///< ICAP request HttpReply* reply; ///< ICAP reply === modified file 'src/HierarchyLogEntry.h' --- src/HierarchyLogEntry.h 2010-06-03 07:49:20 +0000 +++ src/HierarchyLogEntry.h 2010-08-04 07:49:14 +0000 @@ -65,6 +65,7 @@ timeval first_conn_start; ///< first connection use among all peers int64_t total_response_time; ///< cumulative for all peers u_short peer_local_port; //< local port of the last server-side connection + int64_t bodyBytesRead; ///< number of body bytes received from the next hop or -1 }; extern void hierarchyNote(HierarchyLogEntry *, hier_code, const char *); === modified file 'src/Server.cc' --- src/Server.cc 2010-05-23 12:00:47 +0000 +++ src/Server.cc 2010-08-04 06:59:14 +0000 @@ -824,9 +824,27 @@ setFinalReply(virginReply()); } +/// initializes bodyBytesRead stats if needed and applies delta +void +ServerStateData::adjustBodyBytesRead(const int64_t delta) +{ + int64_t &bodyBytesRead = originalRequest()->hier.bodyBytesRead; + + // if we got here, do not log a dash even if we got nothing from the server + if (bodyBytesRead < 0) + bodyBytesRead = 0; + + bodyBytesRead += delta; // supports negative and zero deltas + + // check for overflows ("infinite" response?) and undeflows (a bug) + Must(bodyBytesRead >= 0); +} + void ServerStateData::addVirginReplyBody(const char *data, ssize_t len) { + adjustBodyBytesRead(len); + #if USE_ADAPTATION assert(!adaptationAccessCheckPending); // or would need to buffer while waiting if (startedAdaptation) { === modified file 'src/Server.h' --- src/Server.h 2010-05-23 12:00:47 +0000 +++ src/Server.h 2010-08-02 07:32:32 +0000 @@ -171,6 +171,8 @@ void storeReplyBody(const char *buf, ssize_t len); size_t replyBodySpace(const MemBuf &readBuf, const size_t minSpace) const; + void adjustBodyBytesRead(const int64_t delta); + // These should be private int64_t currentOffset; /**< Our current offset in the StoreEntry */ MemBuf *responseBodyBuffer; /**< Data temporarily buffered for ICAP */ === modified file 'src/adaptation/icap/ModXact.cc' --- src/adaptation/icap/ModXact.cc 2010-06-15 07:21:57 +0000 +++ src/adaptation/icap/ModXact.cc 2010-08-04 07:54:42 +0000 @@ -45,7 +45,8 @@ bodyParser(NULL), canStartBypass(false), // too early protectGroupBypass(true), - replyBodySize(0), + replyHttpHeaderSize(-1),// -1 if there is not any encapsulated message in ICAP reply + replyHttpBodySize(-1), // -1 if there is not any encapsulated message in ICAP reply adaptHistoryId(-1) { assert(virginHeader); @@ -964,11 +965,15 @@ void Adaptation::Icap::ModXact::parseHttpHead() { if (gotEncapsulated("res-hdr") || gotEncapsulated("req-hdr")) { + replyHttpHeaderSize = 0; maybeAllocateHttpMsg(); if (!parseHead(adapted.header)) return; // need more header data + if (adapted.header) + replyHttpHeaderSize = adapted.header->hdr_sz; + if (dynamic_cast(adapted.header)) { const HttpRequest *oldR = dynamic_cast(virgin.header); Must(oldR); @@ -1016,6 +1021,7 @@ if (gotEncapsulated("res-body") || gotEncapsulated("req-body")) { debugs(93, 5, HERE << "expecting a body"); state.parsing = State::psBody; + replyHttpBodySize = 0; bodyParser = new ChunkedCodingParser; makeAdaptedBodyPipe("adapted response from the ICAP server"); Must(state.sending == State::sendingAdapted); @@ -1040,7 +1046,7 @@ debugs(93, 5, HERE << "have " << readBuf.contentSize() << " body bytes after " << "parse; parsed all: " << parsed); - replyBodySize += adapted.body_pipe->buf().contentSize(); + replyHttpBodySize += adapted.body_pipe->buf().contentSize(); // TODO: expose BodyPipe::putSize() to make this check simpler and clearer // TODO: do we really need this if we disable when sending headers? @@ -1195,11 +1201,21 @@ #endif al.cache.code = h->logType; al.cache.requestSize = h->req_sz; + + // leave al.icap.bodyBytesRead negative if no body + if (replyHttpHeaderSize >= 0 || replyHttpBodySize >= 0) { + const int64_t zero = 0; // to make max() argument types the same + al.icap.bodyBytesRead = + max(zero, replyHttpHeaderSize) + max(zero, replyHttpBodySize); + } + if (reply_) { al.http.code = reply_->sline.status; al.http.content_type = reply_->content_type.termedBuf(); - al.cache.replySize = replyBodySize + reply_->hdr_sz; - al.cache.highOffset = replyBodySize; + if (replyHttpBodySize >= 0) { + al.cache.replySize = replyHttpBodySize + reply_->hdr_sz; + al.cache.highOffset = replyHttpBodySize; + } //don't set al.cache.objectSize because it hasn't exist yet Packer p; === modified file 'src/adaptation/icap/ModXact.h' --- src/adaptation/icap/ModXact.h 2010-06-15 07:21:57 +0000 +++ src/adaptation/icap/ModXact.h 2010-08-02 07:32:44 +0000 @@ -273,7 +273,8 @@ bool canStartBypass; // enables bypass of transaction failures bool protectGroupBypass; // protects ServiceGroup-wide bypass of failures - uint64_t replyBodySize; ///< dechunked ICAP reply body size + int64_t replyHttpHeaderSize; ///< size of HTTP header in ICAP reply + int64_t replyHttpBodySize; ///< size of dechunked HTTP body in ICAP reply int adaptHistoryId; ///< adaptation history slot reservation === modified file 'src/adaptation/icap/OptXact.cc' --- src/adaptation/icap/OptXact.cc 2010-06-14 20:01:59 +0000 +++ src/adaptation/icap/OptXact.cc 2010-08-02 07:32:44 +0000 @@ -109,6 +109,10 @@ { // al.cache.caddr = 0; al.icap.reqMethod = Adaptation::methodOptions; + + if (icapReply && al.icap.bytesRead > icapReply->hdr_sz) + al.icap.bodyBytesRead = al.icap.bytesRead - icapReply->hdr_sz; + Adaptation::Icap::Xaction::finalizeLogInfo(); } === modified file 'src/cf.data.pre' --- src/cf.data.pre 2010-07-29 13:04:44 +0000 +++ src/cf.data.pre 2010-08-04 07:33:33 +0000 @@ -2672,6 +2672,11 @@ [http::]ue User name from external acl helper [http::]>Hs HTTP status code sent to the client [http::]Hs", LFT_HTTP_SENT_STATUS_CODE}, {"st", LFT_ICAP_BYTES_SENT}, {"icap::h", LFT_ICAP_REQ_HEADER}, {"icap::icap.bodyBytesRead >= 0) { + outoff = al->icap.bodyBytesRead; + dooff = 1; + } + //else if icap.bodyBytesRead < 0, we do not have any http data, + // (204 or option responses etc) so just print a "-" + break; + case LFT_ICAP_REQ_HEADER: if (NULL != al->icap.request) { sb = al->icap.request->header.getByName(fmt->data.header.header); @@ -1089,6 +1102,15 @@ * quote = 1; * break; */ + case LFT_HTTP_BODY_BYTES_READ: + if (al->hier.bodyBytesRead >= 0) { + outoff = al->hier.bodyBytesRead; + dooff = 1; + } + // else if hier.bodyBytesRead < 0 we did not have any data exchange with + // a peer server (eg requests served from cache, or internal error messages). + // In this case just print a "-". + break; case LFT_SQUID_STATUS: if (al->http.timedout || al->http.aborted) { @@ -2093,7 +2115,8 @@ peer_reply_status(HTTP_STATUS_NONE), peer_response_time(-1), total_response_time(-1), - peer_local_port(0) + peer_local_port(0), + bodyBytesRead(-1) { memset(host, '\0', SQUIDHOSTNAMELEN); memset(cd_host, '\0', SQUIDHOSTNAMELEN);