[cpp-sp] branch main updated: CPPSP-40 - Rework per-request logging API
Codeberg
noreply at shibboleth.net
Fri Dec 5 20:26:10 UTC 2025
This is an automated email from the git hooks/post-receive script.
codeberg pushed a commit to branch main
in repository cpp-sp.
View the commit online:
https://codeberg.org/Shibboleth/cpp-sp/commit/a3af518ed8bd748322a532a2b774f1bec0376e51
The following commit(s) were added to refs/heads/main by this push:
new a3af518e CPPSP-40 - Rework per-request logging API
a3af518e is described below
commit a3af518ed8bd748322a532a2b774f1bec0376e51
Author: Scott Cantor <cantor.2 at osu.edu>
AuthorDate: Fri Dec 5 15:25:20 2025 -0500
CPPSP-40 - Rework per-request logging API
https://shibboleth.atlassian.net/browse/CPPSP-40
Started rework of logging calls.
---
apache/mod_shib4.cpp | 40 ++++---------
shibsp/AbstractSPRequest.cpp | 79 +++++++++++++++++++++++-
shibsp/AbstractSPRequest.h | 7 +++
shibsp/SPRequest.h | 16 +++++
shibsp/session/AbstractSessionCache.h | 15 +++--
shibsp/session/impl/AbstractSessionCache.cpp | 89 +++++++++++++++++-----------
6 files changed, 181 insertions(+), 65 deletions(-)
diff --git a/apache/mod_shib4.cpp b/apache/mod_shib4.cpp
index 461002dc..54f725fd 100644
--- a/apache/mod_shib4.cpp
+++ b/apache/mod_shib4.cpp
@@ -327,18 +327,8 @@ public:
string getLocalAddr() const {
return m_req->connection->local_ip;
}
- void log(Priority::Value level, const string& msg) const {
- AbstractSPRequest::log(level,msg);
- ap_log_rerror(
- APLOG_MARK,
- (level == Priority::SHIB_DEBUG ? APLOG_DEBUG :
- (level == Priority::SHIB_INFO ? APLOG_INFO :
- (level == Priority::SHIB_WARN ? APLOG_WARNING :
- (level == Priority::SHIB_ERROR ? APLOG_ERR : APLOG_CRIT))))|APLOG_NOERRNO,
- 0, m_req,
- "%s",
- msg.c_str()
- );
+ const char* getLogContext() {
+ return m_req->log_id;
}
const char* getQueryString() const { return m_req->args; }
const char* getRequestBody() const {
@@ -826,7 +816,7 @@ AccessControl::aclresult_t htAccessControl::doUser(const ShibTargetApache& sta,
regexp::regex_match(sta.getRemoteUser(), re, match_flags);
}
catch (const regexp::regex_error& e) {
- sta.error(string("htaccess plugin caught exception while parsing regular expression (") + w + "): " + e.what());
+ sta.error("htaccess plugin caught exception while parsing regular expression (%s): %s", w, e.what());
}
}
else if (sta.getRemoteUser() == w) {
@@ -834,9 +824,7 @@ AccessControl::aclresult_t htAccessControl::doUser(const ShibTargetApache& sta,
}
if (match) {
- if (sta.isPriorityEnabled(Priority::SHIB_DEBUG)) {
- sta.debug(string("htaccess: require user ") + (negated ? "rejecting (" : "accepting (") + sta.getRemoteUser() + ")");
- }
+ sta.debug("htaccess: require user %s '%s'", negated ? "rejecting" : "accepting", sta.getRemoteUser().c_str());
return (negated ? shib_acl_false : shib_acl_true);
}
}
@@ -862,22 +850,20 @@ bool htAccessControl::checkAttribute(
regexp::regex exp(toMatch, flags);
if (attrConfig.hasMatchingValue(session, attributeID, exp)) {
if (request.isPriorityEnabled(Priority::SHIB_DEBUG)) {
- request.debug(string("htaccess: attribute (") + attributeID + ") matched regexp: " + toMatch);
+ request.debug("htaccess: attribute (%s) matched regexp: %s", attributeID, toMatch);
}
return true;
}
} catch (const regexp::regex_error& e) {
- request.error(string("htaccess plugin caught exception while parsing regular expression (") + toMatch + "): " + e.what());
+ request.error("htaccess plugin caught exception while parsing regular expression (%s): %s", toMatch, e.what());
}
}
else if (attrConfig.hasMatchingValue(session, attributeID, toMatch)) {
- if (request.isPriorityEnabled(Priority::SHIB_DEBUG)) {
- request.debug(string("htaccess: attribute (") + attributeID + ") matched " + toMatch);
- }
+ request.debug("htaccess: attribute (%s) matched %s", attributeID, toMatch);
return true;
}
- else if (request.isPriorityEnabled(Priority::SHIB_DEBUG)) {
- request.debug(string("htaccess: attribute (") + attributeID + ") did not match " + toMatch);
+ else {
+ request.debug("htaccess: attribute (%s) did not match %s", attributeID, toMatch);
}
return false;
}
@@ -1083,7 +1069,7 @@ extern "C" authz_status shib_session_check_authz(request_rec* r, const char*, co
}
}
catch (std::exception& e) {
- sta.first->warn(string("htaccess: unable to obtain session for access control check: ") + e.what());
+ sta.first->warn("htaccess: unable to obtain session for access control check: %s", e.what());
}
sta.first->debug("htaccess: denying shib-access/valid-user rule, no active session");
@@ -1181,7 +1167,7 @@ extern "C" authz_status shib_acclass_check_authz(request_rec* r, const char* req
return session ? AUTHZ_DENIED : AUTHZ_DENIED_NO_USER;
}
catch (std::exception& e) {
- sta.first->warn(string("htaccess: unable to obtain session for access control check: ") + e.what());
+ sta.first->warn("htaccess: unable to obtain session for access control check: %s", e.what());
}
return AUTHZ_GENERAL_ERROR;
@@ -1205,7 +1191,7 @@ extern "C" authz_status shib_attr_check_authz(request_rec* r, const char* requir
return session ? AUTHZ_DENIED : AUTHZ_DENIED_NO_USER;
}
catch (std::exception& e) {
- sta.first->warn(string("htaccess: unable to obtain session for access control check: ") + e.what());
+ sta.first->warn("htaccess: unable to obtain session for access control check: %s", e.what());
}
return AUTHZ_GENERAL_ERROR;
@@ -1229,7 +1215,7 @@ extern "C" authz_status shib_plugin_check_authz(request_rec* r, const char* requ
return session ? AUTHZ_DENIED : AUTHZ_DENIED_NO_USER;
}
catch (std::exception& e) {
- sta.first->warn(string("htaccess: unable to obtain session for access control check: ") + e.what());
+ sta.first->warn("htaccess: unable to obtain session for access control check: %s", e.what());
}
return AUTHZ_GENERAL_ERROR;
diff --git a/shibsp/AbstractSPRequest.cpp b/shibsp/AbstractSPRequest.cpp
index 0587b519..533643d7 100644
--- a/shibsp/AbstractSPRequest.cpp
+++ b/shibsp/AbstractSPRequest.cpp
@@ -24,6 +24,7 @@
#include "Agent.h"
#include "AgentConfig.h"
#include "logging/Category.h"
+#include "logging/impl/StringUtil.h"
#include "session/SessionCache.h"
#include "util/CGIParser.h"
#include "util/Misc.h"
@@ -437,9 +438,35 @@ void AbstractSPRequest::setAuthType(const char* authtype)
}
+const char* AbstractSPRequest::getLogContext() const{
+ return nullptr;
+}
+
void AbstractSPRequest::log(Priority::Value level, const std::string& msg) const
{
- m_log.log(level, msg);
+ if (isPriorityEnabled(level)) {
+ const char* ctx = getLogContext();
+ if (ctx) {
+ m_log.log(level, "%s %s", ctx, msg.c_str());
+ }
+ else {
+ m_log.log(level, msg);
+ }
+ }
+}
+
+void AbstractSPRequest::log(Priority::Value level, const char* formatString, va_list args) const
+{
+ if (isPriorityEnabled(level)) {
+ const char* ctx = getLogContext();
+ if (ctx) {
+ string msg = StringUtil::vform(formatString, args);
+ m_log.log(level, "%s %s", ctx, msg.c_str());
+ }
+ else {
+ m_log.log(level, formatString, args);
+ }
+ }
}
bool AbstractSPRequest::isPriorityEnabled(Priority::Value level) const
@@ -472,6 +499,56 @@ void SPRequest::crit(const string& msg) const
log(Priority::SHIB_CRIT, msg);
}
+void SPRequest::debug(const char* formatString, ...) const
+{
+ if (isPriorityEnabled(Priority::SHIB_DEBUG)) {
+ va_list va;
+ va_start(va, formatString);
+ log(Priority::SHIB_DEBUG, formatString, va);
+ va_end(va);
+ }
+}
+
+void SPRequest::info(const char* formatString, ...) const
+{
+ if (isPriorityEnabled(Priority::SHIB_INFO)) {
+ va_list va;
+ va_start(va, formatString);
+ log(Priority::SHIB_INFO, formatString, va);
+ va_end(va);
+ }
+}
+
+void SPRequest::warn(const char* formatString, ...) const
+{
+ if (isPriorityEnabled(Priority::SHIB_WARN)) {
+ va_list va;
+ va_start(va, formatString);
+ log(Priority::SHIB_WARN, formatString, va);
+ va_end(va);
+ }
+}
+
+void SPRequest::error(const char* formatString, ...) const
+{
+ if (isPriorityEnabled(Priority::SHIB_ERROR)) {
+ va_list va;
+ va_start(va, formatString);
+ log(Priority::SHIB_ERROR, formatString, va);
+ va_end(va);
+ }
+}
+
+void SPRequest::crit(const char* formatString, ...) const
+{
+ if (isPriorityEnabled(Priority::SHIB_CRIT)) {
+ va_list va;
+ va_start(va, formatString);
+ log(Priority::SHIB_CRIT, formatString, va);
+ va_end(va);
+ }
+}
+
string AbstractSPRequest::getCGINameForHeader(const char* name) const
{
string cgiversion("HTTP_");
diff --git a/shibsp/AbstractSPRequest.h b/shibsp/AbstractSPRequest.h
index 6ef13bbe..cc1f9be2 100644
--- a/shibsp/AbstractSPRequest.h
+++ b/shibsp/AbstractSPRequest.h
@@ -79,6 +79,7 @@ namespace shibsp {
std::string getSecureHeader(const char* name) const;
void setAuthType(const char* authtype);
void log(Priority::Value level, const std::string& msg) const;
+ void log(Priority::Value level, const char* formatString, va_list args) const;
bool isPriorityEnabled(Priority::Value level) const;
protected:
@@ -90,6 +91,12 @@ namespace shibsp {
*/
std::string getCGINameForHeader(const char* name) const;
+ /**
+ * Optionally overrideable method to return logging context information to prefix
+ * to request-specific logging.
+ */
+ virtual const char* getLogContext() const;
+
private:
Category& m_log;
Agent& m_agent;
diff --git a/shibsp/SPRequest.h b/shibsp/SPRequest.h
index 1065b010..d6e65e72 100644
--- a/shibsp/SPRequest.h
+++ b/shibsp/SPRequest.h
@@ -26,6 +26,7 @@
#include <shibsp/io/HTTPResponse.h>
#include <shibsp/logging/Priority.h>
+#include <cstdarg>
#include <mutex>
namespace shibsp {
@@ -172,12 +173,27 @@ namespace shibsp {
*/
virtual void log(Priority::Value level, const std::string& msg) const=0;
+ /**
+ * Log to native server environment using a formatting string and variable arguments.
+ *
+ * @param level logging level
+ * @param formatString formatting string
+ * @param args message arguments
+ */
+ virtual void log(Priority::Value level, const char* formatString, va_list args) const=0;
+
void debug(const std::string& msg) const;
void info(const std::string& msg) const;
void warn(const std::string& msg) const;
void error(const std::string& msg) const;
void crit(const std::string& msg) const;
+ void debug(const char* formatString, ...) const;
+ void info(const char* formatString, ...) const;
+ void warn(const char* formatString, ...) const;
+ void error(const char* formatString, ...) const;
+ void crit(const char* formatString, ...) const;
+
/**
* Test logging level.
*
diff --git a/shibsp/session/AbstractSessionCache.h b/shibsp/session/AbstractSessionCache.h
index 1c0176e9..a44fa5f2 100644
--- a/shibsp/session/AbstractSessionCache.h
+++ b/shibsp/session/AbstractSessionCache.h
@@ -148,7 +148,7 @@ namespace shibsp {
*
* @return logging object
*/
- Category& log() const;
+ Category& logger() const;
/**
* Access the shutdown state.
@@ -166,8 +166,6 @@ namespace shibsp {
* @return true iff the data is valid
*/
static bool isSessionDataValid(DDF& sessionData);
-
- protected:
/**
* Compares two addresses, allowing for the unreliableNetworks fuzzy match option.
*
@@ -195,12 +193,21 @@ namespace shibsp {
*/
static void computeVersionedFilename(std::string& path, unsigned int version);
+ /**
+ * Conditionally logs to request API or directly depending on existence of request.
+ *
+ * @param request request if available
+ * @param log fallback logger
+ * @param level logging level
+ * @param formatString format string
+ */
+ static void log(const SPRequest* request, Category& log, Priority::Value level, const char* formatString, ...);
private:
// Split session key and version from cookie values.
static std::pair<std::string,unsigned int> parseCookieValue(const char* value);
static void* cleanup_fn(void*);
- void dormant(const std::string& key);
+ void dormant(const SPRequest* request, const std::string& key);
// Wrapper for finding sessions via varied inputs.
std::unique_lock<Session> _find(
SPRequest* request,
diff --git a/shibsp/session/impl/AbstractSessionCache.cpp b/shibsp/session/impl/AbstractSessionCache.cpp
index a152c8cd..3d8fec0a 100644
--- a/shibsp/session/impl/AbstractSessionCache.cpp
+++ b/shibsp/session/impl/AbstractSessionCache.cpp
@@ -76,6 +76,13 @@ static bool COOKIE_HTTPONLY_PROP_DEFAULT = true;
static const char COOKIE_PATH_PROP_DEFAULT[] = "/";
static int COOKIE_MAXAGE_PROP_DEFAULT = -1;
+// Logging Macros
+#define DEBUG_MARK request, m_log, Priority::SHIB_DEBUG
+#define INFO_MARK request, m_log, Priority::SHIB_INFO
+#define WARN_MARK request, m_log, Priority::SHIB_WARN
+#define ERROR_MARK request, m_log, Priority::SHIB_ERROR
+#define CRIT_MARK request, m_log, Priority::SHIB_CRIT
+
void SHIBSP_API shibsp::registerSessionCaches()
{
AgentConfig::getConfig().SessionCacheManager.registerFactory(FILESYSTEM_SESSION_CACHE, FilesystemSessionCacheFactory);
@@ -232,7 +239,7 @@ AbstractSessionCache::~AbstractSessionCache()
{
}
-Category& AbstractSessionCache::log() const
+Category& AbstractSessionCache::logger() const
{
return m_log;
}
@@ -299,8 +306,21 @@ void AbstractSessionCache::computeVersionedFilename(string& path, unsigned int v
catch (const boost::bad_lexical_cast& e) {
// Should never happen. In principle the path will effectively not exist when this happens.
Category::getInstance(SHIBSP_LOGCAT ".SessionCache").error(
- "error converting version (%u) into string to cpmpute filename: %s", version, e.what());
+ "error converting version (%u) into string to compute filename: %s", version, e.what());
+ }
+}
+
+void AbstractSessionCache::log(const SPRequest* request, Category& log, Priority::Value level, const char* formatString, ...)
+{
+ va_list va;
+ va_start(va, formatString);
+ if (request) {
+ request->log(level, formatString, va);
+ }
+ else {
+ log.log(level, formatString, va);
}
+ va_end(va);
}
pair<string,unsigned int> AbstractSessionCache::parseCookieValue(const char* value)
@@ -320,7 +340,7 @@ pair<string,unsigned int> AbstractSessionCache::parseCookieValue(const char* val
string AbstractSessionCache::create(SPRequest& request, DDF& data)
{
- m_log.debug("creating new session");
+ request.debug("creating new session");
// Isolate from parent.
data.remove();
@@ -337,7 +357,7 @@ string AbstractSessionCache::create(SPRequest& request, DDF& data)
request.getRequestSettings().first->getString(RequestMapper::ATTRIBUTE_CONFIG_ID_PROP_NAME));
DDF attrs = data["attributes"];
if (!attrConfig.processAttributes(attrs)) {
- m_log.warn("error processing session attributes for storage/use");
+ request.warn("error processing session attributes for storage/use");
data.destroy();
throw SessionException("Error while processing session attributes for storage.");
}
@@ -345,7 +365,7 @@ string AbstractSessionCache::create(SPRequest& request, DDF& data)
// Write the data to the back-end, obtaining a key.
string key;
try {
- m_log.debug("writing new session to persistent store");
+ request.debug("writing new session to persistent store");
key = cache_create(&request, data);
}
catch (const exception&) {
@@ -363,7 +383,7 @@ string AbstractSessionCache::create(SPRequest& request, DDF& data)
issuer = const_cast<DDF&>(attr->second).first().string();
}
- m_log.info("new session created: ID (%s), Issuer (%s), Address (%s)",
+ request.info("new session created: ID (%s), Issuer (%s), Address (%s)",
key.c_str(), issuer ? issuer : "unknown", request.getRemoteAddr().c_str());
// Drop a cookie with the session ID (the initial version suffix is 1).
@@ -393,7 +413,7 @@ unique_lock<Session> AbstractSessionCache::find(SPRequest& request, bool checkTi
const char* cookieval = m_cookieManager->getCookieValue(request);
if (!cookieval) {
- m_log.debug("no session cookie present");
+ request.debug("no session cookie present");
return unique_lock<Session>();
}
@@ -422,7 +442,7 @@ unique_lock<Session> AbstractSessionCache::find(SPRequest& request, bool checkTi
client_addr.empty() ? nullptr : client_addr.c_str());
if (!session) {
// No session, we need to clear the session cookie to prevent further use.
- m_log.debug("clearing cookie for session (%s)", keyver.first.c_str());
+ request.debug("clearing cookie for session (%s)", keyver.first.c_str());
m_cookieManager->unsetCookie(request);
} else if (session.mutex()->getVersion() > keyver.second) {
// The returned session's version is newer than our cookie value, we need to update our cookie.
@@ -451,7 +471,7 @@ unique_lock<Session> AbstractSessionCache::_find(
const char* client_addr
)
{
- m_log.debug("searching local cache for session (%s)", key);
+ log(DEBUG_MARK, "searching local cache for session (%s)", key);
#if defined(HAVE_CXX17)
shared_lock<shared_mutex> readlocker(m_lock);
#elif defined(HAVE_CXX14)
@@ -465,29 +485,29 @@ unique_lock<Session> AbstractSessionCache::_find(
unique_lock<Session> session(*(i->second));
readlocker.unlock();
- m_log.debug("session (%s) found locally, validating for use", key);
+ log(DEBUG_MARK, "session (%s) found locally, validating for use", key);
// Cross-check application and check version for currency.
if (strcmp(applicationId, session.mutex()->getApplicationID())) {
- m_log.warn("session (%s) issued for application (%s), accessed via application (%s)",
+ log(WARN_MARK, "session (%s) issued for application (%s), accessed via application (%s)",
key, session.mutex()->getApplicationID(), applicationId);
session.unlock();
return session;
}
else if (version > session.mutex()->getVersion()) {
// The version we want is newer than the one we have cached.
- m_log.debug("session (%s) has stale version, removing it to reload", key);
+ log(DEBUG_MARK, "session (%s) has stale version, removing it to reload", key);
// We need to dump the local copy so we can recurse back in to load in the "later" version.
session.unlock(); // need to unlock for dormant() to work
- dormant(key);
+ dormant(request, key);
// We want to fall into the cache_read step below to reload the latest version.
}
else if (!dynamic_cast<BasicSession*>(session.mutex())->isValid(request, lifetime, timeout)) {
// Locally invalid on its face, so remove and return nothing.
session.unlock();
- m_log.debug("session (%s) invalid, removing it", key);
+ log(DEBUG_MARK, "session (%s) invalid, removing it", key);
// The record should be gone from the back-end but we need to dump it locally.
- dormant(key);
+ dormant(request, key);
return session;
}
else if (client_addr) {
@@ -496,7 +516,7 @@ unique_lock<Session> AbstractSessionCache::_find(
const char* bound_addr = dynamic_cast<BasicSession*>(session.mutex())->getClientAddress(family);
if (bound_addr) {
if (!isAddressMatch(client_addr, bound_addr)) {
- m_log.warn("session (%s) access invalid, bound to (%s), accessed from (%s)", key, bound_addr, client_addr);
+ log(WARN_MARK, "session (%s) access invalid, bound to (%s), accessed from (%s)", key, bound_addr, client_addr);
session.unlock();
}
// Return locked session or empty wrapper depending on the check result.
@@ -505,10 +525,10 @@ unique_lock<Session> AbstractSessionCache::_find(
else {
// We need to rebind the session and the cleanest way to do so is to leverage the
// back-end's cache_read operation from scratch to refresh the session.
- m_log.debug("session (%s) is unbound to address family (%s), removing session for update/reload", key, family);
+ log(DEBUG_MARK, "session (%s) is unbound to address family (%s), removing session for update/reload", key, family);
// We need to dump the local copy so we can recurse back in to load in the "later" version.
session.unlock(); // need to unlock for dormant() to work
- dormant(key);
+ dormant(request, key);
// We want to fall into the cache_read step below to reload the latest version.
}
}
@@ -520,7 +540,7 @@ unique_lock<Session> AbstractSessionCache::_find(
else {
// No copy locally at all, so just fall into cache_read step below.
readlocker.unlock();
- m_log.debug("session (%s) not found locally, loading from persistent store", key);
+ log(DEBUG_MARK, "session (%s) not found locally, loading from persistent store", key);
}
DDF obj;
@@ -528,7 +548,7 @@ unique_lock<Session> AbstractSessionCache::_find(
// Note this performs the relevant enforcement for us.
obj = cache_read(request, applicationId, key, version, lifetime, timeout, client_addr);
if (obj.isnull()) {
- m_log.info("session (%s) not available in persistent store", key);
+ log(INFO_MARK, "session (%s) not available in persistent store", key);
return unique_lock<Session>();
}
}
@@ -561,7 +581,7 @@ unique_lock<Session> AbstractSessionCache::_find(
// they would have to be inside the cache's critical section to get to it.
// Thus, this sequence transfers ownership out of the table, removes the entry, then
// locks, unlocks, and finally deletes the old session object.
- m_log.debug("replacing session (%s) with fresh copy", key);
+ log(DEBUG_MARK, "replacing session (%s) with fresh copy", key);
unique_ptr<BasicSession> oldSession;
oldSession.swap(m_hashtable[key]);
m_hashtable.erase(key);
@@ -587,12 +607,12 @@ bool AbstractSessionCache::update(SPRequest& request, unique_lock<Session>& sess
request.getRequestSettings().first->getString(RequestMapper::ATTRIBUTE_CONFIG_ID_PROP_NAME));
DDF attrs = data["attributes"];
if (!attrConfig.processAttributes(attrs)) {
- m_log.warn("error processing updated session attributes for storage/use");
+ request.warn("error processing updated session attributes for storage/use");
data.destroy();
throw SessionException("Error while processing updated session attributes for storage.");
}
- m_log.info("updating session (%s), version (%u), reason (%s)",
+ request.info("updating session (%s), version (%u), reason (%s)",
session.mutex()->getID(), session.mutex()->getVersion(), reason ? reason : "(unspecified)");
// The update requires that we copy the existing DDF from the original session and then
@@ -636,13 +656,13 @@ void AbstractSessionCache::remove(SPRequest& request)
{
const char* cookieval = m_cookieManager->getCookieValue(request);
if (!cookieval) {
- m_log.debug("no session cookie present, no session bound to request");
+ request.debug("no session cookie present, no session bound to request for removal");
return;
}
pair<string,unsigned int> keyver = parseCookieValue(cookieval);
- dormant(keyver.first);
+ dormant(&request, keyver.first);
try {
cache_remove(&request, keyver.first.c_str());
}
@@ -654,7 +674,7 @@ void AbstractSessionCache::remove(SPRequest& request)
void AbstractSessionCache::remove(const char* key)
{
- dormant(key);
+ dormant(nullptr, key);
try {
cache_remove(nullptr, key);
}
@@ -663,9 +683,9 @@ void AbstractSessionCache::remove(const char* key)
}
}
-void AbstractSessionCache::dormant(const string& key)
+void AbstractSessionCache::dormant(const SPRequest* request, const string& key)
{
- m_log.debug("deleting local copy of session (%s)", key.c_str());
+ log(DEBUG_MARK, "deleting local copy of session (%s)", key.c_str());
// lock the cache for writing, which means we know nobody is sitting in a lookup.
m_lock.lock();
@@ -760,7 +780,7 @@ void* AbstractSessionCache::cleanup_fn(void* p)
// Pass 2: walk through the list of stale entries and remove them from the local cache.
for (const string& key : stale_keys) {
- pcache->dormant(key.c_str());
+ pcache->dormant(nullptr, key.c_str());
}
}
@@ -844,10 +864,11 @@ bool BasicSession::isValid(SPRequest* request, unsigned int lifetime, unsigned i
if (lifetime) {
// Enforce session lifetime.
if (getCreation() + lifetime < now) {
- if (m_cache.log().isWarnEnabled()) {
+ if ((request && request->isPriorityEnabled(Priority::SHIB_WARN)) || m_cache.logger().isWarnEnabled()) {
string created(date::format("%FT%TZ", chrono::system_clock::from_time_t(getCreation())));
string expired(date::format("%FT%TZ", chrono::system_clock::from_time_t(getCreation() + lifetime)));
- m_cache.log().warn("session (%s) has expired, created (%s), expired (%s)", getID(), created.c_str(), expired.c_str());
+ AbstractSessionCache::log(request, m_cache.logger(), Priority::SHIB_WARN,
+ "session (%s) has expired, created (%s), expired (%s)", getID(), created.c_str(), expired.c_str());
}
try {
m_cache.cache_remove(request, getID());
@@ -869,7 +890,8 @@ bool BasicSession::isValid(SPRequest* request, unsigned int lifetime, unsigned i
try {
// Pass a zero to bypass timeout enforcement as we know as well or better than the back-end...
if (!m_cache.cache_touch(request, getID(), getVersion(), 0)) {
- m_cache.log().warn("session (%) missing in persistent store, invalidating locally", getID());
+ AbstractSessionCache::log(request, m_cache.logger(), Priority::SHIB_WARN,
+ "session (%) missing in persistent store, invalidating locally", getID());
return false;
}
}
@@ -886,7 +908,8 @@ bool BasicSession::isValid(SPRequest* request, unsigned int lifetime, unsigned i
// The session is locally invalid due to inactivity, but this isn't "truth" because other agent processes may
// actively be using it.
if (!m_cache.cache_touch(request, getID(), getVersion(), timeout)) {
- m_cache.log().warn("session (%s) timed out due to inactivity", getID());
+ AbstractSessionCache::log(request, m_cache.logger(), Priority::SHIB_WARN,
+ "session (%s) timed out due to inactivity", getID());
return false;
}
}
--
To stop receiving notification emails like this one, please contact
the administrator of this repository.
More information about the commits
mailing list