We have been using SysCache successfully, but we need something that will work in a web farm. So the obvious angle was to move towards SysCache2. It seems to be setup and working without raising any errors, but it only seems to be hitting the cache about 30% of the time. I came up with this number by using PerfMon and watching the ASP.Net Cache counters, but the problem is apparent in the Log4Net logs as well.

My test has been to flip back and forth between two pages on a single machine with a single user, on pages where there is no data being written. So in theory, my cache hits should be at 100% because I’m just hitting the exact same data over and over. But at the bottom is an example of my logs when I run this query against the Log4Net logs in the db. I have walked through the logs and seen something get put into the cache and then shortly after, it returns the dreaded “cache miss”.

Notes:

I have seen a number of “Cache items for region 'some entity' have been removed from the cache for the following reason : DependencyChanged”, but this makes no sense as there isn’t anything changing in the database. Look at location 475 as an example. It gets added, it gets removed because of a DependencyChanged and then it has to reload it.

I have pretty much one region per entity. Each command is a simple select query. Some examples: SELECT CategoryId FROM Category, SELECT EventId FROM Event, SELECT Location.LocationId, EventLocation.EventLocationId
FROM Location INNER JOIN
EventLocation ON Location.LocationId = EventLocation.LocationId, etc.

The time to expire is 20 minutes and according to the log, it is caching for the correct amount of time.

There is tons of physical memory left on the box

I am completely stumped at this point. I’m probably going to switch to using the table instead of command, but it’s unfortunate as I really don’t like the polling concept.

Anybody have any ideas on what could be causing this? Is anybody using SysCache2 with command cacheRegions successfully?

Query:


Sorry for the long log, but I wanted to try to return as much information as possible.

