shibsp/impl/StorageServiceSessionCache.cpp

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