=== modified file 'acinclude/ax_cxx_0x_types.m4' --- acinclude/ax_cxx_0x_types.m4 2011-08-02 07:31:53 +0000 +++ acinclude/ax_cxx_0x_types.m4 2014-02-17 20:45:35 +0000 @@ -22,20 +22,51 @@ AC_DEFUN([AX_CXX_TYPE_NULLPTR],[ AC_DEFINE(HAVE_NULLPTR_T, 1, [Define to 1 if nullptr_t is supported]) fi AC_LANG_POP ]) ## Hand crafted for Squid under GPL version 2 AC_DEFUN([AX_CXX_TYPE_UNIQUE_PTR],[ AC_REQUIRE([AC_PROG_CXX]) AC_LANG_PUSH([C++]) AC_MSG_CHECKING([whether std::unique_ptr is supported]) AC_TRY_COMPILE([#include ],[std::unique_ptr c;], [ HAVE_UNIQUE_PTR=yes AC_MSG_RESULT(yes)], [ HAVE_UNIQUE_PTR=no AC_MSG_RESULT(no)]) if test "x$HAVE_UNIQUE_PTR" = xyes; then AC_DEFINE(HAVE_UNIQUE_PTR, 1, [Define to 1 if std::unique_ptr is supported]) fi AC_LANG_POP ]) + +## Hand crafted for Squid under GPL version 2 +AC_DEFUN([AX_CXX_TYPE_STD_MUTEX],[ + AC_CACHE_CHECK([whether std::mutex is supported], ac_cv_cxx_stdmutex, [ + AC_TRY_COMPILE([#include ],[std::mutex m;], [ + ac_cv_cxx_stdmutex=yes + ], [ + ac_cv_cxx_stdmutex=no + ]) + ]) + if test "x$ac_cv_cxx_stdmutex" = "xyes"; then + AC_DEFINE(HAVE_STD_MUTEX,1,[Define if c++0x std::mutex is present]) + fi +]) + +## Hand crafted for Squid under GPL version 2 +AC_DEFUN([AX_CXX_TYPE_STD_LOCKGUARD],[ + AC_CACHE_CHECK([whether std::lock_guard is supported], ac_cv_cxx_lockguard, [ + AC_TRY_COMPILE([#include ],[ + std::mutex m; + std::lock_guard lg(m) + ], [ + ac_cv_cxx_lockguard=yes + ], [ + ac_cv_cxx_lockguard=no + ]) + ]) + if test "x$ac_cv_cxx_lockguard" = "xyes"; then + AC_DEFINE(HAVE_STD_LOCK_GUARD,1,[Define if c++11 std::lock_guard is present]) + fi +]) \ No newline at end of file === added file 'compat/mutex.h' --- compat/mutex.h 1970-01-01 00:00:00 +0000 +++ compat/mutex.h 2014-02-17 20:47:26 +0000 @@ -0,0 +1,27 @@ +#ifndef SQUID_MUTEX_H_ +#define SQUID_MUTEX_H_ + +#if HAVE_STD_MUTEX +#include + +typedef std::mutex Mutex; + +#else +#include + +class Mutex { +public: + Mutex() { + if (pthread_mutex_init(&mtx,NULL)) + throw "Failed to create mutex"; + } + ~Mutex() { pthread_mutex_destroy(&mtx); } + void lock() { pthread_mutex_lock(&mtx); } + bool try_lock() { return pthread_mutex_trylock(&mtx) == 0; } + void unlock() { pthread_mutex_unlock(&mtx); } +private: + pthread_mutex_t mtx; +}; +#endif /* HAVE_STD_MUTEX */ + +#endif /* SQUID_MUTEX_H_ */ === modified file 'configure.ac' --- configure.ac 2014-02-13 07:02:35 +0000 +++ configure.ac 2014-02-17 20:46:04 +0000 @@ -2375,40 +2375,42 @@ AC_TYPE_UINT32_T AC_TYPE_INT64_T AC_TYPE_UINT64_T AC_TYPE_PID_T AC_TYPE_SIZE_T AC_TYPE_SSIZE_T AC_TYPE_OFF_T AC_TYPE_UID_T AC_CHECK_TYPE([bool]) #need the defines for PRId64 AC_CHECK_SIZEOF(int64_t) AC_CHECK_SIZEOF(long) #need the defines for PRIuSIZE AC_CHECK_SIZEOF(size_t) #need the define for overflow checks AC_CHECK_SIZEOF(off_t) AC_CHECK_SIZEOF(size_t) dnl Some C++0x types we try to use AX_CXX_TYPE_NULLPTR AX_CXX_TYPE_UNIQUE_PTR +AX_CXX_TYPE_STD_MUTEX +AX_CXX_TYPE_STD_LOCKGUARD dnl On Solaris 9 x86, gcc may includes a "fixed" set of old system include files dnl that is incompatible with the updated Solaris header files. dnl For this reason, we must check if pad128_t and upad128_t are defined. AC_CHECK_TYPE(pad128_t, AC_DEFINE(HAVE_PAD128_T,1,[pad128_t is defined in system headers]), ,SQUID_DEFAULT_INCLUDES) AC_CHECK_TYPE(upad128_t, AC_DEFINE(HAVE_UPAD128_T,1,[upad128_t is defined in system headers]), ,SQUID_DEFAULT_INCLUDES) AC_CHECK_TYPE(mode_t, AC_DEFINE(HAVE_MODE_T,1,[mode_t is defined by the system headers]),,SQUID_DEFAULT_INCLUDES) AC_CHECK_TYPE(fd_mask, AC_DEFINE(HAVE_FD_MASK,1,[fd_mask is defined by the system headers]),,SQUID_DEFAULT_INCLUDES) AC_CHECK_TYPE(socklen_t,AC_DEFINE(HAVE_SOCKLEN_T,1,[socklen_t is defined by the system headers]),,[ #include #include #if STDC_HEADERS #include === modified file 'src/Debug.h' --- src/Debug.h 2013-02-19 00:26:59 +0000 +++ src/Debug.h 2014-02-17 21:07:34 +0000 @@ -15,166 +15,152 @@ * sources; see the CREDITS file for full details. * * This program is free software; you can redistribute it and/or modify * it under the terms of the GNU General Public License as published by * the Free Software Foundation; either version 2 of the License, or * (at your option) any later version. * * This program is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License * along with this program; if not, write to the Free Software * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA. * */ #ifndef SQUID_DEBUG_H #define SQUID_DEBUG_H -#if HAVE_IOSTREAM #include -#endif - #undef assert -#if HAVE_SSTREAM #include -#endif -#if HAVE_IOMANIP #include -#endif #if defined(assert) #undef assert #endif #if PURIFY #define assert(EX) ((void)0) #elif defined(NODEBUG) #define assert(EX) ((void)0) #elif STDC_HEADERS #define assert(EX) ((EX)?((void)0):xassert( # EX , __FILE__, __LINE__)) #else #define assert(EX) ((EX)?((void)0):xassert("EX", __FILE__, __LINE__)) #endif -/* context-based debugging, the actual type is subject to change */ -typedef int Ctx; -Ctx ctx_enter(const char *descr); -void ctx_exit(Ctx ctx); - /* defined debug section limits */ #define MAX_DEBUG_SECTIONS 100 /* defined names for Debug Levels */ #define DBG_CRITICAL 0 /**< critical messages always shown when they occur */ #define DBG_IMPORTANT 1 /**< important messages always shown when their section is being checked */ /* levels 2-8 are still being discussed amongst the developers */ #define DBG_DATA 9 /**< output is a large data dump only necessary for advanced debugging */ #define DBG_PARSE_NOTE(x) (opt_parse_cfg_only?0:(x)) /**< output is always to be displayed on '-k parse' but at level-x normally. */ class Debug { public: static char *debugOptions; static char *cache_log; static int rotateNumber; static int Levels[MAX_DEBUG_SECTIONS]; static int level; ///< minimum debugging level required by debugs() call static int sectionLevel; ///< maximum debugging level allowed now static int override_X; static int log_stderr; static bool log_syslog; static std::ostream &getDebugOut(); - static void finishDebug(); static void parseOptions(char const *); + static void Init(const char *logfile, const char *options); + static void EnableSyslog(const char *facility); + static void LogRotate(); + static void Print(const std::string &); + private: // Hack: replaces global ::xassert() to debug debugging assertions static void xassert(const char *msg, const char *file, int line); static std::ostringstream *CurrentDebug; static int TheDepth; // level of nested debugging calls }; extern FILE *debug_log; -size_t BuildPrefixInit(); const char * SkipBuildPrefix(const char* path); +std::string LogLinePreamble(); /* Debug stream */ #define debugs(SECTION, LEVEL, CONTENT) \ do { \ if ((Debug::level = (LEVEL)) <= Debug::Levels[SECTION]) { \ Debug::sectionLevel = Debug::Levels[SECTION]; \ - std::ostream &_dbo=Debug::getDebugOut(); \ + std::ostringstream dbss; \ + dbss << LogLinePreamble(); \ if (Debug::level > DBG_IMPORTANT) \ - _dbo << SkipBuildPrefix(__FILE__)<<"("<<__LINE__<<") "<<__FUNCTION__<<": "; \ - _dbo << CONTENT; \ - Debug::finishDebug(); \ + dbss << SkipBuildPrefix(__FILE__)<<"("<<__LINE__<<") "<<__FUNCTION__<<": "; \ + dbss << CONTENT << std::endl; \ + Debug::Print(dbss.str()); \ } \ } while (/*CONSTCOND*/ 0) /** stream manipulator which does nothing. * \deprecated Do not add to new code, and remove when editing old code * * Its purpose is to inactivate calls made following previous debugs() * guidelines such as * debugs(1,2, HERE << "some message"); * * His former objective is now absorbed in the debugs call itself */ inline std::ostream& HERE(std::ostream& s) { return s; } /* * MYNAME is for use at debug levels 0 and 1 where HERE is too messy. * * debugs(1,1, MYNAME << "WARNING: some message"); */ #ifdef __PRETTY_FUNCTION__ #define MYNAME __PRETTY_FUNCTION__ << " " #else #define MYNAME __FUNCTION__ << " " #endif /* some uint8_t do not like streaming control-chars (values 0-31, 127+) */ inline std::ostream& operator <<(std::ostream &os, const uint8_t d) { return (os << (int)d); } /* Legacy debug style. Still used in some places. needs to die... */ #define do_debug(SECTION, LEVEL) ((Debug::level = (LEVEL)) <= Debug::Levels[SECTION]) -#define old_debug(SECTION, LEVEL) if do_debug((SECTION), (LEVEL)) _db_print - -/* Legacy debug function definitions */ -void _db_init(const char *logfile, const char *options); -void _db_print(const char *,...) PRINTF_FORMAT_ARG1; -void _db_set_syslog(const char *facility); -void _db_rotate_log(void); /// Prints raw and/or non-terminated data safely, efficiently, and beautifully. /// Allows raw data debugging in debugs() statements with low debugging levels /// by printing only if higher section debugging levels are configured: /// debugs(11, DBG_IMPORTANT, "always printed" << Raw(may be printed...)); class Raw { public: Raw(const char *label, const char *data, const size_t size): level(-1), label_(label), data_(data), size_(size) {} /// limit data printing to at least the given debugging level Raw &minLevel(const int aLevel) { level = aLevel; return *this; } /// If debugging is prohibited by the current debugs() or section level, /// prints nothing. Otherwise, dumps data using one of these formats: /// " label[size]=data" if label was set and data size is positive /// " label[0]" if label was set and data size is zero /// " data" if label was not set and data size is positive /// "" (i.e., prints nothing) if label was not set and data size is zero === modified file 'src/MemObject.cc' --- src/MemObject.cc 2013-12-31 18:49:41 +0000 +++ src/MemObject.cc 2014-02-17 19:30:07 +0000 @@ -113,70 +113,67 @@ MemObject::setUris(char const *aStoreId, #if URL_CHECKSUM_DEBUG chksum = url_checksum(urlXXX()); #endif } MemObject::MemObject(): smpCollapsed(false) { debugs(20, 3, HERE << "new MemObject " << this); _reply = new HttpReply; HTTPMSGLOCK(_reply); object_sz = -1; /* XXX account log_url */ swapout.decision = SwapOut::swNeedsCheck; } MemObject::~MemObject() { - debugs(20, 3, HERE << "del MemObject " << this); - const Ctx ctx = ctx_enter(hasUris() ? urlXXX() : "[unknown_ctx]"); + debugs(20, 3, "del MemObject " << this); #if URL_CHECKSUM_DEBUG checkUrlChecksum(); #endif if (!shutting_down) { // Store::Root() is FATALly missing during shutdown assert(xitTable.index < 0); assert(memCache.index < 0); assert(swapout.sio == NULL); } data_hdr.freeContent(); #if 0 /* * There is no way to abort FD-less clients, so they might * still have mem->clients set. */ assert(clients.head == NULL); #endif HTTPMSGUNLOCK(_reply); HTTPMSGUNLOCK(request); - ctx_exit(ctx); /* must exit before we free mem->url */ - safe_free(vary_headers); } void MemObject::unlinkRequest() { HTTPMSGUNLOCK(request); } void MemObject::write(const StoreIOBuffer &writeBuffer) { PROF_start(MemObject_write); debugs(19, 6, "memWrite: offset " << writeBuffer.offset << " len " << writeBuffer.length); /* We don't separate out mime headers yet, so ensure that the first * write is at offset 0 - where they start */ assert (data_hdr.endOffset() || writeBuffer.offset == 0); === modified file 'src/adaptation/ecap/Host.cc' --- src/adaptation/ecap/Host.cc 2014-02-08 13:36:42 +0000 +++ src/adaptation/ecap/Host.cc 2014-02-16 21:40:08 +0000 @@ -134,42 +134,40 @@ SquidLogLevel(libecap::LogVerbosity lv) return DBG_IMPORTANT; // is it a good idea to ignore other flags? return 2 + 2*lv.debugging() + 3*lv.operation() + 2*lv.xaction(); } std::ostream * Adaptation::Ecap::Host::openDebug(libecap::LogVerbosity lv) { const int squidLevel = SquidLogLevel(lv); const int squidSection = 93; // XXX: this should be a global constant // XXX: Debug.h should provide this to us if ((Debug::level = squidLevel) <= Debug::Levels[squidSection]) return &Debug::getDebugOut(); else return NULL; } void Adaptation::Ecap::Host::closeDebug(std::ostream *debug) { - if (debug) - Debug::finishDebug(); } Adaptation::Ecap::Host::MessagePtr Adaptation::Ecap::Host::newRequest() const { return MessagePtr(new Adaptation::Ecap::MessageRep(new HttpRequest)); } Adaptation::Ecap::Host::MessagePtr Adaptation::Ecap::Host::newResponse() const { return MessagePtr(new Adaptation::Ecap::MessageRep(new HttpReply)); } void Adaptation::Ecap::Host::Register() { if (!TheHost && SupportedVersion(libecap::VersionString(), "Squid executable dynamically linked")) { TheHost.reset(new Adaptation::Ecap::Host); === modified file 'src/base/Lock.h' --- src/base/Lock.h 2012-10-30 00:13:18 +0000 +++ src/base/Lock.h 2014-02-16 21:40:08 +0000 @@ -7,51 +7,51 @@ * * All locks must be cleared with unlock() before this object * is destroyed. * * Accessors provided by this interface are not private, * to allow class hierarchies. * * Build with -DLOCKCOUNT_DEBUG flag to enable lock debugging. * It is disabled by default due to the cost of debug output. */ class Lock { public: Lock():count_(0) {} virtual ~Lock() { assert(count_ == 0); } /// Register one lock / reference against this object. /// All locks must be cleared before it may be destroyed. void lock() const { -#if defined(LOCKCOUNT_DEBUG) - old_debug(0,1)("Incrementing this %p from count %u\n",this,count_); +#if LOCKCOUNT_DEBUG + debugs(0, 8, "Incrementing this " << reinterpret_cast(this) << "from count " << count_); #endif ++count_; } /// Clear one lock / reference against this object. /// All locks must be cleared before it may be destroyed. unsigned unlock() const { -#if defined(LOCKCOUNT_DEBUG) - old_debug(0,1)("Decrementing this %p from count %u\n",this,count_); +#if LOCKCOUNT_DEBUG + debugs(0, 8, "Decrementing this " << reinterpret_cast(this) << "from count " << count_); #endif assert(count_ > 0); return --count_; } /// Inspect the current count of references. unsigned LockCount() const { return count_; } private: mutable unsigned count_; ///< number of references currently being tracked }; // For clarity we provide some aliases for the tracking mechanisms // using Lock so that we can easily see what type of smart pointers // are to be used for the child object. // NP: CbcPointer<> and RefCount<> pointers should be used consistently // for any given child class type /// The locking interface for use on Reference-Counted classes #define RefCountable virtual Lock === modified file 'src/cache_cf.cc' --- src/cache_cf.cc 2014-02-10 16:39:10 +0000 +++ src/cache_cf.cc 2014-02-16 21:40:08 +0000 @@ -615,41 +615,41 @@ parseConfigFile(const char *file_name) ACLMethodData::ThePurgeCount = 0; default_all(); err_count = parseOneConfigFile(file_name, 0); defaults_if_none(); defaults_postscriptum(); /* * We must call configDoConfigure() before leave_suid() because * configDoConfigure() is where we turn username strings into * uid values. */ configDoConfigure(); if (!Config.chroot_dir) { leave_suid(); setUmask(Config.umask); - _db_init(Debug::cache_log, Debug::debugOptions); + Debug::Init(Debug::cache_log, Debug::debugOptions); enter_suid(); } if (opt_send_signal == -1) { Mgr::RegisterAction("config", "Current Squid Configuration", dump_config, 1, 1); } return err_count; } static void configDoConfigure(void) { memset(&Config2, '\0', sizeof(SquidConfig2)); /* init memory as early as possible */ memConfigure(); /* Sanity checks */ === modified file 'src/client_side.cc' --- src/client_side.cc 2014-02-10 13:55:54 +0000 +++ src/client_side.cc 2014-02-16 21:40:08 +0000 @@ -137,43 +137,42 @@ #endif #if USE_SSL #include "ssl/context_storage.h" #include "ssl/gadgets.h" #include "ssl/helper.h" #include "ssl/ProxyCerts.h" #include "ssl/ServerBump.h" #include "ssl/support.h" #endif #if USE_SSL_CRTD #include "ssl/certificate_db.h" #include "ssl/crtd_message.h" #endif #if HAVE_LIMITS_H #include #endif #if HAVE_MATH_H #include #endif -#if HAVE_LIMITS #include -#endif +#include #if LINGERING_CLOSE #define comm_close comm_lingering_close #endif /// dials clientListenerConnectionOpened call class ListeningStartedDialer: public CallDialer, public Ipc::StartListeningCb { public: typedef void (*Handler)(AnyP::PortCfg *portCfg, const Ipc::FdNoteId note, const Subscription::Pointer &sub); ListeningStartedDialer(Handler aHandler, AnyP::PortCfg *aPortCfg, const Ipc::FdNoteId note, const Subscription::Pointer &aSub): handler(aHandler), portCfg(aPortCfg), portTypeNote(note), sub(aSub) {} virtual void print(std::ostream &os) const { startPrint(os) << ", " << FdNote(portTypeNote) << " port=" << (void*)portCfg << ')'; } virtual bool canDial(AsyncCall &) const { return true; } virtual void dial(AsyncCall &) { (handler)(portCfg, portTypeNote, sub); } @@ -3446,40 +3445,58 @@ httpsCreate(const Comm::ConnectionPointe SSL *ssl = SSL_new(sslContext); if (!ssl) { const int ssl_error = ERR_get_error(); debugs(83, DBG_IMPORTANT, "ERROR: httpsAccept: Error allocating handle: " << ERR_error_string(ssl_error, NULL) ); conn->close(); return NULL; } SSL_set_fd(ssl, conn->fd); fd_table[conn->fd].ssl = ssl; fd_table[conn->fd].read_method = &ssl_read_method; fd_table[conn->fd].write_method = &ssl_write_method; debugs(33, 5, "httpsCreate: will negotate SSL on " << conn); fd_note(conn->fd, "client https start"); return ssl; } +/** + * Write out the SSL session details. + */ +static std::string +debugDisplaySslContext(SSL *ssl) +{ + // Actually the call below, but OpenSSL headers do strange typecasts confusing GCC.. + // PEM_write_SSL_SESSION(debug_log, SSL_get_session(ssl)); + +#if defined(OPENSSL_VERSION_NUMBER) && OPENSSL_VERSION_NUMBER >= 0x00908000L + PEM_ASN1_write((i2d_of_void *)i2d_SSL_SESSION, PEM_STRING_SSL_SESSION, debug_log, (char *)SSL_get_session(ssl), NULL,NULL,0,NULL,NULL); + fflush(debug_log); + return " "; // fake string for parent debugs() call. +#else + return "NOTICE: With " OPENSSL_VERSION_TEXT ", session details are not available."; +#endif +} + /** negotiate an SSL connection */ static void clientNegotiateSSL(int fd, void *data) { ConnStateData *conn = (ConnStateData *)data; X509 *client_cert; SSL *ssl = fd_table[fd].ssl; int ret; if ((ret = SSL_accept(ssl)) <= 0) { int ssl_error = SSL_get_error(ssl, ret); switch (ssl_error) { case SSL_ERROR_WANT_READ: Comm::SetSelect(fd, COMM_SELECT_READ, clientNegotiateSSL, conn, 0); return; case SSL_ERROR_WANT_WRITE: Comm::SetSelect(fd, COMM_SELECT_WRITE, clientNegotiateSSL, conn, 0); @@ -3508,66 +3525,41 @@ clientNegotiateSSL(int fd, void *data) case SSL_ERROR_ZERO_RETURN: debugs(83, DBG_IMPORTANT, "clientNegotiateSSL: Error negotiating SSL connection on FD " << fd << ": Closed by client"); comm_close(fd); return; default: debugs(83, DBG_IMPORTANT, "clientNegotiateSSL: Error negotiating SSL connection on FD " << fd << ": " << ERR_error_string(ERR_get_error(), NULL) << " (" << ssl_error << "/" << ret << ")"); comm_close(fd); return; } /* NOTREACHED */ } if (SSL_session_reused(ssl)) { debugs(83, 2, "clientNegotiateSSL: Session " << SSL_get_session(ssl) << " reused on FD " << fd << " (" << fd_table[fd].ipaddr << ":" << (int)fd_table[fd].remote_port << ")"); } else { - if (do_debug(83, 4)) { - /* Write out the SSL session details.. actually the call below, but - * OpenSSL headers do strange typecasts confusing GCC.. */ - /* PEM_write_SSL_SESSION(debug_log, SSL_get_session(ssl)); */ -#if defined(OPENSSL_VERSION_NUMBER) && OPENSSL_VERSION_NUMBER >= 0x00908000L - PEM_ASN1_write((i2d_of_void *)i2d_SSL_SESSION, PEM_STRING_SSL_SESSION, debug_log, (char *)SSL_get_session(ssl), NULL,NULL,0,NULL,NULL); - -#elif (ALLOW_ALWAYS_SSL_SESSION_DETAIL == 1) - - /* When using gcc 3.3.x and OpenSSL 0.9.7x sometimes a compile error can occur here. - * This is caused by an unpredicatble gcc behaviour on a cast of the first argument - * of PEM_ASN1_write(). For this reason this code section is disabled. To enable it, - * define ALLOW_ALWAYS_SSL_SESSION_DETAIL=1. - * Because there are two possible usable cast, if you get an error here, try the other - * commented line. */ - - PEM_ASN1_write((int(*)())i2d_SSL_SESSION, PEM_STRING_SSL_SESSION, debug_log, (char *)SSL_get_session(ssl), NULL,NULL,0,NULL,NULL); - /* PEM_ASN1_write((int(*)(...))i2d_SSL_SESSION, PEM_STRING_SSL_SESSION, debug_log, (char *)SSL_get_session(ssl), NULL,NULL,0,NULL,NULL); */ - -#else - - debugs(83, 4, "With " OPENSSL_VERSION_TEXT ", session details are available only defining ALLOW_ALWAYS_SSL_SESSION_DETAIL=1 in the source." ); - -#endif - /* Note: This does not automatically fflush the log file.. */ - } + debugs(83, 4, debugDisplaySslContext(ssl) << ""); debugs(83, 2, "clientNegotiateSSL: New session " << SSL_get_session(ssl) << " on FD " << fd << " (" << fd_table[fd].ipaddr << ":" << (int)fd_table[fd].remote_port << ")"); } debugs(83, 3, "clientNegotiateSSL: FD " << fd << " negotiated cipher " << SSL_get_cipher(ssl)); client_cert = SSL_get_peer_certificate(ssl); if (client_cert != NULL) { debugs(83, 3, "clientNegotiateSSL: FD " << fd << " client certificate: subject: " << X509_NAME_oneline(X509_get_subject_name(client_cert), 0, 0)); debugs(83, 3, "clientNegotiateSSL: FD " << fd << " client certificate: issuer: " << X509_NAME_oneline(X509_get_issuer_name(client_cert), 0, 0)); === modified file 'src/debug.cc' --- src/debug.cc 2013-10-25 00:13:46 +0000 +++ src/debug.cc 2014-02-17 19:50:00 +0000 @@ -14,196 +14,98 @@ * incorporates software developed and/or copyrighted by other * sources; see the CREDITS file for full details. * * This program is free software; you can redistribute it and/or modify * it under the terms of the GNU General Public License as published by * the Free Software Foundation; either version 2 of the License, or * (at your option) any later version. * * This program is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License * along with this program; if not, write to the Free Software * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA. * */ #include "squid.h" +#include "compat/mutex.h" #include "Debug.h" #include "ipc/Kids.h" #include "SquidTime.h" #include "util.h" /* for shutting_down flag in xassert() */ #include "globals.h" + char *Debug::debugOptions = NULL; int Debug::override_X = 0; int Debug::log_stderr = -1; bool Debug::log_syslog = false; int Debug::Levels[MAX_DEBUG_SECTIONS]; int Debug::level; int Debug::sectionLevel; char *Debug::cache_log = NULL; int Debug::rotateNumber = -1; FILE *debug_log = NULL; static char *debug_log_file = NULL; -static int Ctx_Lock = 0; +//static int Ctx_Lock = 0; static const char *debugLogTime(void); static const char *debugLogKid(void); -static void ctx_print(void); #if HAVE_SYSLOG #ifdef LOG_LOCAL4 static int syslog_facility = 0; #endif -static void _db_print_syslog(const char *format, va_list args); #endif -static void _db_print_stderr(const char *format, va_list args); -static void _db_print_file(const char *format, va_list args); -#if _SQUID_WINDOWS_ -extern LPCRITICAL_SECTION dbg_mutex; -typedef BOOL (WINAPI * PFInitializeCriticalSectionAndSpinCount) (LPCRITICAL_SECTION, DWORD); -#endif +static Mutex printlock; void -_db_print(const char *format,...) +Debug::Print(const std::string & logline) { - char f[BUFSIZ]; - f[0]='\0'; - va_list args1; - va_list args2; - va_list args3; - -#if _SQUID_WINDOWS_ - /* Multiple WIN32 threads may call this simultaneously */ - - if (!dbg_mutex) { - HMODULE krnl_lib = GetModuleHandle("Kernel32"); - PFInitializeCriticalSectionAndSpinCount InitializeCriticalSectionAndSpinCount = NULL; - - if (krnl_lib) - InitializeCriticalSectionAndSpinCount = - (PFInitializeCriticalSectionAndSpinCount) GetProcAddress(krnl_lib, - "InitializeCriticalSectionAndSpinCount"); - - dbg_mutex = static_cast(xcalloc(1, sizeof(CRITICAL_SECTION))); - - if (InitializeCriticalSectionAndSpinCount) { - /* let multiprocessor systems EnterCriticalSection() fast */ - - if (!InitializeCriticalSectionAndSpinCount(dbg_mutex, 4000)) { - if (debug_log) { - fprintf(debug_log, "FATAL: _db_print: can't initialize critical section\n"); - fflush(debug_log); - } - - fprintf(stderr, "FATAL: _db_print: can't initialize critical section\n"); - abort(); - } else - InitializeCriticalSection(dbg_mutex); - } + // temporary note: the API here is different than for old version: + // we expect the preamble to be part of the passed string to increase + // efficiency. + printlock.lock(); + + //log to file if defined + if (debug_log) { + fwrite(logline.data(),logline.size(),1,debug_log); + fflush(debug_log); + } + // log to stderr if configured + if (Debug::log_stderr >= Debug::level && debug_log != stderr) { + fwrite(logline.data(),logline.size(),1,stderr); } - - EnterCriticalSection(dbg_mutex); -#endif - - /* give a chance to context-based debugging to print current context */ - if (!Ctx_Lock) - ctx_print(); - - va_start(args1, format); - va_start(args2, format); - va_start(args3, format); - - snprintf(f, BUFSIZ, "%s%s| %s", - debugLogTime(), - debugLogKid(), - format); - - _db_print_file(f, args1); - _db_print_stderr(f, args2); - + // possibly log to syslog #if HAVE_SYSLOG - _db_print_syslog(format, args3); -#endif - -#if _SQUID_WINDOWS_ - LeaveCriticalSection(dbg_mutex); -#endif - - va_end(args1); - va_end(args2); - va_end(args3); -} - -static void -_db_print_file(const char *format, va_list args) -{ - if (debug_log == NULL) - return; - - /* give a chance to context-based debugging to print current context */ - if (!Ctx_Lock) - ctx_print(); - - vfprintf(debug_log, format, args); - fflush(debug_log); -} - -static void -_db_print_stderr(const char *format, va_list args) -{ - if (Debug::log_stderr < Debug::level) - return; - - if (debug_log == stderr) - return; - - vfprintf(stderr, format, args); -} - -#if HAVE_SYSLOG -static void -_db_print_syslog(const char *format, va_list args) -{ - /* level 0,1 go to syslog */ - - if (Debug::level > 1) - return; - - if (!Debug::log_syslog) - return; - - char tmpbuf[BUFSIZ]; - tmpbuf[0] = '\0'; - - vsnprintf(tmpbuf, BUFSIZ, format, args); - - tmpbuf[BUFSIZ - 1] = '\0'; - - syslog(Debug::level == 0 ? LOG_WARNING : LOG_NOTICE, "%s", tmpbuf); -} + if (Debug::level <= DBG_IMPORTANT && // hardcoded: only important levels go to syslog + Debug::log_syslog) { + syslog(Debug::level == 0 ? LOG_WARNING : LOG_NOTICE, "%s", logline.c_str()); + } #endif /* HAVE_SYSLOG */ + printlock.unlock(); +} static void debugArg(const char *arg) { int s = 0; int l = 0; int i; if (!strncasecmp(arg, "rotate=", 7)) { arg += 7; Debug::rotateNumber = atoi(arg); return; } else if (!strncasecmp(arg, "ALL", 3)) { s = -1; arg += 4; } else { s = atoi(arg); while (*arg && *arg++ != ','); } @@ -360,41 +262,41 @@ syslog_facility_names[] = { }, #endif #ifdef LOG_LOCAL6 { "local6", LOG_LOCAL6 }, #endif #ifdef LOG_LOCAL7 { "local7", LOG_LOCAL7 }, #endif { NULL, 0 } }; #endif void -_db_set_syslog(const char *facility) +Debug::EnableSyslog(const char *facility) { Debug::log_syslog = true; #ifdef LOG_LOCAL4 #ifdef LOG_DAEMON syslog_facility = LOG_DAEMON; #else syslog_facility = LOG_LOCAL4; #endif /* LOG_DAEMON */ if (facility) { struct syslog_facility_name *n; for (n = syslog_facility_names; n->name; ++n) { if (strcmp(n->name, facility) == 0) { syslog_facility = n->facility; return; @@ -423,107 +325,105 @@ Debug::parseOptions(char const *options) if (override_X) { debugs(0, 9, "command-line -X overrides: " << options); return; } for (i = 0; i < MAX_DEBUG_SECTIONS; ++i) Debug::Levels[i] = 0; if (options) { p = xstrdup(options); for (s = strtok(p, w_space); s; s = strtok(NULL, w_space)) debugArg(s); xfree(p); } } void -_db_init(const char *logfile, const char *options) +Debug::Init(const char *logfile, const char *options) { Debug::parseOptions(options); debugOpenLog(logfile); #if HAVE_SYSLOG && defined(LOG_LOCAL4) if (Debug::log_syslog) openlog(APP_SHORTNAME, LOG_PID | LOG_NDELAY | LOG_CONS, syslog_facility); #endif /* HAVE_SYSLOG */ /* Pre-Init TZ env, see bug #2656 */ tzset(); } void -_db_rotate_log(void) +Debug::LogRotate() { if (debug_log_file == NULL) return; #ifdef S_ISREG struct stat sb; if (stat(debug_log_file, &sb) == 0) if (S_ISREG(sb.st_mode) == 0) return; #endif char from[MAXPATHLEN]; from[0] = '\0'; char to[MAXPATHLEN]; to[0] = '\0'; /* * NOTE: we cannot use xrename here without having it in a * separate file -- tools.c has too many dependencies to be * used everywhere debug.c is used. */ /* Rotate numbers 0 through N up one */ for (int i = Debug::rotateNumber; i > 1;) { --i; snprintf(from, MAXPATHLEN, "%s.%d", debug_log_file, i - 1); snprintf(to, MAXPATHLEN, "%s.%d", debug_log_file, i); #if _SQUID_WINDOWS_ - remove - (to); + remove(to); #endif rename(from, to); } /* * You can't rename open files on Microsoft "operating systems" * so we close before renaming. */ #if _SQUID_WINDOWS_ if (debug_log != stderr) fclose(debug_log); #endif /* Rotate the current log to .0 */ if (Debug::rotateNumber > 0) { snprintf(to, MAXPATHLEN, "%s.%d", debug_log_file, 0); #if _SQUID_WINDOWS_ - remove - (to); + remove(to); #endif rename(debug_log_file, to); } /* Close and reopen the log. It may have been renamed "manually" * before HUP'ing us. */ if (debug_log != stderr) debugOpenLog(Debug::cache_log); } static const char * debugLogTime(void) { time_t t = getCurrentTime(); struct tm *tm; static char buf[128]; static time_t last_t = 0; @@ -549,255 +449,76 @@ debugLogKid(void) { if (KidIdentifier != 0) { static char buf[16]; if (!*buf) // optimization: fill only once after KidIdentifier is set snprintf(buf, sizeof(buf), " kid%d", KidIdentifier); return buf; } return ""; } void xassert(const char *msg, const char *file, int line) { debugs(0, DBG_CRITICAL, "assertion failed: " << file << ":" << line << ": \"" << msg << "\""); if (!shutting_down) abort(); } -/* - * Context-based Debugging - * - * Rationale - * --------- - * - * When you have a long nested processing sequence, it is often impossible - * for low level routines to know in what larger context they operate. If a - * routine coredumps, one can restore the context using debugger trace. - * However, in many case you do not want to coredump, but just want to report - * a potential problem. A report maybe useless out of problem context. - * - * To solve this potential problem, use the following approach: - * - * int - * top_level_foo(const char *url) - * { - * // define current context - * // note: we stack but do not dup ctx descriptions! - * Ctx ctx = ctx_enter(url); - * ... - * // go down; middle_level_bar will eventually call bottom_level_boo - * middle_level_bar(method, protocol); - * ... - * // exit, clean after yourself - * ctx_exit(ctx); - * } - * - * void - * bottom_level_boo(int status, void *data) - * { - * // detect exceptional condition, and simply report it, the context - * // information will be available somewhere close in the log file - * if (status == STRANGE_STATUS) - * debugs(13, 6, "DOS attack detected, data: " << data); - * ... - * } - * - * Current implementation is extremely simple but still very handy. It has a - * negligible overhead (descriptions are not duplicated). - * - * When the _first_ debug message for a given context is printed, it is - * prepended with the current context description. Context is printed with - * the same debugging level as the original message. - * - * Note that we do not print context every type you do ctx_enter(). This - * approach would produce too many useless messages. For the same reason, a - * context description is printed at most _once_ even if you have 10 - * debugging messages within one context. - * - * Contexts can be nested, of course. You must use ctx_enter() to enter a - * context (push it onto stack). It is probably safe to exit several nested - * contexts at _once_ by calling ctx_exit() at the top level (this will pop - * all context till current one). However, as in any stack, you cannot start - * in the middle. - * - * Analysis: - * i) locate debugging message, - * ii) locate current context by going _upstream_ in your log file, - * iii) hack away. - * - * - * To-Do: - * ----- - * - * decide if we want to dup() descriptions (adds overhead) but allows to - * add printf()-style interface - * - * implementation: - * --------------- - * - * descriptions for contexts over CTX_MAX_LEVEL limit are ignored, you probably - * have a bug if your nesting goes that deep. - */ - -#define CTX_MAX_LEVEL 255 - -/* - * produce a warning when nesting reaches this level and then double - * the level - */ -static int Ctx_Warn_Level = 32; -/* all descriptions has been printed up to this level */ -static int Ctx_Reported_Level = -1; -/* descriptions are still valid or active up to this level */ -static int Ctx_Valid_Level = -1; -/* current level, the number of nested ctx_enter() calls */ -static int Ctx_Current_Level = -1; -/* saved descriptions (stack) */ -static const char *Ctx_Descrs[CTX_MAX_LEVEL + 1]; -/* "safe" get secription */ -static const char *ctx_get_descr(Ctx ctx); - -Ctx -ctx_enter(const char *descr) -{ - ++Ctx_Current_Level; - - if (Ctx_Current_Level <= CTX_MAX_LEVEL) - Ctx_Descrs[Ctx_Current_Level] = descr; - - if (Ctx_Current_Level == Ctx_Warn_Level) { - debugs(0, DBG_CRITICAL, "# ctx: suspiciously deep (" << Ctx_Warn_Level << ") nesting:"); - Ctx_Warn_Level *= 2; - } - - return Ctx_Current_Level; -} - -void -ctx_exit(Ctx ctx) -{ - assert(ctx >= 0); - Ctx_Current_Level = (ctx >= 0) ? ctx - 1 : -1; - - if (Ctx_Valid_Level > Ctx_Current_Level) - Ctx_Valid_Level = Ctx_Current_Level; -} - -/* - * the idea id to print each context description at most once but provide enough - * info for deducing the current execution stack - */ -static void -ctx_print(void) -{ - /* lock so _db_print will not call us recursively */ - ++Ctx_Lock; - /* ok, user saw [0,Ctx_Reported_Level] descriptions */ - /* first inform about entries popped since user saw them */ - - if (Ctx_Valid_Level < Ctx_Reported_Level) { - if (Ctx_Reported_Level != Ctx_Valid_Level + 1) - _db_print("ctx: exit levels from %2d down to %2d\n", - Ctx_Reported_Level, Ctx_Valid_Level + 1); - else - _db_print("ctx: exit level %2d\n", Ctx_Reported_Level); - - Ctx_Reported_Level = Ctx_Valid_Level; - } - - /* report new contexts that were pushed since last report */ - while (Ctx_Reported_Level < Ctx_Current_Level) { - ++Ctx_Reported_Level; - ++Ctx_Valid_Level; - _db_print("ctx: enter level %2d: '%s'\n", Ctx_Reported_Level, - ctx_get_descr(Ctx_Reported_Level)); - } - - /* unlock */ - --Ctx_Lock; -} - -/* checks for nulls and overflows */ -static const char * -ctx_get_descr(Ctx ctx) -{ - if (ctx < 0 || ctx > CTX_MAX_LEVEL) - return ""; - - return Ctx_Descrs[ctx] ? Ctx_Descrs[ctx] : ""; -} - int Debug::TheDepth = 0; std::ostream & Debug::getDebugOut() { assert(TheDepth >= 0); ++TheDepth; if (TheDepth > 1) { assert(CurrentDebug); *CurrentDebug << std::endl << "reentrant debuging " << TheDepth << "-{"; } else { assert(!CurrentDebug); CurrentDebug = new std::ostringstream(); // set default formatting flags CurrentDebug->setf(std::ios::fixed); CurrentDebug->precision(2); } return *CurrentDebug; } -void -Debug::finishDebug() -{ - assert(TheDepth >= 0); - assert(CurrentDebug); - if (TheDepth > 1) { - *CurrentDebug << "}-" << TheDepth << std::endl; - } else { - assert(TheDepth == 1); - _db_print("%s\n", CurrentDebug->str().c_str()); - delete CurrentDebug; - CurrentDebug = NULL; - } - --TheDepth; -} - // Hack: replaces global ::xassert() to debug debugging assertions // Relies on assert macro calling xassert() without a specific scope. void Debug::xassert(const char *msg, const char *file, int line) { if (CurrentDebug) { *CurrentDebug << "assertion failed: " << file << ":" << line << ": \"" << msg << "\""; } abort(); } std::ostringstream (*Debug::CurrentDebug)(NULL); -size_t +static size_t BuildPrefixInit() { // XXX: This must be kept in sync with the actual debug.cc location const char *ThisFileNameTail = "src/debug.cc"; const char *file=__FILE__; // Disable heuristic if it does not work. if (!strstr(file, ThisFileNameTail)) return 0; return strlen(file)-strlen(ThisFileNameTail); } const char* SkipBuildPrefix(const char* path) { static const size_t BuildPrefixLength = BuildPrefixInit(); return path+BuildPrefixLength; @@ -808,20 +529,29 @@ Raw::print(std::ostream &os) const { if (label_) os << ' ' << label_ << '[' << size_ << ']'; if (!size_) return os; // finalize debugging level if no level was set explicitly via minLevel() const int finalLevel = (level >= 0) ? level : (size_ > 40 ? DBG_DATA : Debug::sectionLevel); if (finalLevel <= Debug::sectionLevel) { os << (label_ ? '=' : ' '); if (data_) os.write(data_, size_); else os << "[null]"; } return os; } + +std::string +LogLinePreamble() +{ + std::string rv(debugLogTime()); + rv.append(debugLogKid()); + rv.append("| "); + return rv; +} === modified file 'src/esi/Expression.cc' --- src/esi/Expression.cc 2012-11-19 11:29:31 +0000 +++ src/esi/Expression.cc 2014-02-16 21:40:08 +0000 @@ -26,40 +26,42 @@ * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License * along with this program; if not, write to the Free Software * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA. * */ #include "squid.h" #include "Debug.h" #include "esi/Expression.h" #include "profiler/Profiler.h" #if HAVE_MATH_H #include #endif #if HAVE_ERRNO_H #include #endif +#include + /* stack precedence rules: * before pushing an operator onto the stack, the * top 2 elements are checked. if either has a higher * or equal precedence than the current operator, they * are evaluated. * Start of expression has 5 precedence, * end of expression has 0 precedence * literal has 1 as does expression results * | has 2 * & has 3 * ! has 4 * == != < > <= >= has 5 * ( has 5 * ) has 0 */ typedef struct _stackmember stackmember; typedef int evaluate(stackmember * stack, int *depth, int whereAmI, stackmember * candidate); @@ -126,42 +128,42 @@ stackpop(stackmember * s, int *depth) static evaluate evalnegate; static evaluate evalliteral; static evaluate evalor; static evaluate evaland; static evaluate evallesseq; static evaluate evallessthan; static evaluate evalmoreeq; static evaluate evalmorethan; static evaluate evalequals; static evaluate evalnotequals; static evaluate evalstartexpr; static evaluate evalendexpr; static evaluate evalexpr; static void dumpstack(stackmember * stack, int depth); static int addmember(stackmember * stack, int *stackdepth, stackmember * candidate); static int membercompare(stackmember a, stackmember b); static char const *trim(char const *s); static stackmember getsymbol(const char *s, char const **endptr); -static void printliteral(stackmember s); -static void printmember(stackmember s); +static void printliteral(stackmember s, std::ostringstream &output); +static void printmember(stackmember s, std::ostringstream &output); /* -2 = failed to compate * -1 = a less than b * 0 = a equal b * 2 - a more than b */ int membercompare(stackmember a, stackmember b) { /* we can compare: sub expressions to sub expressions , * literals to literals */ if (!((a.valuetype == ESI_EXPR_LITERAL && b.valuetype == ESI_EXPR_LITERAL && a.valuestored != ESI_LITERAL_INVALID && b.valuestored != ESI_LITERAL_INVALID) || (a.valuetype == ESI_EXPR_EXPR && b.valuetype == ESI_EXPR_EXPR))) return -2; if (a.valuetype == ESI_EXPR_EXPR) { if (a.value.integral == b.value.integral) @@ -857,138 +859,139 @@ getsymbol(const char *s, char const **en rv.value.integral = 0; rv.precedence = 1; rv.eval = evalexpr; } else if (!strncmp(s, "true", 4)) { debugs(86, 5, "getsymbol: found variable result 'true'"); *endptr = s + 4; rv.valuetype = ESI_EXPR_EXPR; rv.valuestored = ESI_LITERAL_BOOL; rv.value.integral = 1; rv.precedence = 1; rv.eval = evalexpr; } else { debugs(86, DBG_IMPORTANT, "invalid expr '" << s << "'"); *endptr = origs; } return rv; } void -printliteral(stackmember s) +printliteral(stackmember s, std::ostringstream &output) { switch (s.valuestored) { case ESI_LITERAL_INVALID: - old_debug(86, 1)( " Invalid " ); + output << " Invalid "; break; case ESI_LITERAL_FLOAT: - old_debug(86,1)("%f", s.value.floating); + output << s.value.floating; break; case ESI_LITERAL_STRING: - old_debug(86,1)("'%s'", s.value.string); + output << '"' << s.value.string << '"'; break; case ESI_LITERAL_INT: - old_debug(86,1)("%d", s.value.integral); + output << s.value.integral; break; case ESI_LITERAL_BOOL: - old_debug(86,1)("%s",s.value.integral ? "true" : "false"); + output << (s.value.integral ? "true" : "false"); } } void -printmember(stackmember s) +printmember(stackmember s, std::ostringstream & output) { switch (s.valuetype) { case ESI_EXPR_INVALID: - old_debug(86,1)(" Invalid "); + output << " Invalid "; break; case ESI_EXPR_LITERAL: - printliteral(s); + printliteral(s, output); break; case ESI_EXPR_EXPR: - old_debug(86,1)("%s", s.value.integral ? "true" : "false"); + output << (s.value.integral ? "true" : "false"); break; case ESI_EXPR_OR: - old_debug(86,1)("|"); + output << "|"; break; case ESI_EXPR_AND: - old_debug(86,1)("&"); + output << "&"; break; case ESI_EXPR_NOT: - old_debug(86,1)("!"); + output << "!"; break; case ESI_EXPR_START: - old_debug(86,1)("("); + output << "("; break; case ESI_EXPR_END: - old_debug(86,1)(")"); + output << ")"; break; case ESI_EXPR_EQ: - old_debug(86,1)("=="); + output << "=="; break; case ESI_EXPR_NOTEQ: - old_debug(86,1)("!="); + output << "!="; break; case ESI_EXPR_LESS: - old_debug(86,1)("<"); + output << "<"; break; case ESI_EXPR_LESSEQ: - old_debug(86,1)("<="); + output << "<="; break; case ESI_EXPR_MORE: - old_debug(86,1)(">"); + output << ">"; break; case ESI_EXPR_MOREEQ: - old_debug(86,1)(">="); + output << ">="; break; } } void dumpstack(stackmember * stack, int depth) { int i; + std::ostringstream output; for (i = 0; i < depth; ++i) - printmember(stack[i]); + printmember(stack[i],output); if (depth) - old_debug(86,1)("\n"); + debugs(86, DBG_IMPORTANT, output); } int addmember(stackmember * stack, int *stackdepth, stackmember * candidate) { if (candidate->valuetype != ESI_EXPR_LITERAL && *stackdepth > 1) { /* !(!(a==b))) is why thats safe */ /* strictly less than until we unwind */ if (candidate->precedence < stack[*stackdepth - 1].precedence || candidate->precedence < stack[*stackdepth - 2].precedence) { /* must be an operator */ if (stack[*stackdepth - 2].valuetype == ESI_EXPR_LITERAL || stack[*stackdepth - 2].valuetype == ESI_EXPR_INVALID || stack[*stackdepth - 2].eval(stack, stackdepth, *stackdepth - 2, candidate)) { /* cleanup candidate and stack */ dumpstack(stack, *stackdepth); cleanmember(candidate); === modified file 'src/http.cc' --- src/http.cc 2013-12-06 23:52:26 +0000 +++ src/http.cc 2014-02-17 19:30:07 +0000 @@ -691,123 +691,114 @@ HttpStateData::checkDateSkew(HttpReply * { if (reply->date > -1 && !_peer) { int skew = abs((int)(reply->date - squid_curtime)); if (skew > 86400) debugs(11, 3, "" << request->GetHost() << "'s clock is skewed by " << skew << " seconds!"); } } /** * This creates the error page itself.. its likely * that the forward ported reply header max size patch * generates non http conformant error pages - in which * case the errors where should be 'BAD_GATEWAY' etc */ void HttpStateData::processReplyHeader() { /** Creates a blank header. If this routine is made incremental, this will not do */ - /* NP: all exit points to this function MUST call ctx_exit(ctx) */ - Ctx ctx = ctx_enter(entry->mem_obj->urlXXX()); - debugs(11, 3, "processReplyHeader: key '" << entry->getMD5Text() << "'"); assert(!flags.headers_parsed); if (!readBuf->hasContent()) { - ctx_exit(ctx); return; } Http::StatusCode error = Http::scNone; HttpReply *newrep = new HttpReply; const bool parsed = newrep->parse(readBuf, eof, &error); if (!parsed && readBuf->contentSize() > 5 && strncmp(readBuf->content(), "HTTP/", 5) != 0 && strncmp(readBuf->content(), "ICY", 3) != 0) { MemBuf *mb; HttpReply *tmprep = new HttpReply; tmprep->setHeaders(Http::scOkay, "Gatewaying", NULL, -1, -1, -1); tmprep->header.putExt("X-Transformed-From", "HTTP/0.9"); mb = tmprep->pack(); newrep->parse(mb, eof, &error); delete mb; delete tmprep; } else { if (!parsed && error > 0) { // unrecoverable parsing error debugs(11, 3, "processReplyHeader: Non-HTTP-compliant header: '" << readBuf->content() << "'"); flags.headers_parsed = true; // XXX: when sanityCheck is gone and Http::StatusLine is used to parse, // the sline should be already set the appropriate values during that parser stage newrep->sline.set(Http::ProtocolVersion(1,1), error); HttpReply *vrep = setVirginReply(newrep); entry->replaceHttpReply(vrep); - ctx_exit(ctx); return; } if (!parsed) { // need more data assert(!error); assert(!eof); delete newrep; - ctx_exit(ctx); return; } debugs(11, 2, "HTTP Server " << serverConnection); debugs(11, 2, "HTTP Server REPLY:\n---------\n" << readBuf->content() << "\n----------"); header_bytes_read = headersEnd(readBuf->content(), readBuf->contentSize()); readBuf->consume(header_bytes_read); } newrep->removeStaleWarnings(); if (newrep->sline.protocol == AnyP::PROTO_HTTP && newrep->sline.status() >= 100 && newrep->sline.status() < 200) { handle1xx(newrep); - ctx_exit(ctx); return; } flags.chunked = false; if (newrep->sline.protocol == AnyP::PROTO_HTTP && newrep->header.chunked()) { flags.chunked = true; httpChunkDecoder = new ChunkedCodingParser; } if (!peerSupportsConnectionPinning()) request->flags.connectionAuthDisabled = true; HttpReply *vrep = setVirginReply(newrep); flags.headers_parsed = true; keepaliveAccounting(vrep); checkDateSkew(vrep); processSurrogateControl (vrep); request->hier.peer_reply_status = newrep->sline.status(); - - ctx_exit(ctx); } /// ignore or start forwarding the 1xx response (a.k.a., control message) void HttpStateData::handle1xx(HttpReply *reply) { HttpReply::Pointer msg(reply); // will destroy reply if unused // one 1xx at a time: we must not be called while waiting for previous 1xx Must(!flags.handling1xx); flags.handling1xx = true; if (!request->canHandle1xx()) { debugs(11, 2, HERE << "ignoring client-unsupported 1xx"); proceedAfter1xx(); return; } #if USE_HTTP_VIOLATIONS // check whether the 1xx response forwarding is allowed by squid.conf @@ -902,41 +893,40 @@ bool HttpStateData::peerSupportsConnecti reply and has in its list the "Session-Based-Authentication" which means that the peer supports connection pinning. */ if (!hdr->has(HDR_PROXY_SUPPORT)) return false; header = hdr->getStrOrList(HDR_PROXY_SUPPORT); /* XXX This ought to be done in a case-insensitive manner */ rc = (strstr(header.termedBuf(), "Session-Based-Authentication") != NULL); return rc; } // Called when we parsed (and possibly adapted) the headers but // had not starting storing (a.k.a., sending) the body yet. void HttpStateData::haveParsedReplyHeaders() { ServerStateData::haveParsedReplyHeaders(); - Ctx ctx = ctx_enter(entry->mem_obj->urlXXX()); HttpReply *rep = finalReply(); entry->timestampsSet(); /* Check if object is cacheable or not based on reply code */ debugs(11, 3, "HTTP CODE: " << rep->sline.status()); if (neighbors_do_private_keys) httpMaybeRemovePublic(entry, rep->sline.status()); if (rep->header.has(HDR_VARY) #if X_ACCELERATOR_VARY || rep->header.has(HDR_X_ACCELERATOR_VARY) #endif ) { const char *vary = httpMakeVaryMark(request, rep); if (!vary) { entry->makePrivate(); if (!fwd->reforwardableStatus(rep->sline.status())) @@ -1003,42 +993,40 @@ no_cache: if (ccMustRevalidate || ccNoCacheNoParams || ccSMaxAge || ccPrivate) EBIT_SET(entry->flags, ENTRY_REVALIDATE); } #if USE_HTTP_VIOLATIONS // response header Pragma::no-cache is undefined in HTTP else { // Expensive calculation. So only do it IF the CC: header is not present. /* HACK: Pragma: no-cache in _replies_ is not documented in HTTP, * but servers like "Active Imaging Webcast/2.0" sure do use it */ if (rep->header.has(HDR_PRAGMA) && rep->header.hasListMember(HDR_PRAGMA,"no-cache",',')) EBIT_SET(entry->flags, ENTRY_REVALIDATE); } #endif } #if HEADERS_LOG headersLog(1, 0, request->method, rep); #endif - - ctx_exit(ctx); } HttpStateData::ConnectionStatus HttpStateData::statusIfComplete() const { const HttpReply *rep = virginReply(); /** \par * If the reply wants to close the connection, it takes precedence */ if (httpHeaderHasConnDir(&rep->header, "close")) return COMPLETE_NONPERSISTENT_MSG; /** \par * If we didn't send a keep-alive request header, then this * can not be a persistent connection. */ if (!flags.keepalive) return COMPLETE_NONPERSISTENT_MSG; /** \par === modified file 'src/icmp/pinger.cc' --- src/icmp/pinger.cc 2013-01-28 06:20:02 +0000 +++ src/icmp/pinger.cc 2014-02-16 21:40:08 +0000 @@ -134,41 +134,41 @@ main(int argc, char *argv[]) char *t; time_t last_check_time = 0; /* * cevans - do this first. It grabs a raw socket. After this we can * drop privs */ int icmp4_worker = -1; int icmp6_worker = -1; int squid_link = -1; /** start by initializing the pinger debug cache.log-pinger. */ if ((t = getenv("SQUID_DEBUG"))) debug_args = xstrdup(t); getCurrentTime(); // determine IPv4 or IPv6 capabilities before using sockets. Ip::ProbeTransport(); - _db_init(NULL, debug_args); + Debug::Init(NULL, debug_args); debugs(42, DBG_CRITICAL, "pinger: Initialising ICMP pinger ..."); icmp4_worker = icmp4.Open(); if (icmp4_worker < 0) { debugs(42, DBG_CRITICAL, "pinger: Unable to start ICMP pinger."); } max_fd = max(max_fd, icmp4_worker); #if USE_IPV6 icmp6_worker = icmp6.Open(); if (icmp6_worker <0 ) { debugs(42, DBG_CRITICAL, "pinger: Unable to start ICMPv6 pinger."); } max_fd = max(max_fd, icmp6_worker); #endif /** abort if neither worker could open a socket. */ if (icmp4_worker < 0 && icmp6_worker < 0) { debugs(42, DBG_CRITICAL, "FATAL: pinger: Unable to open any ICMP sockets."); === modified file 'src/main.cc' --- src/main.cc 2014-01-24 01:57:15 +0000 +++ src/main.cc 2014-02-16 21:40:08 +0000 @@ -524,41 +524,41 @@ mainParseOptions(int argc, char *argv[]) /** \par r * Set global option opt_remove_service (to TRUE) */ opt_remove_service = TRUE; break; #endif case 'l': /** \par l * Stores the syslog facility name in global opt_syslog_facility * then performs actions for -s option. */ xfree(opt_syslog_facility); // ignore any previous options sent opt_syslog_facility = xstrdup(optarg); case 's': /** \par s * Initialize the syslog for output */ #if HAVE_SYSLOG - _db_set_syslog(opt_syslog_facility); + Debug::EnableSyslog(opt_syslog_facility); break; #else fatal("Logging to syslog not available on this platform"); /* NOTREACHED */ #endif case 'u': /** \par u * Store the ICP port number given in global option icpPortNumOverride * ensuring its a positive number. */ icpPortNumOverride = atoi(optarg); if (icpPortNumOverride < 0) icpPortNumOverride = 0; break; @@ -794,41 +794,41 @@ mainReconfigureFinish(void *) // parse the config returns a count of errors encountered. const int oldWorkers = Config.workers; if ( parseConfigFile(ConfigFile) != 0) { // for now any errors are a fatal condition... self_destruct(); } if (oldWorkers != Config.workers) { debugs(1, DBG_CRITICAL, "WARNING: Changing 'workers' (from " << oldWorkers << " to " << Config.workers << ") requires a full restart. It has been ignored by reconfigure."); Config.workers = oldWorkers; } if (IamPrimaryProcess()) CpuAffinityCheck(); CpuAffinityReconfigure(); setUmask(Config.umask); Mem::Report(); setEffectiveUser(); - _db_init(Debug::cache_log, Debug::debugOptions); + Debug::Init(Debug::cache_log, Debug::debugOptions); ipcache_restart(); /* clear stuck entries */ fqdncache_restart(); /* sigh, fqdncache too */ parseEtcHosts(); errorInitialize(); /* reload error pages */ accessLogInit(); #if USE_LOADABLE_MODULES LoadableModulesConfigure(Config.loadable_module_names); #endif #if USE_ADAPTATION bool enableAdaptation = false; #if ICAP_CLIENT Adaptation::Icap::TheConfig.finalize(); enableAdaptation = Adaptation::Icap::TheConfig.onoff || enableAdaptation; #endif #if USE_ECAP Adaptation::Ecap::TheConfig.finalize(); // must be after we load modules enableAdaptation = Adaptation::Ecap::TheConfig.onoff || enableAdaptation; #endif @@ -886,41 +886,41 @@ mainReconfigureFinish(void *) } else { if (eventFind(start_announce, NULL)) eventDelete(start_announce, NULL); } writePidFile(); /* write PID file */ reconfiguring = 0; } static void mainRotate(void) { icmpEngine.Close(); redirectShutdown(); #if USE_AUTH authenticateRotate(); #endif externalAclShutdown(); - _db_rotate_log(); /* cache.log */ + Debug::LogRotate(); /* cache.log */ storeDirWriteCleanLogs(1); storeLogRotate(); /* store.log */ accessLogRotate(); /* access.log */ #if ICAP_CLIENT icapLogRotate(); /*icap.log*/ #endif icmpEngine.Open(); redirectInit(); #if USE_AUTH authenticateInit(&Auth::TheConfig); #endif externalAclInit(); } static void setEffectiveUser(void) { keepCapabilities(); leave_suid(); /* Run as non privilegied user */ #if _SQUID_OS2_ @@ -982,41 +982,41 @@ mainSetCwd(void) static void mainInitialize(void) { /* chroot if configured to run inside chroot */ mainSetCwd(); if (opt_catch_signals) { squid_signal(SIGSEGV, death, SA_NODEFER | SA_RESETHAND); squid_signal(SIGBUS, death, SA_NODEFER | SA_RESETHAND); } squid_signal(SIGPIPE, SIG_IGN, SA_RESTART); squid_signal(SIGCHLD, sig_child, SA_NODEFER | SA_RESTART); setEffectiveUser(); if (icpPortNumOverride != 1) Config.Port.icp = (unsigned short) icpPortNumOverride; - _db_init(Debug::cache_log, Debug::debugOptions); + Debug::Init(Debug::cache_log, Debug::debugOptions); fd_open(fileno(debug_log), FD_LOG, Debug::cache_log); #if MEM_GEN_TRACE log_trace_init("/tmp/squid.alloc"); #endif debugs(1, DBG_CRITICAL, "Starting Squid Cache version " << version_string << " for " << CONFIG_HOST_TYPE << "..."); debugs(1, DBG_CRITICAL, "Service Name: " << service_name); #if _SQUID_WINDOWS_ if (WIN32_run_mode == _WIN_SQUID_RUN_MODE_SERVICE) { debugs(1, DBG_CRITICAL, "Service command line is: " << WIN32_Service_Command_Line); } else debugs(1, DBG_CRITICAL, "Running on " << WIN32_OS_string); #endif debugs(1, DBG_IMPORTANT, "Process ID " << getpid()); === modified file 'src/tests/stub_debug.cc' --- src/tests/stub_debug.cc 2012-12-15 01:13:21 +0000 +++ src/tests/stub_debug.cc 2014-02-17 19:30:07 +0000 @@ -8,156 +8,98 @@ #include "squid.h" #include "Debug.h" #if HAVE_STDIO_H #include #endif FILE *debug_log = NULL; int Debug::TheDepth = 0; char *Debug::debugOptions; char *Debug::cache_log= NULL; int Debug::rotateNumber = 0; int Debug::Levels[MAX_DEBUG_SECTIONS]; int Debug::level; int Debug::sectionLevel; int Debug::override_X = 0; int Debug::log_stderr = 1; bool Debug::log_syslog = false; -Ctx -ctx_enter(const char *descr) -{ - return -1; -} - void -ctx_exit(Ctx ctx) -{ -} - -void -_db_init(const char *logfile, const char *options) +Debug::Init(const char *logfile, const char *options) {} -void -_db_set_syslog(const char *facility) -{} - -void -_db_rotate_log(void) -{} - -static void -_db_print_stderr(const char *format, va_list args); - -void -_db_print(const char *format,...) -{ - static char f[BUFSIZ]; - va_list args1; - va_list args2; - va_list args3; - - va_start(args1, format); - va_start(args2, format); - va_start(args3, format); - - snprintf(f, BUFSIZ, "%s| %s", - "stub time", //debugLogTime(squid_curtime), - format); - - _db_print_stderr(f, args2); - - va_end(args1); - va_end(args2); - va_end(args3); -} - -static void -_db_print_stderr(const char *format, va_list args) -{ - if (1 < Debug::level) - return; - - vfprintf(stderr, format, args); -} - std::ostream & Debug::getDebugOut() { assert(TheDepth >= 0); ++TheDepth; if (TheDepth > 1) { assert(CurrentDebug); *CurrentDebug << std::endl << "reentrant debuging " << TheDepth << "-{"; } else { assert(!CurrentDebug); CurrentDebug = new std::ostringstream(); // set default formatting flags CurrentDebug->setf(std::ios::fixed); CurrentDebug->precision(2); } return *CurrentDebug; } void Debug::parseOptions(char const *) { return; } void -Debug::finishDebug() -{ - assert(TheDepth >= 0); - assert(CurrentDebug); - if (TheDepth > 1) { - *CurrentDebug << "}-" << TheDepth << std::endl; - } else { - assert(TheDepth == 1); - _db_print("%s\n", CurrentDebug->str().c_str()); - delete CurrentDebug; - CurrentDebug = NULL; - } - --TheDepth; -} - -void Debug::xassert(const char *msg, const char *file, int line) { if (CurrentDebug) { *CurrentDebug << "assertion failed: " << file << ":" << line << ": \"" << msg << "\""; } abort(); } std::ostringstream *Debug::CurrentDebug (NULL); const char* SkipBuildPrefix(const char* path) { return path; } std::ostream & Raw::print(std::ostream &os) const { if (label_) os << ' ' << label_ << '[' << size_ << ']'; if (!size_) return os; // finalize debugging level if no level was set explicitly via minLevel() const int finalLevel = (level >= 0) ? level : (size_ > 40 ? DBG_DATA : Debug::sectionLevel); if (finalLevel <= Debug::sectionLevel) { os << (label_ ? '=' : ' '); os.write(data_, size_); } return os; } + +std::string +LogLinePreamble() +{ + return std::string("stub: "); +} + +void +Debug::Print(const std::string & logline) +{ + std::cerr << "debug: " << logline; +} === modified file 'src/tools.cc' --- src/tools.cc 2013-10-25 00:13:46 +0000 +++ src/tools.cc 2014-02-17 19:30:07 +0000 @@ -434,101 +434,101 @@ death(int sig) puts(dead_msg()); } abort(); } void BroadcastSignalIfAny(int& sig) { if (sig > 0) { if (IamCoordinatorProcess()) Ipc::Coordinator::Instance()->broadcastSignal(sig); sig = -1; } } void sigusr2_handle(int sig) { static int state = 0; - /* no debugs() here; bad things happen if the signal is delivered during _db_print() */ + /* no debugs() here; bad things happen if the signal is delivered during Debug::Print() */ DebugSignal = sig; if (state == 0) { #if !MEM_GEN_TRACE Debug::parseOptions("ALL,7"); #else log_trace_done(); #endif state = 1; } else { #if !MEM_GEN_TRACE Debug::parseOptions(Debug::debugOptions); #else log_trace_init("/tmp/squid.alloc"); #endif state = 0; } #if !HAVE_SIGACTION if (signal(sig, sigusr2_handle) == SIG_ERR) /* reinstall */ debugs(50, DBG_CRITICAL, "signal: sig=" << sig << " func=sigusr2_handle: " << xstrerror()); #endif } void debug_trap(const char *message) { if (!opt_catch_signals) fatal_dump(message); - _db_print("WARNING: %s\n", message); + debugs(50, DBG_CRITICAL, "WARNING: " << message); } void sig_child(int sig) { #if !_SQUID_WINDOWS_ #if _SQUID_NEXT_ union wait status; #else int status; #endif pid_t pid; do { #if _SQUID_NEXT_ pid = wait3(&status, WNOHANG, NULL); #else pid = waitpid(-1, &status, WNOHANG); #endif - /* no debugs() here; bad things happen if the signal is delivered during _db_print() */ + /* no debugs() here; bad things happen if the signal is delivered during Debug::print() */ #if HAVE_SIGACTION } while (pid > 0); #else } while (pid > 0 || (pid < 0 && errno == EINTR)); signal(sig, sig_child); #endif #endif } void sig_shutdown(int sig) { shutting_down = 1; }