Results:
[size=75]Item was already cached: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Creating root cache entry for cache region: Event
Caching: CHO.Next.Global.DataObjects.Events.Event#475
item will expire at: 02/19/2009 10:47:35
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#43@43' from the cache.
Caching: CHO.Next.Global.DataObjects.Role#43
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#35@35' from the cache.
Caching: CHO.Next.Global.DataObjects.Events.Event#310
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#310@310' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#310@310 & value=Item{version=,freshTimestamp=5058720851673088}
item will expire at: 02/19/2009 10:47:50
Cached: CHO.Next.Global.DataObjects.Events.Event#310
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#2381
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2381@2381' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#2381
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#35@35 & value=Item{version=,freshTimestamp=5058720854138880}
item will expire at: 02/19/2009 10:47:51
Cached: CHO.Next.Global.DataObjects.Events.EventTime#35
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#996
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#996@996' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#996
Caching: CHO.Next.Global.DataObjects.Events.Event#347
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#347@347 & value=Item{version=,freshTimestamp=5058720832368640}
item will expire at: 02/19/2009 10:47:45
Cached: CHO.Next.Global.DataObjects.Events.Event#347
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#43
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#43@43' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#43
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1963
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1963@1963' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1963@1963 & value=Item{version=,freshTimestamp=5058720835026944}
item will expire at: 02/19/2009 10:47:46
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1963
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#397
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#397@397' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#397
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#2157
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2157@2157' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#2157
Caching: CHO.Next.Global.DataObjects.Events.EventTime#2157
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2157@2157' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2157@2157 & value=Item{version=,freshTimestamp=5058720839774208}
Caching: CHO.Next.Global.DataObjects.Events.Event#74
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#74@74' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#74@74 & value=Item{version=,freshTimestamp=5058720844029952}
item will expire at: 02/19/2009 10:47:48
Cached: CHO.Next.Global.DataObjects.Events.Event#74
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1014
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1014@1014' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1014
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#731
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#731@731' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#731
Caching: CHO.Next.Global.DataObjects.Events.EventTime#731
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#731@731' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#731@731 & value=Item{version=,freshTimestamp=5058720846864384}
item will expire at: 02/19/2009 10:47:49
Cached: CHO.Next.Global.DataObjects.Events.EventTime#731
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#455
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#455@455' from the cache.
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1919
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1919@1919' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1919@1919 & value=Item{version=,freshTimestamp=5058720849240064}
item will expire at: 02/19/2009 10:47:49
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1919
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#356
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#356@356' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#356
Caching: CHO.Next.Global.DataObjects.Events.EventTime#2381
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2381@2381' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2381@2381 & value=Item{version=,freshTimestamp=5058720851939328}
item will expire at: 02/19/2009 10:47:50
Cached: CHO.Next.Global.DataObjects.Events.EventTime#2381
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#365
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#365@365' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#365
Caching: CHO.Next.Global.DataObjects.Events.Event#996
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#996@996' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#996@996 & value=Item{version=,freshTimestamp=5058720856166400}
item will expire at: 02/19/2009 10:47:51
Cached: CHO.Next.Global.DataObjects.Events.Event#996
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1941
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1941@1941' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1941
Caching: CHO.Next.Global.DataObjects.Events.Event#146
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#146@146 & value=Item{version=,freshTimestamp=5058720825434112}
item will expire at: 02/19/2009 10:47:44
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cached: CHO.Next.Global.DataObjects.Events.Event#146
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1577
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1577@1577' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1577
item will expire at: 02/19/2009 10:47:47
Cache miss: CHO.Next.Global.DataObjects.Events.Event#455
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#365@365' from the cache.
Caching: CHO.Next.Global.DataObjects.Events.EventTime#43
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#43@43' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#43@43 & value=Item{version=,freshTimestamp=5058720832696320}
item will expire at: 02/19/2009 10:47:45
Cached: CHO.Next.Global.DataObjects.Events.EventTime#43
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#849
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#849@849' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#849
Caching: CHO.Next.Global.DataObjects.Events.Event#397
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#397@397' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#397@397 & value=Item{version=,freshTimestamp=5058720837058560}
item will expire at: 02/19/2009 10:47:46
Cached: CHO.Next.Global.DataObjects.Events.Event#397
Cached: CHO.Next.Global.DataObjects.Events.EventTime#2157
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#694
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#694@694' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#694
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1014
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1014@1014' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1014@1014 & value=Item{version=,freshTimestamp=5058720844230656}
item will expire at: 02/19/2009 10:47:48
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1014
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1255
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1255@1255' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1255
Caching: CHO.Next.Global.DataObjects.Events.EventTime#356
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#356@356' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#356@356 & value=Item{version=,freshTimestamp=5058720849506304}
item will expire at: 02/19/2009 10:47:49
Cached: CHO.Next.Global.DataObjects.Events.EventTime#356
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#310
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#310@310' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#310
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#365@365 & value=Item{version=,freshTimestamp=5058720853929984}
item will expire at: 02/19/2009 10:47:50
Cached: CHO.Next.Global.DataObjects.Events.Event#365
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#35
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#35@35' from the cache.
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1941
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1941@1941' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1941@1941 & value=Item{version=,freshTimestamp=5058720856354816}
item will expire at: 02/19/2009 10:47:51
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1941
Caching: CHO.Next.Global.DataObjects.Events.Event#509
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#509@509 & value=Item{version=,freshTimestamp=5058720820895744}
item will expire at: 02/19/2009 10:47:42
Cached: CHO.Next.Global.DataObjects.Events.Event#509
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1011
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1011@1011' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1011
item will expire at: 02/19/2009 10:47:46
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#35
Caching: CHO.Next.Global.DataObjects.Events.Event#3
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#3@3 & value=Item{version=,freshTimestamp=5058720827789312}
item will expire at: 02/19/2009 10:47:44
Cached: CHO.Next.Global.DataObjects.Events.Event#3
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#759
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#759@759' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#759
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1091
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1091@1091' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1091
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1091
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1091@1091' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1091@1091 & value=Item{version=,freshTimestamp=5058720837255168}
item will expire at: 02/19/2009 10:47:46
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1091
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#771
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#771@771' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#771
Caching: CHO.Next.Global.DataObjects.Events.Event#694
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#694@694' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#694@694 & value=Item{version=,freshTimestamp=5058720841752576}
item will expire at: 02/19/2009 10:47:48
Cached: CHO.Next.Global.DataObjects.Events.Event#694
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#953
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#953@953' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#953
Caching: CHO.Next.Global.DataObjects.Events.EventTime#2869
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2869@2869' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2869@2869 & value=Item{version=,freshTimestamp=5058720830435328}
item will expire at: 02/19/2009 10:47:45
Cached: CHO.Next.Global.DataObjects.Events.EventTime#2869
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#347
Cache miss: CHO.Next.Global.DataObjects.Events.Event#347
Caching: CHO.Next.Global.DataObjects.Events.Event#771
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#771@771' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#771@771 & value=Item{version=,freshTimestamp=5058720839229440}
item will expire at: 02/19/2009 10:47:47
Cached: CHO.Next.Global.DataObjects.Events.Event#771
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1255
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1255@1255' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1255@1255 & value=Item{version=,freshTimestamp=5058720844619776}
item will expire at: 02/19/2009 10:47:48
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1255
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#69
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#69@69' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#69
Caching: CHO.Next.Global.DataObjects.Events.Event#455
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#455@455' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#455@455 & value=Item{version=,freshTimestamp=5058720849027072}
item will expire at: 02/19/2009 10:47:49
Cached: CHO.Next.Global.DataObjects.Events.Event#455
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1919
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1919@1919' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1919
Caching: CHO.Next.Global.DataObjects.Events.Event#849
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#849@849' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#849@849 & value=Item{version=,freshTimestamp=5058720834822144}
Caching: CHO.Next.Global.DataObjects.Events.Event#528
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#528@528 & value=Item{version=,freshTimestamp=5058720794923008}
item will expire at: 02/19/2009 10:47:36
Cached: CHO.Next.Global.DataObjects.Events.Event#528
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#2869
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2869@2869' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#2869
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#43@43 & value=Item{version=,freshTimestamp=5058720797401088}
item will expire at: 02/19/2009 10:47:37
Cached: CHO.Next.Global.DataObjects.Events.EventTime#43
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#849
Cache miss: CHO.Next.Global.DataObjects.Events.Event#849
Caching: CHO.Next.Global.DataObjects.Events.Event#397
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#397@397 & value=Item{version=,freshTimestamp=5058720801751040}
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:38
Cached: CHO.Next.Global.DataObjects.Events.Event#397
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1091
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1091@1091' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1091
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Club#7
Cache miss: CHO.Next.Global.DataObjects.Club#7
Cache lookup: CHO.Next.Global.DataObjects.TimeZoneData#72
Cache miss: CHO.Next.Global.DataObjects.TimeZoneData#72
Fetching object 'NHibernate-Cache:SecurityEntity:CHO.Next.Global.DataObjects.Role#43@43' from the cache.
Item was already cached: CHO.Next.Global.DataObjects.Role#43
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1920
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1920@1920' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1920
Caching: CHO.Next.Global.DataObjects.Events.Event#365
Caching: CHO.Next.Global.DataObjects.Category#1
root cache item for region not found.
Creating root cache entry for cache region: Category
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Category:CHO.Next.Global.DataObjects.Category#1@1 & value=Item{version=,freshTimestamp=5058720816922624}
item will expire at: 02/19/2009 10:47:41
Cache items for region 'Category' have been removed from the cache for the following reason : DependencyChanged
Cached: CHO.Next.Global.DataObjects.Category#1
root cache item for region not found.
Creating root cache entry for cache region: EventTemplate
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:EventTemplate:CHO.Next.Global.DataObjects.Events.EventTemplate#3@3 & value=NHibernate.Cache.Entry.CacheEntry
Cache items for region 'EventTemplate' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:42
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1546
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1546@1546' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1546@1546 & value=Item{version=,freshTimestamp=5058720818851840}
item will expire at: 02/19/2009 10:47:42
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1546
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#509
Cache miss: CHO.Next.Global.DataObjects.Events.Event#509
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1953
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1953@1953' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1953@1953 & value=Item{version=,freshTimestamp=5058720823455744}
item will expire at: 02/19/2009 10:47:43
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1953
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#146
Cache miss: CHO.Next.Global.DataObjects.Events.Event#146
Caching: CHO.Next.Global.DataObjects.Events.EventTime#759
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#759@759' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#759@759 & value=Item{version=,freshTimestamp=5058720828026880}
item will expire at: 02/19/2009 10:47:44
Cached: CHO.Next.Global.DataObjects.Events.EventTime#759
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#528
Cache miss: CHO.Next.Global.DataObjects.Events.Event#528
Cached: CHO.Next.Global.DataObjects.Events.Event#849
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1963
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1963@1963' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1963
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1011
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1011@1011' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1011@1011 & value=Item{version=,freshTimestamp=5058720787881984}
item will expire at: 02/19/2009 10:47:34
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1011
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1953
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1953@1953' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1953
Cached: CHO.Next.Global.DataObjects.Events.Event#146
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1577
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1577@1577' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1577
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1577
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1577@1577' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1577@1577 & value=Item{version=,freshTimestamp=5058720790446080}
item will expire at: 02/19/2009 10:47:35
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1577
Caching: CHO.Next.Global.DataObjects.Events.EventTime#759
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#759@759' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#759@759 & value=Item{version=,freshTimestamp=5058720792858624}
item will expire at: 02/19/2009 10:47:36
Cached: CHO.Next.Global.DataObjects.Events.EventTime#759
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#528
Cache miss: CHO.Next.Global.DataObjects.Events.Event#528
Caching: CHO.Next.Global.DataObjects.Events.EventTime#2869
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2869@2869' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2869@2869 & value=Item{version=,freshTimestamp=5058720795144192}
item will expire at: 02/19/2009 10:47:36
Cached: CHO.Next.Global.DataObjects.Events.EventTime#2869
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#347
Cache miss: CHO.Next.Global.DataObjects.Events.Event#347
Caching: CHO.Next.Global.DataObjects.Events.EventTime#35
Caching: CHO.Next.Global.DataObjects.Events.Event#849
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#849@849 & value=Item{version=,freshTimestamp=5058720799514624}
item will expire at: 02/19/2009 10:47:37
Cached: CHO.Next.Global.DataObjects.Events.Event#849
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1963
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1091
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1091@1091' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1091@1091 & value=Item{version=,freshTimestamp=5058720802074624}
item will expire at: 02/19/2009 10:47:38
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1091
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#771
Cache miss: CHO.Next.Global.DataObjects.Events.Event#771
Caching: CHO.Next.Global.DataObjects.Events.Event#528
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#528@528 & value=Item{version=,freshTimestamp=5058720830115840}
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:45
Cached: CHO.Next.Global.DataObjects.Events.Event#528
Caching: CHO.Next.Global.DataObjects.TimeZoneData#72
root cache item for region not found.
Creating root cache entry for cache region: TimeZoneData
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:TimeZoneData:CHO.Next.Global.DataObjects.TimeZoneData#72@72 & value=Item{version=,freshTimestamp=5058720813764608}
Cache items for region 'TimeZoneData' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:41
Cached: CHO.Next.Global.DataObjects.TimeZoneData#72
Caching: CHO.Next.Global.DataObjects.Club#7
root cache item for region not found.
Creating root cache entry for cache region: Club
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Club:CHO.Next.Global.DataObjects.Club#7@7 & value=Item{version=,freshTimestamp=5058720813899776}
Cache items for region 'Club' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:41
Cached: CHO.Next.Global.DataObjects.Club#7
Cache lookup: CHO.Next.Global.DataObjects.Member#4196
Fetching object 'NHibernate-Cache:Member:CHO.Next.Global.DataObjects.Member#4196@4196' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Member#4196
Caching: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Fetching object 'NHibernate-Cache:SecurityEntity:CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight@23311' from the cache.
Item was already cached: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Caching: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Fetching object 'NHibernate-Cache:SecurityEntity:CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight@23351' from the cache.
Item was already cached: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Caching: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Fetching object 'NHibernate-Cache:SecurityEntity:CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight@23388' from the cache.
Item was already cached: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Caching: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Fetching object 'NHibernate-Cache:SecurityEntity:CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight@23425' from the cache.
Item was already cached: CHO.Next.Global.DataObjects.EntityRight#CHO.Next.Global.DataObjects.EntityRight
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1920
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1920@1920' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1920@1920 & value=Item{version=,freshTimestamp=5058720815476736}
item will expire at: 02/19/2009 10:47:41
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1920
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#475
Cache miss: CHO.Next.Global.DataObjects.Events.Event#475
Caching: CHO.Next.Global.DataObjects.Events.Event#708
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#708@708 & value=Item{version=,freshTimestamp=5058720823123968}
item will expire at: 02/19/2009 10:47:43
Cached: CHO.Next.Global.DataObjects.Events.Event#708
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
root cache item for region not found.
Creating root cache entry for cache region: EventTemplate
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:EventTemplate:CHO.Next.Global.DataObjects.Events.EventTemplate#4@4 & value=NHibernate.Cache.Entry.CacheEntry
Cache items for region 'EventTemplate' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:42
Caching: CHO.Next.Global.DataObjects.Events.Event#475
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#475@475 & value=Item{version=,freshTimestamp=5058720818552832}
item will expire at: 02/19/2009 10:47:42
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cached: CHO.Next.Global.DataObjects.Events.Event#475
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1546
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1546@1546' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1546
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1011
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1011@1011' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1011@1011 & value=Item{version=,freshTimestamp=5058720821211136}
item will expire at: 02/19/2009 10:47:42
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1011
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#708
Cache miss: CHO.Next.Global.DataObjects.Events.Event#708
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1953
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1953@1953' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1953
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1577
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1577@1577' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1577@1577 & value=Item{version=,freshTimestamp=5058720825696256}
item will expire at: 02/19/2009 10:47:44
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1577
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#3
Cache miss: CHO.Next.Global.DataObjects.Events.Event#3
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#2869
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2869@2869' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#2869
Caching: CHO.Next.Global.DataObjects.Events.EventTime#953
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#953@953' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#953@953 & value=Item{version=,freshTimestamp=5058720841961472}
item will expire at: 02/19/2009 10:47:48
Cached: CHO.Next.Global.DataObjects.Events.EventTime#953
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#74
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#74@74' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#74
Caching: CHO.Next.Global.DataObjects.Events.Event#69
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#69@69' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#69@69 & value=Item{version=,freshTimestamp=5058720846663680}
item will expire at: 02/19/2009 10:47:49
Cached: CHO.Next.Global.DataObjects.Events.Event#69
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#475@475 & value=Item{version=,freshTimestamp=5058720775200768}
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:31
Cached: CHO.Next.Global.DataObjects.Events.Event#475
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#356
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#356@356' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#356
Caching: CHO.Next.Global.DataObjects.Events.EventTime#356
Caching: CHO.Next.Global.DataObjects.Events.Event#310
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#310@310 & value=Item{version=,freshTimestamp=5058720777674752}
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Caching: CHO.Next.Global.DataObjects.Events.Event#365
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#365@365 & value=Item{version=,freshTimestamp=5058720780001280}
item will expire at: 02/19/2009 10:47:32
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cached: CHO.Next.Global.DataObjects.Events.Event#365
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#35
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#35@35' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#35
Caching: CHO.Next.Global.DataObjects.Events.Event#996
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#996@996 & value=Item{version=,freshTimestamp=5058720782348288}
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:33
Cached: CHO.Next.Global.DataObjects.Events.Event#996
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1941
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1941@1941' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1941
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1546
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1546@1546' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1546@1546 & value=Item{version=,freshTimestamp=5058720785440768}
item will expire at: 02/19/2009 10:47:34
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1546
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#509
Cache miss: CHO.Next.Global.DataObjects.Events.Event#509
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1963@1963' from the cache.
Caching: CHO.Next.Global.DataObjects.Events.Event#509
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#509@509 & value=Item{version=,freshTimestamp=5058720787582976}
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:34
Cached: CHO.Next.Global.DataObjects.Events.Event#509
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1941
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1941@1941' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1941@1941 & value=Item{version=,freshTimestamp=5058720782651392}
item will expire at: 02/19/2009 10:47:33
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1941
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#140
Cache miss: CHO.Next.Global.DataObjects.Events.Event#140
Caching: CHO.Next.Global.DataObjects.Events.EventTime#43
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1953
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1953@1953' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1953@1953 & value=Item{version=,freshTimestamp=5058720788090880}
item will expire at: 02/19/2009 10:47:34
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1953
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#146
Cache miss: CHO.Next.Global.DataObjects.Events.Event#146
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#347@347 & value=Item{version=,freshTimestamp=5058720797147136}
item will expire at: 02/19/2009 10:47:37
Cached: CHO.Next.Global.DataObjects.Events.Event#347
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#43
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#43@43' from the cache.
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#3
Cache miss: CHO.Next.Global.DataObjects.Events.Event#3
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1963
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1963
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1963@1963' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1963@1963 & value=Item{version=,freshTimestamp=5058720799809536}
item will expire at: 02/19/2009 10:47:37
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1963
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#397
Cache miss: CHO.Next.Global.DataObjects.Events.Event#397
Caching: CHO.Next.Global.DataObjects.Events.Event#771
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#771@771 & value=Item{version=,freshTimestamp=5058720804163584}
item will expire at: 02/19/2009 10:47:38
Cached: CHO.Next.Global.DataObjects.Events.Event#771
Caching: CHO.Next.Global.DataObjects.Member#4196
Fetching object 'NHibernate-Cache:Member:CHO.Next.Global.DataObjects.Member#4196@4196' from the cache.
adding new data: key=NHibernate-Cache:Member:CHO.Next.Global.DataObjects.Member#4196@4196 & value=Item{version=,freshTimestamp=5058720814182400}
item will expire at: 02/19/2009 10:47:41
Cached: CHO.Next.Global.DataObjects.Member#4196
root cache item for region not found.
Creating root cache entry for cache region: EventTemplate
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:EventTemplate:CHO.Next.Global.DataObjects.Events.EventTemplate#3@3 & value=NHibernate.Cache.Entry.CacheEntry
item will expire at: 02/19/2009 10:47:28
Cache items for region 'EventTemplate' have been removed from the cache for the following reason : DependencyChanged
root cache item for region not found.
Creating root cache entry for cache region: EventTemplate
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:EventTemplate:CHO.Next.Global.DataObjects.Events.EventTemplate#4@4 & value=NHibernate.Cache.Entry.CacheEntry
Cache items for region 'EventTemplate' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:28
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#74@74 & value=Item{version=,freshTimestamp=5058720765743104}
item will expire at: 02/19/2009 10:47:29
Cached: CHO.Next.Global.DataObjects.Events.Event#74
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1014
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1014@1014' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1014
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1014
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1014@1014' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1014@1014 & value=Item{version=,freshTimestamp=5058720766046208}
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#69
Cache miss: CHO.Next.Global.DataObjects.Events.Event#69
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#356@356' from the cache.
Caching: CHO.Next.Global.DataObjects.Events.EventTime#35
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#35@35' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#35@35 & value=Item{version=,freshTimestamp=5058720780247040}
item will expire at: 02/19/2009 10:47:32
Cached: CHO.Next.Global.DataObjects.Events.EventTime#35
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#996
Cache miss: CHO.Next.Global.DataObjects.Events.Event#996
Caching: CHO.Next.Global.DataObjects.Events.Event#140
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#43
Caching: CHO.Next.Global.DataObjects.Events.Event#455
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#455@455 & value=Item{version=,freshTimestamp=5058720772882432}
item will expire at: 02/19/2009 10:47:31
Cached: CHO.Next.Global.DataObjects.Events.Event#455
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#356@356 & value=Item{version=,freshTimestamp=5058720775585792}
item will expire at: 02/19/2009 10:47:31
Cached: CHO.Next.Global.DataObjects.Events.EventTime#356
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#310
Cache miss: CHO.Next.Global.DataObjects.Events.Event#310
Caching: CHO.Next.Global.DataObjects.Events.Event#146
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#146@146 & value=Item{version=,freshTimestamp=5058720790102016}
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#140@140 & value=Item{version=,freshTimestamp=5058720784646144}
item will expire at: 02/19/2009 10:47:34
Cached: CHO.Next.Global.DataObjects.Events.Event#140
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1920
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1920@1920' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1920
Caching: CHO.Next.Global.DataObjects.Events.Event#3
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#3@3 & value=Item{version=,freshTimestamp=5058720792514560}
item will expire at: 02/19/2009 10:47:35
Cached: CHO.Next.Global.DataObjects.Events.Event#3
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#759
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#759@759' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#759
item will expire at: 02/19/2009 10:47:32
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1011
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1011@1011' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1011
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1919
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1919@1919' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1919
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1919
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1919@1919' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1919@1919 & value=Item{version=,freshTimestamp=5058720773210112}
item will expire at: 02/19/2009 10:47:31
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1919
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#475
Cache miss: CHO.Next.Global.DataObjects.Events.Event#475
Cached: CHO.Next.Global.DataObjects.Events.Event#310
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#2381
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2381@2381' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#2381
Caching: CHO.Next.Global.DataObjects.Events.EventTime#2381
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2381@2381' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2381@2381 & value=Item{version=,freshTimestamp=5058720777908224}
item will expire at: 02/19/2009 10:47:32
Cached: CHO.Next.Global.DataObjects.Events.EventTime#2381
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1920
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1920@1920' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1920@1920 & value=Item{version=,freshTimestamp=5058720785235968}
item will expire at: 02/19/2009 10:47:34
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1920
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1546
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1546@1546' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1546
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#2157
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2157@2157' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#2157
item will expire at: 02/19/2009 10:47:29
Caching: CHO.Next.Global.DataObjects.Events.EventTime#2157
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2157@2157' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#2157@2157 & value=Item{version=,freshTimestamp=5058720760348672}
item will expire at: 02/19/2009 10:47:28
Cached: CHO.Next.Global.DataObjects.Events.EventTime#2157
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#694
Cache miss: CHO.Next.Global.DataObjects.Events.Event#694
Caching: CHO.Next.Global.DataObjects.Events.Event#694
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#694@694 & value=Item{version=,freshTimestamp=5058720763473920}
item will expire at: 02/19/2009 10:47:28
Cached: CHO.Next.Global.DataObjects.Events.Event#694
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#953
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#953@953' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#953
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1014
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#708
Cache miss: CHO.Next.Global.DataObjects.Events.Event#708
Caching: CHO.Next.Global.DataObjects.Events.Event#74
root cache item for region not found.
Caching: CHO.Next.Global.DataObjects.Events.Event#69
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#69@69 & value=Item{version=,freshTimestamp=5058720770482176}
item will expire at: 02/19/2009 10:47:30
Cached: CHO.Next.Global.DataObjects.Events.Event#69
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#365
Cache miss: CHO.Next.Global.DataObjects.Events.Event#365
Caching: CHO.Next.Global.DataObjects.Events.Event#140
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#140@140 & value=Item{version=,freshTimestamp=5058720673239040}
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:06
Cached: CHO.Next.Global.DataObjects.Events.Event#140
Cache lookup: CHO.Next.Global.DataObjects.Club#7
Cache miss: CHO.Next.Global.DataObjects.Club#7
Caching: CHO.Next.Global.DataObjects.Events.Event#347
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Cache lookup: CHO.Next.Global.DataObjects.Category#1
Cache miss: CHO.Next.Global.DataObjects.Category#1
Caching: CHO.Next.Global.DataObjects.Events.Event#708
root cache item for region not found.
Creating root cache entry for cache region: Event
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#708@708 & value=Item{version=,freshTimestamp=5058720768176128}
Caching: CHO.Next.Global.DataObjects.Events.EventTime#953
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#953@953' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#953@953 & value=Item{version=,freshTimestamp=5058720763805696}
item will expire at: 02/19/2009 10:47:28
Cached: CHO.Next.Global.DataObjects.Events.EventTime#953
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#74
Cache miss: CHO.Next.Global.DataObjects.Events.Event#74
item will expire at: 02/19/2009 10:47:30
Cache lookup: CHO.Next.Global.DataObjects.Category#1
Cache miss: CHO.Next.Global.DataObjects.Category#1
Caching: CHO.Next.Global.DataObjects.Category#1
root cache item for region not found.
Creating root cache entry for cache region: Category
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Category:CHO.Next.Global.DataObjects.Category#1@1 & value=Item{version=,freshTimestamp=5058720761905152}
item will expire at: 02/19/2009 10:47:28
Cached: CHO.Next.Global.DataObjects.Category#1
Cache items for region 'Category' have been removed from the cache for the following reason : DependencyChanged
Cached: CHO.Next.Global.DataObjects.Events.Event#708
Cache items for region 'Event' have been removed from the cache for the following reason : DependencyChanged
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#1255
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1255@1255' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#1255
Caching: CHO.Next.Global.DataObjects.Events.EventTime#1255
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1255@1255' from the cache.
adding new data: key=NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#1255@1255 & value=Item{version=,freshTimestamp=5058720768409600}
item will expire at: 02/19/2009 10:47:30
Cached: CHO.Next.Global.DataObjects.Events.EventTime#1255
Cache lookup: CHO.Next.Global.DataObjects.TimeZoneData#72
Cache miss: CHO.Next.Global.DataObjects.TimeZoneData#72
Caching: CHO.Next.Global.DataObjects.TimeZoneData#72
root cache item for region not found.
Creating root cache entry for cache region: TimeZoneData
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:TimeZoneData:CHO.Next.Global.DataObjects.TimeZoneData#72@72 & value=Item{version=,freshTimestamp=5058720758620160}
item will expire at: 02/19/2009 10:47:27
Cached: CHO.Next.Global.DataObjects.TimeZoneData#72
Cache items for region 'TimeZoneData' have been removed from the cache for the following reason : DependencyChanged
Caching: CHO.Next.Global.DataObjects.Club#7
root cache item for region not found.
Creating root cache entry for cache region: Club
Enlisting cache dependency for change notification
Attaching cache dependencies to root cache entry. Cache entry will be removed when change is detected.
adding new data: key=NHibernate-Cache:Club:CHO.Next.Global.DataObjects.Club#7@7 & value=Item{version=,freshTimestamp=5058720758820864}
Cache items for region 'Club' have been removed from the cache for the following reason : DependencyChanged
item will expire at: 02/19/2009 10:47:27
Cached: CHO.Next.Global.DataObjects.Club#7
Cache lookup: CHO.Next.Global.DataObjects.Events.EventTime#731
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#731@731' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.EventTime#731
Caching: CHO.Next.Global.DataObjects.Events.EventTime#731
Fetching object 'NHibernate-Cache:EventTime:CHO.Next.Global.DataObjects.Events.EventTime#731@731' from the cache.
adding new data: key=NHibernate-Cac

