Add some debug/info logging for the shar cache cleanup thread
[shibboleth/cpp-sp.git] / shib-target / shib-ccache.cpp
1 /*
2  * The Shibboleth License, Version 1.
3  * Copyright (c) 2002
4  * University Corporation for Advanced Internet Development, Inc.
5  * All rights reserved
6  *
7  *
8  * Redistribution and use in source and binary forms, with or without
9  * modification, are permitted provided that the following conditions are met:
10  *
11  * Redistributions of source code must retain the above copyright notice, this
12  * list of conditions and the following disclaimer.
13  *
14  * Redistributions in binary form must reproduce the above copyright notice,
15  * this list of conditions and the following disclaimer in the documentation
16  * and/or other materials provided with the distribution, if any, must include
17  * the following acknowledgment: "This product includes software developed by
18  * the University Corporation for Advanced Internet Development
19  * <http://www.ucaid.edu>Internet2 Project. Alternately, this acknowledegement
20  * may appear in the software itself, if and wherever such third-party
21  * acknowledgments normally appear.
22  *
23  * Neither the name of Shibboleth nor the names of its contributors, nor
24  * Internet2, nor the University Corporation for Advanced Internet Development,
25  * Inc., nor UCAID may be used to endorse or promote products derived from this
26  * software without specific prior written permission. For written permission,
27  * please contact shibboleth@shibboleth.org
28  *
29  * Products derived from this software may not be called Shibboleth, Internet2,
30  * UCAID, or the University Corporation for Advanced Internet Development, nor
31  * may Shibboleth appear in their name, without prior written permission of the
32  * University Corporation for Advanced Internet Development.
33  *
34  *
35  * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
36  * AND WITH ALL FAULTS. ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
37  * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY, FITNESS FOR A
38  * PARTICULAR PURPOSE, AND NON-INFRINGEMENT ARE DISCLAIMED AND THE ENTIRE RISK
39  * OF SATISFACTORY QUALITY, PERFORMANCE, ACCURACY, AND EFFORT IS WITH LICENSEE.
40  * IN NO EVENT SHALL THE COPYRIGHT OWNER, CONTRIBUTORS OR THE UNIVERSITY
41  * CORPORATION FOR ADVANCED INTERNET DEVELOPMENT, INC. BE LIABLE FOR ANY DIRECT,
42  * INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
43  * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
44  * LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
45  * ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
46  * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
47  * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
48  */
49
50
51 /*
52  * shib-ccache.cpp -- SHAR Credential Cache
53  *
54  * Originally from mod_shib
55  * Modified by: Derek Atkins <derek@ihtfp.com>
56  *
57  * $Id$
58  */
59
60 #ifndef WIN32
61 # include <unistd.h>
62 #endif
63
64 #include "shib-target.h"
65 #include "shib-threads.h"
66
67 #include <log4cpp/Category.hh>
68
69 #include <sstream>
70 #include <stdexcept>
71
72 #ifdef HAVE_LIBDMALLOCXX
73 #include <dmalloc.h>
74 #endif
75
76 using namespace std;
77 using namespace saml;
78 using namespace shibboleth;
79 using namespace shibtarget;
80
81 class ResourceEntry
82 {
83 public:
84   ResourceEntry(SAMLResponse* response);
85   ~ResourceEntry();
86
87   bool isValid();
88   Iterator<SAMLAssertion*> getAssertions();
89
90   static vector<SAMLAssertion*> g_emptyVector;
91
92 private:
93   SAMLResponse* m_response;
94
95   log4cpp::Category* log;
96 };
97
98 class InternalCCache;
99 class InternalCCacheEntry : public CCacheEntry
100 {
101 public:
102   InternalCCacheEntry(SAMLAuthenticationStatement *s, const char *client_addr);
103   ~InternalCCacheEntry();
104
105   virtual Iterator<SAMLAssertion*> getAssertions(Resource& resource);
106   virtual bool isSessionValid(time_t lifetime, time_t timeout);
107   virtual const char* getClientAddress() { return m_clientAddress.c_str(); }
108
109   void setCache(InternalCCache *cache) { m_cache = cache; }
110   time_t lastAccess() { Lock lock(access_lock); return m_lastAccess; }
111
112 private:
113   ResourceEntry* populate(Resource& resource);
114   ResourceEntry* find(const char* resource);
115   void insert(const char* resource, ResourceEntry* entry);
116   void remove(const char* resource);
117
118   string m_originSite;
119   string m_handle;
120   string m_clientAddress;
121   time_t m_sessionCreated;
122   time_t m_lastAccess;
123   bool m_hasbinding;
124
125   const SAMLSubject* m_subject;
126   SAMLAuthenticationStatement* p_auth;
127   InternalCCache *m_cache;
128
129   map<string,ResourceEntry*> m_resources;
130
131   static saml::QName g_authorityKind;
132   static saml::QName g_respondWith;
133
134   log4cpp::Category* log;
135
136   // This is used to keep track of in-process "populate()" calls,
137   // to make sure that we don't try to populate the same resource
138   // in multiple threads.
139   map<string,Mutex*>    populate_locks;
140   Mutex*        pop_locks_lock;
141
142   Mutex*        access_lock;
143   RWLock*       resource_lock;
144
145   class ResourceLock
146   {
147   public:
148     ResourceLock(InternalCCacheEntry* entry, string resource);
149     ~ResourceLock();
150
151   private:
152     Mutex*                      find(string& resource);
153     InternalCCacheEntry*        entry;
154     string                      resource;
155   };
156 };
157
158 class InternalCCache : public CCache
159 {
160 public:
161   InternalCCache();
162   virtual ~InternalCCache();
163
164   virtual SAMLBinding* getBinding(const XMLCh* bindingProt);
165   virtual CCacheEntry* find(const char* key);
166   virtual void insert(const char* key, SAMLAuthenticationStatement *s,
167                       const char *client_addr);
168   virtual void remove(const char* key);
169
170   void  cleanup();
171 private:
172   SAMLBinding* m_SAMLBinding;
173   map<string,InternalCCacheEntry*> m_hashtable;
174
175   log4cpp::Category* log;
176   RWLock *lock;
177
178   static void*  cleanup_fcn(void*); // XXX Assumed an InternalCCache
179   bool          shutdown;
180   CondWait*     shutdown_wait;
181   Thread*       cleanup_thread;
182 };
183
184 // Global Constructors & Destructors
185 CCache::~CCache() { }
186
187 CCache* CCache::getInstance(const char* type)
188 {
189   return (CCache*) new InternalCCache();
190 }
191
192 // static members
193 saml::QName InternalCCacheEntry::g_authorityKind(saml::XML::SAMLP_NS,L(AttributeQuery));
194 saml::QName InternalCCacheEntry::g_respondWith(saml::XML::SAML_NS,L(AttributeStatement));
195 vector<SAMLAssertion*> ResourceEntry::g_emptyVector;
196
197
198 /******************************************************************************/
199 /* InternalCCache:  A Credential Cache                                        */
200 /******************************************************************************/
201
202 InternalCCache::InternalCCache()
203 {
204   m_SAMLBinding=SAMLBindingFactory::getInstance();
205   string ctx="shibtarget.InternalCCache";
206   log = &(log4cpp::Category::getInstance(ctx));
207   lock = RWLock::create();
208
209   shutdown_wait = CondWait::create();
210   shutdown = false;
211   cleanup_thread = Thread::create(&cleanup_fcn, (void*)this);
212 }
213
214 InternalCCache::~InternalCCache()
215 {
216   // Shut down the cleanup thread and let it know...
217   shutdown = true;
218   shutdown_wait->signal();
219   cleanup_thread->join(NULL);
220
221   delete m_SAMLBinding;
222   for (map<string,InternalCCacheEntry*>::iterator i=m_hashtable.begin(); i!=m_hashtable.end(); i++)
223     delete i->second;
224   delete lock;
225   delete shutdown_wait;
226 }
227
228 SAMLBinding* InternalCCache::getBinding(const XMLCh* bindingProt)
229 {
230   log->debug("looking for binding...");
231   if (!XMLString::compareString(bindingProt,SAMLBinding::SAML_SOAP_HTTPS)) {
232     log->debug("https binding found");
233     return m_SAMLBinding;
234   }
235   return NULL;
236 }
237
238 CCacheEntry* InternalCCache::find(const char* key)
239 {
240   log->debug("Find: \"%s\"", key);
241   ReadLock rwlock(lock);
242
243   map<string,InternalCCacheEntry*>::const_iterator i=m_hashtable.find(key);
244   if (i==m_hashtable.end()) {
245     log->debug("No Match found");
246     return NULL;
247   }
248   log->debug("Match Found.");
249   return dynamic_cast<CCacheEntry*>(i->second);
250 }
251
252 void InternalCCache::insert(const char* key, SAMLAuthenticationStatement *s,
253                             const char *client_addr)
254 {
255   log->debug("caching new entry for \"%s\"", key);
256
257   InternalCCacheEntry* entry = new InternalCCacheEntry (s, client_addr);
258   entry->setCache(this);
259
260   lock->wrlock();
261   m_hashtable[key]=entry;
262   lock->unlock();
263 }
264
265 void InternalCCache::remove(const char* key)
266 {
267   log->debug("removing cache entry \"key\"", key);
268
269   // XXX: FIXME? do we need to delete the CacheEntry?
270
271   lock->wrlock();
272   m_hashtable.erase(key);
273   lock->unlock();
274 }
275
276 void InternalCCache::cleanup()
277 {
278   Mutex* mutex = Mutex::create();
279   saml::NDC ndc("InternalCCache::cleanup()");
280
281   mutex->lock();
282
283   log->debug("Cleanup thread started...");
284
285   while (shutdown == false) {
286     struct timespec ts;
287     memset (&ts, 0, sizeof(ts));
288     ts.tv_sec = time(NULL) + 3600;      // run every hour
289
290     shutdown_wait->timedwait(mutex, &ts);
291
292     if (shutdown == true)
293       break;
294
295     log->info("Cleanup thread running...");
296
297     // Ok, let's run through the cleanup process and clean out
298     // really old sessions.  This is a two-pass process.  The
299     // first pass is done holding a read-lock while we iterate over
300     // the database.  The second pass doesn't need a lock because
301     // the 'deletes' will lock the database.
302
303     // Pass 1: iterate over the map and find all entries that have not been
304     // used in X hours
305     vector<string> stale_keys;
306     time_t stale = time(NULL) - 8 * 3600; // XXX: 8 hour timeout.
307
308     lock->rdlock();
309     for (map<string,InternalCCacheEntry*>::iterator i=m_hashtable.begin();
310          i != m_hashtable.end(); i++)
311     {
312       // If the last access was BEFORE the stale timeout...
313       if (i->second->lastAccess() < stale)
314         stale_keys.push_back(i->first);
315     }
316     lock->unlock();
317
318     log->info("deleting %d old items.", stale_keys.size());
319
320     // Pass 2: walk through the list of stale entries and remove them from
321     // the database
322     for (vector<string>::iterator i = stale_keys.begin();
323          i != stale_keys.end(); i++)
324     {
325       remove (i->c_str());
326     }
327
328   }
329
330   mutex->unlock();
331   delete mutex;
332   Thread::exit(NULL);
333 }
334
335 void* InternalCCache::cleanup_fcn(void* cache_p)
336 {
337   InternalCCache* cache = (InternalCCache*)cache_p;
338
339   // First, let's block all signals
340   sigset_t sigmask;
341   sigfillset(&sigmask);
342   Thread::mask_signals(SIG_BLOCK, &sigmask, NULL);
343
344   // Now run the cleanup process.
345   cache->cleanup();
346 }
347
348 /******************************************************************************/
349 /* InternalCCacheEntry:  A Credential Cache Entry                             */
350 /******************************************************************************/
351
352 InternalCCacheEntry::InternalCCacheEntry(SAMLAuthenticationStatement *s, const char *client_addr)
353   : m_hasbinding(false)
354 {
355   string ctx = "shibtarget::InternalCCacheEntry";
356   log = &(log4cpp::Category::getInstance(ctx));
357   pop_locks_lock = Mutex::create();
358   access_lock = Mutex::create();
359   resource_lock = RWLock::create();
360
361   if (s == NULL) {
362     log->error("NULL auth statement");
363     throw runtime_error("InternalCCacheEntry() was passed an empty SAML Statement");
364   }
365
366   m_subject = s->getSubject();
367
368   xstring name = m_subject->getName();
369   xstring qual = m_subject->getNameQualifier();
370
371   auto_ptr<char> h(XMLString::transcode(name.c_str()));
372   auto_ptr<char> d(XMLString::transcode(qual.c_str()));
373
374   m_handle = h.get();
375   m_originSite = d.get();
376
377   Iterator<SAMLAuthorityBinding*> bindings = s->getBindings();
378   if (bindings.hasNext())
379     m_hasbinding = true;
380
381   m_clientAddress = client_addr;
382   m_sessionCreated = m_lastAccess = time(NULL);
383
384   // Save for later.
385   p_auth = s;
386
387   log->info("New Session Created...");
388   log->debug("Handle: \"%s\", Site: \"%s\", Address: %s", h.get(), d.get(),
389              client_addr);
390 }
391
392 InternalCCacheEntry::~InternalCCacheEntry()
393 {
394   log->debug("deleting entry for %s@%s", m_handle.c_str(), m_originSite.c_str());
395   delete p_auth;
396   for (map<string,ResourceEntry*>::iterator i=m_resources.begin();
397        i!=m_resources.end(); i++)
398     delete i->second;
399
400   for (map<string,Mutex*>::iterator i=populate_locks.begin();
401        i!=populate_locks.end(); i++)
402     delete i->second;
403
404   delete pop_locks_lock;
405   delete resource_lock;
406   delete access_lock;
407 }
408
409 bool InternalCCacheEntry::isSessionValid(time_t lifetime, time_t timeout)
410 {
411   saml::NDC ndc("isSessionValid");
412   log->debug("test session %s@%s, (lifetime=%ld, timeout=%ld)",
413              m_handle.c_str(), m_originSite.c_str(), lifetime, timeout);
414   time_t now=time(NULL);
415   if (lifetime > 0 && now > m_sessionCreated+lifetime) {
416     log->debug("session beyond lifetime");
417     return false;
418   }
419
420   // Lock the access-time from here until we return
421   Lock lock(access_lock);
422   if (timeout > 0 && now-m_lastAccess >= timeout) {
423     log->debug("session timed out");
424     return false;
425   }
426   m_lastAccess=now;
427   return true;
428 }
429
430 Iterator<SAMLAssertion*> InternalCCacheEntry::getAssertions(Resource& resource)
431 {
432   saml::NDC ndc("getAssertions");
433   ResourceEntry* entry = populate(resource);
434   if (entry)
435     return entry->getAssertions();
436   return Iterator<SAMLAssertion*>(ResourceEntry::g_emptyVector);
437 }
438
439 ResourceEntry* InternalCCacheEntry::populate(Resource& resource)
440 {
441   saml::NDC ndc("populate");
442   log->debug("populating entry for %s (%s)",
443              resource.getResource(), resource.getURL());
444
445   // Lock the resource within this entry...
446   InternalCCacheEntry::ResourceLock lock(this, resource.getResource());
447
448   // Can we use what we have?
449   ResourceEntry *entry = find(resource.getResource());
450   if (entry) {
451     log->debug("found resource");
452     if (entry->isValid())
453       return entry;
454
455     // entry is invalid (expired) -- go fetch a new one.
456     log->debug("removing resource cache; assertion is invalid");
457     remove (resource.getResource());
458     delete entry;
459   }
460
461   // Nope, no entry.. Create a new resource entry
462
463   if (!m_hasbinding) {
464     log->error("No binding!");
465     return NULL;
466   }
467
468   log->info("trying to request attributes for %s@%s -> %s",
469             m_handle.c_str(), m_originSite.c_str(), resource.getURL());
470
471   auto_ptr<XMLCh> resourceURL(XMLString::transcode(resource.getURL()));
472   Iterator<saml::QName> respond_withs = ArrayIterator<saml::QName>(&g_respondWith);
473
474   // Clone the subject...
475   // 1) I know the static_cast is safe from clone()
476   // 2) the AttributeQuery will destroy this new subject.
477   SAMLSubject* subject=static_cast<SAMLSubject*>(m_subject->clone());
478
479   // Build a SAML Request....
480   SAMLAttributeQuery* q=new SAMLAttributeQuery(subject,resourceURL.get(),
481                                                resource.getDesignators());
482   SAMLRequest* req=new SAMLRequest(respond_withs,q);
483
484   // Try this request against all the bindings in the AuthenticationStatement
485   // (i.e. send it to each AA in the list of bindings)
486   Iterator<SAMLAuthorityBinding*> bindings = p_auth->getBindings();
487   SAMLResponse* response = NULL;
488
489   while (!response && bindings.hasNext()) {
490     SAMLAuthorityBinding* binding = bindings.next();
491
492     log->debug("Trying binding...");
493     SAMLBinding* pBinding=m_cache->getBinding(binding->getBinding());
494     log->debug("Sending request");
495     response=pBinding->send(*binding,*req);
496   }
497
498   // ok, we can delete the request now.
499   delete req;
500
501   // Make sure we got a response
502   if (!response) {
503     log->info ("No Response");
504     return NULL;
505   }
506
507   entry = new ResourceEntry(response);
508   insert (resource.getResource(), entry);
509
510   log->info("fetched and stored SAML response");
511   return entry;
512 }
513
514 ResourceEntry* InternalCCacheEntry::find(const char* resource_url)
515 {
516   ReadLock rwlock(resource_lock);
517
518   log->debug("find: %s", resource_url);
519   map<string,ResourceEntry*>::const_iterator i=m_resources.find(resource_url);
520   if (i==m_resources.end()) {
521     log->debug("no match found");
522     return NULL;
523   }
524   log->debug("match found");
525   return i->second;
526 }
527
528 void InternalCCacheEntry::insert(const char* resource, ResourceEntry* entry)
529 {
530   log->debug("inserting %s", resource);
531
532   resource_lock->wrlock();
533   m_resources[resource]=entry;
534   resource_lock->unlock();
535 }
536
537 void InternalCCacheEntry::remove(const char* resource)
538 {
539   log->debug("removing %s", resource);
540
541   resource_lock->wrlock();
542   m_resources.erase(resource);
543   resource_lock->unlock();
544 }
545
546
547 // a lock on a resource.  This is a specific "table of locks" that
548 // will provide a mutex on a particular resource within a Cache Entry.
549 // Just instantiate a ResourceLock within scope of the function and it
550 // will obtain and hold the proper lock until it goes out of scope and
551 // deconstructs.
552
553 InternalCCacheEntry::ResourceLock::ResourceLock(InternalCCacheEntry* entry,
554                                                 string resource) :
555   entry(entry), resource(resource)
556 {
557   Mutex *mutex = find(resource);
558   mutex->lock();
559 }
560
561 InternalCCacheEntry::ResourceLock::~ResourceLock()
562 {
563   Mutex *mutex = find(resource);
564   mutex->unlock();
565 }
566
567 Mutex* InternalCCacheEntry::ResourceLock::find(string& resource)
568 {
569   Lock(entry->pop_locks_lock);
570   
571   map<string,Mutex*>::const_iterator i=entry->populate_locks.find(resource);
572   if (i==entry->populate_locks.end()) {
573     Mutex* mutex = Mutex::create();
574     entry->populate_locks[resource] = mutex;
575     return mutex;
576   }
577   return i->second;
578 }
579
580 /******************************************************************************/
581 /* ResourceEntry:  A Credential Cache Entry for a particular Resource URL     */
582 /******************************************************************************/
583
584 ResourceEntry::ResourceEntry(SAMLResponse* response)
585 {
586   string ctx = "shibtarget::ResourceEntry";
587   log = &(log4cpp::Category::getInstance(ctx));
588
589   log->info("caching resource entry");
590
591   m_response = response;
592 }
593
594 ResourceEntry::~ResourceEntry()
595 {
596   delete m_response;
597 }
598
599 Iterator<SAMLAssertion*> ResourceEntry::getAssertions()
600 {
601   saml::NDC ndc("getAssertions");
602   return m_response->getAssertions();
603 }
604
605 bool ResourceEntry::isValid()
606 {
607   saml::NDC ndc("isValid");
608
609   log->info("checking validity");
610
611   // This is awful, but the XMLDateTime class is truly horrible.
612   time_t now=time(NULL);
613 #ifdef WIN32
614   struct tm* ptime=gmtime(&now);
615 #else
616   struct tm res;
617   struct tm* ptime=gmtime_r(&now,&res);
618 #endif
619   char timebuf[32];
620   strftime(timebuf,32,"%Y-%m-%dT%H:%M:%SZ",ptime);
621   auto_ptr<XMLCh> timeptr(XMLString::transcode(timebuf));
622   XMLDateTime curDateTime(timeptr.get());
623
624   Iterator<SAMLAssertion*> iter = getAssertions();
625
626   while (iter.hasNext()) {
627     SAMLAssertion* assertion = iter.next();
628
629     log->debug ("testing assertion...");
630
631     if (! assertion->getNotOnOrAfter()) {
632       log->debug ("getNotOnOrAfter failed.");
633       return false;
634     }
635
636     int result=XMLDateTime::compareOrder(&curDateTime,
637                                          assertion->getNotOnOrAfter());
638     if (result != XMLDateTime::LESS_THAN) {
639       log->debug("nope, not still valid");
640       return false;
641     }
642   } // while
643
644   log->debug("yep, all still valid");
645   return true;
646 }