Author: Alex Rousskov <rousskov@measurement-factory.com>, Christos Tsantilas <chtsant...

Added %err_code and %err_detail logformat codes to record details about transaction failures

For example, when Squid responds with 500 Internal Server Error, it is often
useful to know what went wrong.

This patch :
 - log a detail string instead of numbers for common errors
 - log a label with the detail code number for generic errors (system errors,
   or exceptions)
 - adds more details about errors, especially those detected with exceptions:
   We record a hash of the filename and the source code line number of the
   first caught exception.
 - adds two scripts which can help the developers to find the exact position
   of the caught exception:
   1) The calc-must-ids.pl take as argument one or more files and compute for
      each Must expression in the given files its  id;
   2) The calc-must-ids.sh can be used to find the exact position of a Must
      expression from its id. Example usage:
          # ./scripts/calc-must-ids.sh 0xB79EF14
          ./src/adaptation/ecap/MessageRep.cc:356: 0xB79EF14 Must(false);

diff --git a/scripts/calc-must-ids.pl b/scripts/calc-must-ids.pl
new file mode 100644 (file)
index 0000000..c609609
--- /dev/null
+++ b/scripts/calc-must-ids.pl
@@ -0,0 +1,65 @@
+#!/usr/bin/perl
+#
+# Author: Tsantilas Christos
+# (C) 2010 The Measurement Factory
+# 
+# Usage: 
+#     calc-must-ids.pl file1 file2 ...
+# Compute the ids of Must expressions of the given files.
+# It returns one line per Must expression in the form:
+#     filename: line: MustID 'Must Text'
+#
+
+use warnings;
+use strict;
+
+# This constant should be synced with ERR_DETAIL_EXCEPTION_START enum
+# defined in src/err_detail_type.h
+use constant ERR_DETAIL_EXCEPTION_START => 110000;
+
+my $file;
+while ($file = shift @ARGV)  {
+    ComputeMustIds($file);
+}
+sub FileNameHash
+{
+# Please keep in sync this function with the FileNameHash function in
+# src/base/TextException.cc file
+    my($name) = @_;
+    $name =~  s/.*\///g;
+    my($i) = 0;
+    my($j) =0;
+    my($n) = 0;
+    my(@na) = split(//, $name);
+    for($j=0; $j < @na; $j++) {
+        $n = $n ^ (271 * ord($na[$j])); 
+    }
+    $i = $n ^ ($j *271);
+    
+    # Currently 18bits of a 32 bit integer used  for filename hash 
+    # (max hash=262143),  and 14 bits for storing line number
+    $i = $i % 262143;
+    return $i;
+}
+
+sub ComputeMustIds
+{
+    my($file) = @_;
+    my($hash) = FileNameHash($file);
+    if(!open(IN, "<$file")) {
+        printf STDERR "error opening file $file. Ignore ...";
+        return;
+    }
+    while(<IN>) {
+        my($line) = $_;
+        my($id);
+        if ( $line =~ /^\s*Must\s*\(/  || $line =~ /^\s*throw\s*TexcHere\s*\(/){
+            $line =~ s/^\s*//;
+            $id= ($hash <<14) | ($. & 0x3FFF);
+            $id += ERR_DETAIL_EXCEPTION_START;
+#            print "$file:$.: $id $line";
+            printf "%s:%d: 0x%X %s", $file, $., $id, $line;
+        }            
+    }    
+    close(IN);
+}

diff --git a/scripts/calc-must-ids.sh b/scripts/calc-must-ids.sh
new file mode 100644 (file)
index 0000000..d1d1b9e
--- /dev/null
+++ b/scripts/calc-must-ids.sh
@@ -0,0 +1,22 @@
+#!/bin/sh
+#
+# Usage:
+#         calc-must-ids.sh [MustID]
+# Given an id it searches for the related Must expression in all
+# source files. If no arguments given it returns all Must expressions 
+# with its ids and their  exact position in the source files.
+#
+# Example usage:
+#     # ./scripts/calc-must-ids.sh 0xB79EF14
+#     ./src/adaptation/ecap/MessageRep.cc:356: 0xB79EF14 Must(false);
+#
+
+if test -z "$1"; then
+    find . -name "*.cc" -o -name "*.h" -o -name "*.cci" | \
+        xargs `dirname $0`/calc-must-ids.pl
+else
+    find . -name "*.cc" -o -name "*.h" -o -name "*.cci" | \
+        xargs `dirname $0`/calc-must-ids.pl | grep ": $1 "
+fi
+
+

diff --git a/src/HttpRequest.cc b/src/HttpRequest.cc
index b8274800a9987af7dc444887e237aa37b3ef1440..eb7276ac614f1c3c9096943fd107c1fdab9b2cb4 100644 (file)
--- a/src/HttpRequest.cc
+++ b/src/HttpRequest.cc
@@ -44,6 +44,7 @@
 #include "adaptation/icap/icap_log.h"
 #endif
 #include "acl/FilledChecklist.h"
+#include "err_detail_type.h"
 
 HttpRequest::HttpRequest() : HttpMsg(hoRequest)
 {
@@ -101,6 +102,7 @@ HttpRequest::init()
     // hier
     dnsWait = -1;
     errType = ERR_NONE;
+    errDetail = ERR_DETAIL_NONE;
     peer_login = NULL;         // not allocated/deallocated by this class
     peer_domain = NULL;                // not allocated/deallocated by this class
     vary_headers = NULL;
@@ -467,6 +469,20 @@ HttpRequest::bodyNibbled() const
     return body_pipe != NULL && body_pipe->consumedSize() > 0;
 }
 
+void
+HttpRequest::detailError(err_type aType, int aDetail)
+{
+    if (errType || errDetail)
+        debugs(11, 5, HERE << "old error details: " << errType << '/' << errDetail);
+    debugs(11, 5, HERE << "current error details: " << aType << '/' << aDetail);
+    // checking type and detail separately may cause inconsistency, but
+    // may result in more details available if they only become available later
+    if (!errType)
+        errType = aType;
+    if (!errDetail)
+        errDetail = aDetail;
+}
+
 const char *HttpRequest::packableURI(bool full_uri) const
 {
     if (full_uri)
@@ -607,6 +623,9 @@ bool HttpRequest::inheritProperties(const HttpMsg *aMsg)
     // may eventually need cloneNullAdaptationImmune() for that.
     flags = aReq->flags.cloneAdaptationImmune();
 
+    errType = aReq->errType;
+    errDetail = aReq->errDetail;
+
     auth_user_request = aReq->auth_user_request;
 
     if (aReq->pinned_connection) {

diff --git a/src/HttpRequest.h b/src/HttpRequest.h
index b632829336169123be5183c4387f21c39494d03f..e6ad3d56ed774b103ca7e0e3a9461b7265f301b5 100644 (file)
--- a/src/HttpRequest.h
+++ b/src/HttpRequest.h
@@ -126,6 +126,9 @@ public:
 
     void recordLookup(const DnsLookupDetails &detail);
 
+    /// sets error detail if no earlier detail was available
+    void detailError(err_type aType, int aDetail);
+
 protected:
     void clean();
 
@@ -194,6 +197,7 @@ public:
     int dnsWait; ///< sum of DNS lookup delays in milliseconds, for %dt
 
     err_type errType;
+    int errDetail; ///< errType-specific detail about the transaction error
 
     char *peer_login;          /* Configured peer login:password */
 

diff --git a/src/Makefile.am b/src/Makefile.am
index 25b433b025a43fc4f1ebe2ad68fbfc210438e64b..d50a1b1fc4fd735fcba52c735da17b39a8709a15 100644 (file)
--- a/src/Makefile.am
+++ b/src/Makefile.am
@@ -526,6 +526,7 @@ BUILT_SOURCES = \
        cf_gen_defines.cci \
        cf_parser.cci \
        err_type.cc \
+       err_detail_type.cc \
        globals.cc \
        hier_code.cc \
        icp_opcode.cc \
@@ -769,6 +770,9 @@ hier_code.cc: hier_code.h mk-string-arrays.awk
 err_type.cc: err_type.h mk-string-arrays.awk
        $(AWK) -f $(srcdir)/mk-string-arrays.awk < $(srcdir)/err_type.h > $@ || ($(RM) -f $@ && exit 1)
 
+err_detail_type.cc: err_detail_type.h mk-string-arrays.awk
+       $(AWK) -f $(srcdir)/mk-string-arrays.awk < $(srcdir)/err_detail_type.h | sed 's/ERR_DETAIL_//' > $@ || ($(RM) -f $@ && exit 1)
+
 lookup_t.cc: lookup_t.h mk-string-arrays.awk
        $(AWK) -f $(srcdir)/mk-string-arrays.awk < $(srcdir)/lookup_t.h > $@ || ($(RM) -f $@ && exit 1)
 

diff --git a/src/Server.cc b/src/Server.cc
index 8f11549bb13c28fbcf46ede20442e2c8f7b1c51e..065b79b59ea4ae148e8b941b789422831543f71d 100644 (file)
--- a/src/Server.cc
+++ b/src/Server.cc
@@ -40,6 +40,7 @@
 #include "HttpRequest.h"
 #include "HttpReply.h"
 #include "errorpage.h"
+#include "err_detail_type.h"
 #include "SquidTime.h"
 
 #if USE_ADAPTATION
@@ -766,10 +767,13 @@ ServerStateData::handleAdaptationAborted(bool bypassable)
     if (entry->isEmpty()) {
         debugs(11,9, HERE << "creating ICAP error entry after ICAP failure");
         ErrorState *err = errorCon(ERR_ICAP_FAILURE, HTTP_INTERNAL_SERVER_ERROR, request);
-        err->xerrno = errno;
+        err->xerrno = ERR_DETAIL_ICAP_RESPMOD_EARLY;
         fwd->fail(err);
         fwd->dontRetry(true);
     }
+    else if (request) { // update logged info directly
+        request->detailError(ERR_ICAP_FAILURE, ERR_DETAIL_ICAP_RESPMOD_LATE);
+    }
 
     abortTransaction("ICAP failure");
 }

diff --git a/src/adaptation/icap/ModXact.cc b/src/adaptation/icap/ModXact.cc
index b1d1db08dc35ccebf96622a6c58c3488210f5b7d..48260bed79d19bf85512168032c91c4453cf4f9f 100644 (file)
--- a/src/adaptation/icap/ModXact.cc
+++ b/src/adaptation/icap/ModXact.cc
@@ -20,6 +20,7 @@
 #include "HttpRequest.h"
 #include "HttpReply.h"
 #include "SquidTime.h"
+#include "err_detail_type.h"
 
 // flow and terminology:
 //     HTTP| --> receive --> encode --> write --> |network
@@ -605,6 +606,12 @@ void Adaptation::Icap::ModXact::parseMore()
 void Adaptation::Icap::ModXact::callException(const std::exception &e)
 {
     if (!canStartBypass || isRetriable) {
+        if (!isRetriable) {
+            if (const TextException *te = dynamic_cast<const TextException *>(&e))
+                detailError(ERR_DETAIL_EXCEPTION_START + te->id());
+            else
+                detailError(ERR_DETAIL_EXCEPTION_OTHER);
+        }
         Adaptation::Icap::Xaction::callException(e);
         return;
     }
@@ -613,7 +620,11 @@ void Adaptation::Icap::ModXact::callException(const std::exception &e)
         debugs(93, 3, HERE << "bypassing " << inCall << " exception: " <<
                e.what() << ' ' << status());
         bypassFailure();
+    } catch (const TextException &bypassTe) {
+        detailError(ERR_DETAIL_EXCEPTION_START + bypassTe.id());
+        Adaptation::Icap::Xaction::callException(bypassTe);
     } catch (const std::exception &bypassE) {
+        detailError(ERR_DETAIL_EXCEPTION_OTHER);
         Adaptation::Icap::Xaction::callException(bypassE);
     }
 }
@@ -1161,6 +1172,7 @@ void Adaptation::Icap::ModXact::noteMoreBodySpaceAvailable(BodyPipe::Pointer)
 // adapted body consumer aborted
 void Adaptation::Icap::ModXact::noteBodyConsumerAborted(BodyPipe::Pointer)
 {
+    detailError(ERR_DETAIL_ICAP_XACT_BODY_CONSUMER_ABORT);
     mustStop("adapted body consumer aborted");
 }
 
@@ -1177,6 +1189,9 @@ void Adaptation::Icap::ModXact::swanSong()
     stopWriting(false);
     stopSending(false);
 
+    if (theInitiator.set()) // we have not sent the answer to the initiator
+        detailError(ERR_DETAIL_ICAP_XACT_OTHER);
+
     // update adaptation history if start was called and we reserved a slot
     Adaptation::History::Pointer ah = virginRequest().adaptLogHistory();
     if (ah != NULL && adaptHistoryId >= 0)
@@ -1823,6 +1838,13 @@ bool Adaptation::Icap::ModXact::fillVirginHttpHeader(MemBuf &mb) const
     return true;
 }
 
+void Adaptation::Icap::ModXact::detailError(int errDetail)
+{
+    if (HttpRequest *request = virgin.cause ?
+        virgin.cause : dynamic_cast<HttpRequest*>(virgin.header)) {
+        request->detailError(ERR_ICAP_FAILURE, errDetail);
+    }
+}
 
 /* Adaptation::Icap::ModXactLauncher */
 

diff --git a/src/adaptation/icap/ModXact.h b/src/adaptation/icap/ModXact.h
index fb08d02e55ab259a82cd4523ddd50d6d5cd99833..f9117c98a965a5518cd9112563628b4e571e950e 100644 (file)
--- a/src/adaptation/icap/ModXact.h
+++ b/src/adaptation/icap/ModXact.h
@@ -165,6 +165,9 @@ public:
     // bypasses exceptions if needed and possible
     virtual void callException(const std::exception &e);
 
+    /// record error detail in the virgin request if possible
+    virtual void detailError(int errDetail);
+
 private:
     virtual void start();
 

diff --git a/src/adaptation/icap/Xaction.cc b/src/adaptation/icap/Xaction.cc
index 14fedfabaf94180c5c12f96c68fff4f40bcb90cd..b37032a14dc5b73cf2d9dae2589392d83a176365 100644 (file)
--- a/src/adaptation/icap/Xaction.cc
+++ b/src/adaptation/icap/Xaction.cc
@@ -18,6 +18,7 @@
 #include "icap_log.h"
 #include "fde.h"
 #include "SquidTime.h"
+#include "err_detail_type.h"
 
 static PconnPool *icapPconnPool = new PconnPool("ICAP Servers");
 
@@ -225,6 +226,7 @@ void Adaptation::Icap::Xaction::dieOnConnectionFailure()
 {
     debugs(93, 2, HERE << typeName <<
            " failed to connect to " << service().cfg().uri);
+    detailError(ERR_DETAIL_ICAP_XACT_START);
     throw TexcHere("cannot connect to the ICAP service");
 }
 
@@ -284,6 +286,7 @@ void Adaptation::Icap::Xaction::noteCommClosed(const CommCloseCbParams &io)
 
 void Adaptation::Icap::Xaction::handleCommClosed()
 {
+    detailError(ERR_DETAIL_ICAP_XACT_CLOSE);
     mustStop("ICAP service connection externally closed");
 }
 
@@ -441,6 +444,7 @@ void Adaptation::Icap::Xaction::noteInitiatorAborted()
 
     if (theInitiator.set()) {
         clearInitiator();
+        detailError(ERR_DETAIL_ICAP_INIT_GONE);
         mustStop("initiator aborted");
     }
 

diff --git a/src/adaptation/icap/Xaction.h b/src/adaptation/icap/Xaction.h
index 7eb8d010c26d67a96cc8a54b2b8084092553a38c..b22cbbe4b8219b10c36af8ca0a03ddd744545a5d 100644 (file)
--- a/src/adaptation/icap/Xaction.h
+++ b/src/adaptation/icap/Xaction.h
@@ -96,6 +96,9 @@ protected:
     virtual void handleCommTimedout();
     virtual void handleCommClosed();
 
+    /// record error detail if possible
+    virtual void detailError(int errDetail) {}
+
     void openConnection();
     void closeConnection();
     void dieOnConnectionFailure();

diff --git a/src/base/TextException.cc b/src/base/TextException.cc
index c595e3093757baafbae2dd54fc53c289d54e7918..04c0ab3359c351899d25504b6b93ab426d9ba9dc 100644 (file)
--- a/src/base/TextException.cc
+++ b/src/base/TextException.cc
@@ -1,4 +1,4 @@
-#include "config.h"
+#include "squid.h"
 #include "base/TextException.h"
 #include "Debug.h"
 #include "util.h"
@@ -8,15 +8,16 @@ TextException::TextException()
     message=NULL;
     theFileName=NULL;
     theLineNo=0;
+    theId=0;
 }
 
 TextException::TextException(const TextException& right) :
-        message((right.message?xstrdup(right.message):NULL)), theFileName(right.theFileName), theLineNo(right.theLineNo)
+    message((right.message?xstrdup(right.message):NULL)), theFileName(right.theFileName), theLineNo(right.theLineNo), theId(right.theId)
 {
 }
 
-TextException::TextException(const char *aMsg, const char *aFileName, int aLineNo):
-        message(xstrdup(aMsg)), theFileName(aFileName), theLineNo(aLineNo)
+TextException::TextException(const char *aMsg, const char *aFileName, int aLineNo, unsigned int anId):
+    message(xstrdup(aMsg)), theFileName(aFileName), theLineNo(aLineNo), theId(anId)
 {}
 
 TextException::~TextException() throw()
@@ -31,7 +32,7 @@ TextException& TextException::operator=(const TextException &right)
     message=(right.message?xstrdup(right.message):NULL);
     theFileName=right.theFileName;
     theLineNo=right.theLineNo;
-
+    theId=right.theId;
     return *this;
 }
 
