Bug 5256: Intercepting port fails to accept (#1238)

    ERROR: NF getsockopt(ORIGINAL_DST) failed on ... Bad file descriptor
    ERROR: NAT lookup failed to locate original IPs on ...

Ip::Interceptor.LookupNat() needs an open Connection, but commit 7185c9e
supplied a half-baked details object, resulting in ERRORs (showing a
closed connection -- no FD... field) for every otherwise successful
accept(2) attempt on an intercepting port.

Refactored oldAccept() to use exceptions for error handling and false
return result for no-error-but-no-connection cases (Comm::NOMESSAGE).
This refactoring allows us to centralize connection closing code instead
of chasing individual COMM_ERROR and NOMESSAGE cases while still missing
connection closure (if a function called by oldAccept() throws). With
connection closure handled, we can now open the details Connection
earlier, as we have done before commit 7185c9e, meeting current
LookupNat() and other/future code expectations.

Positive side effects of this fix include elimination of the following
old error reporting problems that left admins puzzled why Squid is not
handling new connections with no error messages in non-debugging
cache.log (and with the socket listening queue growing).

* Silent lack of accept() after an ENFILE or EMFILE failure.
* Silent lack of accept() if some function used by oldAccept() throws.
* Silent at level-0 lack of accept() after logging a level-1 ERROR. This
  problem was specific to ALL,0 and similar (rare) configurations.

diff --git a/src/comm/Flag.h b/src/comm/Flag.h
index 1ea53193f17216c65489b12c5568bb3f28b08046..76cc27d7e7ac1cf2f4926bd98ad04a6a8fa3b4dd 100644 (file)
--- a/src/comm/Flag.h
+++ b/src/comm/Flag.h
@@ -15,7 +15,6 @@ namespace Comm
 typedef enum {
     OK = 0,
     COMM_ERROR = -1,
-    NOMESSAGE = -3,
     TIMEOUT = -4,
     SHUTDOWN = -5,
     IDLE = -6, /* there are no active fds and no pending callbacks. */

diff --git a/src/comm/TcpAcceptor.cc b/src/comm/TcpAcceptor.cc
index 46b997e66673a0e6ad24a82bbf1e42ff18c57ed9..dddcb33f2638f4680283ce91ffd1696787aadf9c 100644 (file)
--- a/src/comm/TcpAcceptor.cc
+++ b/src/comm/TcpAcceptor.cc
@@ -28,6 +28,7 @@
 #include "ip/QosConfig.h"
 #include "log/access_log.h"
 #include "MasterXaction.h"
+#include "sbuf/Stream.h"
 #include "SquidConfig.h"
 #include "StatCounters.h"
 
@@ -271,33 +272,41 @@ Comm::TcpAcceptor::acceptOne()
 
     /* Accept a new connection */
     ConnectionPointer newConnDetails = new Connection();
-    const Comm::Flag flag = oldAccept(newConnDetails);
-
-    if (flag == Comm::COMM_ERROR) {
-        // A non-recoverable error; notify the caller */
-        debugs(5, 5, "non-recoverable error:" << status() << " handler Subscription: " << theCallSub);
-        if (intendedForUserConnections())
-            logAcceptError(newConnDetails);
-        notify(flag, newConnDetails);
-        // XXX: not under async job call protections
-        mustStop("Listener socket closed");
+    try {
+        if (acceptInto(newConnDetails)) {
+            Assure(newConnDetails->isOpen());
+            CallBack(newConnDetails, [&] {
+                debugs(5, 5, "Listener: " << conn <<
+                       " accepted new connection " << newConnDetails <<
+                       " handler Subscription: " << theCallSub);
+                notify(Comm::OK, newConnDetails);
+            });
+        } else {
+            debugs(5, 5, "try later: " << conn << " handler Subscription: " << theCallSub);
+            newConnDetails->close(); // paranoid manual closure (and may already be closed)
+        }
+
+        SetSelect(conn->fd, COMM_SELECT_READ, doAccept, this, 0);
         return;
+    } catch (...) {
+        const auto debugLevel = intendedForUserConnections() ? DBG_CRITICAL : 3;
+        debugs(5, debugLevel, "ERROR: Stopped accepting connections:" <<
+               Debug::Extra << "error: " << CurrentException);
     }
 
-    if (flag == Comm::NOMESSAGE) {
-        /* register interest again */
-        debugs(5, 5, "try later: " << conn << " handler Subscription: " << theCallSub);
-    } else {
-        // TODO: When ALE, MasterXaction merge, use them or ClientConn instead.
-        CallBack(newConnDetails, [&] {
-            debugs(5, 5, "Listener: " << conn <<
-                   " accepted new connection " << newConnDetails <<
-                   " handler Subscription: " << theCallSub);
-            notify(flag, newConnDetails);
-        });
-    }
+    if (intendedForUserConnections())
+        logAcceptError(newConnDetails);
+
+    // do not expose subscribers to a "usable" descriptor of a failed connection
+    newConnDetails->close(); // may already be closed
 
-    SetSelect(conn->fd, COMM_SELECT_READ, doAccept, this, 0);
+    CallBack(newConnDetails, [&] {
+        notify(Comm::COMM_ERROR, newConnDetails);
+    });
+
+    // XXX: Not under AsyncJob call protections but, if placed there, may cause
+    // problems like making the corresponding HttpSockets entry (if any) stale.
+    mustStop("unrecoverable accept failure");
 }
 
 void
@@ -329,17 +338,11 @@ Comm::TcpAcceptor::notify(const Comm::Flag flag, const Comm::ConnectionPointer &
     }
 }
 
-/**
- * accept() and process
- * Wait for an incoming connection on our listener socket.
- *
- * \retval Comm::OK          success. details parameter filled.
- * \retval Comm::NOMESSAGE   attempted accept() but nothing useful came in.
- *                           Or this client has too many connections already.
- * \retval Comm::COMM_ERROR  an outright failure occurred.
- */
-Comm::Flag
-Comm::TcpAcceptor::oldAccept(Comm::ConnectionPointer &details)
+/// acceptOne() helper: accept(2) a new TCP connection and fill in its details
+/// \retval false indicates that details do not contain a usable TCP connection,
+/// but future attempts to accept may still be successful
+bool
+Comm::TcpAcceptor::acceptInto(Comm::ConnectionPointer &details)
 {
     ++statCounter.syscalls.sock.accepts;
     struct addrinfo *gai = nullptr;
@@ -354,13 +357,9 @@ Comm::TcpAcceptor::oldAccept(Comm::ConnectionPointer &details)
 
         if (ignoreErrno(errcode) || errcode == ECONNABORTED) {
             debugs(50, 5, status() << ": " << xstrerr(errcode));
-            return Comm::NOMESSAGE;
-        } else if (errcode == ENFILE || errcode == EMFILE) {
-            debugs(50, 3, status() << ": " << xstrerr(errcode));
-            return Comm::COMM_ERROR;
+            return false;
         } else {
-            debugs(50, DBG_IMPORTANT, "ERROR: failed to accept an incoming connection: " << xstrerr(errcode));
-            return Comm::COMM_ERROR;
+            throw TextException(ToSBuf("Failed to accept an incoming connection: ", xstrerr(errcode)), Here());
         }
     }
 
@@ -369,7 +368,10 @@ Comm::TcpAcceptor::oldAccept(Comm::ConnectionPointer &details)
     // Sync with Comm ASAP so that abandoned details can properly close().
     // XXX : these are not all HTTP requests. use a note about type and ip:port details->
     // so we end up with a uniform "(HTTP|FTP-data|HTTPS|...) remote-ip:remote-port"
-    Descriptor sock(rawSock, FD_SOCKET, "HTTP Request");
+    const auto sock = rawSock;
+    fd_open(sock, FD_SOCKET, "HTTP Request");
+    details->fd = sock;
+    details->enterOrphanage();
 
     details->remote = *gai;
 
@@ -378,9 +380,8 @@ Comm::TcpAcceptor::oldAccept(Comm::ConnectionPointer &details)
     details->local.setEmpty();
     if (getsockname(sock, gai->ai_addr, &gai->ai_addrlen) != 0) {
         int xerrno = errno;
-        debugs(50, DBG_IMPORTANT, "ERROR: getsockname() failed to locate local-IP on " << details << ": " << xstrerr(xerrno));
         Ip::Address::FreeAddr(gai);
-        return Comm::COMM_ERROR;
+        throw TextException(ToSBuf("getsockname() failed to locate local-IP on ", details, ": ", xstrerr(xerrno)), Here());
     }
     details->local = *gai;
     Ip::Address::FreeAddr(gai);
@@ -389,14 +390,14 @@ Comm::TcpAcceptor::oldAccept(Comm::ConnectionPointer &details)
         details->flags |= COMM_TRANSPARENT;
         if (!Ip::Interceptor.TransparentActive()) {
             debugs(50, DBG_IMPORTANT, "ERROR: Cannot use transparent " << details << " because TPROXY mode became inactive");
-            // TODO: consider returning Comm::COMM_ERROR instead
-            return Comm::NOMESSAGE;
+            // TODO: consider throwing instead
+            return false;
         }
     } else if (conn->flags & COMM_INTERCEPTION) { // request the real client/dest IP address from NAT
         details->flags |= COMM_INTERCEPTION;
         if (!Ip::Interceptor.LookupNat(*details)) {
             debugs(50, DBG_IMPORTANT, "ERROR: NAT lookup failed to locate original IPs on " << details);
-            return Comm::NOMESSAGE;
+            return false;
         }
     }
 
