Mantis - Quercus
Viewing Issue Advanced Details
ID: Category: Severity: Reproducibility: Date Submitted: Last Update:
3404 minor always 03-20-09 15:46 04-04-09 02:23
Reporter: koreth Platform:  
Assigned To: nam OS:  
Priority: normal OS Version:  
Status: closed Product Version: 4.0.0  
Product Build: Resolution: fixed  
Projection: none      
ETA: none Fixed in Version: 4.0.0  
Summary: 0003404: Tunability or dynamic sizing of regexp cache needed to avoid concurrency bottleneck
Description: I tried hitting Quercus with 10 concurrent requests for one of our AJAX scripts. Here's an excerpt from a thread dump I just took.

The code in question has a big list of regular expressions that it successively tries to match the browser's User-Agent string against. My benchmark tool's user agent is pretty far down the list so this ends up doing quite a few regex matches in rapid succession.

Ideally Quercus would notice that its LRU cache is too small to do any good and dynamically grow it until it's big enough to hold all these expressions. Barring that, a config option to make it tunable would be nice.

Obviously I can hack my source code locally to hardwire a larger size so this isn't super urgent.

"http--8080-12" daemon prio=10 tid=0x00002aac739a4800 nid=0x3a35 waiting for monitor entry [0x0000000043f65000..0x0000000043f67b30]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.removeTail(LruCache.java:466)
        - waiting to lock <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-17" daemon prio=10 tid=0x00002aac6f87e400 nid=0x3971 waiting for monitor entry [0x000000004375d000..0x000000004375fbb0]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.removeTail(LruCache.java:466)
        - locked <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-22" daemon prio=10 tid=0x00002aac6f360000 nid=0x3970 waiting for monitor entry [0x000000004365c000..0x000000004365ed30]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.removeTail(LruCache.java:466)
        - waiting to lock <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-20" daemon prio=10 tid=0x00002aac6f363800 nid=0x396f waiting for monitor entry [0x000000004355b000..0x000000004355dcb0]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.remove(LruCache.java:533)
        - locked <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.removeTail(LruCache.java:481)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-16" daemon prio=10 tid=0x00002aac6fabf800 nid=0x395a waiting for monitor entry [0x000000004345a000..0x000000004345ce30]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.removeTail(LruCache.java:466)
        - waiting to lock <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-18" daemon prio=10 tid=0x00002aac6ebbf400 nid=0x3955 waiting for monitor entry [0x0000000042f55000..0x0000000042f57bb0]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.removeTail(LruCache.java:466)
        - waiting to lock <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-14" daemon prio=10 tid=0x00002aac6ebbe000 nid=0x3954 waiting for monitor entry [0x0000000042e54000..0x0000000042e56d30]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.removeTail(LruCache.java:466)
        - waiting to lock <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-10" daemon prio=10 tid=0x00002aac6e2b8000 nid=0x3951 waiting for monitor entry [0x0000000042b51000..0x0000000042b53db0]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.remove(LruCache.java:533)
        - waiting to lock <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.removeTail(LruCache.java:481)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-19" daemon prio=10 tid=0x00002aac6db96800 nid=0x3944 waiting for monitor entry [0x000000004244a000..0x000000004244ce30]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.remove(LruCache.java:533)
        - waiting to lock <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.removeTail(LruCache.java:481)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)

"http--8080-9" daemon prio=10 tid=0x00002aac6db8d800 nid=0x3942 waiting for monitor entry [0x0000000042248000..0x000000004224ab30]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.caucho.util.LruCache.removeTail(LruCache.java:466)
        - waiting to lock <0x00002aaab8b51ec0> (a com.caucho.util.LruCache)
        at com.caucho.util.LruCache.compareAndPut(LruCache.java:313)
        at com.caucho.util.LruCache.put(LruCache.java:253)
        at com.caucho.quercus.lib.regexp.RegexpModule.getRegexp(RegexpModule.java:1505)
        at com.caucho.quercus.lib.regexp.RegexpModule.createRegexp(RegexpModule.java:254)
        at _quercus._lib._browscap__php$quercus_Browscap_0$fun_getBrowser_1.callMethod(_browscap__php.java:326)
Steps To Reproduce:
Additional Information:
Relationships
Attached Files:

Notes
(0003916)
nam   
03-21-09 03:02   
Added optims to regular expressions.

Static and most dynamic preg_* regular expressions are now stored locally to the page. It should be very rare that Quercus would ever need to fetch a regular expression from the LruCache.

Also added LruCache bins to reduce the probability of blocking.
(0003918)
koreth   
03-23-09 12:04   
I'm still seeing this even with relatively low concurrency (4). Everything gets jammed up pretty severely when this hits -- the JVM starts consuming large amounts of CPU time and requests stop processing as soon as they hit some regexp code.

Test case:

<?php
function testRegexes() {
  for ($i = 0; $i < 3000; $i++) {
    $regex = "/some-.*-regex-$i/i";
    preg_match($regex, 'some random text');
  }
}
testRegexes();

Run this in "ab" with a concurrency of 1 and there's no problem. Run it with a concurrency of 4 and within a second or two Quercus will jam up.
(0003921)
nam   
03-24-09 09:00   
Removed LruCache.
(0003944)
nam   
03-27-09 15:10   
How big is the list of regular expressions? The LruCache should be able to handle it unless the LruCache gets zero hits for that page. Is the regular called inside a loop? I.e.

  for ($array => $regexp) {
    preg_match($regexp, ...);
  }
(0003949)
nam   
04-04-09 02:23   
php/2025

added <regexp-cache-size> and <page-cache-entries> is going to be renamed to <page-cache-size>