@@ -41,7 +42,33 @@ const char *TextException::what() const throw()
     return message ? message : "TextException without a message";
 }
 
-void Throw(const char *message, const char *fileName, int lineNo)
+unsigned int TextException::FileNameHash(const char *fname)
+{    
+    const char *s = NULL;
+    unsigned int n = 0;
+    unsigned int j = 0;
+    unsigned int i = 0;
+    s = strrchr(fname, '/');
+    
+    if (s)
+        s++;
+    else
+        s = fname;
+
+    while (*s) {
+        j++;
+        n ^= 271 * (unsigned) *s++;
+    }
+    i = n ^ (j * 271);
+    /*18bits of a 32 bit integer used  for filename hash (max hash=262143),
+      and 14 bits for storing line number (16k max).
+      If you change this policy remember to update the FileNameHash function
+      in the scripts/calc-must-ids.pl script
+    */
+    return i % 262143;
+}
+
+void Throw(const char *message, const char *fileName, int lineNo, unsigned int id)
 {
 
     // or should we let the exception recepient print the exception instead?
@@ -54,5 +81,5 @@ void Throw(const char *message, const char *fileName, int lineNo)
                (message ? ": " : ".") << (message ? message : ""));
     }
 
-    throw TextException(message, fileName, lineNo);
+    throw TextException(message, fileName, lineNo, id);
 }