@@ -415,7 +416,7 @@ Comm::TcpAcceptor::oldAccept(Comm::ConnectionPointer &details)
     if (Config.client_ip_max_connections >= 0) {
         if (clientdbEstablished(details->remote, 0) > Config.client_ip_max_connections) {
             debugs(50, DBG_IMPORTANT, "WARNING: " << details->remote << " attempting more than " << Config.client_ip_max_connections << " connections.");
-            return Comm::NOMESSAGE;
+            return false;
         }
     }
 
@@ -434,8 +435,6 @@ Comm::TcpAcceptor::oldAccept(Comm::ConnectionPointer &details)
     /* IFF the socket is (tproxy) transparent, pass the flag down to allow spoofing */
     F->flags.transparent = fd_table[conn->fd].flags.transparent; // XXX: can we remove this line yet?
 
-    details->fd = sock.release();
-    details->enterOrphanage();
-    return Comm::OK;
+    return true;
 }
 

diff --git a/src/comm/TcpAcceptor.h b/src/comm/TcpAcceptor.h
index 857d99bdeb8f98463df52c9df5a9a184a3b8b53e..73515b7581116e21fbd87028e5ceb81ed2a5b061 100644 (file)
--- a/src/comm/TcpAcceptor.h
+++ b/src/comm/TcpAcceptor.h
@@ -100,7 +100,7 @@ private:
     static void doAccept(int fd, void *data);
 
     void acceptOne();