I still have this problem but I've removed all cacheRegions except for one. I'm also using a query that has all of the columns instead of just the primary key. This seems to have removed (or reduced?) the issue with DependencyChanged being raised. But the problem is still there that it seems to rarely hit the cached items.

I've included a smaller subset of the log. All I wanted to show was how it behaved for a single entity. In this case, Event#347. As you can see from the log, it misses the cache, adds it and then when the same entity is accessed...it misses the cache again.

Cache lookup: CHO.Next.Global.DataObjects.Events.Event#347
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#347@347' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#347
adding entity to second-level cache: [CHO.Next.Global.DataObjects.Events.Event#347]
Caching: CHO.Next.Global.DataObjects.Events.Event#347
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#347@347' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#347@347 & value=Item{version=,freshTimestamp=5058741851631616}
Cached: CHO.Next.Global.DataObjects.Events.Event#347
done materializing entity [CHO.Next.Global.DataObjects.Events.Event#347]
resolving associations for [CHO.Next.Global.DataObjects.Events.Event#347]
Cache lookup: CHO.Next.Global.DataObjects.Events.Event#347
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#347@347' from the cache.
Cache miss: CHO.Next.Global.DataObjects.Events.Event#347
resolving associations for [CHO.Next.Global.DataObjects.Events.Event#347]
adding entity to second-level cache: [CHO.Next.Global.DataObjects.Events.Event#347]
Caching: CHO.Next.Global.DataObjects.Events.Event#347
Fetching object 'NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#347@347' from the cache.
adding new data: key=NHibernate-Cache:Event:CHO.Next.Global.DataObjects.Events.Event#347@347 & value=Item{version=,freshTimestamp=5058740826562560}
Cached: CHO.Next.Global.DataObjects.Events.Event#347
done materializing entity [CHO.Next.Global.DataObjects.Events.Event#347]

I fixed the problem, so I thought I would post the resolution in the hopes that other people don't run into the same problem I did. It ended up being a simple fix, but it took a lot of effort and actually debugging and adding some debugging code to the source before I figured it out.

This is what I had:
<cacheRegion name="Category" relativeExpiration="1200" priority="High">
<dependencies>
<commands>
<add name="Category" command="SELECT CategoryId, Name FROM Category" />
</commands>
</dependencies>
</cacheRegion>

And this is what fixed it:

<cacheRegion name="Category" relativeExpiration="1200" priority="High">
<dependencies>
<commands>
<add name="Category" command="SELECT CategoryId, Name FROM dbo.Category" />
</commands>
</dependencies>
</cacheRegion>

It ends up you have to preface all table and stored procedures with dbo. This is a requirement of the SqlCacheDependency class. If it's anywhere in the NHibernate documentation, I didn't see it. I actually figured it out by looking at these posts.

Special Considerations Using Query Notifications (ADO.NET) - http://msdn.microsoft.com/en-us/library/aewzkxxh.aspx
Using SqlDependency for data change events - http://www.codeproject.com/KB/database/chatter.aspx
SqlCacheDependency immediately gets DependencyChanged - http://bytes.com/topic/net/answers/6462 ... ncychanged