diff --git a/src/base/TextException.h b/src/base/TextException.h
index c559c52e8ac9bcad4ca1f2bddac89f1afe18b8e4..c69e4726752357c69947c6156f2901a4f2b68392 100644 (file)
--- a/src/base/TextException.h
+++ b/src/base/TextException.h
@@ -6,6 +6,8 @@
 #include "config.h"
 #include <exception>
 
+static unsigned int FileNameHashCached(const char *fname);
+
 // simple exception to report custom errors
 // we may want to change the interface to be able to report system errors
 
@@ -14,10 +16,13 @@ class TextException: public std::exception
 
 public:
     TextException();
-    TextException(const char *aMessage, const char *aFileName = 0, int aLineNo = -1);
+    TextException(const char *aMessage, const char *aFileName = 0, int aLineNo = -1, unsigned int anId =0);
     TextException(const TextException& right);
     virtual ~TextException() throw();
 
+    // unique exception ID for transaction error detail logging
+    unsigned int id() const { return theId; }
+    
     virtual const char *what() const throw();
 
     TextException& operator=(const TextException &right);
@@ -26,9 +31,15 @@ public:
     char *message; // read-only
 
 protected:
+    /// a small integer hash value to semi-uniquely identify the source file
+    static unsigned int FileNameHash(const char *fname);
+
     // optional location information
     const char *theFileName;
     int theLineNo;