-    Comm::Flag oldAccept(Comm::ConnectionPointer &details);
+    bool acceptInto(Comm::ConnectionPointer &);
     void setListen();
     void handleClosure(const CommCloseCbParams &io);
     /// whether we are listening on one of the squid.conf *ports

diff --git a/src/fd.cc b/src/fd.cc
index 46f0e187c86023e929056a9f0e1aeeaf6f586699..02e8e1e9095bf4d1e26d11248a213af4dc913ac1 100644 (file)
--- a/src/fd.cc
+++ b/src/fd.cc
@@ -12,7 +12,6 @@
 #include "comm/Loops.h"
 #include "debug/Messages.h"
 #include "debug/Stream.h"
-#include "error/SysErrorDetail.h"
 #include "fatal.h"
 #include "fd.h"
 #include "fde.h"
@@ -320,21 +319,3 @@ fdAdjustReserved(void)
     RESERVED_FD = newReserve;
 }
 
-/* Comm::Descriptor */
-
-Comm::Descriptor::Descriptor(const int fd, const unsigned int type, const char * const description): fd_(fd)
-{
-    fd_open(fd_, type, description);
-}
-
-Comm::Descriptor::~Descriptor()
-{
-    if (fd_ >= 0) {
-        fd_close(fd_);
-        if (close(fd_) != 0) {
-            const auto savedErrno = errno;
-            debugs(51, 7, "failed to close FD " << fd_ << ReportSysError(savedErrno));
-        }
-    }
-}
-

diff --git a/src/fd.h b/src/fd.h
index 267e7849a86bc45a2bef4891733cd2e764fba24b..e3f1ba3618307193da2e7da5fc74e8bf2c6c75e9 100644 (file)
--- a/src/fd.h
+++ b/src/fd.h
@@ -11,34 +11,6 @@
 #ifndef SQUID_FD_H_
 #define SQUID_FD_H_
 
-namespace Comm {
-
-/// An open Comm-registered file descriptor guard that, upon creation, registers
-/// the descriptor with Comm and, upon destruction, unregisters and closes the
-/// descriptor (unless the descriptor has been release()d by then).
-class Descriptor
-{
-public:
-    /// Starts owning the given FD of a given type, with a given description.
-    /// Assumes the given descriptor is open and calls legacy fd_open().
-    Descriptor(int fd, unsigned int type, const char *description);
-    Descriptor(Descriptor &&) = delete; // no copying (and, for now, moving) of any kind
-
-    /// Closes and calls legacy fd_close() unless release() was called earlier.
-    ~Descriptor();
-
-    /// A copy of the descriptor for use in system calls and such.
-    operator int() const { return fd_; }
-
-    /// Forgets the descriptor and prevents its automatic closure (by us).
-    int release() { const auto result = fd_; fd_ = -1; return result; }
-
-private:
-    int fd_;
-};
-
-} // namespace Comm
-
 void fd_close(int fd);
 void fd_open(int fd, unsigned int type, const char *);
 void fd_note(int fd, const char *);