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