CB cache not caching

[Judah McAuley]

I'm just starting into manually using the CB cache for objects and
have run into a confusing issue, namely that the system says it is
caching objects and all of the timeouts and what not it reports in the
cache monitor are correct but when you try and retrieve the object
from the cache it returns a _NOTFOUND_ value.

Some objects seem to be cached correctly. The attached screenshot
shows the cache monitor report. plugin-json, for instance, shows up as
cached and has an expiration date of 5:02 pm. When I click on it, it
pops up a window and returns the contents correct. Awesome. But
plugin-messagebox, on the other hand, shows an identical timeout but
when I click on it, I get a popup showing the contest as _NOTFOUND_
The same results for an item I manually insert via the getOCM.set()
command (the one that looks like an SHA hash as a key name) and
services that I autowire into the cache.

It doesn't seem to matter how they are created or how long they are
supposed to be persisted. And yet some objects are, in fact, persisted
to the cache. There doesn't seem to be much rhyme or reason that I can
determine.

The cache isn't full to cause eviction (14 out of 1000 spots used) and
I even get the _NOTFOUND_ when I try access it before the
ReapFrequency interval of 1 minute is hit. So I'm stumped.

Any thoughts?

Setup:
Coldbox 3.0.0 Beta 2
Railo 3.1.1.000 final

Windows XP Pro 32-bit, Java 1.6.0_16

[Judah McAuley]

Helps when I attach the actual screenshot I guess.

[Luis Majano]

Try the nighlty build I beleive there was a bug on the reaping methods.

--
Luis F. Majano
President
Ortus Solutions, Corp

ColdBox Platform: http://www.coldbox.org
Linked In: http://www.linkedin.com/pub/3/731/483
Blog: http://www.luismajano.com
IECFUG Manager: http://www.iecfug.com

[Luis Majano]

Once you try it let me know please

[Judah McAuley]

Grabbed the nightly build from SVN this morning and dropped the
install and system folders over my existing install and restarted
Railo.

Alas, having the same behavior still. I tried it in multiple browsers
as well, just in case, and got he same behavior. Oddly, the same
pattern of what gets cached and what does not get cached stays the
same, so I'm guessing that it has something to do with the order of
instantiation/caching.

Also, I wanted to note that I was getting a new error thrown with the
nightly build about passing the Event into my handler. The error is as
follows:

Error Messages: invalid call of the function index
(C:\tomcat\webapps\ROOT\reminders\handlers\AppointmentImport.cfc),
first Argument (event) is of invalid type, can't cast Object type
[Component coldbox.system.web.context.RequestContext] to a value of
type [coldbox.system.beans.requestContext]

The problem stems from me being too explicit about the arguments in my
handler. I declared the event argument thusly:
<cfargument name="event" type="coldbox.system.beans.requestContext"
required="yes">

I believe that this is copied from old code. It seems that Event moved
to a new spot in the nightly build so it wasn't able to cast correctly
as I used the fully qualified path. When I removed the type attribute
on the argument, it worked fine. Not a big deal and easy to fix, but
thought I'd tell you.

Cheers,
Judah

[Judah McAuley]

Is there any further info I could get you that would help troubleshoot
the problem Luis? I took a brief look at the cacheing code in the
system folder and nothing jumped out at me.

Cheers,
Judah

On Mon, Oct 26, 2009 at 7:11 PM, Luis Majano <lma...@gmail.com> wrote:
>

[Luis Majano]

Judah,

I have tried it on cf7,8,9 and railo and cannot reproduce what you are doing.

The only reason why an object would say _NOT_FOUND, is because the JVM garbage collected it, which is common if you do not have enough RAM or the like.

Memory issues are always tricky and can be dubious to nail.  Please keep at it and let me know what else you find.  These issues are not solved quickly or easily.

Luis

[Judah McAuley]

I could try upping the ram allocated to the JVM but that doesn't seem
to be the problem as far as I can tell. Here is what I'm seeing in the
cache monitor report:

Cache Performance
Hit Ratio: 55.81% ==> Hits: 24 | Misses: 19 | Evictions: 0 | Garbage
Collections: 0
JVM Memory Stats
92.09 % Free | Total Assigned: 520,256 KB | Max: 520,256 KB
JVM Threshold
0% (0=Unlimited)
Last Reap
Oct-28-2009 12:13:59 PM
Reap Frequency
Every 1 Minute(s)
Eviction Policy
LRU
Default Timeout
60 Minutes
Last Access Timeout
30 Minutes
Cache Contents
13 / 1000 (0=Unlimited)

Oct-28-2009 12:13:59 PM is the time of the request, so Last Reap seems
to be occuring on the current request. Is that supposed to be correct?
Or should that Last Reap time be null since it is a brand new request
for these objects that haven't been in the cache today?

Perhaps I'm running into a problem with one area of JVM Memory. Where
does the soft reference get stored? Perm, Eve, etc?

Here are the JAVA_OPTS I'm using for Tomcat:
set JAVA_OPTS=-Xms512m -Xmx512m -XX:PermSize=64M -XX:MaxPermSize=128M

I notice there that I'm not explicitly setting a garbage collection
method. Perhaps that has something to do with it?

Thanks,
Judah

[Judah McAuley]

Another point I find curious:

When I do the initial request, it shows up as I first sent. No
evictions, no garbage collections, all the items are listed as being
in the cache just like you'd expect. Then I open up the cache monitor.

The cache monitor shows most of my objects gone from the cache. The
Hit Ratio report shows the following:

Cache Performance
Hit Ratio: 57.14% ==> Hits: 4 | Misses: 3 | Evictions: 0 | Garbage
Collections: 0

So Hits has gone down from 24 to 4, Misses from 19 to 3 and there
still supposedly haven't been any evictions or garbage collections yet
the objects are no longer in the cache. I'm assuming that they must
have been garbage collected in the 6 seconds it took me to open the
cache monitor monitor popup but that doesn't seem to be reported by
the cache monitor.

Another curious thing is that the Last Reap time is *always* the
current request time. If I leave the cache monitor window open and set
it to a 5 second poll, Last Reap will be whatever time the current
poll is at, regardless of the Reap Frequency.

Not sure what to make of it.

I appreciate your help a great deal Luis.

Judah

[Luis Majano]

Judah,

OK, this might make you hit yourself in the head!!

Check the config file, do you have the following setting on: ConfigAutoReload

If you do have this to true, then you are seeing first requests only.

[Judah McAuley]

Good thought Luis, but alas, no, I have it set to False.

And then I just went to triple check and you know what? I had it
overridden in the environment control and set to True for dev, which
is the environment I'm in. D'oh. I even looked at that in the
coldbox.xml just in case but had not thought to look in environments.

And now the items are found.

Thanks Luis

[Judah McAuley]

Just to make sure that I understand it correctly and for the
edification of fellow list members and Google searchers, here is my
understanding of what was going on:

The ConfigAutoReload setting was set to True which means that each
time a request comes in, Coldbox reinitializes itself thereby
delivering a new, clean copy of the framework. So I would tell the
framework to cache my object but then when I went to retrieve the
object from the cache on another request or in the monitor (which is
another request) the act of calling it reinitializes the framework and
therefore loses any notion of anything I'd done before. So as far as
it is concerned, my previous objects were never set in the cache at
all because that happened in some old instance of the framework. I did
see some things in the cache which made me thought that my objects had
been evicted but those objects were set into cache at framework
startup which is why the same objects were always present in the
cache. Hence there were no evictions or garbage collections, the cache
was just created anew without my objects in it.

Fascinating stuff.

Cheers,
Judah