From d897915e13aaf84f1685b26ad920c447749a023c Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Tue, 5 Oct 2021 17:32:27 +0300 Subject: [PATCH 1/5] Responses with truncated bodies Squid used an error-prone approach to identifying truncated responses: The response is treated as whole[1] unless somebody remembers to mark it as truncated. This dangerous default naturally resulted in bugs where truncated responses are treated as complete under various conditions, This change reverses that approach: Responses not explicitly marked as whole are treated as truncated. This change affects all Squid-server FwsState-dispatched communications: HTTP, FTP, Gopher, and WHOIS. It also affects responses received from the adaptation services. Squid still tries to deliver responses with truncated bodies to clients in most cases (no changes are expected/intended in that area). [1]: A better word to describe a "whole" response would be "complete", but several key Squid APIs use "complete" to mean "no more content is coming", misleading developers into thinking that a "completed" response has all the expected bytes and may be cached/shared/etc. Responses with truncated HTTP headers This change also starts treating responses with truncated HTTP headers (i.e. no CRLF after all the field-lines) as malformed, replacing them with an HTTP 502 ERR_INVALID_RESP error (same as any other HTTP response with malformed headers would get). Since Bug 2879 (commit da6c841 and earlier v2-only changes), Squid was "fixing" such truncated headers by adding an extra CRLF sequence and re-parsing them. Depending on the truncation circumstances, that old workaround could result in rather bad outcomes for Squid and its clients. Hopefully, we no longer need to work around such bugs. If we do, we should do it in a safer manner and with admin permission. Related access-logging improvements Transactions that failed due to origin server or peer timeout (a common source of truncation) are now logged with a _TIMEOUT %Ss suffix and ERR_READ_TIMEOUT/WITH_SRV %err_code/%err_detail. Transactions prematurely canceled by Squid during client-Squid communication (usually due to various timeouts) now have WITH_CLT default %err_detail. This detail helps distinguish otherwise similarly-logged problems that may happen when talking to the client or to the origin server/peer. Other FwdState now (indirectly) complete()s truncated entries _after_ releasing/adjusting them so that invokeHandlers() and others do not get a dangerous glimpse at a seemingly OK entry before its release(). --- src/FwdState.cc | 52 +++++++++++++++++++++++++++++++++----- src/FwdState.h | 11 ++++++++ src/Store.h | 16 ++++++++++-- src/client_side.cc | 10 +++++++- src/client_side_request.cc | 15 ++++++++++- src/client_side_request.h | 3 +++ src/clients/Client.cc | 34 ++++++++++++++++++++++++- src/clients/Client.h | 7 +++++ src/clients/FtpGateway.cc | 1 + src/clients/FtpRelay.cc | 8 +++++- src/gopher.cc | 14 ++++++++++ src/http.cc | 33 +++++++++++++++--------- src/store.cc | 18 +++++++++++-- src/whois.cc | 3 +++ 14 files changed, 199 insertions(+), 26 deletions(-) diff --git a/src/FwdState.cc b/src/FwdState.cc index f68538b45bc..d1df784cdc1 100644 --- a/src/FwdState.cc +++ b/src/FwdState.cc @@ -150,7 +150,8 @@ FwdState::FwdState(const Comm::ConnectionPointer &client, StoreEntry * e, HttpRe start_t(squid_curtime), n_tries(0), destinations(new ResolvedPeers()), - pconnRace(raceImpossible) + pconnRace(raceImpossible), + storedWholeReply_(nullptr) { debugs(17, 2, "Forwarding client request " << client << ", url=" << e->url()); HTTPMSGLOCK(request); @@ -255,6 +256,23 @@ FwdState::selectPeerForIntercepted() } #endif +/// updates ALE when we finalize the transaction error (if any) +void +FwdState::updateAleWithFinalError() +{ + if (!err || !al) + return; + + LogTagsErrors lte; + lte.timedout = (err->xerrno == ETIMEDOUT || err->type == ERR_READ_TIMEOUT); + al->cache.code.err.update(lte); + if (!err->detail) { + static const auto d = MakeNamedErrorDetail("WITH_SRV"); + err->detailError(d); + } + al->updateError(Error(err->type, err->detail)); +} + void FwdState::completed() { @@ -279,20 +297,26 @@ FwdState::completed() if (entry->store_status == STORE_PENDING) { if (entry->isEmpty()) { + assert(!storedWholeReply_); if (!err) // we quit (e.g., fd closed) before an error or content fail(new ErrorState(ERR_READ_ERROR, Http::scBadGateway, request, al)); assert(err); + updateAleWithFinalError(); errorAppendEntry(entry, err); err = NULL; #if USE_OPENSSL if (request->flags.sslPeek && request->clientConnectionManager.valid()) { CallJobHere1(17, 4, request->clientConnectionManager, ConnStateData, ConnStateData::httpsPeeked, ConnStateData::PinnedIdleContext(Comm::ConnectionPointer(nullptr), request)); + // no flags.dont_retry: completed() is a post-reforward() act } #endif } else { - entry->complete(); - entry->releaseRequest(); + updateAleWithFinalError(); // if any + if (storedWholeReply_) + entry->completeSuccessfully(storedWholeReply_); + else + entry->completeTruncated("FwdState default"); } } @@ -549,6 +573,7 @@ FwdState::complete() serverConn = nullptr; destinationReceipt = nullptr; + storedWholeReply_ = nullptr; entry->reset(); useDestinations(); @@ -558,10 +583,8 @@ FwdState::complete() debugs(17, 3, "server FD " << serverConnection()->fd << " not re-forwarding status " << replyStatus); else debugs(17, 3, "server (FD closed) not re-forwarding status " << replyStatus); - entry->complete(); - if (!Comm::IsConnOpen(serverConn)) - completed(); + completed(); stopAndDestroy("forwarding completed"); } @@ -573,6 +596,18 @@ FwdState::usingDestination() const return encryptionWait || peerWait || Comm::IsConnOpen(serverConn); } +void +FwdState::markStoredReplyAsWhole(const char * const whyWeAreSure) +{ + debugs(17, 5, whyWeAreSure << " for " << *entry); + + // the caller wrote everything to Store, but Store may silently abort writes + if (EBIT_TEST(entry->flags, ENTRY_ABORTED)) + return; + + storedWholeReply_ = whyWeAreSure; +} + void FwdState::noteDestination(Comm::ConnectionPointer path) { @@ -1010,6 +1045,8 @@ FwdState::connectedToPeer(Security::EncryptorAnswer &answer) // [in ways that may affect logging?]. Consider informing // ConnStateData about our tunnel or otherwise unifying tunnel // establishment [side effects]. + flags.dont_retry = true; // TunnelStateData took forwarding control + entry->abort(); complete(); // destroys us return; } else if (!Comm::IsConnOpen(answer.conn) || fd_table[answer.conn->fd].closing()) { @@ -1203,9 +1240,12 @@ FwdState::dispatch() #if USE_OPENSSL if (request->flags.sslPeek) { + // we were just asked to peek at the server, and we did that CallJobHere1(17, 4, request->clientConnectionManager, ConnStateData, ConnStateData::httpsPeeked, ConnStateData::PinnedIdleContext(serverConnection(), request)); unregister(serverConn); // async call owns it now + flags.dont_retry = true; // we gave up forwarding control + entry->abort(); complete(); // destroys us return; } diff --git a/src/FwdState.h b/src/FwdState.h index d4d607664fb..94db48fc418 100644 --- a/src/FwdState.h +++ b/src/FwdState.h @@ -78,6 +78,11 @@ class FwdState: public RefCountable, public PeerSelectionInitiator void unregister(Comm::ConnectionPointer &conn); void unregister(int fd); void complete(); + + /// Mark reply as written to Store in its entirety, including the header and + /// any body. If the reply has a body, the entire body has to be stored. + void markStoredReplyAsWhole(const char *whyWeAreSure); + void handleUnregisteredServerEnd(); int reforward(); bool reforwardableStatus(const Http::StatusCode s) const; @@ -159,6 +164,8 @@ class FwdState: public RefCountable, public PeerSelectionInitiator void notifyConnOpener(); void reactToZeroSizeObject(); + void updateAleWithFinalError(); + public: StoreEntry *entry; HttpRequest *request; @@ -200,6 +207,10 @@ class FwdState: public RefCountable, public PeerSelectionInitiator /// possible pconn race states typedef enum { raceImpossible, racePossible, raceHappened } PconnRace; PconnRace pconnRace; ///< current pconn race state + + /// Whether the entire reply (including any body) was written to Store. + /// The string literal value is only used for debugging. + const char *storedWholeReply_ = nullptr; }; class acl_tos; diff --git a/src/Store.h b/src/Store.h index 16520001c2d..5f19842d9c8 100644 --- a/src/Store.h +++ b/src/Store.h @@ -67,9 +67,18 @@ class StoreEntry : public hash_link, public Packable bool isEmpty() const { return mem().endOffset() == 0; } bool isAccepting() const; size_t bytesWanted(Range const aRange, bool ignoreDelayPool = false) const; - /// flags [truncated or too big] entry with ENTRY_BAD_LENGTH and releases it - void lengthWentBad(const char *reason); + + /// Signals that the entire response has been stored and no more append() + /// calls should be expected; cf. completeTruncated(). + void completeSuccessfully(const char *whyWeAreSureWeStoredTheWholeReply); + + /// Signals that a partial response (if any) has been stored but no more + /// append() calls should be expected; cf. completeSuccessfully(). + void completeTruncated(const char *whyWeConsiderTheReplyTruncated); + + /// \deprecated use either completeSuccessfully() or completeTruncated() instead void complete(); + store_client_t storeClientType() const; /// \returns a malloc()ed buffer containing a length-long packed swap header const char *getSerialisedMetaData(size_t &length) const; @@ -308,6 +317,9 @@ class StoreEntry : public hash_link, public Packable StoreEntry *adjustVary(); const cache_key *calcPublicKey(const KeyScope keyScope); + /// flags [truncated or too big] entry with ENTRY_BAD_LENGTH and releases it + void lengthWentBad(const char *reason); + static MemAllocator *pool; unsigned short lock_count; /* Assume < 65536! */ diff --git a/src/client_side.cc b/src/client_side.cc index bb5e087e7d4..eaf24afe31f 100644 --- a/src/client_side.cc +++ b/src/client_side.cc @@ -3993,8 +3993,16 @@ ConnStateData::unpinConnection(const bool andClose) } void -ConnStateData::terminateAll(const Error &error, const LogTagsErrors <e) +ConnStateData::terminateAll(const Error &rawError, const LogTagsErrors <e) { + auto error = rawError; // (cheap) copy so that we can detail + // We detail even ERR_NONE: There should be no transactions left, and + // detailed ERR_NONE will be unused. Otherwise, this detail helps in triage. + if (!error.detail) { + static const auto d = MakeNamedErrorDetail("WITH_CLT"); + error.detail = d; + } + debugs(33, 3, pipeline.count() << '/' << pipeline.nrequests << " after " << error); if (pipeline.empty()) { diff --git a/src/client_side_request.cc b/src/client_side_request.cc index b9624ee4e09..6e9598030fc 100644 --- a/src/client_side_request.cc +++ b/src/client_side_request.cc @@ -161,6 +161,7 @@ ClientHttpRequest::ClientHttpRequest(ConnStateData * aConn) : , sslBumpNeed_(Ssl::bumpEnd) #endif #if USE_ADAPTATION + , receivedWholeAdaptedReply(false) , request_satisfaction_mode(false) , request_satisfaction_offset(0) #endif @@ -2113,6 +2114,11 @@ void ClientHttpRequest::noteBodyProductionEnded(BodyPipe::Pointer) { assert(!virginHeadSource); + + // distinguish this code path from future noteBodyProducerAborted() that + // would continue storing/delivering (truncated) reply if necessary (TODO) + receivedWholeAdaptedReply = true; + // should we end request satisfaction now? if (adaptedBodySource != NULL && adaptedBodySource->exhausted()) endRequestSatisfaction(); @@ -2126,7 +2132,14 @@ ClientHttpRequest::endRequestSatisfaction() stopConsumingFrom(adaptedBodySource); // TODO: anything else needed to end store entry formation correctly? - storeEntry()->complete(); + if (receivedWholeAdaptedReply) { + // We received the entire reply per receivedWholeAdaptedReply. + // We are called when we consumed everything received (per our callers). + // We consume only what we store per noteMoreBodyDataAvailable(). + storeEntry()->completeSuccessfully("received,consumed=>stored the entire REQMOD reply"); + } else { + storeEntry()->completeTruncated("REQMOD request satisfaction default"); + } } void diff --git a/src/client_side_request.h b/src/client_side_request.h index a560561ef77..e2c3160e668 100644 --- a/src/client_side_request.h +++ b/src/client_side_request.h @@ -240,6 +240,9 @@ class ClientHttpRequest CbcPointer virginHeadSource; BodyPipe::Pointer adaptedBodySource; + /// noteBodyProductionEnded() was called + bool receivedWholeAdaptedReply; + bool request_satisfaction_mode; int64_t request_satisfaction_offset; #endif diff --git a/src/clients/Client.cc b/src/clients/Client.cc index 5b1dcc27129..8cb6e9a27b1 100644 --- a/src/clients/Client.cc +++ b/src/clients/Client.cc @@ -155,6 +155,27 @@ Client::setFinalReply(HttpReply *rep) return theFinalReply; } +void +Client::markParsedVirginReplyAsWhole(const char *reasonWeAreSure) +{ + assert(reasonWeAreSure); + debugs(11, 3, reasonWeAreSure); + + // The code storing adapted reply takes care of markStoredReplyAsWhole(). + // We need to take care of the remaining regular network-to-store case. +#if USE_ADAPTATION + if (startedAdaptation) { + debugs(11, 5, "adaptation handles markStoredReplyAsWhole()"); + return; + } +#endif + + // Convert the "parsed whole virgin reply" event into the "stored..." event + // because, without adaptation, we store everything we parse: There is no + // buffer for parsed content; addVirginReplyBody() stores every parsed byte. + fwd->markStoredReplyAsWhole(reasonWeAreSure); +} + // called when no more server communication is expected; may quit void Client::serverComplete() @@ -722,6 +743,7 @@ Client::handleAdaptedHeader(Http::Message *msg) assert(result); } else { // no body + fwd->markStoredReplyAsWhole("setFinalReply() stored header-only adapted reply"); if (doneWithAdaptation()) // we may still be sending virgin response handleAdaptationCompleted(); } @@ -796,6 +818,9 @@ Client::handleAdaptedBodyProductionEnded() if (abortOnBadEntry("entry went bad while waiting for adapted body eof")) return; + // distinguish this code path from handleAdaptedBodyProducerAborted() + receivedWholeAdaptedReply = true; + // end consumption if we consumed everything if (adaptedBodySource != NULL && adaptedBodySource->exhausted()) endAdaptedBodyConsumption(); @@ -806,6 +831,14 @@ void Client::endAdaptedBodyConsumption() { stopConsumingFrom(adaptedBodySource); + + if (receivedWholeAdaptedReply) { + // We received the entire adapted reply per receivedWholeAdaptedReply. + // We are called when we consumed everything received (per our callers). + // We consume only what we store per handleMoreAdaptedBodyAvailable(). + fwd->markStoredReplyAsWhole("received,consumed=>stored the entire RESPMOD reply"); + } + handleAdaptationCompleted(); } @@ -826,7 +859,6 @@ void Client::handleAdaptedBodyProducerAborted() if (handledEarlyAdaptationAbort()) return; - entry->lengthWentBad("body adaptation aborted"); handleAdaptationCompleted(); // the user should get a truncated response } diff --git a/src/clients/Client.h b/src/clients/Client.h index e9d1c3389ec..d19cbe9aed7 100644 --- a/src/clients/Client.h +++ b/src/clients/Client.h @@ -81,6 +81,10 @@ class Client: public: // should be protected void serverComplete(); /**< call when no server communication is expected */ + /// remember that the received virgin reply was parsed in its entirety, + /// including its body (if any) + void markParsedVirginReplyAsWhole(const char *reasonWeAreSure); + private: void serverComplete2(); /**< Continuation of serverComplete */ bool completed = false; /**< serverComplete() has been called */ @@ -176,6 +180,9 @@ class Client: bool adaptationAccessCheckPending = false; bool startedAdaptation = false; + + /// handleAdaptedBodyProductionEnded() was called + bool receivedWholeAdaptedReply = false; #endif bool receivedWholeRequestBody = false; ///< handleRequestBodyProductionEnded called diff --git a/src/clients/FtpGateway.cc b/src/clients/FtpGateway.cc index 504b1ea3cbf..9f62f3e76f7 100644 --- a/src/clients/FtpGateway.cc +++ b/src/clients/FtpGateway.cc @@ -2233,6 +2233,7 @@ ftpReadTransferDone(Ftp::Gateway * ftpState) ftpState->completedListing(); /* QUIT operation handles sending the reply to client */ } + ftpState->markParsedVirginReplyAsWhole("ftpReadTransferDone code 226 or 250"); ftpSendQuit(ftpState); } else { /* != 226 */ debugs(9, DBG_IMPORTANT, HERE << "Got code " << code << " after reading data"); diff --git a/src/clients/FtpRelay.cc b/src/clients/FtpRelay.cc index da84beea549..6e7cc6071d5 100644 --- a/src/clients/FtpRelay.cc +++ b/src/clients/FtpRelay.cc @@ -386,6 +386,7 @@ Ftp::Relay::forwardReply() reply->sources |= Http::Message::srcFtp; setVirginReply(reply); + markParsedVirginReplyAsWhole("Ftp::Relay::handleControlReply() does not forward partial replies"); adaptOrFinalizeReply(); serverComplete(); @@ -719,7 +720,12 @@ Ftp::Relay::readTransferDoneReply() { debugs(9, 3, status()); - if (ctrl.replycode != 226 && ctrl.replycode != 250) { + // RFC 959 says that code 226 may indicate a successful response to a file + // transfer and file abort commands, but since we do not send abort + // commands, let's assume it was a successful file transfer. + if (ctrl.replycode == 226 || ctrl.replycode == 250) { + markParsedVirginReplyAsWhole("Ftp::Relay::readTransferDoneReply() code 226 or 250"); + } else { debugs(9, DBG_IMPORTANT, "got FTP code " << ctrl.replycode << " after reading response data"); } diff --git a/src/gopher.cc b/src/gopher.cc index 7c0e6662527..489f9cf47e6 100644 --- a/src/gopher.cc +++ b/src/gopher.cc @@ -89,6 +89,7 @@ class GopherStateData HTML_header_added(0), HTML_pre(0), type_id(GOPHER_FILE /* '0' */), + overflowed(false), cso_recno(0), len(0), buf(NULL), @@ -116,8 +117,15 @@ class GopherStateData int HTML_pre; char type_id; char request[MAX_URL]; + + /// some received bytes ignored due to internal buffer capacity limits + bool overflowed; + int cso_recno; + + /// the number of not-yet-parsed Gopher line bytes in this->buf int len; + char *buf; /* pts to a 4k page */ Comm::ConnectionPointer serverConn; FwdState::Pointer fwd; @@ -431,6 +439,7 @@ gopherToHTML(GopherStateData * gopherState, char *inbuf, int len) if (gopherState->len + llen >= TEMP_BUF_SIZE) { debugs(10, DBG_IMPORTANT, "GopherHTML: Buffer overflow. Lost some data on URL: " << entry->url() ); llen = TEMP_BUF_SIZE - gopherState->len - 1; + gopherState->overflowed = true; // may already be true } if (!lpos) { /* there is no complete line in inbuf */ @@ -804,6 +813,10 @@ gopherReadReply(const Comm::ConnectionPointer &conn, char *buf, size_t len, Comm entry->timestampsSet(); entry->flush(); + + if (!gopherState->len && !gopherState->overflowed) + gopherState->fwd->markStoredReplyAsWhole("gopher EOF after receiving/storing some bytes"); + gopherState->fwd->complete(); gopherState->serverConn->close(); } else { @@ -962,6 +975,7 @@ gopherStart(FwdState * fwd) } gopherToHTML(gopherState, (char *) NULL, 0); + fwd->markStoredReplyAsWhole("gopher instant internal request satisfaction"); fwd->complete(); return; } diff --git a/src/http.cc b/src/http.cc index 4a7c3daf634..85077e3b08b 100644 --- a/src/http.cc +++ b/src/http.cc @@ -672,15 +672,8 @@ HttpStateData::processReplyHeader() if (hp->needsMoreData()) { if (eof) { // no more data coming - /* Bug 2879: Replies may terminate with \r\n then EOF instead of \r\n\r\n. - * We also may receive truncated responses. - * Ensure here that we have at minimum two \r\n when EOF is seen. - */ - inBuf.append("\r\n\r\n", 4); - // retry the parse - parsedOk = hp->parse(inBuf); - // sync the buffers after parsing. - inBuf = hp->remaining(); + assert(!parsedOk); + // fall through to handle this premature EOF as an error } else { debugs(33, 5, "Incomplete response, waiting for end of response headers"); return; @@ -693,7 +686,11 @@ HttpStateData::processReplyHeader() debugs(11, 3, "Non-HTTP-compliant header:\n---------\n" << inBuf << "\n----------"); flags.headers_parsed = true; HttpReply *newrep = new HttpReply; - newrep->sline.set(Http::ProtocolVersion(), hp->parseStatusCode); + // hp->needsMoreData() means hp->parseStatusCode is unusable, but it + // also means that the reply header got truncated by a premature EOF + assert(!hp->needsMoreData() || eof); + const auto scode = hp->needsMoreData() ? Http::scInvalidHeader : hp->parseStatusCode; + newrep->sline.set(Http::ProtocolVersion(), scode); setVirginReply(newrep); return; } @@ -1422,6 +1419,19 @@ HttpStateData::writeReplyBody() int len = inBuf.length(); addVirginReplyBody(data, len); inBuf.consume(len); + + // after addVirginReplyBody() wrote (when not adapting) everything we have + // received to Store, check whether we have received/parsed the entire reply + int64_t clen = -1; + const char *parsedWhole = nullptr; + if (!virginReply()->expectingBody(request->method, clen)) + parsedWhole = "http parsed header-only reply"; + else if (clen >= 0 && clen == payloadSeen - payloadTruncated) + parsedWhole = "http parsed Content-Length body bytes"; + else if (clen < 0 && eof) + parsedWhole = "http parsed body ending with expected/required EOF"; + if (parsedWhole) + markParsedVirginReplyAsWhole(parsedWhole); } bool @@ -1439,6 +1449,7 @@ HttpStateData::decodeAndWriteReplyBody() if (doneParsing) { lastChunk = 1; flags.do_next_read = false; + markParsedVirginReplyAsWhole("http parsed last-chunk"); } return true; } @@ -1556,8 +1567,6 @@ HttpStateData::processReplyBody() case COMPLETE_NONPERSISTENT_MSG: debugs(11, 5, "processReplyBody: COMPLETE_NONPERSISTENT_MSG from " << serverConnection); - if (flags.chunked && !lastChunk) - entry->lengthWentBad("missing last-chunk"); serverComplete(); return; diff --git a/src/store.cc b/src/store.cc index 61266c2ee4d..6031f493112 100644 --- a/src/store.cc +++ b/src/store.cc @@ -745,7 +745,7 @@ StoreEntry::adjustVary() pe->startWriting(); // after timestampsSet() - pe->complete(); + pe->completeSuccessfully("wrote the entire Vary marker object"); return pe; } @@ -1030,6 +1030,20 @@ StoreEntry::lengthWentBad(const char *reason) releaseRequest(); } +void +StoreEntry::completeSuccessfully(const char * const whyWeAreSure) +{ + debugs(20, 3, whyWeAreSure << "; " << *this); + complete(); +} + +void +StoreEntry::completeTruncated(const char * const truncationReason) +{ + lengthWentBad(truncationReason); + complete(); +} + void StoreEntry::complete() { @@ -1703,7 +1717,7 @@ StoreEntry::storeErrorResponse(HttpReply *reply) buffer(); replaceHttpReply(HttpReplyPointer(reply)); flush(); - complete(); + completeSuccessfully("replaceHttpReply() stored the entire error"); negativeCache(); releaseRequest(false); // if it is safe to negatively cache, sharing is OK unlock("StoreEntry::storeErrorResponse"); diff --git a/src/whois.cc b/src/whois.cc index 0fd47be5a57..eb2380fbf72 100644 --- a/src/whois.cc +++ b/src/whois.cc @@ -170,6 +170,9 @@ WhoisState::readReply(const Comm::ConnectionPointer &conn, char *aBuffer, size_t if (!entry->makePublic()) entry->makePrivate(true); + if (dataWritten) // treat zero-length responses as incomplete + fwd->markStoredReplyAsWhole("whois received/stored the entire response"); + fwd->complete(); debugs(75, 3, "whoisReadReply: Done: " << entry->url()); conn->close(); From 17d499dfc4135f314b1147bf54bfe2d9d557bff5 Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Fri, 8 Oct 2021 00:37:56 +0300 Subject: [PATCH 2/5] Restored the HTTP-completion hack so that it could be applied as an independent change. --- src/http.cc | 17 ++++++++++------- 1 file changed, 10 insertions(+), 7 deletions(-) diff --git a/src/http.cc b/src/http.cc index 85077e3b08b..f0db7ca8ab5 100644 --- a/src/http.cc +++ b/src/http.cc @@ -672,8 +672,15 @@ HttpStateData::processReplyHeader() if (hp->needsMoreData()) { if (eof) { // no more data coming - assert(!parsedOk); - // fall through to handle this premature EOF as an error + /* Bug 2879: Replies may terminate with \r\n then EOF instead of \r\n\r\n. + * We also may receive truncated responses. + * Ensure here that we have at minimum two \r\n when EOF is seen. + */ + inBuf.append("\r\n\r\n", 4); + // retry the parse + parsedOk = hp->parse(inBuf); + // sync the buffers after parsing. + inBuf = hp->remaining(); } else { debugs(33, 5, "Incomplete response, waiting for end of response headers"); return; @@ -686,11 +693,7 @@ HttpStateData::processReplyHeader() debugs(11, 3, "Non-HTTP-compliant header:\n---------\n" << inBuf << "\n----------"); flags.headers_parsed = true; HttpReply *newrep = new HttpReply; - // hp->needsMoreData() means hp->parseStatusCode is unusable, but it - // also means that the reply header got truncated by a premature EOF - assert(!hp->needsMoreData() || eof); - const auto scode = hp->needsMoreData() ? Http::scInvalidHeader : hp->parseStatusCode; - newrep->sline.set(Http::ProtocolVersion(), scode); + newrep->sline.set(Http::ProtocolVersion(), hp->parseStatusCode); setVirginReply(newrep); return; } From 060345726cf5e62e659dd7592d53d3bcd8969fa8 Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Fri, 8 Oct 2021 00:52:13 +0300 Subject: [PATCH 3/5] Polished, addressing review requests * removed a default member initializer (avoid mixing member initialization styles for FwdState) * renamed WITH_SRV/WITH_CLT to their non-abbreviated analogs --- src/FwdState.cc | 2 +- src/FwdState.h | 2 +- src/client_side.cc | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/src/FwdState.cc b/src/FwdState.cc index d1df784cdc1..a9b3200a108 100644 --- a/src/FwdState.cc +++ b/src/FwdState.cc @@ -267,7 +267,7 @@ FwdState::updateAleWithFinalError() lte.timedout = (err->xerrno == ETIMEDOUT || err->type == ERR_READ_TIMEOUT); al->cache.code.err.update(lte); if (!err->detail) { - static const auto d = MakeNamedErrorDetail("WITH_SRV"); + static const auto d = MakeNamedErrorDetail("WITH_SERVER"); err->detailError(d); } al->updateError(Error(err->type, err->detail)); diff --git a/src/FwdState.h b/src/FwdState.h index 94db48fc418..85c0af496c7 100644 --- a/src/FwdState.h +++ b/src/FwdState.h @@ -210,7 +210,7 @@ class FwdState: public RefCountable, public PeerSelectionInitiator /// Whether the entire reply (including any body) was written to Store. /// The string literal value is only used for debugging. - const char *storedWholeReply_ = nullptr; + const char *storedWholeReply_ ; }; class acl_tos; diff --git a/src/client_side.cc b/src/client_side.cc index eaf24afe31f..9f14323b3e2 100644 --- a/src/client_side.cc +++ b/src/client_side.cc @@ -3999,7 +3999,7 @@ ConnStateData::terminateAll(const Error &rawError, const LogTagsErrors <e) // We detail even ERR_NONE: There should be no transactions left, and // detailed ERR_NONE will be unused. Otherwise, this detail helps in triage. if (!error.detail) { - static const auto d = MakeNamedErrorDetail("WITH_CLT"); + static const auto d = MakeNamedErrorDetail("WITH_CLIENT"); error.detail = d; } From 7fa6a68a85fd081591fa0a33b9a50bfcacb567ee Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Fri, 8 Oct 2021 01:01:55 +0300 Subject: [PATCH 4/5] Fixed a typo --- src/FwdState.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/FwdState.h b/src/FwdState.h index 85c0af496c7..20d8cfe0170 100644 --- a/src/FwdState.h +++ b/src/FwdState.h @@ -210,7 +210,7 @@ class FwdState: public RefCountable, public PeerSelectionInitiator /// Whether the entire reply (including any body) was written to Store. /// The string literal value is only used for debugging. - const char *storedWholeReply_ ; + const char *storedWholeReply_; }; class acl_tos; From fb307b3b68e9511f31b0a86e2e20034b05ca2297 Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Sun, 10 Oct 2021 00:29:57 +0300 Subject: [PATCH 5/5] Adjusted a completeSuccessfully() reason wording thus addressing a review request. --- src/client_side_request.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/client_side_request.cc b/src/client_side_request.cc index 6e9598030fc..ae498388416 100644 --- a/src/client_side_request.cc +++ b/src/client_side_request.cc @@ -2136,7 +2136,7 @@ ClientHttpRequest::endRequestSatisfaction() // We received the entire reply per receivedWholeAdaptedReply. // We are called when we consumed everything received (per our callers). // We consume only what we store per noteMoreBodyDataAvailable(). - storeEntry()->completeSuccessfully("received,consumed=>stored the entire REQMOD reply"); + storeEntry()->completeSuccessfully("received, consumed, and, hence, stored the entire REQMOD reply"); } else { storeEntry()->completeTruncated("REQMOD request satisfaction default"); }