負荷テストその3(Grails 0.5)

Grails

先日までの内容の負荷テストを元にちょっといじってみた。なお、以下の内容についての責任は一切負わないので自己の責任で。
まずは、コントローラの生成が重い点についてだが、どうもクロージャの生成が特に重いようだ。以下のメソッドを変えてみる。Groovyの1.1 BETA 1のソースをSVNで取ってきて変更する。
groovy.lang.MetaClassImplの以下のメソッド

   public int selectConstructorAndTransformArguments(int numberOfCosntructors, Object[] arguments) {
       //TODO: that is just a quick prototype, not the real thing!
       if (numberOfCosntructors != constructors.size()) {

       [...]

       List l = new ArrayList(constructors);
       Comparator comp = new Comparator() {
           public int compare(Object arg0, Object arg1) {
               Constructor c0 = (Constructor) arg0;
               Constructor c1 = (Constructor) arg1;
               String descriptor0 = BytecodeHelper.getMethodDescriptor(Void.TYPE, c0.getParameterTypes()); 
               String descriptor1 = BytecodeHelper.getMethodDescriptor(Void.TYPE, c1.getParameterTypes());
               return descriptor0.compareTo(descriptor1);
           }            
       };
       Collections.sort(l,comp);

       [...]
       return ret;
   }

「just a quick prototype」なので、重いのもしょうがないのかも。constructorsの内容自体は変更されることはないようだ。で、これを以下のように変更。

       List l = sortedConstructors;
       if (l == null) {
           l = new ArrayList(constructors);
           Comparator comp = new Comparator() {
               public int compare(Object arg0, Object arg1) {
                   Constructor c0 = (Constructor) arg0;
                   Constructor c1 = (Constructor) arg1;
                   String descriptor0 = BytecodeHelper.getMethodDescriptor(Void.TYPE, c0.getParameterTypes()); 
                   String descriptor1 = BytecodeHelper.getMethodDescriptor(Void.TYPE, c1.getParameterTypes());
                   return descriptor0.compareTo(descriptor1);
               }
           };
           Collections.sort(l,comp);
           sortedConstructors = l;
       }

インスタンス変数sortedConstructorsを追加して、そこに結果を保持するようにした。要はキャッシュした、ということ。

次に、コントローラのgetProperty()が重いことについての変更。
まずは、テストプログラムで検証。

package jp.ne.hatena.d.noryksj.test.groovy;

import groovy.lang.GroovyClassLoader;
import groovy.lang.GroovyObject;

public class PropertyLabo {
	String code =
		"class LaboLabo {\n" +
		"private String address\n" +
		"def message = 'Hello'\n" +
		"def square = {x -> x * x }\n" +
		"def getNow = {-> new java.util.Date() }\n" +
		"static staticSquare = {x -> x * x }\n" +
		"String getName() { return 'YOUR NAME' }\n" +
		"void setAddress(String address) {  }\n" +
		"}";
	GroovyClassLoader loader;
	
	public GroovyObject loadObject() throws Exception {
		if (loader == null) {
			loader = new GroovyClassLoader();
		}
		return	(GroovyObject)loader.parseClass(code).newInstance();
	}
}

以下のようなテストケースでテスト。

package jp.ne.hatena.d.noryksj.test.groovy;

[...]

public class PropertyLaboTest extends TestCase {
	static int COUNT = 300000;

	public PropertyLaboTest(String name) {
		super(name);
	}
	
	public void testSimpleProp() throws Exception {
		PropertyLabo labo = new PropertyLabo();
		GroovyObject obj = labo.loadObject();
		assertNotNull(obj);
		assertEquals("Hello", obj.getProperty("message"));
		long start, end;
		
		start = System.currentTimeMillis();
		for (int i = COUNT; i > 0; --i) {
			assertEquals("Hello", obj.getProperty("message"));
		}
		end = System.currentTimeMillis();
		System.out.println("01 Elapsed = " + (end - start));
	}
	
	public void testSimplePropCachedMP() throws Exception {
		PropertyLabo labo = new PropertyLabo();
		GroovyObject obj = labo.loadObject();
		
		MetaClass mc = obj.getMetaClass();
		List props = mc.getProperties();
		Map map = new HashMap(props.size());
		for (Iterator it = props.iterator(); it.hasNext(); ) {
			MetaProperty mp = (MetaProperty)it.next();
			map.put(mp.getName(), mp);
		}
        
		assertNotNull(obj);
		assertEquals("Hello", obj.getProperty("message"));
		long start, end;
		
		start = System.currentTimeMillis();
		for (int i = COUNT; i > 0; --i) {
			MetaProperty mp = (MetaProperty)map.get("message");
			assertEquals("Hello", mp.getProperty(obj));
		}
		end = System.currentTimeMillis();
		System.out.println("02 Elapsed = " + (end - start));
	}
	
	public void testSimplePropDirectMP() throws Exception {
		PropertyLabo labo = new PropertyLabo();
		GroovyObject obj = labo.loadObject();
		
		assertNotNull(obj);
		assertEquals("Hello", obj.getProperty("message"));
		long start, end;
		
		start = System.currentTimeMillis();
		for (int i = COUNT; i > 0; --i) {
			assertEquals("Hello", obj.getMetaClass().getProperty(obj, "message"));
		}
		end = System.currentTimeMillis();
		System.out.println("03 Elapsed = " + (end - start));
	}

	[...]
}

テストの内容としては、

  1. GroovyObject.getProperty(String)を毎回実行
  2. GroovyObject.getMetaClass().getProperties()を最初に実行して、結果を最初に取っておいて、MetaProperty.getProperty(Object)のみを毎回実行
  3. GroovyObject.getmetaClass().getProperty(Object, String)を毎回実行

で、結果は、

01 Elapsed = 843
02 Elapsed = 78
03 Elapsed = 204

となった。MetaProperty.getProperty()を実行するだけが一番速い。
なぜこんなに時間の差があるのかというと、多分、GroovyObject.getProperty(String)とMetaProperty.getProperty(Object)は等価ではないのだろう。ただし、今回のようなコントローラのプロパティ取得という限定された状況で、結果が同じならばより速い方法を採用してもいいかもしれない。取得するコントローラのプロパティはプログラム上ほぼ固定なので、その範囲内で等価な動作であるかを確認すればよいのではなかろうか？
で、とりあえず、GrailsUtil内にこんなユーティリティメソッドを作ってみた。

    public static Object getProperty(GroovyObject object, String name) {
//    	if (isDevelopmentEnv()) {
//    		return	object.getProperty(name);
//    	}
    	return	GPUTIL.getProperty(object, name, false);
    }

    private static GroovyPropertyUtil GPUTIL = new GroovyPropertyUtil();
    private static class GroovyPropertyUtil {
    	private Map cache = Collections.synchronizedMap(new HashMap());
    	private static final Object[] EMPTY = {};
    	
    	public Object getProperty(GroovyObject object, String name) {
    		MetaClass mc = null;
    		Class clazz = object.getClass();
    		Map mpMap = (Map)cache.get(clazz);
    		if (mpMap == null) {
    			mc = object.getMetaClass();
    			mpMap = buildMetaPropertyMap(mc);
    	        	cache.put(clazz, mpMap);
    		}
    		MetaProperty mp = (MetaProperty)mpMap.get(name);
    		if (mp == null) {
    			else if (mc == null) {
    				mc = object.getMetaClass();
    			}
    			return	mc.getProperty(object, name);
    		}
   		return	mp.getProperty(object);
    	}
    	
    	private void appendMetaBeanProperty(Map toAdd, List props) {
    		for (Iterator it = props.iterator(); it.hasNext(); ) {
    			MetaProperty mp = (MetaProperty)it.next();
    			toAdd.put(mp.getName(), mp);
    		}
    	}
    	
    	private Map buildMetaPropertyMap(MetaClass mc) {
    		Map mpMap = new HashMap();
    		appendMetaBeanProperty(mpMap, mc.getProperties());
    		return	mpMap;
    	}
    }

コントローラのプロパティを取得しているところをこのメソッドの呼出に置き換える。例えば、org.codehaus.groovy.grails.web.servlet.mvc.SimpleGrailsControllerHelperではコントローラのプロパティを取得しまくっている(ここでは割愛)。
変更してビルドするとエラーが。「Cannot read write-only property: constraints」だそうだ。
投げ元はMetaBeanPropertyのここ。

    public Object getProperty(Object object) {
        if (getter == null) {
            //TODO: we probably need a WriteOnlyException class
            throw new GroovyRuntimeException("Cannot read write-only property: " + name);
        }
        return getter.invoke(object, MetaClassHelper.EMPTY_ARRAY);
    }

ふむふむ、getterがないわけね。Write-Onlyのプロパティを取得するわけがないと思うのだけれど、先ほどのユーティリティをこんな風にしてみた。

    	private void appendMetaBeanProperty(Map toAdd, List props) {
    		for (Iterator it = props.iterator(); it.hasNext(); ) {
    			MetaProperty mp = (MetaProperty)it.next();
    			String name = mp.getName();
    			if (!(mp instanceof MetaBeanProperty)) {
    				continue;
    			}
    			MetaBeanProperty mbp = (MetaBeanProperty)mp;
    			final MetaMethod getter = mbp.getGetter();
    			if (getter == null) {
    				mp = new MetaProperty(name, mp.getType()) {
    					public Object getProperty(Object object) {
    						return	null;
    					}
    					public void setProperty(Object object, Object value) {
    						// Do nothing.
    					}
    				};
    			}
    			toAdd.put(mp.getName(), mp);
    		}
    	}

getterがなかったらnull返すMetaPropertyをキャッシュするようにしてみた。で、テスト。結果は同じ。getterあるのにないってどういうことだ！！
よくよく調べると、GroovyObject.getMetaClass()で返ってきているのはExpandoMetaClassで、このクラスは、getGetter()をオーバライドしていて常にgetterを返す。しかし、実際にgetProperty()を実行すると、親クラス側にはgetterがセットされていないらしい、ということみたいだ。
それから、それから、他にもまだまだたくさんあるが、とりあえず以下のようなコードにしている。

    	private void appendMetaBeanProperty(Map toAdd, List props) {
    		for (Iterator it = props.iterator(); it.hasNext(); ) {
    			MetaProperty mp = (MetaProperty)it.next();
    			String name = mp.getName();
    			if (!(mp instanceof MetaBeanProperty)) {
    				continue;
    			}
    			MetaBeanProperty mbp = (MetaBeanProperty)mp;
    			final MetaMethod getter = mbp.getGetter();
    			if (getter == null) {
    				mp = new MetaProperty(name, mp.getType()) {
    					public Object getProperty(Object object) {
    						return	null;
    					}
    					public void setProperty(Object object, Object value) {
    						// Do nothing.
    					}
    				};
    			}
    			else {
    				mp = new MetaProperty(name, mp.getType()) {
    					public Object getProperty(Object object) {
    						return	getter.invoke(object, EMPTY);
    					}
    					public void setProperty(Object object, Object value) {
    						// Do nothing.
    					}
    				};
    			}
    			toAdd.put(mp.getName(), mp);
    		}
    	}

getterがあったらそれを実行する、という内容にしてみた。
次に、DefaultGrailsControllerClassにある以下のような箇所。

	public boolean isInterceptedBefore(GroovyObject controller, String action) {
		final Map controllerProperties = DefaultGroovyMethods.getProperties(controller);
		return isIntercepted(controllerProperties.get(BEFORE_INTERCEPTOR),action);
	}

どうもDefaultGroovyMethods.getProperties(controller)で、コントローラのプロパティを一括してとって、その後にインタセプターがあるかを判定しているようだ。要は全部のプロパティを取得しているわけで、インタセプタの登録ない場合にNoSuchPropertyみたいな例外が上がらないようにということなのだろうか？これは、先ほどのMetaPropertyにインタセプタのMetaPropertyがないかを判定するだけでいいような気がする。
次に、ControllersGrailsPlugin.groovyのactionUriと、controllerNameを以下のように展開した。

			metaClass.getActionUri = {->
				('/' << RCH.currentRequestAttributes().controllerName << '/' << RCH.currentRequestAttributes().actionName).toString()
			}
			metaClass.getControllerUri = {->
				('/' << RCH.currentRequestAttributes().controllerName).toString()
			}

最後に、Grailsとは関係ないが、自前のHttpSessionの実装でフラッシュスコープの中身が存在しない場合には、フラッシュスコープを永続化しないように修正した。

これらの修正を施した結果は、

$ ab -c 300 -n 30000 http://localhost:8080/pagetest-0.1/test01
This is ApacheBench, Version 2.0.40-dev <$Revision: 1.146 $> apache-2.0
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Copyright 2006 The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
Completed 3000 requests
Completed 6000 requests
Completed 9000 requests
Completed 12000 requests
Completed 15000 requests
Completed 18000 requests
Completed 21000 requests
Completed 24000 requests
Completed 27000 requests
Finished 30000 requests


Server Software:        Apache-Coyote/1.1
Server Hostname:        localhost
Server Port:            8080

Document Path:          /pagetest-0.1/test01
Document Length:        90 bytes

Concurrency Level:      300
Time taken for tests:   38.879998 seconds
Complete requests:      30000
Failed requests:        0
Write errors:           0
Total transferred:      8097996 bytes
HTML transferred:       2700000 bytes
Requests per second:    771.60 [#/sec] (mean)
Time per request:       388.800 [ms] (mean)
Time per request:       1.296 [ms] (mean, across all concurrent requests)
Transfer rate:          203.40 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0  151 791.9      1   21018
Processing:     4  143  87.6    125    1342
Waiting:        0  138  86.9    119    1340
Total:         15  295 796.8    133   21132

Percentage of the requests served within a certain time (ms)
  50%    133
  66%    162
  75%    183
  80%    200
  90%    267
  95%    574
  98%   3154
  99%   3209
 100%  21132 (longest request)

まだまだだけども、前の結果と見比べて欲しい。