]> git.ipfire.org Git - thirdparty/squid.git/commitdiff
Restore errno in %err_detail for ERR_CONNECT_FAIL (#1368)
authorAlex Rousskov <rousskov@measurement-factory.com>
Fri, 8 Sep 2023 06:05:36 +0000 (06:05 +0000)
committerSquid Anubis <squid-anubis@squid-cache.org>
Fri, 8 Sep 2023 06:05:45 +0000 (06:05 +0000)
Squid was sometimes logging %err_code/%err_detail as
ERR_CONNECT_FAIL/WITH_SERVER. It now logs
ERR_CONNECT_FAIL/WITH_SERVER+errno=111 (or similar).

When dealing with two error details, Squid was ignoring the latter one.
The new ErrorDetails code combines multiple details, reusing the
existing Security::ErrorDetail::brief() "a+b+c" syntax.

The new detail accumulation functionality may help detail other errors.

At least some of the logged errno details were lost in commit ba3fe8d.

src/base/IoManip.h
src/cf.data.pre
src/client_side.cc
src/error/Detail.h
src/error/Error.cc
src/error/Error.h
src/errorpage.cc
src/format/Format.cc
src/servers/FtpServer.cc
src/tests/stub_liberror.cc

index 3feb928a11ebbcbfaa05d81001f1270d70b3a340..d8ac5287c6500305591031f94ef8b054caab9385 100644 (file)
@@ -13,6 +13,7 @@
 
 #include <iostream>
 #include <iomanip>
+#include <optional>
 
 /// Safely prints an object pointed to by the given pointer: [label]<object>
 /// Prints nothing at all if the pointer is nil.
@@ -101,5 +102,48 @@ inline AsHex<Integer> asHex(const Integer n) { return AsHex<Integer>(n); }
 /// Prints the first n data bytes using hex notation. Does nothing if n is 0.
 void PrintHex(std::ostream &, const char *data, size_t n);
 
+/// std::ostream manipulator to print containers as flat lists
+template <typename Container>
+class AsList
+{
+public:
+    explicit AsList(const Container &c): container(c) {}
+
+    /// a character to print before the first item (if any)
+    auto &prefixedBy(const char ch) { prefix = ch; return *this; }
+
+    /// a character to print between consecutive items (if any)
+    auto &delimitedBy(const char ch) { delimiter = ch; return *this; }
+
+public:
+    const Container &container; ///< zero or more items to print
+
+    std::optional<char> prefix; ///< \copydoc prefixedBy()
+    std::optional<char> delimiter; ///< \copydoc delimitedBy()
+};
+
+template <class Container>
+inline std::ostream &
+operator <<(std::ostream &os, const AsList<Container> &manipulator)
+{
+    bool opened = false;
+    for (const auto &item: manipulator.container) {
+        if (!opened) {
+            if (manipulator.prefix)
+                os << *manipulator.prefix;
+            opened = true;
+        } else {
+            if (manipulator.delimiter)
+                os << *manipulator.delimiter;
+        }
+        os << item;
+    }
+    return os;
+}
+
+/// a helper to ease AsList object creation
+template <typename Container>
+inline auto asList(const Container &c) { return AsList<Container>(c); }
+
 #endif /* SQUID_SRC_BASE_IO_MANIP_H */
 
index 010bf88456f3e59449dc22cbe071267ed926c861..f20e598277e18324d170c7f3f9a3df04c2b910a2 100644 (file)
@@ -4688,7 +4688,13 @@ DOC_START
                sn      Unique sequence number per log line entry
                err_code    The ID of an error response served by Squid or
                                a similar internal error identifier.
-               err_detail  Additional err_code-dependent error information.
+
+               err_detail  Additional err_code-dependent error information. Multiple
+                       details are separated by the plus sign ('+'). Admins should not
+                       rely on a particular detail listing order, the uniqueness of the
+                       entries, or individual detail text stability. All those properties
+                       depend on many unstable factors, including external libraries.
+
                note    The annotation specified by the argument. Also
                        logs the adaptation meta headers set by the
                        adaptation_meta configuration parameter.
index 1bca92017f7fd4202dec8a5a739f0deb4c58964c..e62bcf0fc7de4f2e7b89cffe4772fedc5c9a1278 100644 (file)
@@ -3989,9 +3989,9 @@ ConnStateData::terminateAll(const Error &rawError, const LogTagsErrors &lte)
     auto error = rawError; // (cheap) copy so that we can detail
     // We detail even ERR_NONE: There should be no transactions left, and
     // detailed ERR_NONE will be unused. Otherwise, this detail helps in triage.
-    if (!error.detail) {
+    if (error.details.empty()) {
         static const auto d = MakeNamedErrorDetail("WITH_CLIENT");
-        error.detail = d;
+        error.details.push_back(d);
     }
 
     debugs(33, 3, pipeline.count() << '/' << pipeline.nrequests << " after " << error);
index ec4df88a6d2ef795dac7bdf3fc1e31a17f969f3e..059c4bd28e072df1c6e5e05543c666f97eda78b5 100644 (file)
@@ -31,6 +31,17 @@ public:
     /// \returns all available details; may be customized for the given request
     /// suitable for error pages and other output meant for human consumption
     virtual SBuf verbose(const HttpRequestPointer &) const = 0;
+
+    // Duplicate details for the same error typically happen when we update some
+    // error storage (e.g., ALE) twice from the same detail source (e.g., the
+    // same HttpRequest object reachable via two different code/pointer paths)
+    // or retag the error with the same context information (e.g., WITH_CLIENT).
+    // In all those cases, comparing detail object addresses is enough to detect
+    // duplicates. In other cases (if they exist), a duplicate detail would
+    // imply inefficient or buggy error detailing code. Instead of spending ink
+    // and CPU cycles on hiding them, this comparison may expose those (minor)
+    // problems (in hope that they get fixed).
+    bool equals(const ErrorDetail &other) const { return this == &other; }
 };
 
 /// creates a new NamedErrorDetail object with a unique name
index d42cc7f161c5b249eddba48715d577cccdb8b55e..6789474c72b2d8e53e060a70c4e67e6c1856a20c 100644 (file)
@@ -9,31 +9,75 @@
 /* DEBUG: section 04    Error Management */
 
 #include "squid.h"
+#include "base/IoManip.h"
 #include "debug/Stream.h"
 #include "error/Error.h"
 
+void
+Error::update(const err_type recentCategory)
+{
+    if (recentCategory == ERR_NONE)
+        return; // no category given
+
+    if (category == recentCategory)
+        return; // no new category given
+
+    if (category != ERR_NONE) {
+        debugs(4, 5, "ignoring: " << errorTypeName(recentCategory) << "; keeping " << *this);
+        return; // the category given earlier has won
+    }
+
+    category = recentCategory;
+    debugs(4, 3, "new: " << errorTypeName(category));
+}
+
+void
+Error::update(const ErrorDetail::Pointer &recentDetail)
+{
+    if (!recentDetail)
+        return; // no new detail given
+
+    // an error can only have a few details so linear search is faster than indexing
+    for (const auto &oldDetail: details) {
+        if (recentDetail->equals(*oldDetail))
+            return; // the given detail is already present
+    }
+
+    details.push_back(recentDetail);
+    debugs(4, 3, "new: " << recentDetail);
+}
+
 void
 Error::update(const Error &recent)
 {
-    if (*this)
-        debugs(4, 5, "old: " << *this);
-    if (!recent)
-        return; // no changes
-    debugs(4, 3, "recent: " << recent);
     // checking category and detail separately may cause inconsistency, but
     // may result in more details available if they only become available later
-    if (category == ERR_NONE)
-        category = recent.category; // may still be ERR_NONE
-    if (!detail)
-        detail = recent.detail; // may still be nil
+    update(recent.category);
+    for (const auto &recentDetail: recent.details)
+        update(recentDetail);
+}
+
+void
+Error::update(const err_type recentCategory, const ErrorDetail::Pointer &recentDetail)
+{
+    // Optimization: Do not simply call update(Error(...)) here because that
+    // would require allocating and freeing heap memory for storing the detail.
+    update(recentCategory);
+    update(recentDetail);
+}
+
+std::ostream &
+operator <<(std::ostream &os, const ErrorDetails &details)
+{
+    os << AsList(details).delimitedBy('+');
+    return os;
 }
 
 std::ostream &
 operator <<(std::ostream &os, const Error &error)
 {
     os << errorTypeName(error.category);
-    if (error.detail)
-        os << '/' << *error.detail;
+    os << AsList(error.details).prefixedBy('/').delimitedBy('+');
     return os;
 }
 
index fc3ed42f9df9352384ec9ff7db1ab36d46205fce..a1074b6269773794d6bf41ffb85644ac844ffed9 100644 (file)
 
 #include "error/Detail.h"
 #include "error/forward.h"
+#include "mem/PoolingAllocator.h"
 
 #include <iosfwd>
+#include <vector>
+
+/// zero or more details of a single error
+using ErrorDetails = std::vector<ErrorDetailPointer, PoolingAllocator<ErrorDetailPointer> >;
+
+/// prints all given details separated by '+';
+/// if no details were given, prints nothing
+std::ostream &operator <<(std::ostream &, const ErrorDetails &);
 
 /// a transaction problem
 class Error {
 public:
     Error() = default;
     Error(const err_type c): category(c) {} ///< support implicit conversions
-    Error(const err_type c, const ErrorDetailPointer &d): category(c), detail(d) {}
+    Error(const err_type c, const ErrorDetailPointer &d): Error(c) { update(d); }
 
     explicit operator bool() const { return category != ERR_NONE; }
 
     /// if necessary, stores the given error information (if any)
     void update(const Error &);
 
-    /// convenience wrapper for update(Error)
-    void update(const err_type c, const ErrorDetailPointer &d) { update(Error(c, d)); }
+    /// if necessary, stores the given error information (if any);
+    /// more convenient and faster alternative to calling update(Error(c, d))
+    void update(err_type, const ErrorDetailPointer &);
+
+    /// if necessary, stores the given error category (if any), leaving details unchanged;
+    /// the first non-ERR_NONE category wins;
+    /// more convenient alternative to calling update(Error(c))
+    void update(err_type);
+
+    /// records an additional error detail (if any), leaving category unchanged
+    /// more convenient and faster alternative to calling update(Error(ERR_NONE, d))
+    /// \param detail either nil or a pointer to a new or an already known detail
+    void update(const ErrorDetailPointer &detail);
 
     /// switch to the default "no error information" state
     void clear() { *this = Error(); }
 
     err_type category = ERR_NONE; ///< primary error classification (or ERR_NONE)
-    ErrorDetailPointer detail; ///< additional details about the error
+
+    /// Zero or more details of a single error, in temporal order of discovery
+    /// without duplicates or nil pointers. The order/timing of update() calls
+    /// is used to approximate detail discovery time.
+    ErrorDetails details;
 };
 
 extern const char *err_type_str[];
index 0f648a4681fa29f9b6b50d8d86cc4ace2ff4577f..8200e28f7f673bab95767a61d5a0365fba6e6caa 100644 (file)
@@ -1348,15 +1348,12 @@ ErrorState::BuildHttpReply()
     // Make sure error codes get back to the client side for logging and
     // error tracking.
     if (request) {
-        if (detail)
-            request->detailError(type, detail);
-        else
-            request->detailError(type, SysErrorDetail::NewIfAny(xerrno));
+        request->error.update(type, detail);
+        request->error.update(SysErrorDetail::NewIfAny(xerrno));
     } else if (ale) {
-        if (detail)
-            ale->updateError(Error(type, detail));
-        else
-            ale->updateError(Error(type, SysErrorDetail::NewIfAny(xerrno)));
+        Error err(type, detail);
+        err.update(SysErrorDetail::NewIfAny(xerrno));
+        ale->updateError(err);
     }
 
     return rep;
index e7e689d381f9757df9798e9d70fa08c134ea7d4c..d0c6719f458edcd1fb1684f05914d58140e3a669 100644 (file)
@@ -1004,8 +1004,8 @@ Format::Format::assemble(MemBuf &mb, const AccessLogEntry::Pointer &al, int logS
 
         case LFT_SQUID_ERROR_DETAIL:
             if (const auto error = al->error()) {
-                if (const auto detail = error->detail) {
-                    sb = detail->brief();
+                if (!error->details.empty()) {
+                    sb = ToSBuf(error->details);
                     out = sb.c_str();
                 }
             }
index 65d628cb42cf11b5c58be6787491248eedac042a..976fe4e1f169a3a0d19d1bf075d006f5fb8c6391 100644 (file)
@@ -1103,7 +1103,7 @@ Ftp::Server::writeErrorReply(const HttpReply *reply, const int scode)
     if (request->error)
         mb.appendf("%i-%s\r\n", scode, errorPageName(request->error.category));
 
-    if (const auto &detail = request->error.detail) {
+    for (const auto &detail: request->error.details) {
         mb.appendf("%i-Error-Detail-Brief: " SQUIDSBUFPH "\r\n", scode, SQUIDSBUFPRINT(detail->brief()));
         mb.appendf("%i-Error-Detail-Verbose: " SQUIDSBUFPH "\r\n", scode, SQUIDSBUFPRINT(detail->verbose(request)));
     }
index 94a1ffa941b82b975b1f4580c20576a43ca6204c..3baa65e3e08107ee55adeb565c956060d976bf67 100644 (file)
 
 const char * err_type_str[ERR_MAX] = {};
 
+void Error::update(err_type) STUB_NOP
+void Error::update(const ErrorDetailPointer &) STUB_NOP
 void Error::update(const Error &) STUB_NOP
+void Error::update(err_type, const ErrorDetailPointer &) STUB_NOP
 
 std::ostream &operator <<(std::ostream &os, const Error &) STUB_RETVAL(os)
 std::ostream &operator <<(std::ostream &os, const ErrorDetail::Pointer &) STUB_RETVAL(os)
+std::ostream &operator <<(std::ostream &os, const ErrorDetails &) STUB_RETVAL(os)
 
 ErrorDetail::Pointer MakeNamedErrorDetail(const char *) STUB_RETVAL(ErrorDetail::Pointer())