From 670180f80ac05d65b30af7ef7ea26fb619df101f Mon Sep 17 00:00:00 2001 From: Alex Rousskov Date: Sat, 20 May 2023 21:38:38 +0000 Subject: [PATCH] Bug 5148: Log %Ss of failed tunnels as TCP_TUNNEL (#1354) ERR_CONNECT_FAIL/errno=111 NONE_NONE/503 CONNECT TAG_NONE/503 0 CONNECT example.com:443 - HIER_NONE/- - When Squid failed to open a TCP connection to an origin server (or through a cache peer) while handling a CONNECT request, Squid logged %Ss as NONE_NONE because TunnelStateData waited for a successful TCP connection to update the log tag. That unnecessary wait (modeled after the necessary HTTP status code wait) complicated code. Squid now logs TCP_TUNNEL to indicate the request handling path chosen by Squid. We already use the same "handling path" approach for most other request status codes. For example, TCP_MISS does not mean the miss transaction was successful. It only means that Squid satisfied the request using the cache miss forwarding logic. Even the LOG_TCP_REFRESH_FAIL_ERR status code does not imply that the error response was successfully forwarded to the client; only that the request was satisfied on a particular (albeit very detailed in this case!) handling path. Apply the same logic to tunneling attempts blocked by miss_access. They were also logged as NONE_NONE and are now logged as TCP_TUNNEL. The actual outcome of a tunneling attempt can usually be determined using %err_code/%err_detail and %>Hs logformat codes. --- doc/release-notes/release-6.sgml.in | 2 ++ src/LogTags.h | 2 +- src/tunnel.cc | 6 +++--- 3 files changed, 6 insertions(+), 4 deletions(-) diff --git a/doc/release-notes/release-6.sgml.in b/doc/release-notes/release-6.sgml.in index 11c51da87b..ac0c786c48 100644 --- a/doc/release-notes/release-6.sgml.in +++ b/doc/release-notes/release-6.sgml.in @@ -234,6 +234,8 @@ This section gives an account of those changes in three categories: made for this request.

Squid now adds ABORTED to values printed by the Ss code in more cases where a TCP Squid-to-server connection was closed prematurely. +

Squid now logs TCP_TUNNEL with the Ss code when a CONNECT tunnel + is attempted, not just on successful tunnel setup. server_cert_fingerprint

Removed the broken -sha option. SHA1 remains the default and diff --git a/src/LogTags.h b/src/LogTags.h index a33c1d0ee9..d8c13cf37c 100644 --- a/src/LogTags.h +++ b/src/LogTags.h @@ -53,7 +53,7 @@ typedef enum { LOG_TCP_DENIED_REPLY, LOG_TCP_OFFLINE_HIT, LOG_TCP_REDIRECT, - LOG_TCP_TUNNEL, // a binary tunnel was established for this transaction + LOG_TCP_TUNNEL, ///< an attempt to establish a bidirectional TCP tunnel LOG_UDP_HIT, LOG_UDP_MISS, LOG_UDP_DENIED, diff --git a/src/tunnel.cc b/src/tunnel.cc index 75facc9e4c..af3d50ffeb 100644 --- a/src/tunnel.cc +++ b/src/tunnel.cc @@ -370,6 +370,8 @@ TunnelStateData::TunnelStateData(ClientHttpRequest *clientRequest) : al = clientRequest->al; http = clientRequest; + al->cache.code.update(LOG_TCP_TUNNEL); + client.initConnection(clientRequest->getConn()->clientConnection, tunnelClientClosed, "tunnelClientClosed", this); AsyncCall::Pointer timeoutCall = commCbCall(5, 4, "tunnelTimeout", @@ -927,7 +929,6 @@ tunnelStartShoveling(TunnelStateData *tunnelState) commSetConnTimeout(tunnelState->server.conn, Config.Timeout.read, timeoutCall); *tunnelState->status_ptr = Http::scOkay; - tunnelState->al->cache.code.update(LOG_TCP_TUNNEL); if (cbdataReferenceValid(tunnelState)) { // Shovel any payload already pushed into reply buffer by the server response @@ -980,8 +981,6 @@ TunnelStateData::tunnelEstablishmentDone(Http::TunnelerAnswer &answer) peerWait.finish(); server.len = 0; - al->cache.code.update(LOG_TCP_TUNNEL); - // XXX: al->http.code (i.e. *status_ptr) should not be (re)set // until we actually start responding to the client. Right here/now, we only // know how this cache_peer has responded to us. @@ -1164,6 +1163,7 @@ tunnelStart(ClientHttpRequest * http) ch.syncAle(request, http->log_uri); if (ch.fastCheck().denied()) { debugs(26, 4, "MISS access forbidden."); + http->updateLoggingTags(LOG_TCP_TUNNEL); err = new ErrorState(ERR_FORWARDING_DENIED, Http::scForbidden, request, http->al); http->al->http.code = Http::scForbidden; errorSend(http->getConn()->clientConnection, err); -- 2.47.2