shibsp/impl/StorageServiceSessionCache.cpp

   1 /*
   2  *  Copyright 2001-2010 Internet2
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *     http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16
  17 /**
  18  * StorageServiceSessionCache.cpp
  19  *
  20  * StorageService-based SessionCache implementation.
  21  *
  22  * Instead of optimizing this plugin with a buffering scheme that keeps objects around
  23  * and avoids extra parsing steps, I'm assuming that systems that require such can
  24  * layer their own cache plugin on top of this version either by delegating to it
  25  * or using the remoting support. So this version will load sessions directly
  26  * from the StorageService, instantiate enough to expose the Session API,
  27  * and then delete everything when they're unlocked. All data in memory is always
  28  * kept in sync with the StorageService (no lazy updates).
  29  */
  30
  31 #include "internal.h"
  32 #include "Application.h"
  33 #include "exceptions.h"
  34 #include "ServiceProvider.h"
  35 #include "SessionCacheEx.h"
  36 #include "TransactionLog.h"
  37 #include "attribute/Attribute.h"
  38 #include "remoting/ListenerService.h"
  39 #include "util/SPConstants.h"
  40
  41 #include <algorithm>
  42 #include <xmltooling/io/HTTPRequest.h>
  43 #include <xmltooling/io/HTTPResponse.h>
  44 #include <xmltooling/util/DateTime.h>
  45 #include <xmltooling/util/NDC.h>
  46 #include <xmltooling/util/ParserPool.h>
  47 #include <xmltooling/util/Threads.h>
  48 #include <xmltooling/util/XMLHelper.h>
  49 #include <xercesc/util/XMLUniDefs.hpp>
  50
  51 #ifndef SHIBSP_LITE
  52 # include <saml/exceptions.h>
  53 # include <saml/SAMLConfig.h>
  54 # include <saml/saml2/core/Assertions.h>
  55 # include <saml/saml2/metadata/Metadata.h>
  56 # include <xmltooling/XMLToolingConfig.h>
  57 # include <xmltooling/util/StorageService.h>
  58 using namespace opensaml::saml2md;
  59 #else
  60 # include <ctime>
  61 # include <xmltooling/util/DateTime.h>
  62 #endif
  63
  64 using namespace shibsp;
  65 using namespace opensaml;
  66 using namespace xmltooling;
  67 using namespace std;
  68
  69 namespace shibsp {
  70
  71     class StoredSession;
  72     class SSCache : public SessionCacheEx
  73 #ifndef SHIBSP_LITE
  74         ,public virtual Remoted
  75 #endif
  76     {
  77     public:
  78         SSCache(const DOMElement* e);
  79         ~SSCache();
  80
  81 #ifndef SHIBSP_LITE
  82         void receive(DDF& in, ostream& out);
  83
  84         void insert(
  85             const Application& application,
  86             const HTTPRequest& httpRequest,
  87             HTTPResponse& httpResponse,
  88             time_t expires,
  89             const saml2md::EntityDescriptor* issuer=nullptr,
  90             const XMLCh* protocol=nullptr,
  91             const saml2::NameID* nameid=nullptr,
  92             const XMLCh* authn_instant=nullptr,
  93             const XMLCh* session_index=nullptr,
  94             const XMLCh* authncontext_class=nullptr,
  95             const XMLCh* authncontext_decl=nullptr,
  96             const vector<const Assertion*>* tokens=nullptr,
  97             const vector<Attribute*>* attributes=nullptr
  98             );
  99         vector<string>::size_type logout(
 100             const Application& application,
 101             const saml2md::EntityDescriptor* issuer,
 102             const saml2::NameID& nameid,
 103             const set<string>* indexes,
 104             time_t expires,
 105             vector<string>& sessions
 106             );
 107         bool matches(
 108             const Application& application,
 109             const xmltooling::HTTPRequest& request,
 110             const saml2md::EntityDescriptor* issuer,
 111             const saml2::NameID& nameid,
 112             const set<string>* indexes
 113             );
 114 #endif
 115         Session* find(const Application& application, const char* key, const char* client_addr=nullptr, time_t* timeout=nullptr);
 116         void remove(const Application& application, const char* key);
 117         void test();
 118
 119         string active(const Application& application, const xmltooling::HTTPRequest& request) {
 120             pair<string,const char*> shib_cookie = application.getCookieNameProps("_shibsession_");
 121             const char* session_id = request.getCookie(shib_cookie.first.c_str());
 122             return (session_id ? session_id : "");
 123         }
 124
 125         Session* find(const Application& application, const HTTPRequest& request, const char* client_addr=nullptr, time_t* timeout=nullptr) {
 126             string id = active(application, request);
 127             if (!id.empty())
 128                 return find(application, id.c_str(), client_addr, timeout);
 129             return nullptr;
 130         }
 131
 132         Session* find(const Application& application, HTTPRequest& request, const char* client_addr=nullptr, time_t* timeout=nullptr) {
 133             string id = active(application, request);
 134             if (id.empty())
 135                 return nullptr;
 136             try {
 137                 Session* session = find(application, id.c_str(), client_addr, timeout);
 138                 if (session)
 139                     return session;
 140                 HTTPResponse* response = dynamic_cast<HTTPResponse*>(&request);
 141                 if (response) {
 142                     pair<string,const char*> shib_cookie = application.getCookieNameProps("_shibsession_");
 143                     string exp(shib_cookie.second);
 144                     exp += "; expires=Mon, 01 Jan 2001 00:00:00 GMT";
 145                     response->setCookie(shib_cookie.first.c_str(), exp.c_str());
 146                 }
 147             }
 148             catch (exception&) {
 149                 HTTPResponse* response = dynamic_cast<HTTPResponse*>(&request);
 150                 if (response) {
 151                     pair<string,const char*> shib_cookie = application.getCookieNameProps("_shibsession_");
 152                     string exp(shib_cookie.second);
 153                     exp += "; expires=Mon, 01 Jan 2001 00:00:00 GMT";
 154                     response->setCookie(shib_cookie.first.c_str(), exp.c_str());
 155                 }
 156                 throw;
 157             }
 158             return nullptr;
 159         }
 160
 161         void remove(const Application& application, const HTTPRequest& request, HTTPResponse* response=nullptr) {
 162             pair<string,const char*> shib_cookie = application.getCookieNameProps("_shibsession_");
 163             const char* session_id = request.getCookie(shib_cookie.first.c_str());
 164             if (session_id && *session_id) {
 165                 if (response) {
 166                     string exp(shib_cookie.second);
 167                     exp += "; expires=Mon, 01 Jan 2001 00:00:00 GMT";
 168                     response->setCookie(shib_cookie.first.c_str(), exp.c_str());
 169                 }
 170                 remove(application, session_id);
 171             }
 172         }
 173
 174         Category& m_log;
 175         bool inproc;
 176         unsigned long m_cacheTimeout;
 177 #ifndef SHIBSP_LITE
 178         StorageService* m_storage;
 179         StorageService* m_storage_lite;
 180 #endif
 181
 182     private:
 183 #ifndef SHIBSP_LITE
 184         // maintain back-mappings of NameID/SessionIndex -> session key
 185         void insert(const char* key, time_t expires, const char* name, const char* index);
 186         bool stronglyMatches(const XMLCh* idp, const XMLCh* sp, const saml2::NameID& n1, const saml2::NameID& n2) const;
 187
 188         bool m_cacheAssertions;
 189 #endif
 190         const DOMElement* m_root;         // Only valid during initialization
 191         unsigned long m_inprocTimeout;
 192
 193         // inproc means we buffer sessions in memory
 194         RWLock* m_lock;
 195         map<string,StoredSession*> m_hashtable;
 196
 197         // management of buffered sessions
 198        void dormant(const char* key);
 199        static void* cleanup_fn(void*);
 200
 201         bool shutdown;
 202         CondWait* shutdown_wait;
 203         Thread* cleanup_thread;
 204     };
 205
 206     class StoredSession : public virtual Session
 207     {
 208     public:
 209         StoredSession(SSCache* cache, DDF& obj) : m_obj(obj),
 210 #ifndef SHIBSP_LITE
 211                 m_nameid(nullptr),
 212 #endif
 213                 m_cache(cache), m_expires(0), m_lastAccess(time(nullptr)), m_lock(nullptr) {
 214             auto_ptr_XMLCh exp(m_obj["expires"].string());
 215             if (exp.get()) {
 216                 DateTime iso(exp.get());
 217                 iso.parseDateTime();
 218                 m_expires = iso.getEpoch();
 219             }
 220
 221 #ifndef SHIBSP_LITE
 222             const char* nameid = obj["nameid"].string();
 223             if (nameid) {
 224                 // Parse and bind the document into an XMLObject.
 225                 istringstream instr(nameid);
 226                 DOMDocument* doc = XMLToolingConfig::getConfig().getParser().parse(instr);
 227                 XercesJanitor<DOMDocument> janitor(doc);
 228                 auto_ptr<saml2::NameID> n(saml2::NameIDBuilder::buildNameID());
 229                 n->unmarshall(doc->getDocumentElement(), true);
 230                 janitor.release();
 231                 m_nameid = n.release();
 232             }
 233 #endif
 234             if (cache->inproc)
 235                 m_lock = Mutex::create();
 236         }
 237
 238         ~StoredSession() {
 239             delete m_lock;
 240             m_obj.destroy();
 241             for_each(m_attributes.begin(), m_attributes.end(), xmltooling::cleanup<Attribute>());
 242 #ifndef SHIBSP_LITE
 243             delete m_nameid;
 244             for_each(m_tokens.begin(), m_tokens.end(), cleanup_pair<string,Assertion>());
 245 #endif
 246         }
 247
 248         Lockable* lock() {
 249             if (m_lock)
 250                 m_lock->lock();
 251             return this;
 252         }
 253         void unlock() {
 254             if (m_lock)
 255                 m_lock->unlock();
 256             else
 257                 delete this;
 258         }
 259
 260         const char* getID() const {
 261             return m_obj.name();
 262         }
 263         const char* getApplicationID() const {
 264             return m_obj["application_id"].string();
 265         }
 266         const char* getClientAddress() const {
 267             return m_obj["client_addr"].string();
 268         }
 269         const char* getEntityID() const {
 270             return m_obj["entity_id"].string();
 271         }
 272         const char* getProtocol() const {
 273             return m_obj["protocol"].string();
 274         }
 275         const char* getAuthnInstant() const {
 276             return m_obj["authn_instant"].string();
 277         }
 278 #ifndef SHIBSP_LITE
 279         const saml2::NameID* getNameID() const {
 280             return m_nameid;
 281         }
 282 #endif
 283         const char* getSessionIndex() const {
 284             return m_obj["session_index"].string();
 285         }
 286         const char* getAuthnContextClassRef() const {
 287             return m_obj["authncontext_class"].string();
 288         }
 289         const char* getAuthnContextDeclRef() const {
 290             return m_obj["authncontext_decl"].string();
 291         }
 292         const vector<Attribute*>& getAttributes() const {
 293             if (m_attributes.empty())
 294                 unmarshallAttributes();
 295             return m_attributes;
 296         }
 297         const multimap<string,const Attribute*>& getIndexedAttributes() const {
 298             if (m_attributeIndex.empty()) {
 299                 if (m_attributes.empty())
 300                     unmarshallAttributes();
 301                 for (vector<Attribute*>::const_iterator a = m_attributes.begin(); a != m_attributes.end(); ++a) {
 302                     const vector<string>& aliases = (*a)->getAliases();
 303                     for (vector<string>::const_iterator alias = aliases.begin(); alias != aliases.end(); ++alias)
 304                         m_attributeIndex.insert(multimap<string,const Attribute*>::value_type(*alias, *a));
 305                 }
 306             }
 307             return m_attributeIndex;
 308         }
 309         const vector<const char*>& getAssertionIDs() const {
 310             if (m_ids.empty()) {
 311                 DDF ids = m_obj["assertions"];
 312                 DDF id = ids.first();
 313                 while (id.isstring()) {
 314                     m_ids.push_back(id.string());
 315                     id = ids.next();
 316                 }
 317             }
 318             return m_ids;
 319         }
 320
 321         void validate(const Application& application, const char* client_addr, time_t* timeout);
 322
 323 #ifndef SHIBSP_LITE
 324         void addAttributes(const vector<Attribute*>& attributes);
 325         const Assertion* getAssertion(const char* id) const;
 326         void addAssertion(Assertion* assertion);
 327 #endif
 328
 329         time_t getExpiration() const { return m_expires; }
 330         time_t getLastAccess() const { return m_lastAccess; }
 331
 332     private:
 333         void unmarshallAttributes() const;
 334
 335         DDF m_obj;
 336 #ifndef SHIBSP_LITE
 337         saml2::NameID* m_nameid;
 338         mutable map<string,Assertion*> m_tokens;
 339 #endif
 340         mutable vector<Attribute*> m_attributes;
 341         mutable multimap<string,const Attribute*> m_attributeIndex;
 342         mutable vector<const char*> m_ids;
 343
 344         SSCache* m_cache;
 345         time_t m_expires,m_lastAccess;
 346         Mutex* m_lock;
 347     };
 348
 349     SessionCache* SHIBSP_DLLLOCAL StorageServiceCacheFactory(const DOMElement* const & e)
 350     {
 351         return new SSCache(e);
 352     }
 353 }
 354
 355 Session* SessionCache::find(const Application& application, HTTPRequest& request, const char* client_addr, time_t* timeout)
 356 {
 357     return find(application, const_cast<const HTTPRequest&>(request), client_addr, timeout);
 358 }
 359
 360 void SHIBSP_API shibsp::registerSessionCaches()
 361 {
 362     SPConfig::getConfig().SessionCacheManager.registerFactory(STORAGESERVICE_SESSION_CACHE, StorageServiceCacheFactory);
 363 }
 364
 365 Session::Session()
 366 {
 367 }
 368
 369 Session::~Session()
 370 {
 371 }
 372
 373 void StoredSession::unmarshallAttributes() const
 374 {
 375     Attribute* attribute;
 376     DDF attrs = m_obj["attributes"];
 377     DDF attr = attrs.first();
 378     while (!attr.isnull()) {
 379         try {
 380             attribute = Attribute::unmarshall(attr);
 381             m_attributes.push_back(attribute);
 382             if (m_cache->m_log.isDebugEnabled())
 383                 m_cache->m_log.debug("unmarshalled attribute (ID: %s) with %d value%s",
 384                     attribute->getId(), attr.first().integer(), attr.first().integer()!=1 ? "s" : "");
 385         }
 386         catch (AttributeException& ex) {
 387             const char* id = attr.first().name();
 388             m_cache->m_log.error("error unmarshalling attribute (ID: %s): %s", id ? id : "none", ex.what());
 389         }
 390         attr = attrs.next();
 391     }
 392 }
 393
 394 void StoredSession::validate(const Application& application, const char* client_addr, time_t* timeout)
 395 {
 396     time_t now = time(nullptr);
 397
 398     // Basic expiration?
 399     if (m_expires > 0) {
 400         if (now > m_expires) {
 401             m_cache->m_log.info("session expired (ID: %s)", getID());
 402             throw RetryableProfileException("Your session has expired, and you must re-authenticate.");
 403         }
 404     }
 405
 406     // Address check?
 407     if (client_addr) {
 408         if (m_cache->m_log.isDebugEnabled())
 409             m_cache->m_log.debug("comparing client address %s against %s", client_addr, getClientAddress());
 410         if (!XMLString::equals(getClientAddress(),client_addr)) {
 411             m_cache->m_log.warn("client address mismatch");
 412             throw RetryableProfileException(
 413                 "Your IP address ($1) does not match the address recorded at the time the session was established.",
 414                 params(1,client_addr)
 415                 );
 416         }
 417     }
 418
 419     if (!timeout)
 420         return;
 421
 422     if (!SPConfig::getConfig().isEnabled(SPConfig::OutOfProcess)) {
 423         DDF in("touch::"STORAGESERVICE_SESSION_CACHE"::SessionCache"), out;
 424         DDFJanitor jin(in);
 425         in.structure();
 426         in.addmember("key").string(getID());
 427         in.addmember("version").integer(m_obj["version"].integer());
 428         if (*timeout) {
 429             // On 64-bit Windows, time_t doesn't fit in a long, so I'm using ISO timestamps.
 430 #ifndef HAVE_GMTIME_R
 431             struct tm* ptime=gmtime(timeout);
 432 #else
 433             struct tm res;
 434             struct tm* ptime=gmtime_r(timeout,&res);
 435 #endif
 436             char timebuf[32];
 437             strftime(timebuf,32,"%Y-%m-%dT%H:%M:%SZ",ptime);
 438             in.addmember("timeout").string(timebuf);
 439         }
 440
 441         try {
 442             out=application.getServiceProvider().getListenerService()->send(in);
 443         }
 444         catch (...) {
 445             out.destroy();
 446             throw;
 447         }
 448
 449         if (out.isstruct()) {
 450             // We got an updated record back.
 451             m_ids.clear();
 452             for_each(m_attributes.begin(), m_attributes.end(), xmltooling::cleanup<Attribute>());
 453             m_attributes.clear();
 454             m_attributeIndex.clear();
 455             m_obj.destroy();
 456             m_obj = out;
 457         }
 458     }
 459     else {
 460 #ifndef SHIBSP_LITE
 461         if (!m_cache->m_storage)
 462             throw ConfigurationException("Session touch requires a StorageService.");
 463
 464         // Do a versioned read.
 465         string record;
 466         time_t lastAccess;
 467         int curver = m_obj["version"].integer();
 468         int ver = m_cache->m_storage->readText(getID(), "session", &record, &lastAccess, curver);
 469         if (ver == 0) {
 470             m_cache->m_log.warn("unsuccessful versioned read of session (ID: %s), cache out of sync?", getID());
 471             throw RetryableProfileException("Your session has expired, and you must re-authenticate.");
 472         }
 473
 474         // Adjust for expiration to recover last access time and check timeout.
 475         lastAccess -= m_cache->m_cacheTimeout;
 476         if (*timeout > 0 && now - lastAccess >= *timeout) {
 477             m_cache->m_log.info("session timed out (ID: %s)", getID());
 478             throw RetryableProfileException("Your session has expired, and you must re-authenticate.");
 479         }
 480
 481         // Update storage expiration, if possible.
 482         try {
 483             m_cache->m_storage->updateContext(getID(), now + m_cache->m_cacheTimeout);
 484         }
 485         catch (exception& ex) {
 486             m_cache->m_log.error("failed to update session expiration: %s", ex.what());
 487         }
 488
 489         if (ver > curver) {
 490             // We got an updated record back.
 491             DDF newobj;
 492             istringstream in(record);
 493             in >> newobj;
 494             m_ids.clear();
 495             for_each(m_attributes.begin(), m_attributes.end(), xmltooling::cleanup<Attribute>());
 496             m_attributes.clear();
 497             m_attributeIndex.clear();
 498             m_obj.destroy();
 499             m_obj = newobj;
 500         }
 501 #else
 502         throw ConfigurationException("Session touch requires a StorageService.");
 503 #endif
 504     }
 505
 506     m_lastAccess = now;
 507 }
 508
 509 #ifndef SHIBSP_LITE
 510
 511 void StoredSession::addAttributes(const vector<Attribute*>& attributes)
 512 {
 513 #ifdef _DEBUG
 514     xmltooling::NDC ndc("addAttributes");
 515 #endif
 516
 517     if (!m_cache->m_storage)
 518         throw ConfigurationException("Session modification requires a StorageService.");
 519
 520     m_cache->m_log.debug("adding attributes to session (%s)", getID());
 521
 522     int ver;
 523     do {
 524         DDF attr;
 525         DDF attrs = m_obj["attributes"];
 526         if (!attrs.islist())
 527             attrs = m_obj.addmember("attributes").list();
 528         for (vector<Attribute*>::const_iterator a=attributes.begin(); a!=attributes.end(); ++a) {
 529             attr = (*a)->marshall();
 530             attrs.add(attr);
 531         }
 532
 533         // Tentatively increment the version.
 534         m_obj["version"].integer(m_obj["version"].integer()+1);
 535
 536         ostringstream str;
 537         str << m_obj;
 538         string record(str.str());
 539
 540         try {
 541             ver = m_cache->m_storage->updateText(getID(), "session", record.c_str(), 0, m_obj["version"].integer()-1);
 542         }
 543         catch (exception&) {
 544             // Roll back modification to record.
 545             m_obj["version"].integer(m_obj["version"].integer()-1);
 546             vector<Attribute*>::size_type count = attributes.size();
 547             while (count--)
 548                 attrs.last().destroy();
 549             throw;
 550         }
 551
 552         if (ver <= 0) {
 553             // Roll back modification to record.
 554             m_obj["version"].integer(m_obj["version"].integer()-1);
 555             vector<Attribute*>::size_type count = attributes.size();
 556             while (count--)
 557                 attrs.last().destroy();
 558         }
 559         if (!ver) {
 560             // Fatal problem with update.
 561             throw IOException("Unable to update stored session.");
 562         }
 563         else if (ver < 0) {
 564             // Out of sync.
 565             m_cache->m_log.warn("storage service indicates the record is out of sync, updating with a fresh copy...");
 566             ver = m_cache->m_storage->readText(getID(), "session", &record, nullptr);
 567             if (!ver) {
 568                 m_cache->m_log.error("readText failed on StorageService for session (%s)", getID());
 569                 throw IOException("Unable to read back stored session.");
 570             }
 571
 572             // Reset object.
 573             DDF newobj;
 574             istringstream in(record);
 575             in >> newobj;
 576
 577             m_ids.clear();
 578             for_each(m_attributes.begin(), m_attributes.end(), xmltooling::cleanup<Attribute>());
 579             m_attributes.clear();
 580             m_attributeIndex.clear();
 581             newobj["version"].integer(ver);
 582             m_obj.destroy();
 583             m_obj = newobj;
 584
 585             ver = -1;
 586         }
 587     } while (ver < 0);  // negative indicates a sync issue so we retry
 588
 589     TransactionLog* xlog = SPConfig::getConfig().getServiceProvider()->getTransactionLog();
 590     Locker locker(xlog);
 591     xlog->log.infoStream() <<
 592         "Added the following attributes to session (ID: " <<
 593             getID() <<
 594         ") for (applicationId: " <<
 595             m_obj["application_id"].string() <<
 596         ") {";
 597     for (vector<Attribute*>::const_iterator a=attributes.begin(); a!=attributes.end(); ++a)
 598         xlog->log.infoStream() << "\t" << (*a)->getId() << " (" << (*a)->valueCount() << " values)";
 599     xlog->log.info("}");
 600
 601     // We own them now, so clean them up.
 602     for_each(attributes.begin(), attributes.end(), xmltooling::cleanup<Attribute>());
 603 }
 604
 605 const Assertion* StoredSession::getAssertion(const char* id) const
 606 {
 607     if (!m_cache->m_storage)
 608         throw ConfigurationException("Assertion retrieval requires a StorageService.");
 609
 610     map<string,Assertion*>::const_iterator i = m_tokens.find(id);
 611     if (i!=m_tokens.end())
 612         return i->second;
 613
 614     string tokenstr;
 615     if (!m_cache->m_storage->readText(getID(), id, &tokenstr, nullptr))
 616         throw FatalProfileException("Assertion not found in cache.");
 617
 618     // Parse and bind the document into an XMLObject.
 619     istringstream instr(tokenstr);
 620     DOMDocument* doc = XMLToolingConfig::getConfig().getParser().parse(instr);
 621     XercesJanitor<DOMDocument> janitor(doc);
 622     auto_ptr<XMLObject> xmlObject(XMLObjectBuilder::buildOneFromElement(doc->getDocumentElement(), true));
 623     janitor.release();
 624
 625     Assertion* token = dynamic_cast<Assertion*>(xmlObject.get());
 626     if (!token)
 627         throw FatalProfileException("Request for cached assertion returned an unknown object type.");
 628
 629     // Transfer ownership to us.
 630     xmlObject.release();
 631     m_tokens[id]=token;
 632     return token;
 633 }
 634
 635 void StoredSession::addAssertion(Assertion* assertion)
 636 {
 637 #ifdef _DEBUG
 638     xmltooling::NDC ndc("addAssertion");
 639 #endif
 640
 641     if (!m_cache->m_storage)
 642         throw ConfigurationException("Session modification requires a StorageService.");
 643
 644     if (!assertion)
 645         throw FatalProfileException("Unknown object type passed to session for storage.");
 646
 647     auto_ptr_char id(assertion->getID());
 648
 649     m_cache->m_log.debug("adding assertion (%s) to session (%s)", id.get(), getID());
 650
 651     time_t exp;
 652     if (!m_cache->m_storage->readText(getID(), "session", nullptr, &exp))
 653         throw IOException("Unable to load expiration time for stored session.");
 654
 655     ostringstream tokenstr;
 656     tokenstr << *assertion;
 657     if (!m_cache->m_storage->createText(getID(), id.get(), tokenstr.str().c_str(), exp))
 658         throw IOException("Attempted to insert duplicate assertion ID into session.");
 659
 660     int ver;
 661     do {
 662         DDF token = DDF(nullptr).string(id.get());
 663         m_obj["assertions"].add(token);
 664
 665         // Tentatively increment the version.
 666         m_obj["version"].integer(m_obj["version"].integer()+1);
 667
 668         ostringstream str;
 669         str << m_obj;
 670         string record(str.str());
 671
 672         try {
 673             ver = m_cache->m_storage->updateText(getID(), "session", record.c_str(), 0, m_obj["version"].integer()-1);
 674         }
 675         catch (exception&) {
 676             token.destroy();
 677             m_obj["version"].integer(m_obj["version"].integer()-1);
 678             m_cache->m_storage->deleteText(getID(), id.get());
 679             throw;
 680         }
 681
 682         if (ver <= 0) {
 683             token.destroy();
 684             m_obj["version"].integer(m_obj["version"].integer()-1);
 685         }
 686         if (!ver) {
 687             // Fatal problem with update.
 688             m_cache->m_log.error("updateText failed on StorageService for session (%s)", getID());
 689             m_cache->m_storage->deleteText(getID(), id.get());
 690             throw IOException("Unable to update stored session.");
 691         }
 692         else if (ver < 0) {
 693             // Out of sync.
 694             m_cache->m_log.warn("storage service indicates the record is out of sync, updating with a fresh copy...");
 695             ver = m_cache->m_storage->readText(getID(), "session", &record, nullptr);
 696             if (!ver) {
 697                 m_cache->m_log.error("readText failed on StorageService for session (%s)", getID());
 698                 m_cache->m_storage->deleteText(getID(), id.get());
 699                 throw IOException("Unable to read back stored session.");
 700             }
 701
 702             // Reset object.
 703             DDF newobj;
 704             istringstream in(record);
 705             in >> newobj;
 706
 707             m_ids.clear();
 708             for_each(m_attributes.begin(), m_attributes.end(), xmltooling::cleanup<Attribute>());
 709             m_attributes.clear();
 710             m_attributeIndex.clear();
 711             newobj["version"].integer(ver);
 712             m_obj.destroy();
 713             m_obj = newobj;
 714
 715             ver = -1;
 716         }
 717     } while (ver < 0); // negative indicates a sync issue so we retry
 718
 719     m_ids.clear();
 720     delete assertion;
 721
 722     TransactionLog* xlog = SPConfig::getConfig().getServiceProvider()->getTransactionLog();
 723     Locker locker(xlog);
 724     xlog->log.info(
 725         "Added assertion (ID: %s) to session for (applicationId: %s) with (ID: %s)",
 726         id.get(), m_obj["application_id"].string(), getID()
 727         );
 728 }
 729
 730 #endif
 731
 732 SessionCache::SessionCache()
 733 {
 734 }
 735
 736 SessionCache::~SessionCache()
 737 {
 738 }
 739
 740 SessionCacheEx::SessionCacheEx()
 741 {
 742 }
 743
 744 SessionCacheEx::~SessionCacheEx()
 745 {
 746 }
 747
 748 SSCache::SSCache(const DOMElement* e)
 749     : m_log(Category::getInstance(SHIBSP_LOGCAT".SessionCache")), inproc(true), m_cacheTimeout(28800),
 750 #ifndef SHIBSP_LITE
 751       m_storage(nullptr), m_storage_lite(nullptr), m_cacheAssertions(true),
 752 #endif
 753       m_root(e), m_inprocTimeout(900), m_lock(nullptr), shutdown(false), shutdown_wait(nullptr), cleanup_thread(nullptr)
 754 {
 755     SPConfig& conf = SPConfig::getConfig();
 756     inproc = conf.isEnabled(SPConfig::InProcess);
 757
 758     static const XMLCh cacheAssertions[] =  UNICODE_LITERAL_15(c,a,c,h,e,A,s,s,e,r,t,i,o,n,s);
 759     static const XMLCh cacheTimeout[] =     UNICODE_LITERAL_12(c,a,c,h,e,T,i,m,e,o,u,t);
 760     static const XMLCh inprocTimeout[] =    UNICODE_LITERAL_13(i,n,p,r,o,c,T,i,m,e,o,u,t);
 761     static const XMLCh _StorageService[] =  UNICODE_LITERAL_14(S,t,o,r,a,g,e,S,e,r,v,i,c,e);
 762     static const XMLCh _StorageServiceLite[] = UNICODE_LITERAL_18(S,t,o,r,a,g,e,S,e,r,v,i,c,e,L,i,t,e);
 763
 764     m_cacheTimeout = XMLHelper::getAttrInt(e, 28800, cacheTimeout);
 765     if (inproc)
 766         m_inprocTimeout = XMLHelper::getAttrInt(e, 900, inprocTimeout);
 767
 768 #ifndef SHIBSP_LITE
 769     if (conf.isEnabled(SPConfig::OutOfProcess)) {
 770         string ssid = XMLHelper::getAttrString(e, nullptr, _StorageService);
 771         if (!ssid.empty()) {
 772             m_storage = conf.getServiceProvider()->getStorageService(ssid.c_str());
 773             if (m_storage)
 774                 m_log.info("bound to StorageService (%s)", ssid.c_str());
 775         }
 776         if (!m_storage)
 777             throw ConfigurationException("SessionCache unable to locate StorageService, check configuration.");
 778
 779         ssid = XMLHelper::getAttrString(e, nullptr, _StorageServiceLite);
 780         if (!ssid.empty()) {
 781             m_storage_lite = conf.getServiceProvider()->getStorageService(ssid.c_str());
 782             if (m_storage_lite)
 783                 m_log.info("bound to StorageServiceLite (%s)", ssid.c_str());
 784         }
 785         if (!m_storage_lite) {
 786             m_log.info("No StorageServiceLite specified. Using standard StorageService.");
 787             m_storage_lite = m_storage;
 788         }
 789
 790         m_cacheAssertions = XMLHelper::getAttrBool(e, true, cacheAssertions);
 791     }
 792 #endif
 793
 794     ListenerService* listener=conf.getServiceProvider()->getListenerService(false);
 795     if (inproc) {
 796         if (!conf.isEnabled(SPConfig::OutOfProcess) && !listener)
 797             throw ConfigurationException("SessionCache requires a ListenerService, but none available.");
 798         m_lock = RWLock::create();
 799         shutdown_wait = CondWait::create();
 800         cleanup_thread = Thread::create(&cleanup_fn, this);
 801     }
 802 #ifndef SHIBSP_LITE
 803     else {
 804         if (listener && conf.isEnabled(SPConfig::OutOfProcess)) {
 805             listener->regListener("find::"STORAGESERVICE_SESSION_CACHE"::SessionCache",this);
 806             listener->regListener("remove::"STORAGESERVICE_SESSION_CACHE"::SessionCache",this);
 807             listener->regListener("touch::"STORAGESERVICE_SESSION_CACHE"::SessionCache",this);
 808         }
 809         else {
 810             m_log.info("no ListenerService available, cache remoting disabled");
 811         }
 812     }
 813 #endif
 814 }
 815
 816 SSCache::~SSCache()
 817 {
 818     if (inproc) {
 819         // Shut down the cleanup thread and let it know...
 820         shutdown = true;
 821         shutdown_wait->signal();
 822         cleanup_thread->join(nullptr);
 823
 824         for_each(m_hashtable.begin(),m_hashtable.end(),cleanup_pair<string,StoredSession>());
 825         delete m_lock;
 826
 827         delete cleanup_thread;
 828         delete shutdown_wait;
 829     }
 830 #ifndef SHIBSP_LITE
 831     else {
 832         SPConfig& conf = SPConfig::getConfig();
 833         ListenerService* listener=conf.getServiceProvider()->getListenerService(false);
 834         if (listener && conf.isEnabled(SPConfig::OutOfProcess)) {
 835             listener->unregListener("find::"STORAGESERVICE_SESSION_CACHE"::SessionCache",this);
 836             listener->unregListener("remove::"STORAGESERVICE_SESSION_CACHE"::SessionCache",this);
 837             listener->unregListener("touch::"STORAGESERVICE_SESSION_CACHE"::SessionCache",this);
 838         }
 839     }
 840 #endif
 841 }
 842
 843 #ifndef SHIBSP_LITE
 844
 845 void SSCache::test()
 846 {
 847     auto_ptr_char temp(SAMLConfig::getConfig().generateIdentifier());
 848     m_storage->createString("SessionCacheTest", temp.get(), "Test", time(nullptr) + 60);
 849     m_storage->deleteString("SessionCacheTest", temp.get());
 850 }
 851
 852 void SSCache::insert(const char* key, time_t expires, const char* name, const char* index)
 853 {
 854     string dup;
 855     if (strlen(name) > 255) {
 856         dup = string(name).substr(0,255);
 857         name = dup.c_str();
 858     }
 859
 860     DDF obj;
 861     DDFJanitor jobj(obj);
 862
 863     // Since we can't guarantee uniqueness, check for an existing record.
 864     string record;
 865     time_t recordexp;
 866     int ver = m_storage_lite->readText("NameID", name, &record, &recordexp);
 867     if (ver > 0) {
 868         // Existing record, so we need to unmarshall it.
 869         istringstream in(record);
 870         in >> obj;
 871     }
 872     else {
 873         // New record.
 874         obj = DDF(nullptr).structure();
 875     }
 876
 877     if (!index || !*index)
 878         index = "_shibnull";
 879     DDF sessions = obj.addmember(index);
 880     if (!sessions.islist())
 881         sessions.list();
 882     DDF session = DDF(nullptr).string(key);
 883     sessions.add(session);
 884
 885     // Remarshall the record.
 886     ostringstream out;
 887     out << obj;
 888
 889     // Try and store it back...
 890     if (ver > 0) {
 891         ver = m_storage_lite->updateText("NameID", name, out.str().c_str(), max(expires, recordexp), ver);
 892         if (ver <= 0) {
 893             // Out of sync, or went missing, so retry.
 894             return insert(key, expires, name, index);
 895         }
 896     }
 897     else if (!m_storage_lite->createText("NameID", name, out.str().c_str(), expires)) {
 898         // Hit a dup, so just retry, hopefully hitting the other branch.
 899         return insert(key, expires, name, index);
 900     }
 901 }
 902
 903 void SSCache::insert(
 904     const Application& application,
 905     const HTTPRequest& httpRequest,
 906     HTTPResponse& httpResponse,
 907     time_t expires,
 908     const saml2md::EntityDescriptor* issuer,
 909     const XMLCh* protocol,
 910     const saml2::NameID* nameid,
 911     const XMLCh* authn_instant,
 912     const XMLCh* session_index,
 913     const XMLCh* authncontext_class,
 914     const XMLCh* authncontext_decl,
 915     const vector<const Assertion*>* tokens,
 916     const vector<Attribute*>* attributes
 917     )
 918 {
 919 #ifdef _DEBUG
 920     xmltooling::NDC ndc("insert");
 921 #endif
 922     if (!m_storage)
 923         throw ConfigurationException("SessionCache insertion requires a StorageService.");
 924
 925     m_log.debug("creating new session");
 926
 927     time_t now = time(nullptr);
 928     auto_ptr_char index(session_index);
 929     auto_ptr_char entity_id(issuer ? issuer->getEntityID() : nullptr);
 930     auto_ptr_char name(nameid ? nameid->getName() : nullptr);
 931
 932     if (nameid) {
 933         // Check for a pending logout.
 934         if (strlen(name.get()) > 255)
 935             const_cast<char*>(name.get())[255] = 0;
 936         string pending;
 937         int ver = m_storage_lite->readText("Logout", name.get(), &pending);
 938         if (ver > 0) {
 939             DDF pendobj;
 940             DDFJanitor jpend(pendobj);
 941             istringstream pstr(pending);
 942             pstr >> pendobj;
 943             // IdP.SP.index contains logout expiration, if any.
 944             DDF deadmenwalking = pendobj[issuer ? entity_id.get() : "_shibnull"][application.getRelyingParty(issuer)->getString("entityID").second];
 945             const char* logexpstr = deadmenwalking[session_index ? index.get() : "_shibnull"].string();
 946             if (!logexpstr && session_index)    // we tried an exact session match, now try for nullptr
 947                 logexpstr = deadmenwalking["_shibnull"].string();
 948             if (logexpstr) {
 949                 auto_ptr_XMLCh dt(logexpstr);
 950                 DateTime dtobj(dt.get());
 951                 dtobj.parseDateTime();
 952                 time_t logexp = dtobj.getEpoch();
 953                 if (now - XMLToolingConfig::getConfig().clock_skew_secs < logexp)
 954                     throw FatalProfileException("A logout message from your identity provider has blocked your login attempt.");
 955             }
 956         }
 957     }
 958
 959     auto_ptr_char key(SAMLConfig::getConfig().generateIdentifier());
 960
 961     // Store session properties in DDF.
 962     DDF obj = DDF(key.get()).structure();
 963     DDFJanitor entryobj(obj);
 964     obj.addmember("version").integer(1);
 965     obj.addmember("application_id").string(application.getId());
 966
 967     // On 64-bit Windows, time_t doesn't fit in a long, so I'm using ISO timestamps.
 968 #ifndef HAVE_GMTIME_R
 969     struct tm* ptime=gmtime(&expires);
 970 #else
 971     struct tm res;
 972     struct tm* ptime=gmtime_r(&expires,&res);
 973 #endif
 974     char timebuf[32];
 975     strftime(timebuf,32,"%Y-%m-%dT%H:%M:%SZ",ptime);
 976     obj.addmember("expires").string(timebuf);
 977
 978     obj.addmember("client_addr").string(httpRequest.getRemoteAddr().c_str());
 979     if (issuer)
 980         obj.addmember("entity_id").string(entity_id.get());
 981     if (protocol) {
 982         auto_ptr_char prot(protocol);
 983         obj.addmember("protocol").string(prot.get());
 984     }
 985     if (authn_instant) {
 986         auto_ptr_char instant(authn_instant);
 987         obj.addmember("authn_instant").string(instant.get());
 988     }
 989     if (session_index)
 990         obj.addmember("session_index").string(index.get());
 991     if (authncontext_class) {
 992         auto_ptr_char ac(authncontext_class);
 993         obj.addmember("authncontext_class").string(ac.get());
 994     }
 995     if (authncontext_decl) {
 996         auto_ptr_char ad(authncontext_decl);
 997         obj.addmember("authncontext_decl").string(ad.get());
 998     }
 999
1000     if (nameid) {
1001         ostringstream namestr;
1002         namestr << *nameid;
1003         obj.addmember("nameid").string(namestr.str().c_str());
1004     }
1005
1006     if (tokens && m_cacheAssertions) {
1007         obj.addmember("assertions").list();
1008         for (vector<const Assertion*>::const_iterator t = tokens->begin(); t!=tokens->end(); ++t) {
1009             auto_ptr_char tokenid((*t)->getID());
1010             DDF tokid = DDF(nullptr).string(tokenid.get());
1011             obj["assertions"].add(tokid);
1012         }
1013     }
1014
1015     if (attributes) {
1016         DDF attr;
1017         DDF attrlist = obj.addmember("attributes").list();
1018         for (vector<Attribute*>::const_iterator a=attributes->begin(); a!=attributes->end(); ++a) {
1019             attr = (*a)->marshall();
1020             attrlist.add(attr);
1021         }
1022     }
1023
1024     ostringstream record;
1025     record << obj;
1026
1027     m_log.debug("storing new session...");
1028     if (!m_storage->createText(key.get(), "session", record.str().c_str(), now + m_cacheTimeout))
1029         throw FatalProfileException("Attempted to create a session with a duplicate key.");
1030
1031     // Store the reverse mapping for logout.
1032     try {
1033         if (nameid)
1034             insert(key.get(), expires, name.get(), index.get());
1035     }
1036     catch (exception& ex) {
1037         m_log.error("error storing back mapping of NameID for logout: %s", ex.what());
1038     }
1039
1040     if (tokens && m_cacheAssertions) {
1041         try {
1042             for (vector<const Assertion*>::const_iterator t = tokens->begin(); t!=tokens->end(); ++t) {
1043                 ostringstream tokenstr;
1044                 tokenstr << *(*t);
1045                 auto_ptr_char tokenid((*t)->getID());
1046                 if (!m_storage->createText(key.get(), tokenid.get(), tokenstr.str().c_str(), now + m_cacheTimeout))
1047                     throw IOException("duplicate assertion ID ($1)", params(1, tokenid.get()));
1048             }
1049         }
1050         catch (exception& ex) {
1051             m_log.error("error storing assertion along with session: %s", ex.what());
1052         }
1053     }
1054
1055     const char* pid = obj["entity_id"].string();
1056     const char* prot = obj["protocol"].string();
1057     m_log.info("new session created: ID (%s) IdP (%s) Protocol(%s) Address (%s)",
1058         key.get(), pid ? pid : "none", prot ? prot : "none", httpRequest.getRemoteAddr().c_str());
1059
1060     // Transaction Logging
1061     string primaryAssertionID("none");
1062     if (m_cacheAssertions) {
1063         if (tokens)
1064             primaryAssertionID = obj["assertions"].first().string();
1065     }
1066     else if (tokens) {
1067         auto_ptr_char tokenid(tokens->front()->getID());
1068         primaryAssertionID = tokenid.get();
1069     }
1070     TransactionLog* xlog = application.getServiceProvider().getTransactionLog();
1071     Locker locker(xlog);
1072     xlog->log.infoStream() <<
1073         "New session (ID: " <<
1074             key.get() <<
1075         ") with (applicationId: " <<
1076             application.getId() <<
1077         ") for principal from (IdP: " <<
1078             (pid ? pid : "none") <<
1079         ") at (ClientAddress: " <<
1080             httpRequest.getRemoteAddr() <<
1081         ") with (NameIdentifier: " <<
1082             (nameid ? name.get() : "none") <<
1083         ") using (Protocol: " <<
1084             (prot ? prot : "none") <<
1085         ") from (AssertionID: " <<
1086             primaryAssertionID <<
1087         ")";
1088
1089     if (attributes) {
1090         xlog->log.infoStream() <<
1091             "Cached the following attributes with session (ID: " <<
1092                 key.get() <<
1093             ") for (applicationId: " <<
1094                 application.getId() <<
1095             ") {";
1096         for (vector<Attribute*>::const_iterator a=attributes->begin(); a!=attributes->end(); ++a)
1097             xlog->log.infoStream() << "\t" << (*a)->getId() << " (" << (*a)->valueCount() << " values)";
1098         xlog->log.info("}");
1099     }
1100
1101     time_t cookieLifetime = 0;
1102     pair<string,const char*> shib_cookie = application.getCookieNameProps("_shibsession_", &cookieLifetime);
1103     string k(key.get());
1104     k += shib_cookie.second;
1105
1106     if (cookieLifetime > 0) {
1107         cookieLifetime += now;
1108 #ifndef HAVE_GMTIME_R
1109         ptime=gmtime(&cookieLifetime);
1110 #else
1111         ptime=gmtime_r(&cookieLifetime,&res);
1112 #endif
1113         char cookietimebuf[64];
1114         strftime(cookietimebuf,64,"; expires=%a, %d %b %Y %H:%M:%S GMT",ptime);
1115         k += cookietimebuf;
1116     }
1117
1118     httpResponse.setCookie(shib_cookie.first.c_str(), k.c_str());
1119 }
1120
1121 bool SSCache::matches(
1122     const Application& application,
1123     const xmltooling::HTTPRequest& request,
1124     const saml2md::EntityDescriptor* issuer,
1125     const saml2::NameID& nameid,
1126     const set<string>* indexes
1127     )
1128 {
1129     auto_ptr_char entityID(issuer ? issuer->getEntityID() : nullptr);
1130     try {
1131         Session* session = find(application, request);
1132         if (session) {
1133             Locker locker(session, false);
1134             if (XMLString::equals(session->getEntityID(), entityID.get()) && session->getNameID() &&
1135                     stronglyMatches(issuer->getEntityID(), application.getRelyingParty(issuer)->getXMLString("entityID").second, nameid, *session->getNameID())) {
1136                 return (!indexes || indexes->empty() || (session->getSessionIndex() ? (indexes->count(session->getSessionIndex())>0) : false));
1137             }
1138         }
1139     }
1140     catch (exception& ex) {
1141         m_log.error("error while matching session: %s", ex.what());
1142     }
1143     return false;
1144 }
1145
1146 vector<string>::size_type SSCache::logout(
1147     const Application& application,
1148     const saml2md::EntityDescriptor* issuer,
1149     const saml2::NameID& nameid,
1150     const set<string>* indexes,
1151     time_t expires,
1152     vector<string>& sessionsKilled
1153     )
1154 {
1155 #ifdef _DEBUG
1156     xmltooling::NDC ndc("logout");
1157 #endif
1158
1159     if (!m_storage)
1160         throw ConfigurationException("SessionCache insertion requires a StorageService.");
1161
1162     auto_ptr_char entityID(issuer ? issuer->getEntityID() : nullptr);
1163     auto_ptr_char name(nameid.getName());
1164
1165     m_log.info("request to logout sessions from (%s) for (%s)", entityID.get() ? entityID.get() : "unknown", name.get());
1166
1167     if (strlen(name.get()) > 255)
1168         const_cast<char*>(name.get())[255] = 0;
1169
1170     DDF obj;
1171     DDFJanitor jobj(obj);
1172     string record;
1173     int ver;
1174
1175     if (expires) {
1176         // Record the logout to prevent post-delivered assertions.
1177         // On 64-bit Windows, time_t doesn't fit in a long, so I'm using ISO timestamps.
1178 #ifndef HAVE_GMTIME_R
1179         struct tm* ptime=gmtime(&expires);
1180 #else
1181         struct tm res;
1182         struct tm* ptime=gmtime_r(&expires,&res);
1183 #endif
1184         char timebuf[32];
1185         strftime(timebuf,32,"%Y-%m-%dT%H:%M:%SZ",ptime);
1186
1187         time_t oldexp = 0;
1188         ver = m_storage_lite->readText("Logout", name.get(), &record, &oldexp);
1189         if (ver > 0) {
1190             istringstream lin(record);
1191             lin >> obj;
1192         }
1193         else {
1194             obj = DDF(nullptr).structure();
1195         }
1196
1197         // Structure is keyed by the IdP and SP, with a member per session index containing the expiration.
1198         DDF root = obj.addmember(issuer ? entityID.get() : "_shibnull").addmember(application.getRelyingParty(issuer)->getString("entityID").second);
1199         if (indexes) {
1200             for (set<string>::const_iterator x = indexes->begin(); x!=indexes->end(); ++x)
1201                 root.addmember(x->c_str()).string(timebuf);
1202         }
1203         else {
1204             root.addmember("_shibnull").string(timebuf);
1205         }
1206
1207         // Write it back.
1208         ostringstream lout;
1209         lout << obj;
1210
1211         if (ver > 0) {
1212             ver = m_storage_lite->updateText("Logout", name.get(), lout.str().c_str(), max(expires, oldexp), ver);
1213             if (ver <= 0) {
1214                 // Out of sync, or went missing, so retry.
1215                 return logout(application, issuer, nameid, indexes, expires, sessionsKilled);
1216             }
1217         }
1218         else if (!m_storage_lite->createText("Logout", name.get(), lout.str().c_str(), expires)) {
1219             // Hit a dup, so just retry, hopefully hitting the other branch.
1220             return logout(application, issuer, nameid, indexes, expires, sessionsKilled);
1221         }
1222
1223         obj.destroy();
1224         record.erase();
1225     }
1226
1227     // Read in potentially matching sessions.
1228     ver = m_storage_lite->readText("NameID", name.get(), &record);
1229     if (ver == 0) {
1230         m_log.debug("no active sessions to logout for supplied issuer and subject");
1231         return 0;
1232     }
1233
1234     istringstream in(record);
1235     in >> obj;
1236
1237     // The record contains child lists for each known session index.
1238     DDF key;
1239     DDF sessions = obj.first();
1240     while (sessions.islist()) {
1241         if (!indexes || indexes->empty() || indexes->count(sessions.name())) {
1242             key = sessions.first();
1243             while (key.isstring()) {
1244                 // Fetch the session for comparison.
1245                 Session* session = nullptr;
1246                 try {
1247                     session = find(application, key.string());
1248                 }
1249                 catch (exception& ex) {
1250                     m_log.error("error locating session (%s): %s", key.string(), ex.what());
1251                 }
1252
1253                 if (session) {
1254                     Locker locker(session, false);
1255                     // Same issuer?
1256                     if (XMLString::equals(session->getEntityID(), entityID.get())) {
1257                         // Same NameID?
1258                         if (stronglyMatches(issuer->getEntityID(), application.getRelyingParty(issuer)->getXMLString("entityID").second, nameid, *session->getNameID())) {
1259                             sessionsKilled.push_back(key.string());
1260                             key.destroy();
1261                         }
1262                         else {
1263                             m_log.debug("session (%s) contained a non-matching NameID, leaving it alone", key.string());
1264                         }
1265                     }
1266                     else {
1267                         m_log.debug("session (%s) established by different IdP, leaving it alone", key.string());
1268                     }
1269                 }
1270                 else {
1271                     // Session's gone, so...
1272                     sessionsKilled.push_back(key.string());
1273                     key.destroy();
1274                 }
1275                 key = sessions.next();
1276             }
1277
1278             // No sessions left for this index?
1279             if (sessions.first().isnull())
1280                 sessions.destroy();
1281         }
1282         sessions = obj.next();
1283     }
1284
1285     if (obj.first().isnull())
1286         obj.destroy();
1287
1288     // If possible, write back the mapping record (this isn't crucial).
1289     try {
1290         if (obj.isnull()) {
1291             m_storage_lite->deleteText("NameID", name.get());
1292         }
1293         else if (!sessionsKilled.empty()) {
1294             ostringstream out;
1295             out << obj;
1296             if (m_storage_lite->updateText("NameID", name.get(), out.str().c_str(), 0, ver) <= 0)
1297                 m_log.warn("logout mapping record changed behind us, leaving it alone");
1298         }
1299     }
1300     catch (exception& ex) {
1301         m_log.error("error updating logout mapping record: %s", ex.what());
1302     }
1303
1304     return sessionsKilled.size();
1305 }
1306
1307 bool SSCache::stronglyMatches(const XMLCh* idp, const XMLCh* sp, const saml2::NameID& n1, const saml2::NameID& n2) const
1308 {
1309     if (!XMLString::equals(n1.getName(), n2.getName()))
1310         return false;
1311
1312     const XMLCh* s1 = n1.getFormat();
1313     const XMLCh* s2 = n2.getFormat();
1314     if (!s1 || !*s1)
1315         s1 = saml2::NameID::UNSPECIFIED;
1316     if (!s2 || !*s2)
1317         s2 = saml2::NameID::UNSPECIFIED;
1318     if (!XMLString::equals(s1,s2))
1319         return false;
1320
1321     s1 = n1.getNameQualifier();
1322     s2 = n2.getNameQualifier();
1323     if (!s1 || !*s1)
1324         s1 = idp;
1325     if (!s2 || !*s2)
1326         s2 = idp;
1327     if (!XMLString::equals(s1,s2))
1328         return false;
1329
1330     s1 = n1.getSPNameQualifier();
1331     s2 = n2.getSPNameQualifier();
1332     if (!s1 || !*s1)
1333         s1 = sp;
1334     if (!s2 || !*s2)
1335         s2 = sp;
1336     if (!XMLString::equals(s1,s2))
1337         return false;
1338
1339     return true;
1340 }
1341
1342 #endif
1343
1344 Session* SSCache::find(const Application& application, const char* key, const char* client_addr, time_t* timeout)
1345 {
1346 #ifdef _DEBUG
1347     xmltooling::NDC ndc("find");
1348 #endif
1349     StoredSession* session=nullptr;
1350
1351     if (inproc) {
1352         m_log.debug("searching local cache for session (%s)", key);
1353         m_lock->rdlock();
1354         map<string,StoredSession*>::const_iterator i=m_hashtable.find(key);
1355         if (i!=m_hashtable.end()) {
1356             // Save off and lock the session.
1357             session = i->second;
1358             session->lock();
1359             m_lock->unlock();
1360             m_log.debug("session found locally, validating it for use");
1361         }
1362         else {
1363             m_lock->unlock();
1364         }
1365     }
1366
1367     if (!session) {
1368         if (!SPConfig::getConfig().isEnabled(SPConfig::OutOfProcess)) {
1369             m_log.debug("session not found locally, remoting the search");
1370             // Remote the request.
1371             DDF in("find::"STORAGESERVICE_SESSION_CACHE"::SessionCache"), out;
1372             DDFJanitor jin(in);
1373             in.structure();
1374             in.addmember("key").string(key);
1375             in.addmember("application_id").string(application.getId());
1376             if (timeout && *timeout) {
1377                 // On 64-bit Windows, time_t doesn't fit in a long, so I'm using ISO timestamps.
1378 #ifndef HAVE_GMTIME_R
1379                 struct tm* ptime=gmtime(timeout);
1380 #else
1381                 struct tm res;
1382                 struct tm* ptime=gmtime_r(timeout,&res);
1383 #endif
1384                 char timebuf[32];
1385                 strftime(timebuf,32,"%Y-%m-%dT%H:%M:%SZ",ptime);
1386                 in.addmember("timeout").string(timebuf);
1387             }
1388
1389             try {
1390                 out=application.getServiceProvider().getListenerService()->send(in);
1391                 if (!out.isstruct()) {
1392                     out.destroy();
1393                     m_log.debug("session not found in remote cache");
1394                     return nullptr;
1395                 }
1396
1397                 // Wrap the results in a local entry and save it.
1398                 session = new StoredSession(this, out);
1399                 // The remote end has handled timeout issues, we handle address and expiration checks.
1400                 timeout = nullptr;
1401             }
1402             catch (...) {
1403                 out.destroy();
1404                 throw;
1405             }
1406         }
1407         else {
1408             // We're out of process, so we can search the storage service directly.
1409 #ifndef SHIBSP_LITE
1410             if (!m_storage)
1411                 throw ConfigurationException("SessionCache lookup requires a StorageService.");
1412
1413             m_log.debug("searching for session (%s)", key);
1414
1415             DDF obj;
1416             time_t lastAccess;
1417             string record;
1418             int ver = m_storage->readText(key, "session", &record, &lastAccess);
1419             if (!ver)
1420                 return nullptr;
1421
1422             m_log.debug("reconstituting session and checking validity");
1423
1424             istringstream in(record);
1425             in >> obj;
1426
1427             lastAccess -= m_cacheTimeout;   // adjusts it back to the last time the record's timestamp was touched
1428             time_t now=time(nullptr);
1429
1430             if (timeout && *timeout > 0 && now - lastAccess >= *timeout) {
1431                 m_log.info("session timed out (ID: %s)", key);
1432                 remove(application, key);
1433                 const char* eid = obj["entity_id"].string();
1434                 if (!eid) {
1435                     obj.destroy();
1436                     throw RetryableProfileException("Your session has expired, and you must re-authenticate.");
1437                 }
1438                 string eid2(eid);
1439                 obj.destroy();
1440                 throw RetryableProfileException("Your session has expired, and you must re-authenticate.", namedparams(1, "entityID", eid2.c_str()));
1441             }
1442
1443             if (timeout) {
1444                 // Update storage expiration, if possible.
1445                 try {
1446                     m_storage->updateContext(key, now + m_cacheTimeout);
1447                 }
1448                 catch (exception& ex) {
1449                     m_log.error("failed to update session expiration: %s", ex.what());
1450                 }
1451             }
1452
1453             // Wrap the results in a local entry and save it.
1454             session = new StoredSession(this, obj);
1455             // We handled timeout issues, still need to handle address and expiration checks.
1456             timeout = nullptr;
1457 #else
1458             throw ConfigurationException("SessionCache search requires a StorageService.");
1459 #endif
1460         }
1461
1462         if (inproc) {
1463             // Lock for writing and repeat the search to avoid duplication.
1464             m_lock->wrlock();
1465             SharedLock shared(m_lock, false);
1466             if (m_hashtable.count(key)) {
1467                 // We're using an existing session entry.
1468                 delete session;
1469                 session = m_hashtable[key];
1470                 session->lock();
1471             }
1472             else {
1473                 m_hashtable[key]=session;
1474                 session->lock();
1475             }
1476         }
1477     }
1478
1479     if (!XMLString::equals(session->getApplicationID(), application.getId())) {
1480         m_log.error("an application (%s) tried to access another application's session", application.getId());
1481         session->unlock();
1482         return nullptr;
1483     }
1484
1485     // Verify currency and update the timestamp if indicated by caller.
1486     try {
1487         session->validate(application, client_addr, timeout);
1488     }
1489     catch (...) {
1490         session->unlock();
1491         remove(application, key);
1492         throw;
1493     }
1494
1495     return session;
1496 }
1497
1498 void SSCache::remove(const Application& application, const char* key)
1499 {
1500 #ifdef _DEBUG
1501     xmltooling::NDC ndc("remove");
1502 #endif
1503     // Take care of local copy.
1504     if (inproc)
1505         dormant(key);
1506
1507     if (SPConfig::getConfig().isEnabled(SPConfig::OutOfProcess)) {
1508         // Remove the session from storage directly.
1509 #ifndef SHIBSP_LITE
1510         m_storage->deleteContext(key);
1511         m_log.info("removed session (%s)", key);
1512
1513         TransactionLog* xlog = application.getServiceProvider().getTransactionLog();
1514         Locker locker(xlog);
1515         xlog->log.info("Destroyed session (applicationId: %s) (ID: %s)", application.getId(), key);
1516 #else
1517         throw ConfigurationException("SessionCache removal requires a StorageService.");
1518 #endif
1519     }
1520     else {
1521         // Remote the request.
1522         DDF in("remove::"STORAGESERVICE_SESSION_CACHE"::SessionCache");
1523         DDFJanitor jin(in);
1524         in.structure();
1525         in.addmember("key").string(key);
1526         in.addmember("application_id").string(application.getId());
1527
1528         DDF out = application.getServiceProvider().getListenerService()->send(in);
1529         out.destroy();
1530     }
1531 }
1532
1533 void SSCache::dormant(const char* key)
1534 {
1535 #ifdef _DEBUG
1536     xmltooling::NDC ndc("dormant");
1537 #endif
1538
1539     m_log.debug("deleting local copy of session (%s)", key);
1540
1541     // lock the cache for writing, which means we know nobody is sitting in find()
1542     m_lock->wrlock();
1543
1544     // grab the entry from the table
1545     map<string,StoredSession*>::const_iterator i=m_hashtable.find(key);
1546     if (i==m_hashtable.end()) {
1547         m_lock->unlock();
1548         return;
1549     }
1550
1551     // ok, remove the entry and lock it
1552     StoredSession* entry=i->second;
1553     m_hashtable.erase(key);
1554     entry->lock();
1555
1556     // unlock the cache
1557     m_lock->unlock();
1558
1559     // we can release the cache entry lock because we know we're not in the cache anymore
1560     entry->unlock();
1561
1562     delete entry;
1563 }
1564
1565 void* SSCache::cleanup_fn(void* p)
1566 {
1567 #ifdef _DEBUG
1568     xmltooling::NDC ndc("cleanup");
1569 #endif
1570
1571     SSCache* pcache = reinterpret_cast<SSCache*>(p);
1572
1573 #ifndef WIN32
1574     // First, let's block all signals
1575     Thread::mask_all_signals();
1576 #endif
1577
1578     auto_ptr<Mutex> mutex(Mutex::create());
1579
1580     // Load our configuration details...
1581     static const XMLCh cleanupInterval[] = UNICODE_LITERAL_15(c,l,e,a,n,u,p,I,n,t,e,r,v,a,l);
1582     const XMLCh* tag=pcache->m_root ? pcache->m_root->getAttributeNS(nullptr, cleanupInterval) : nullptr;
1583     int rerun_timer = 900;
1584     if (tag && *tag) {
1585         rerun_timer = XMLString::parseInt(tag);
1586         if (rerun_timer <= 0)
1587             rerun_timer = 900;
1588     }
1589
1590     mutex->lock();
1591
1592     pcache->m_log.info("cleanup thread started...run every %d secs; timeout after %d secs", rerun_timer, pcache->m_inprocTimeout);
1593
1594     while (!pcache->shutdown) {
1595         pcache->shutdown_wait->timedwait(mutex.get(), rerun_timer);
1596         if (pcache->shutdown)
1597             break;
1598
1599         // Ok, let's run through the cleanup process and clean out
1600         // really old sessions.  This is a two-pass process.  The
1601         // first pass is done holding a read-lock while we iterate over
1602         // the cache.  The second pass doesn't need a lock because
1603         // the 'deletes' will lock the cache.
1604
1605         // Pass 1: iterate over the map and find all entries that have not been
1606         // used in the allotted timeout.
1607         vector<string> stale_keys;
1608         time_t stale = time(nullptr) - pcache->m_inprocTimeout;
1609
1610         pcache->m_log.debug("cleanup thread running");
1611
1612         pcache->m_lock->rdlock();
1613         for (map<string,StoredSession*>::const_iterator i=pcache->m_hashtable.begin(); i!=pcache->m_hashtable.end(); ++i) {
1614             // If the last access was BEFORE the stale timeout...
1615             i->second->lock();
1616             time_t last=i->second->getLastAccess();
1617             i->second->unlock();
1618             if (last < stale)
1619                 stale_keys.push_back(i->first);
1620         }
1621         pcache->m_lock->unlock();
1622
1623         if (!stale_keys.empty()) {
1624             pcache->m_log.info("purging %d old sessions", stale_keys.size());
1625
1626             // Pass 2: walk through the list of stale entries and remove them from the cache
1627             for (vector<string>::const_iterator j = stale_keys.begin(); j != stale_keys.end(); ++j)
1628                 pcache->dormant(j->c_str());
1629         }
1630
1631         pcache->m_log.debug("cleanup thread completed");
1632     }
1633
1634     pcache->m_log.info("cleanup thread exiting");
1635
1636     mutex->unlock();
1637     return nullptr;
1638 }
1639
1640 #ifndef SHIBSP_LITE
1641
1642 void SSCache::receive(DDF& in, ostream& out)
1643 {
1644 #ifdef _DEBUG
1645     xmltooling::NDC ndc("receive");
1646 #endif
1647
1648     if (!strcmp(in.name(),"find::"STORAGESERVICE_SESSION_CACHE"::SessionCache")) {
1649         const char* key=in["key"].string();
1650         if (!key)
1651             throw ListenerException("Required parameters missing for session lookup.");
1652
1653         const Application* app = SPConfig::getConfig().getServiceProvider()->getApplication(in["application_id"].string());
1654         if (!app)
1655             throw ListenerException("Application not found, check configuration?");
1656
1657         // Do an unversioned read.
1658         string record;
1659         time_t lastAccess;
1660         if (!m_storage->readText(key, "session", &record, &lastAccess)) {
1661             DDF ret(nullptr);
1662             DDFJanitor jan(ret);
1663             out << ret;
1664             return;
1665         }
1666
1667         // Adjust for expiration to recover last access time and check timeout.
1668         lastAccess -= m_cacheTimeout;
1669         time_t now=time(nullptr);
1670
1671         // See if we need to check for a timeout.
1672         if (in["timeout"].string()) {
1673             time_t timeout = 0;
1674             auto_ptr_XMLCh dt(in["timeout"].string());
1675             DateTime dtobj(dt.get());
1676             dtobj.parseDateTime();
1677             timeout = dtobj.getEpoch();
1678
1679             if (timeout > 0 && now - lastAccess >= timeout) {
1680                 m_log.info("session timed out (ID: %s)", key);
1681                 remove(*app, key);
1682                 throw RetryableProfileException("Your session has expired, and you must re-authenticate.");
1683             }
1684
1685             // Update storage expiration, if possible.
1686             try {
1687                 m_storage->updateContext(key, now + m_cacheTimeout);
1688             }
1689             catch (exception& ex) {
1690                 m_log.error("failed to update session expiration: %s", ex.what());
1691             }
1692         }
1693
1694         // Send the record back.
1695         out << record;
1696     }
1697     else if (!strcmp(in.name(),"touch::"STORAGESERVICE_SESSION_CACHE"::SessionCache")) {
1698         const char* key=in["key"].string();
1699         if (!key)
1700             throw ListenerException("Required parameters missing for session check.");
1701
1702         // Do a versioned read.
1703         string record;
1704         time_t lastAccess;
1705         int curver = in["version"].integer();
1706         int ver = m_storage->readText(key, "session", &record, &lastAccess, curver);
1707         if (ver == 0) {
1708             m_log.warn("unsuccessful versioned read of session (ID: %s), caches out of sync?", key);
1709             throw RetryableProfileException("Your session has expired, and you must re-authenticate.");
1710         }
1711
1712         // Adjust for expiration to recover last access time and check timeout.
1713         lastAccess -= m_cacheTimeout;
1714         time_t now=time(nullptr);
1715
1716         // See if we need to check for a timeout.
1717         time_t timeout = 0;
1718         auto_ptr_XMLCh dt(in["timeout"].string());
1719         if (dt.get()) {
1720             DateTime dtobj(dt.get());
1721             dtobj.parseDateTime();
1722             timeout = dtobj.getEpoch();
1723         }
1724
1725         if (timeout > 0 && now - lastAccess >= timeout) {
1726             m_log.info("session timed out (ID: %s)", key);
1727             throw RetryableProfileException("Your session has expired, and you must re-authenticate.");
1728         }
1729
1730         // Update storage expiration, if possible.
1731         try {
1732             m_storage->updateContext(key, now + m_cacheTimeout);
1733         }
1734         catch (exception& ex) {
1735             m_log.error("failed to update session expiration: %s", ex.what());
1736         }
1737
1738         if (ver > curver) {
1739             // Send the record back.
1740             out << record;
1741         }
1742         else {
1743             DDF ret(nullptr);
1744             DDFJanitor jan(ret);
1745             out << ret;
1746         }
1747     }
1748     else if (!strcmp(in.name(),"remove::"STORAGESERVICE_SESSION_CACHE"::SessionCache")) {
1749         const char* key=in["key"].string();
1750         if (!key)
1751             throw ListenerException("Required parameter missing for session removal.");
1752
1753         const Application* app = SPConfig::getConfig().getServiceProvider()->getApplication(in["application_id"].string());
1754         if (!app)
1755             throw ConfigurationException("Application not found, check configuration?");
1756
1757         remove(*app, key);
1758         DDF ret(nullptr);
1759         DDFJanitor jan(ret);
1760         out << ret;
1761     }
1762 }
1763
1764 #endif