+    unsigned int theId;
+    
+    friend unsigned int FileNameHashCached(const char *fname);
 };
 
 //inline
@@ -36,17 +47,38 @@ protected:
 //    return exx.print(os);
 //}
 
+/// caches the result of FileNameHash() for each translation unit
+static unsigned int
+FileNameHashCached(const char *fname)
+{
+    static const char *lastFname = 0;
+    static int lastHash = 0;
+    // __FILE__ changes when we #include files
+    if (lastFname != fname) { // cheap pointer comparison
+        lastFname = fname;
+        lastHash = TextException::FileNameHash(fname);
+    }
+    return lastHash;
+}
+
+///  Avoids "defined but not used" warnings for FileNameHashCached
+class FileNameHashCacheUser {
+    bool use(void *ptr=NULL) { return ptr != &FileNameHashCached;}
+};
+
 #if !defined(TexcHere)
-#    define TexcHere(msg) TextException((msg), __FILE__, __LINE__)
+#    define TexcHere(msg) TextException((msg), __FILE__, __LINE__, \
+                                         (FileNameHashCached(__FILE__)<<14) | (__LINE__ & 0x3FFF))
 #endif
 
-extern void Throw(const char *message, const char *fileName, int lineNo);
+extern void Throw(const char *message, const char *fileName, int lineNo, unsigned int id);
 
 // Must(condition) is like assert(condition) but throws an exception instead
 #if !defined(Must)
 #   define Must(cond) ((cond) ? \
         (void)0 : \
