[Coldbox-4.3] cachebox timeout

Hi,

In one coldbox app that we are migrating from fw/1 sometimes the following timeout in cachebox. The cachebox configuration is the default.

Lucee vers: 4.5.3.020
Tomcat 7

When the timeout occurs, just reloading the page again works.

request (path: /var/www/todocoleccion/production/app_coldbox/index.cfm (/var/www/todocoleccion/production/app_coldbox/coldbox/system/cache/store/ConcurrentSoftReferenceStore.cfc):21) has run into a timeout (50 seconds) and has been stopped. open locks at this time (cacheboxprovider.reap.629908707, concurrentsoftreferencestore.reap.1949878502).

The Error Occurred in
/var/www/todocoleccion/production/app_coldbox/coldbox/system/cache/store/ConcurrentSoftReferenceStore.cfc: line 56

54:
55: // Let’s reap the garbage collected soft references
56: while( structKeyExists(reflocal, “collected”) ){
57:
58: // Clean if it still exists

called from /var/www/todocoleccion/production/app_coldbox/coldbox/system/cache/providers/CacheBoxProvider.cfc: line 624
622:
623: // Run Storage reaping first, before our local algorithm
624: instance.objectStore.reap();
625:
626: // Let’s Get our reaping vars ready, get a duplicate of the pool metadata so we can work on a good copy

Thanks

David Sedeño

The way CF reports timeouts doesn’t tell you in the message what was necessarily slow-- just the line of code that happened to be running when the page reached the timeout point. This is quite possibly related to the locking in cachebox and was part of the reaping that occurs. When these pages timeout, can you tell us if there are a large number of running requests that are backed up? If so, please pull a stack trace for the entire server and it may give us some clues on what other threads were doing. I’m guessing the threads in question are having to wait in order to acquire the lock on line 49 of that file, and once they acquire it, immediately timeout since they’re over the threshhold.

Thanks!

~Brad

ColdBox/CommandBox Developer Advocate
Ortus Solutions, Corp

E-mail: brad@coldbox.org
ColdBox Platform: http://www.coldbox.org
Blog: http://www.codersrevolution.com

Also.

What type of caches do you have defined. Can you post your cachebox config.

Luis Majano
CEO
Ortus Solutions, Corp
www.ortussolutions.com
P/F: 1-888-557-8057

Hi,

my cachebox is the default of coldbox I have not defined any. Only have defined at lucee level. Attached config/CacheBox.cfc btw.

Brad, the server is my local dev machine (vagrant with virtualbox ) so there is no others requests around. Also the pages that timeouts are not always the same, but the error is always the same.

CacheBox.cfc (1.45 KB)

Well, you’re going to have to figure out why the requests are taking a long time. Try to do some cache tuning to establish some information such as the number of items in your cache, hit/miss rates, etc. Install the cbdebugger module and use the cache panel to get all this information. You’ll also need to catch your local server when the actual requests are running long. I would recommend using a tool like FusionReactor that can be configured to look for requests whose time running exceeds a given threshold and then you can configure it to E-mail you a full thread dump of the JVM and you’ll see exactly what’s happening in that case.

The default object cache is an in memory cache and has a max of 300 items, so reaping should be an operation that takes very little time at all.

Thanks!

~Brad

ColdBox/CommandBox Developer Advocate
Ortus Solutions, Corp

E-mail: brad@coldbox.org
ColdBox Platform: http://www.coldbox.org
Blog: http://www.codersrevolution.com

Attached you have a screenshot of fusionreactor profiler when the request gets the timeout. I am not very good reading the profiler, but as I see the time goes in the cachebox function.

The only thing I have is the patch of coldbox to work with lucee full null support. I don’t know if this is could be related with the timeout.

Thanks