Debug tls_read_method()/tls_write_method() errors (#2295)

A Comm::ReadNow() caller or similar high-level reading code that
triggers tls_read_method() calls is often unaware that it is doing TLS.
Comm::ReadNow() and similar TCP I/O APIs return decoded bytes or I/O
errors. This lack of awareness keeps high-level reading code simple, but
it becomes a problem in triage because neither low-level BIO code nor
high-level ReadNow() callers report TLS state/errors. They report
errno-based outcomes that may be faked by translation layers and may not
fully describe what happened at TLS layer.

Translations are highly environment/configuration/transaction specific,
but here are a few examples:

* EGAIN becomes SSL_ERROR_WANT_READ becomes EAGAIN;
* TLS close_alert becomes SSL_ERROR_ZERO_RETURN becomes zero-size read;
* TCP EOF becomes SSL_ERROR_SYSCALL becomes COMM_ERROR with zero errno!

These changes expose TLS state/errors hidden by translation (e.g.,
SSL_ERROR_WANT_READ, SSL_ERROR_ZERO_RETURN, SSL_ERROR_SYSCALL above).

Similar changes were applied to tls_write_method(), for similar reasons.

Debugging and error reporting improvements aside, no functionality
changes are expected. These enhancements were instrumental in tunnel
closure problems triage, but those problems deserve dedicated fixes.

diff --git a/src/security/Io.cc b/src/security/Io.cc
index d7f9f9a1cddcfaf736e6fde31b1792edce052a25..94d6b5685552464f94dc6e3f58171544b7f73113 100644 (file)
--- a/src/security/Io.cc
+++ b/src/security/Io.cc
@@ -18,7 +18,6 @@ namespace Security {
 
 template <typename Fun>
 static IoResult Handshake(Comm::Connection &, ErrorCode, Fun);
-static void PrepForIo();
 
 typedef SessionPointer::element_type *ConnectionPointer;
 
@@ -75,9 +74,7 @@ Security::ForgetErrors()
 #endif
 }
 
-/// the steps necessary to perform before the upcoming TLS I/O
-/// to correctly interpret/detail the outcome of that I/O
-static void
+void
 Security::PrepForIo()
 {
     // flush earlier errors that some call forgot to extract, so that we will

diff --git a/src/security/Io.h b/src/security/Io.h
index 6075fa115764d7d8a767090dfa56d62b44df9195..2aa310395caf2441031631b7df6b633ff7b95578 100644 (file)
--- a/src/security/Io.h
+++ b/src/security/Io.h
@@ -68,6 +68,10 @@ IoResult Connect(Comm::Connection &transport);
 /// clear any errors that a TLS library has accumulated in its global storage
 void ForgetErrors();
 
+/// perform the steps that are necessary to perform before the upcoming TLS I/O
+/// to correctly interpret/detail the outcome of that I/O; implies ForgetErrors()
+void PrepForIo();
+
 } // namespace Security
 
 #endif /* SQUID_SRC_SECURITY_IO_H */

diff --git a/src/security/Session.cc b/src/security/Session.cc
index cf798c37b2073b6e346ca3bdedaa9dbf187ed08c..2ab1ef577c228af79d3e34b4f9ef0ebc02b5f34e 100644 (file)
--- a/src/security/Session.cc
+++ b/src/security/Session.cc
@@ -13,9 +13,11 @@
 #include "base/RunnersRegistry.h"
 #include "CachePeer.h"
 #include "debug/Stream.h"
+#include "error/SysErrorDetail.h"
 #include "fd.h"
 #include "fde.h"
 #include "ipc/MemMap.h"
+#include "security/Io.h"
 #include "security/Session.h"
 #include "SquidConfig.h"
 #include "ssl/bio.h"
@@ -33,12 +35,27 @@ static int
 tls_read_method(int fd, char *buf, int len)
 {
     auto session = fd_table[fd].ssl.get();
-    debugs(83, 3, "started for session=" << (void*)session);
+    debugs(83, 5, "started for session=" << static_cast<void*>(session) << " FD " << fd << " buf.len=" << len);
+
+    Security::PrepForIo();
 
 #if USE_OPENSSL
     int i = SSL_read(session, buf, len);
+    const auto savedErrno = errno; // zero if SSL_read() does not set it
+
+    if (i <= 0) {
+        debugs(83, 3, "SSL_read(FD " << fd << ") error(" << i << "): " << SSL_get_error(session, i) << ReportSysError(savedErrno));
+        Security::ForgetErrors(); // will debugs() errors before forgetting them
+        errno = savedErrno;
+    }
 #elif HAVE_LIBGNUTLS
     int i = gnutls_record_recv(session, buf, len);
+    const auto savedErrno = errno; // zero if gnutls_record_recv() does not set it
+
+    if (i < 0) {
+        debugs(83, 3, "gnutls_record_recv(FD " << fd << ") error(" << i << "): " << Security::ErrorString(i) << ReportSysError(savedErrno));
+        errno = savedErrno;
+    }
 #endif
 
     if (i > 0) {
@@ -63,19 +80,35 @@ static int
 tls_write_method(int fd, const char *buf, int len)
 {
     auto session = fd_table[fd].ssl.get();
-    debugs(83, 3, "started for session=" << (void*)session);
+    debugs(83, 5, "started for session=" << static_cast<void*>(session) << " FD " << fd << " buf.len=" << len);
 
 #if USE_OPENSSL
     if (!SSL_is_init_finished(session)) {
+        debugs(83, 3, "FD " << fd << " is not in TLS init_finished state");
         errno = ENOTCONN;
         return -1;
     }
 #endif
 
+    Security::PrepForIo();
+
 #if USE_OPENSSL
     int i = SSL_write(session, buf, len);
+    const auto savedErrno = errno; // zero if SSL_write() does not set it
+
+    if (i <= 0) {
+        debugs(83, 3, "SSL_write(FD " << fd << ") error(" << i << "): " << SSL_get_error(session, i) << ReportSysError(savedErrno));
+        Security::ForgetErrors(); // will debugs() errors before forgetting them
+        errno = savedErrno;
+    }
 #elif HAVE_LIBGNUTLS
     int i = gnutls_record_send(session, buf, len);
+    const auto savedErrno = errno; // zero if gnutls_record_send() does not set it
+
+    if (i < 0) {
+        debugs(83, 3, "gnutls_record_send(FD " << fd << ") error(" << i << "): " << Security::ErrorString(i) << ReportSysError(savedErrno));
+        errno = savedErrno;
+    }
 #endif
 
     if (i > 0) {

diff --git a/src/tests/stub_libsecurity.cc b/src/tests/stub_libsecurity.cc
index 8185979d2b997f52a4134aaee812c4d1089f9b1a..bbbdfcc6a3cb79d8498e60a0655bb2534682e1d4 100644 (file)
--- a/src/tests/stub_libsecurity.cc
+++ b/src/tests/stub_libsecurity.cc
@@ -51,6 +51,7 @@ Security::IoResult Security::Connect(Comm::Connection &) STUB_RETVAL(IoResult(Io
 void Security::IoResult::printGist(std::ostream &) const STUB
 void Security::IoResult::printWithExtras(std::ostream &) const STUB
 void Security::ForgetErrors() STUB
+void Security::PrepForIo() STUB
 
 #include "security/KeyData.h"
 namespace Security