-        (void)Throw(#cond, __FILE__, __LINE__))
+                      (void)Throw(#cond, __FILE__, __LINE__, \
+                                  (FileNameHashCached(__FILE__)<<14) | (__LINE__ & 0x3FFF)))
 #endif
 
 #endif /* SQUID__TEXTEXCEPTION_H */

diff --git a/src/cf.data.pre b/src/cf.data.pre
index 2c850cb01b89b68dd632af7316a6ff079d9150f8..815e8dd24edb5293fd19eb33bf29ad8c9c2db8c8 100644 (file)
--- a/src/cf.data.pre
+++ b/src/cf.data.pre
@@ -2725,6 +2725,9 @@ DOC_START
                                default %d/%b/%Y:%H:%M:%S %z
                tr      Response time (milliseconds)
                dt      Total time spent making DNS lookups (milliseconds)
+               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.
 
        HTTP cache related format codes:
 

diff --git a/src/client_side.cc b/src/client_side.cc
index 52b6090313ae660c87e0e88fd270a7368da71a74..eb7f749c7cf318c3ebef5ac19fcf8d32b3992fc3 100644 (file)
--- a/src/client_side.cc
+++ b/src/client_side.cc
@@ -585,6 +585,11 @@ prepareLogWithRequestDetails(HttpRequest * request, AccessLogEntry * aLogEntry)
 
 // WTF??        request->auth_user_request = NULL;
     }
