Do not mark successful FTP PUT entries with ENTRY_BAD_LENGTH

[eduard-bagdasaryan]

Since 2021 commit ba3fe8d, we explicitly mark complete responses and
treat all other responses as truncated. That commit missed a case where
the FTP server responds with 226 or 250 code after receiving the upload.
The bug affects HTTP PUT requests using ftp URI scheme.

Incorrect truncation marking adds an unwanted WITH_CLIENT %err_detail to
ERR_FTP_PUT_CREATED transaction records in access.log:

201 PUT ftp://... ERR_FTP_PUT_CREATED/FTP_REPLY_CODE=226+WITH_CLIENT

Fixed code logs:

201 PUT ftp://... ERR_FTP_PUT_CREATED/FTP_REPLY_CODE=226

[rousskov]

Thank you. If possible, please adjust PR description to add a partial¹ access.log record sample to illustrate the admin-visible effects and the scope of the fixed bug.

Footnotes

1. I am thinking something like %Ss/%03>Hs %rm %ru %err_code/%err_detail with %err_code/%err_detail part removed if it expands to -/- in this case. ↩

[eduard-bagdasaryan]

to illustrate the admin-visible effects

The only admin-visible effect is the WITH_CLIENT error detail. Note that the root of the problem (ENTRY_BAD_LENGTH) is not reflected in access.log. It can be gathered from cache.log, by 'STREAM_UNPLANNED_COMPLETE' and other related tags.

[rousskov]

The only admin-visible effect is the WITH_CLIENT error detail.

Interesting. I assume that affected ERR_FTP_PUT_CREATED responses are not cachable even when not marked as incomplete, so I am not surprised that incorrect ENTRY_BAD_LENGTH marking does not affect future hits -- there can be no hits here. How about HTTP connection persistency? In other words, if the HTTP client signals that it will keep the connection open/persistent after this PUT request,

• Does unpatched Squid close HTTP client-to-Squid connection after writing ERR_FTP_PUT_CREATED to the client?
• Does fixed Squid close HTTP client-to-Squid connection after writing ERR_FTP_PUT_CREATED to the client?

Note that the root of the problem (ENTRY_BAD_LENGTH) is not reflected in access.log.

Noted. On one hand, this is probably just a corner case because the actual stored HTTP response body is complete here -- Ftp::Gateway (i.e. ftpSendReply) generates ERR_FTP_PUT_CREATED HTTP response and stores all of its bytes in the corresponding StoreEntry. On the other hand, we should double check whether access.log record reflects truncation if that response with ENTRY_BAD_LENGTH does get truncated during storage for some reason (e.g., some kind of internal Store forwarding bug or error like inconsistent index state or lack of RAM). Would Squid close HTTP connection to signal truncation to the HTTP client and then log something special to access.log if Store does not store the last ERR_FTP_PUT_CREATED body byte and turns ENTRY_BAD_LENGTH flag on?

To avoid misunderstanding, even if we need to fix some other bugs based on the discussion/investigations above, this minimal PR is ready to be merged IMO. I am clearing it for merging after polishing its description a little.

It can be gathered from cache.log, by 'STREAM_UNPLANNED_COMPLETE' and other related tags.

Yes, of course. In the context of this discussion, we are only interested in admin- or agent-observable effects outside of debugging logs.