trace()とlogger.debug()の負荷テスト

<?xml version="1.0" encoding="utf-8"?>
<mx:Application xmlns:mx="http://www.adobe.com/2006/mxml"
	xmlns:local="*"
	layout="vertical"
	scriptTimeLimit="5"
	viewSourceURL="srcview/index.html">
	
	<mx:Script>
	<![CDATA[
	import mx.logging.ILogger;
	import mx.logging.Log;
	import mx.logging.targets.TraceTarget;
	
	private static const logger:ILogger = Log.getLogger("TraceTest");
	
	private static const NONE:String = "trace()なし";
	private static const TRACE:String = "trace()あり";
	private static const LOGGER:String = "logger.debug()"
	
	private var tt:TraceTarget;
	
	private function test(testCase:String):void
	{
		var loopCount:int = int(count_ns.value);
		
		var start:int, now:int;
		var i:int;
		
		output("■" + testCase);
		
		try
		{
			switch (testCase)
			{
				case NONE:
					start = getTimer();
					for (i = 0; i < loopCount; i++) {
						"abcdefghijklmnopqrstuvwxyz";
					}
					now = getTimer();
					break;
				case TRACE:
					start = getTimer();
					for (i = 0; i < loopCount; i++) {
						trace("abcdefghijklmnopqrstuvwxyz");
					}
					now = getTimer();
					break;
				case LOGGER:
					start = getTimer();
					for (i = 0; i < loopCount; i++) {
						logger.debug("abcdefghijklmnopqrstuvwxyz");
					}
					now = getTimer();
					break;
			}
		}
		catch (e:Error)
		{
			now = getTimer();
			
			output("  " + i + "回目でエラー: " + e);
		}
		var time:int = now - start;
		output("  経過時間(ミリ秒): " + nf.format(time));
		output("  1秒あたりのループ回数: " + nf.format(i * 1000 / time));
		output("----------------------------------------");
	}
	
	private function updateTraceTarget():void
	{
		if (!tt)
		{
			tt = new TraceTarget();
			tt.includeDate = false;
			tt.includeTime = false;
			tt.includeLevel = true;
			tt.includeCategory = true;
		}
		
		if (traceTarget_ch.selected)
		{
			Log.addTarget(tt);
		}
		else
		{
			Log.removeTarget(tt);
		}
	}
	
	private function output(msg:String):void
	{
		output_ta.text += msg + "\n";
	}

	]]>
	</mx:Script>
	
	<mx:NumberFormatter id="nf" precision="0" />
	
	<mx:Panel title="trace()とlogger.debug()の負荷テスト"
		width="100%" height="100%"
		paddingTop="8" paddingRight="8" paddingBottom="8" paddingLeft="8">
		
		<mx:HBox>
			<mx:Label text="forループ回数:" />
			<mx:NumericStepper id="count_ns" value="1000000" maximum="10000000" />
		</mx:HBox>
		
		<mx:HBox>
			<mx:Button label="trace()なし" click="test(NONE)" />
			<mx:Button label="trace()あり" click="test(TRACE)" />
			<mx:Button label="logger.debug()" click="test(LOGGER)" />
			<mx:CheckBox id="traceTarget_ch" label="TraceTargetを追加" change="updateTraceTarget()"/>
		</mx:HBox>
		
		<mx:TextArea id="output_ta" width="100%" height="100%" />
		
		<mx:Label color="red" text="※Application.scriptTimeLimitを5秒に設定してます" selectable="true" />
		
		<mx:ControlBar verticalAlign="middle">
			<mx:Label text="Compiled with Flex Builder 3 beta 3 (3.0.190133)" selectable="true" />
			<mx:Spacer width="100%" minWidth="10" />
			<local:SignatureBox />
		</mx:ControlBar>
		
	</mx:Panel>
	
</mx:Application>

trace()は確かに負荷があります。それに比べるとlogger.debug()は軽いですね（TraceTargetを追加していない状態で）。

現時点ではFlexのコードにはtrace()を書かないのが正解なのかも。同じことが1年以上前にsato-shiさんのブログに書かれてました。

僕はFlexのロギングAPIが割と好きですが、mxパッケージに依存するがちょっといやな感じです。FlashでもFlexでも使える共通のロギングAPIがあればいいなと以前から思っていたので、今度時間があるときにそういうのを提案しようかな。

追記（2008-01-13）: 負荷テスト結果をグラフにまとめました。