+
+    if (aLogEntry->request) {
+        aLogEntry->request->errType = request->errType;
+        aLogEntry->request->errDetail = request->errDetail;
+    }
 }
 
 void

diff --git a/src/client_side_request.cc b/src/client_side_request.cc
index 9c939491d23381230bac5831429183b9f9971a48..28b97083d025e8fd9b460e25d9127fbd5909c17d 100644 (file)
--- a/src/client_side_request.cc
+++ b/src/client_side_request.cc
@@ -69,6 +69,7 @@
 #include "Store.h"
 #include "SquidTime.h"
 #include "wordlist.h"
+#include "err_detail_type.h"
 
 
 #if LINGERING_CLOSE
@@ -1455,7 +1456,7 @@ ClientHttpRequest::noteAdaptationQueryAbort(bool final)
 {
     clearAdaptation(virginHeadSource);
     assert(!adaptedBodySource);
-    handleAdaptationFailure(!final);
+    handleAdaptationFailure(ERR_DETAIL_ICAP_REQMOD_ABORT, !final);
 }
 
 void
@@ -1508,11 +1509,11 @@ ClientHttpRequest::noteBodyProducerAborted(BodyPipe::Pointer)
 {
     assert(!virginHeadSource);
     stopConsumingFrom(adaptedBodySource);
-    handleAdaptationFailure();
+    handleAdaptationFailure(ERR_DETAIL_ICAP_RESPMOD_CLT_SIDE_BODY);
 }
 
 void
-ClientHttpRequest::handleAdaptationFailure(bool bypassable)
+ClientHttpRequest::handleAdaptationFailure(int errDetail, bool bypassable)
 {
     debugs(85,3, HERE << "handleAdaptationFailure(" << bypassable << ")");
 
@@ -1545,6 +1546,8 @@ ClientHttpRequest::handleAdaptationFailure(bool bypassable)
                                 (c != NULL && c->auth_user_request != NULL ?
                                  c->auth_user_request : request->auth_user_request));
 
+    request->detailError(ERR_ICAP_FAILURE, errDetail);
+
     node = (clientStreamNode *)client_stream.tail->data;
     clientStreamRead(node, this, node->readBuffer);
 }

diff --git a/src/client_side_request.h b/src/client_side_request.h
index facfc4b2d471e779a9640fbabe4d878dcc5bcdad..f39d8b54a5b76bf076a113794665668ed0bd596b 100644 (file)
--- a/src/client_side_request.h
+++ b/src/client_side_request.h
@@ -162,7 +162,7 @@ public:
     void startAdaptation(const Adaptation::ServiceGroupPointer &g);
 
     // private but exposed for ClientRequestContext
-    void handleAdaptationFailure(bool bypassable = false);
+    void handleAdaptationFailure(int errDetail, bool bypassable = false);
 
 private:
     // Adaptation::Initiator API

