From 2759372a8d9ff4539e804b86472dc55d26b35323 Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Thu, 3 Oct 2024 00:02:08 +0300 Subject: [PATCH 1/8] FtpGateway: Unexpected ABORTED suffixes in %Ss While downloading/uploading files using HTTP GET/PUT requests with ftp URI scheme, Squid completes these transactions successfully but sometimes logs the ABORTED suffix, e.g., TCP_MISS_ABORTED. This happens because Squid postpones completing the corresponding StoreEntry until getting 221 reply from FTP server, even though the server has sent all response bytes already. So if the client closes the client-to-Squid connection before that, the cleanup code in ConnStateData::terminateAll() finishes the transaction which is logged as 'ABORTED' because the StoreEntry is still in the STORE_PENDING state. Now we complete the entry, calling Ftp::Gateway::completeForwarding() as soon as Squid got all FTP response bytes. --- src/clients/FtpClient.cc | 11 +++++++++-- src/clients/FtpClient.h | 6 ++++++ src/clients/FtpGateway.cc | 8 +++++++- 3 files changed, 22 insertions(+), 3 deletions(-) diff --git a/src/clients/FtpClient.cc b/src/clients/FtpClient.cc index 15a20b4b10c..7a48812a003 100644 --- a/src/clients/FtpClient.cc +++ b/src/clients/FtpClient.cc @@ -179,6 +179,14 @@ Ftp::DataChannel::addr(const Ip::Address &import) port = import.port(); } +void +Ftp::DataChannel::appended(const size_t size) +{ + readBuf->appended(size); + payloadSeen += size; + debugs(9, 5, size << " bytes to readBuf, payloadSeen: " << payloadSeen); +} + /* Ftp::Client */ Ftp::Client::Client(FwdState *fwdState): @@ -979,8 +987,7 @@ Ftp::Client::dataRead(const CommIoCbParams &io) } if (io.flag == Comm::OK && io.size > 0) { - debugs(9, 5, "appended " << io.size << " bytes to readBuf"); - data.readBuf->appended(io.size); + data.appended(io.size); #if USE_DELAY_POOLS DelayId delayId = entry->mem_obj->mostBytesAllowed(); delayId.bytesIn(io.size); diff --git a/src/clients/FtpClient.h b/src/clients/FtpClient.h index a42e0e199a6..4428a78991a 100644 --- a/src/clients/FtpClient.h +++ b/src/clients/FtpClient.h @@ -99,11 +99,17 @@ class DataChannel: public Ftp::Channel void addr(const Ip::Address &addr); ///< import host and port + /// updates counters after this number of bytes have been added to readBuf + void appended(size_t size); + public: MemBuf *readBuf; char *host; unsigned short port; bool read_pending; + + /// amount of message payload/body received so far + int64_t payloadSeen = 0; }; /// FTP client functionality shared among FTP Gateway and Relay clients. diff --git a/src/clients/FtpGateway.cc b/src/clients/FtpGateway.cc index 675c08dfec2..3c7ae0ac3b7 100644 --- a/src/clients/FtpGateway.cc +++ b/src/clients/FtpGateway.cc @@ -1008,6 +1008,11 @@ Ftp::Gateway::processReplyBody() entry->flush(); + if (theSize >= 0 && data.payloadSeen >= theSize) { + markParsedVirginReplyAsWhole("whole virgin body"); + completeForwarding(); + } + maybeReadVirginBody(); } @@ -2274,6 +2279,7 @@ ftpWriteTransferDone(Ftp::Gateway * ftpState) ftpState->entry->timestampsSet(); /* XXX Is this needed? */ ftpState->markParsedVirginReplyAsWhole("ftpWriteTransferDone code 226 or 250"); ftpSendReply(ftpState); + ftpState->completeForwarding(); } static void @@ -2639,7 +2645,7 @@ Ftp::Gateway::completeForwarding() { if (fwd == nullptr || flags.completed_forwarding) { debugs(9, 3, "avoid double-complete on FD " << - (ctrl.conn ? ctrl.conn->fd : -1) << ", Data FD " << data.conn->fd << + (ctrl.conn ? ctrl.conn->fd : -1) << ", Data FD " << (data.conn ? data.conn->fd : -1) << ", this " << this << ", fwd " << fwd); return; } From 74cf59a7caeca3353369d26c5df8c5d6a78bfb56 Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Thu, 3 Oct 2024 17:58:20 +0300 Subject: [PATCH 2/8] Take adaptation into account before completeForwarding() Another method (serverDataComplete) is called instead to take care about doneWithAdaptation() condition. Also serverDataComplete() for all other ftpSendReply() cases, such as ftpReadMkdir(). --- src/clients/Client.cc | 6 ++++++ src/clients/Client.h | 5 ++++- src/clients/FtpGateway.cc | 6 ++++-- 3 files changed, 14 insertions(+), 3 deletions(-) diff --git a/src/clients/Client.cc b/src/clients/Client.cc index 4f68b48e178..80a4fcfeabf 100644 --- a/src/clients/Client.cc +++ b/src/clients/Client.cc @@ -186,6 +186,12 @@ Client::serverComplete() assert(doneWithServer()); } + serverDataComplete(); +} + +void +Client::serverDataComplete() +{ completed = true; if (requestBodySource != nullptr) diff --git a/src/clients/Client.h b/src/clients/Client.h index 6a533156377..ba8dd3fb310 100644 --- a/src/clients/Client.h +++ b/src/clients/Client.h @@ -81,13 +81,16 @@ class Client: public: // should be protected void serverComplete(); /**< call when no server communication is expected */ + /// called when we received the whole virgin reply + void serverDataComplete(); + /// 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 */ + bool completed = false; /**< serverDataComplete() has been called */ protected: // kids customize these diff --git a/src/clients/FtpGateway.cc b/src/clients/FtpGateway.cc index 3c7ae0ac3b7..3820fadd518 100644 --- a/src/clients/FtpGateway.cc +++ b/src/clients/FtpGateway.cc @@ -1010,7 +1010,7 @@ Ftp::Gateway::processReplyBody() if (theSize >= 0 && data.payloadSeen >= theSize) { markParsedVirginReplyAsWhole("whole virgin body"); - completeForwarding(); + serverDataComplete(); } maybeReadVirginBody(); @@ -2246,6 +2246,7 @@ ftpReadTransferDone(Ftp::Gateway * ftpState) /* QUIT operation handles sending the reply to client */ } ftpState->markParsedVirginReplyAsWhole("ftpReadTransferDone code 226 or 250"); + ftpState->serverDataComplete(); ftpSendQuit(ftpState); } else { /* != 226 */ debugs(9, DBG_IMPORTANT, "Got code " << code << " after reading data"); @@ -2279,7 +2280,6 @@ ftpWriteTransferDone(Ftp::Gateway * ftpState) ftpState->entry->timestampsSet(); /* XXX Is this needed? */ ftpState->markParsedVirginReplyAsWhole("ftpWriteTransferDone code 226 or 250"); ftpSendReply(ftpState); - ftpState->completeForwarding(); } static void @@ -2486,6 +2486,8 @@ ftpSendReply(Ftp::Gateway * ftpState) ftpState->entry->replaceHttpReply(err.BuildHttpReply()); + ftpState->serverDataComplete(); + ftpSendQuit(ftpState); } From e322b470b9a099f37cbefb80bb597a73ce0a8277 Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Mon, 21 Oct 2024 17:58:09 +0300 Subject: [PATCH 3/8] Complete StoreEntry from FwdState::markStoredReplyAsWhole() Partially undone 74cf59a7 (serverDataComplete() method). markStoredReplyAsWhole() is a common place for marking the reply as complete for both adaptation and non-adaptation cases. Special care should be taken about not calling complete() twice. --- src/FwdState.cc | 18 +++++++++++++----- src/clients/Client.cc | 6 ------ src/clients/Client.h | 5 +---- src/clients/FtpGateway.cc | 14 ++++++-------- 4 files changed, 20 insertions(+), 23 deletions(-) diff --git a/src/FwdState.cc b/src/FwdState.cc index bbca57e56f6..090837643c7 100644 --- a/src/FwdState.cc +++ b/src/FwdState.cc @@ -290,10 +290,9 @@ FwdState::completed() #endif } else { updateAleWithFinalError(); // if any - if (storedWholeReply_) - entry->completeSuccessfully(storedWholeReply_); - else + if (!storedWholeReply_) entry->completeTruncated("FwdState default"); + assert(entry->store_status == STORE_OK); } } @@ -580,7 +579,12 @@ FwdState::markStoredReplyAsWhole(const char * const whyWeAreSure) if (EBIT_TEST(entry->flags, ENTRY_ABORTED)) return; - storedWholeReply_ = whyWeAreSure; + if (!storedWholeReply_) { + storedWholeReply_ = whyWeAreSure; + + if (!reforward()) + entry->completeSuccessfully(whyWeAreSure); + } } void @@ -1314,7 +1318,11 @@ FwdState::reforward() return 0; } - assert(e->store_status == STORE_PENDING); + if (e->store_status == STORE_OK) { + debugs(17, 3, "No, the entry is STORE_OK already"); + return 0; + } + assert(e->mem_obj); #if URL_CHECKSUM_DEBUG diff --git a/src/clients/Client.cc b/src/clients/Client.cc index 80a4fcfeabf..4f68b48e178 100644 --- a/src/clients/Client.cc +++ b/src/clients/Client.cc @@ -186,12 +186,6 @@ Client::serverComplete() assert(doneWithServer()); } - serverDataComplete(); -} - -void -Client::serverDataComplete() -{ completed = true; if (requestBodySource != nullptr) diff --git a/src/clients/Client.h b/src/clients/Client.h index ba8dd3fb310..6a533156377 100644 --- a/src/clients/Client.h +++ b/src/clients/Client.h @@ -81,16 +81,13 @@ class Client: public: // should be protected void serverComplete(); /**< call when no server communication is expected */ - /// called when we received the whole virgin reply - void serverDataComplete(); - /// 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; /**< serverDataComplete() has been called */ + bool completed = false; /**< serverComplete() has been called */ protected: // kids customize these diff --git a/src/clients/FtpGateway.cc b/src/clients/FtpGateway.cc index 3820fadd518..caec6aec08a 100644 --- a/src/clients/FtpGateway.cc +++ b/src/clients/FtpGateway.cc @@ -970,8 +970,10 @@ Ftp::Gateway::processReplyBody() return; } + const auto csize = data.readBuf->contentSize(); + /* Directory listings are special. They write ther own headers via the error objects */ - if (!flags.http_header_sent && data.readBuf->contentSize() >= 0 && !flags.isdir) + if (!flags.http_header_sent && csize >= 0 && !flags.isdir) appendSuccessHeader(); if (EBIT_TEST(entry->flags, ENTRY_ABORTED)) { @@ -1000,7 +1002,7 @@ Ftp::Gateway::processReplyBody() parseListing(); maybeReadVirginBody(); return; - } else if (const auto csize = data.readBuf->contentSize()) { + } else if (csize) { writeReplyBody(data.readBuf->content(), csize); debugs(9, 5, "consuming " << csize << " bytes of readBuf"); data.readBuf->consume(csize); @@ -1008,10 +1010,8 @@ Ftp::Gateway::processReplyBody() entry->flush(); - if (theSize >= 0 && data.payloadSeen >= theSize) { + if (csize && theSize >= 0 && data.payloadSeen >= theSize) markParsedVirginReplyAsWhole("whole virgin body"); - serverDataComplete(); - } maybeReadVirginBody(); } @@ -2246,7 +2246,6 @@ ftpReadTransferDone(Ftp::Gateway * ftpState) /* QUIT operation handles sending the reply to client */ } ftpState->markParsedVirginReplyAsWhole("ftpReadTransferDone code 226 or 250"); - ftpState->serverDataComplete(); ftpSendQuit(ftpState); } else { /* != 226 */ debugs(9, DBG_IMPORTANT, "Got code " << code << " after reading data"); @@ -2278,7 +2277,6 @@ ftpWriteTransferDone(Ftp::Gateway * ftpState) } ftpState->entry->timestampsSet(); /* XXX Is this needed? */ - ftpState->markParsedVirginReplyAsWhole("ftpWriteTransferDone code 226 or 250"); ftpSendReply(ftpState); } @@ -2486,7 +2484,7 @@ ftpSendReply(Ftp::Gateway * ftpState) ftpState->entry->replaceHttpReply(err.BuildHttpReply()); - ftpState->serverDataComplete(); + ftpState->markParsedVirginReplyAsWhole("ftpSendReply"); ftpSendQuit(ftpState); } From 43fbb6dc71b613ed6b58bd83e521979b0fce970b Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Thu, 24 Oct 2024 01:07:11 +0300 Subject: [PATCH 4/8] Add missing markStoredReplyAsWhole() in FTP code Before this fix, the (fully completed) entry was completeTruncated() instead, 'WITH_CLIENT' (a kind of error indicator) was logged in err_detail. Also undone branch adjustments in FwdState::completed(): there can be scenarios when the entry status != STORE_OK (e.g., due to reforward() depending on many factors). --- src/FwdState.cc | 6 ++++-- src/clients/FtpGateway.cc | 9 +++++++-- 2 files changed, 11 insertions(+), 4 deletions(-) diff --git a/src/FwdState.cc b/src/FwdState.cc index 090837643c7..c2816f54459 100644 --- a/src/FwdState.cc +++ b/src/FwdState.cc @@ -290,9 +290,10 @@ FwdState::completed() #endif } else { updateAleWithFinalError(); // if any - if (!storedWholeReply_) + if (storedWholeReply_) + entry->completeSuccessfully(storedWholeReply_); + else entry->completeTruncated("FwdState default"); - assert(entry->store_status == STORE_OK); } } @@ -1348,6 +1349,7 @@ FwdState::reforward() return 0; if (destinations->empty() && !PeerSelectionInitiator::subscribed) { + debugs(17, 3, "No alternative forwarding paths left"); return 0; } diff --git a/src/clients/FtpGateway.cc b/src/clients/FtpGateway.cc index caec6aec08a..89367f1ac72 100644 --- a/src/clients/FtpGateway.cc +++ b/src/clients/FtpGateway.cc @@ -1156,6 +1156,7 @@ Ftp::Gateway::start() SBuf realm(ftpRealm()); // local copy so SBuf will not disappear too early const auto reply = ftpAuthRequired(request.getRaw(), realm, fwd->al); entry->replaceHttpReply(reply); + fwd->markStoredReplyAsWhole("checkAuth failed"); serverComplete(); return; } @@ -1262,6 +1263,7 @@ Ftp::Gateway::loginFailed() // add it to the store entry for response.... entry->replaceHttpReply(newrep); + fwd->markStoredReplyAsWhole("loginFailed"); serverComplete(); } @@ -2230,6 +2232,7 @@ Ftp::Gateway::completedListing() ctrl.message = nullptr; entry->replaceHttpReply(ferr.BuildHttpReply()); entry->flush(); + fwd->markStoredReplyAsWhole("completedListing"); entry->unlock("Ftp::Gateway"); } @@ -2244,8 +2247,9 @@ ftpReadTransferDone(Ftp::Gateway * ftpState) if (ftpState->flags.listing) { ftpState->completedListing(); /* QUIT operation handles sending the reply to client */ + } else { + ftpState->markParsedVirginReplyAsWhole("ftpReadTransferDone code 226 or 250"); } - ftpState->markParsedVirginReplyAsWhole("ftpReadTransferDone code 226 or 250"); ftpSendQuit(ftpState); } else { /* != 226 */ debugs(9, DBG_IMPORTANT, "Got code " << code << " after reading data"); @@ -2405,6 +2409,7 @@ ftpFail(Ftp::Gateway *ftpState) delete ftperr; ftpState->entry->replaceHttpReply(newrep); + ftpState->fwd->markStoredReplyAsWhole("ftpFail"); ftpSendQuit(ftpState); } @@ -2484,7 +2489,7 @@ ftpSendReply(Ftp::Gateway * ftpState) ftpState->entry->replaceHttpReply(err.BuildHttpReply()); - ftpState->markParsedVirginReplyAsWhole("ftpSendReply"); + ftpState->fwd->markStoredReplyAsWhole("ftpSendReply"); ftpSendQuit(ftpState); } From 03e4d091b12ea77468caee2b350594784d0a643d Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Thu, 24 Oct 2024 01:21:51 +0300 Subject: [PATCH 5/8] Undone an out-of-scope change --- src/FwdState.cc | 1 - 1 file changed, 1 deletion(-) diff --git a/src/FwdState.cc b/src/FwdState.cc index c2816f54459..83bd07b31d4 100644 --- a/src/FwdState.cc +++ b/src/FwdState.cc @@ -1349,7 +1349,6 @@ FwdState::reforward() return 0; if (destinations->empty() && !PeerSelectionInitiator::subscribed) { - debugs(17, 3, "No alternative forwarding paths left"); return 0; } From 5ebd6522042c510f6a04da17539ab3809edd852c Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Mon, 28 Oct 2024 02:13:54 +0300 Subject: [PATCH 6/8] Made Ftp::DataChannel::payloadSeen unsigned --- src/clients/FtpClient.h | 2 +- src/clients/FtpGateway.cc | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/clients/FtpClient.h b/src/clients/FtpClient.h index 4428a78991a..a49dee0a605 100644 --- a/src/clients/FtpClient.h +++ b/src/clients/FtpClient.h @@ -109,7 +109,7 @@ class DataChannel: public Ftp::Channel bool read_pending; /// amount of message payload/body received so far - int64_t payloadSeen = 0; + size_t payloadSeen = 0; }; /// FTP client functionality shared among FTP Gateway and Relay clients. diff --git a/src/clients/FtpGateway.cc b/src/clients/FtpGateway.cc index 89367f1ac72..69a49a16823 100644 --- a/src/clients/FtpGateway.cc +++ b/src/clients/FtpGateway.cc @@ -1010,7 +1010,7 @@ Ftp::Gateway::processReplyBody() entry->flush(); - if (csize && theSize >= 0 && data.payloadSeen >= theSize) + if (csize && theSize >= 0 && data.payloadSeen >= static_cast(theSize)) markParsedVirginReplyAsWhole("whole virgin body"); maybeReadVirginBody(); From 3b1c523bf97e561b26780df087125a0e26fce0e2 Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Mon, 28 Oct 2024 02:32:02 +0300 Subject: [PATCH 7/8] Undone Ftp::Gateway::completeForwarding() fix as I am going to post it as a separate PR. --- src/clients/FtpGateway.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/clients/FtpGateway.cc b/src/clients/FtpGateway.cc index 69a49a16823..1fa0c7d195d 100644 --- a/src/clients/FtpGateway.cc +++ b/src/clients/FtpGateway.cc @@ -2650,7 +2650,7 @@ Ftp::Gateway::completeForwarding() { if (fwd == nullptr || flags.completed_forwarding) { debugs(9, 3, "avoid double-complete on FD " << - (ctrl.conn ? ctrl.conn->fd : -1) << ", Data FD " << (data.conn ? data.conn->fd : -1) << + (ctrl.conn ? ctrl.conn->fd : -1) << ", Data FD " << data.conn->fd << ", this " << this << ", fwd " << fwd); return; } From abe83b9d9643e53954d8bee7c1ad2176c127ce48 Mon Sep 17 00:00:00 2001 From: Eduard Bagdasaryan Date: Tue, 29 Oct 2024 01:57:35 +0300 Subject: [PATCH 8/8] Adjusted a variable type and removed an always-true check --- src/clients/FtpClient.h | 2 +- src/clients/FtpGateway.cc | 14 +++++++------- 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/src/clients/FtpClient.h b/src/clients/FtpClient.h index a49dee0a605..9e1d4614f33 100644 --- a/src/clients/FtpClient.h +++ b/src/clients/FtpClient.h @@ -109,7 +109,7 @@ class DataChannel: public Ftp::Channel bool read_pending; /// amount of message payload/body received so far - size_t payloadSeen = 0; + uint64_t payloadSeen = 0; }; /// FTP client functionality shared among FTP Gateway and Relay clients. diff --git a/src/clients/FtpGateway.cc b/src/clients/FtpGateway.cc index 1fa0c7d195d..c2bc3a0bbca 100644 --- a/src/clients/FtpGateway.cc +++ b/src/clients/FtpGateway.cc @@ -970,10 +970,10 @@ Ftp::Gateway::processReplyBody() return; } - const auto csize = data.readBuf->contentSize(); + const auto availableDataSize = data.readBuf->contentSize(); /* Directory listings are special. They write ther own headers via the error objects */ - if (!flags.http_header_sent && csize >= 0 && !flags.isdir) + if (!flags.http_header_sent && !flags.isdir) appendSuccessHeader(); if (EBIT_TEST(entry->flags, ENTRY_ABORTED)) { @@ -1002,15 +1002,15 @@ Ftp::Gateway::processReplyBody() parseListing(); maybeReadVirginBody(); return; - } else if (csize) { - writeReplyBody(data.readBuf->content(), csize); - debugs(9, 5, "consuming " << csize << " bytes of readBuf"); - data.readBuf->consume(csize); + } else if (availableDataSize) { + writeReplyBody(data.readBuf->content(), availableDataSize); + debugs(9, 5, "consuming " << availableDataSize << " bytes of readBuf"); + data.readBuf->consume(availableDataSize); } entry->flush(); - if (csize && theSize >= 0 && data.payloadSeen >= static_cast(theSize)) + if (availableDataSize && theSize >= 0 && data.payloadSeen >= static_cast(theSize)) markParsedVirginReplyAsWhole("whole virgin body"); maybeReadVirginBody();