diff --git a/src/err_detail_type.h b/src/err_detail_type.h
new file mode 100644 (file)
index 0000000..7ebbbbf
--- /dev/null
+++ b/src/err_detail_type.h
@@ -0,0 +1,37 @@
+#ifndef _SQUID_ERR_DETAIL_H
+#define  _SQUID_ERR_DETAIL_H
+
+typedef enum {
+    ERR_DETAIL_NONE,
+    ERR_DETAIL_START = 100000, // to avoid clashes with most OS error numbers
+    ERR_DETAIL_ICAP_REQMOD_ABORT = ERR_DETAIL_START, // transaction abort
+    ERR_DETAIL_ICAP_RESPMOD_CLT_SIDE_BODY, // client-side detected body abort
+    ERR_DETAIL_ICAP_RESPMOD_EARLY, // RESPMOD failed w/o store entry
+    ERR_DETAIL_ICAP_RESPMOD_LATE,  // RESPMOD failed with a store entry
+    ERR_DETAIL_ICAP_XACT_START, // transaction start failure
+    ERR_DETAIL_ICAP_XACT_BODY_CONSUMER_ABORT, // transaction body consumer gone
+    ERR_DETAIL_ICAP_INIT_GONE, // initiator gone
+    ERR_DETAIL_ICAP_XACT_CLOSE, // ICAP connection closed unexpectedly
+    ERR_DETAIL_ICAP_XACT_OTHER, // other ICAP transaction errors
+    ERR_DETAIL_EXCEPTION_OTHER, //other errors ( eg std C++ lib errors)
+    ERR_DETAIL_MAX,
+    ERR_DETAIL_EXCEPTION_START = 110000 // offset for exception ID details
+} err_detail_type;
+
+extern const char *err_detail_type_str[];
+
+inline
+const char *errorDetailName(int errDetailId) {
+    if (errDetailId < ERR_DETAIL_START)
+        return "SYSERR";
+
+    if (errDetailId < ERR_DETAIL_MAX)
+        return err_detail_type_str[errDetailId-ERR_DETAIL_START+2];
+    
+    if (errDetailId >=ERR_DETAIL_EXCEPTION_START)
+        return "EXCEPTION";
+
+    return "UNKNOWN";
+}
+
+#endif

diff --git a/src/errorpage.cc b/src/errorpage.cc
index bcc3e2e966167eb213ab7e395c6eb53ae6a80eb6..feec181c4a2a8143c337e1423bfb41d493c4313c 100644 (file)
--- a/src/errorpage.cc
+++ b/src/errorpage.cc
@@ -45,6 +45,7 @@
 #include "rfc1738.h"
 #include "URLScheme.h"
 #include "wordlist.h"
+#include "err_detail_type.h"
 
 /**
  \defgroup ErrorPageInternal Error Page Internals
@@ -368,7 +369,7 @@ errorReservePageId(const char *page_name)
 }
 
 /// \ingroup ErrorPageInternal
-static const char *
+const char *
 errorPageName(int pageId)
 {
     if (pageId >= ERR_NONE && pageId < ERR_MAX)                /* common case */
@@ -392,6 +393,7 @@ errorCon(err_type type, http_status status, HttpRequest * request)
     if (request != NULL) {
         err->request = HTTPMSGLOCK(request);
         err->src_addr = request->client_addr;
+        request->detailError(type, ERR_DETAIL_NONE);
     }
 
     return err;
@@ -450,7 +452,7 @@ errorSend(int fd, ErrorState * err)
      */
 
     if (err->request)
-        err->request->errType = err->type;
+        err->request->detailError(err->type, err->xerrno);
 
     /* moved in front of errorBuildBuf @?@ */
     err->flags.flag_cbdata = 1;

diff --git a/src/errorpage.h b/src/errorpage.h
index 785458efd34f6870ac41b1c324c6f79d3b5f56f0..74a30b6efc504a8a3f44a1c57c47ad95763baf65 100644 (file)
--- a/src/errorpage.h
+++ b/src/errorpage.h
@@ -225,5 +225,6 @@ SQUIDCEXTERN err_type errorReservePageId(const char *page_name);
  * This function creates a ErrorState object.
  */
 SQUIDCEXTERN ErrorState *errorCon(err_type type, http_status, HttpRequest * request);
+SQUIDCEXTERN const char *errorPageName(int pageId); ///< error ID to string
 
 #endif /* SQUID_ERRORPAGE_H */

diff --git a/src/forward.cc b/src/forward.cc
index 8f9c3dcb886739c650c8696506952a48a3bcc1cb..6e0a46be09812c149c411ee30ecd544631b9c385 100644 (file)
--- a/src/forward.cc
+++ b/src/forward.cc
@@ -290,6 +290,8 @@ FwdState::fail(ErrorState * errorState)
 
     if (!errorState->request)
         errorState->request = HTTPMSGLOCK(request);
+
+    request->detailError(errorState->type, errorState->xerrno);
 }
 
 /**

diff --git a/src/ftp.cc b/src/ftp.cc
index fb7d7bcf79a105ed28fa8ce7894a8524d5b9a7c2..9a0e61e97b1777228191d82a219e05b6a29e943b 100644 (file)
--- a/src/ftp.cc
+++ b/src/ftp.cc
@@ -3637,6 +3637,9 @@ ftpSendReply(FtpStateData * ftpState)
         http_code = HTTP_INTERNAL_SERVER_ERROR;
     }
 
+    if (ftpState->request)
+        ftpState->request->detailError(err_code, code);
+
     err = errorCon(err_code, http_code, ftpState->request);
 
     if (ftpState->old_request)

diff --git a/src/http.cc b/src/http.cc
index 25adee2a67698395bbaf969debcc77eb02783f0a..59cef61db4a9754a4fbac1c125203a4b5a8c73f7 100644 (file)
--- a/src/http.cc
+++ b/src/http.cc
@@ -2302,6 +2302,14 @@ void
 HttpStateData::handleRequestBodyProducerAborted()
 {
     ServerStateData::handleRequestBodyProducerAborted();
+    if (entry->isEmpty()) {
+        debugs(11, 3, "request body aborted: FD " << fd);
+        ErrorState *err;
+        err = errorCon(ERR_READ_ERROR, HTTP_BAD_GATEWAY, fwd->request);
+        err->xerrno = errno;
+        fwd->fail(err);
+    }
+
     abortTransaction("request body producer aborted");
 }
 

diff --git a/src/log/access_log.cc b/src/log/access_log.cc
index e21c4c4dad7415ec79edea67975957d6ccf37cdf..54d5d1cedaa205c11192b87b71c6a74eb1c8d873 100644 (file)
--- a/src/log/access_log.cc
+++ b/src/log/access_log.cc
@@ -39,6 +39,8 @@
 // Store.h Required by configuration directives parsing/dumping only
 #include "Store.h"
 
+#include "errorpage.h"
+#include "err_detail_type.h"
 #include "acl/Checklist.h"
 #include "CacheManager.h"
 #if USE_SQUID_EUI
@@ -383,7 +385,8 @@ typedef enum {
     LFT_HTTP_BODY_BYTES_READ,
 
     LFT_SQUID_STATUS,
-    /*LFT_SQUID_ERROR, */
+    LFT_SQUID_ERROR, 
+    LFT_SQUID_ERROR_DETAIL, 
     LFT_SQUID_HIERARCHY,
 
     LFT_MIME_TYPE,
@@ -542,7 +545,8 @@ struct logformat_token_table_entry logformat_token_table[] = {
     {"<bs", LFT_HTTP_BODY_BYTES_READ},
 
     {"Ss", LFT_SQUID_STATUS},
-    /*{ "Se", LFT_SQUID_ERROR }, */
+    { "err_code", LFT_SQUID_ERROR },
+    { "err_detail", LFT_SQUID_ERROR_DETAIL },
     {"Sh", LFT_SQUID_HIERARCHY},
 
     {"mt", LFT_MIME_TYPE},
@@ -1124,7 +1128,27 @@ accessLogCustom(AccessLogEntry * al, customlog * log)
 
             break;
 
-            /* case LFT_SQUID_ERROR: */
+        case LFT_SQUID_ERROR:
+            if (al->request && al->request->errType != ERR_NONE)
+                out = errorPageName(al->request->errType);
+            break;
+
+        case LFT_SQUID_ERROR_DETAIL:
+            if (al->request && al->request->errDetail != ERR_DETAIL_NONE) {
+                if (al->request->errDetail > ERR_DETAIL_START  &&
+                    al->request->errDetail < ERR_DETAIL_MAX)
+                    out = errorDetailName(al->request->errDetail);
+                else {
+                    if (al->request->errDetail >= ERR_DETAIL_EXCEPTION_START)
+                        snprintf(tmp, sizeof(tmp), "%s=0x%X",
+                                 errorDetailName(al->request->errDetail), (uint32_t) al->request->errDetail);
+                    else
+                        snprintf(tmp, sizeof(tmp), "%s=%d",
+                                 errorDetailName(al->request->errDetail), al->request->errDetail);
+                    out = tmp;
+                }
+            }
+            break;
 
         case LFT_SQUID_HIERARCHY:
             if (al->hier.ping.timedout)