package com.snail.exam.aj.performance; import org.aspectj.lang.JoinPoint; import org.aspectj.lang.Signature; import org.aspectj.lang.annotation.After; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.annotation.Before; import org.aspectj.lang.annotation.Pointcut; import java.util.Date; import java.util.Stack; import java.util.logging.Logger; // !! 必要があればlog4jに変えて !! @Aspect public class PerformanceLog { private static ThreadLocal<Stack<Date>> threadLocalStack = new ThreadLocal<Stack<Date>>() { @Override public Stack<Date> initialValue() { return new Stack<Date>(); } }; Logger logger = Logger.getLogger("PerformanceLog"); @After("performanceLog()") public void afterPublicMethodCall(JoinPoint thisJoinPoint) { Date start = threadLocalStack.get().pop(); long diff = System.currentTimeMillis() - start.getTime(); diff = diff < 1 ? 1 : diff; // 0ms の場合は切り上げ Signature sig = thisJoinPoint.getSignature(); Object[] args = thisJoinPoint.getArgs(); String clazzName = sig.getDeclaringTypeName(); String methodName = sig.getName(); StringBuilder sb = new StringBuilder(); sb.append(clazzName); sb.append("#"); sb.append(methodName); sb.append("("); try { if (args.length > 0) { int cnt; for (cnt = 0; cnt < (args.length - 1); cnt++) { sb.append(args[cnt].getClass().getName()); sb.append("_ "); // 集計VBSの都合上 "," ではなく "_" を使う } sb.append(args[cnt].getClass().getName()); } } catch (Exception ignore) { // native メソッドの引数を取ろうとすると Null Pointer Exception が起きる ignore = null; } sb.append("),"); sb.append(diff); logger.info(sb.toString()); } @Before("performanceLog()") public void beforePublicMethodCall(JoinPoint thisJoinPoint) { threadLocalStack.get().push(new Date()); } @Pointcut("execution(public * *.*(..)) && !within(PerformanceLog)") public void performanceLog() { } }
※実行時に aspectjrt.jar (AspectJのランタイムライブラリ)に Classpath を通しておく必要がある
# java -jar aspectj-1.6.10.jar
<project name="simple-example" default="compile" > <taskdef resource="org/aspectj/tools/ant/taskdefs/aspectjTaskdefs.properties"> <classpath> <pathelement location="${aspectj.dir}/tools/aspectj/lib/aspectjtools.jar"/> </classpath> </taskdef> <target name="compile2" > <iajc sourceroots="${aspectj.dir}/ec/project/src" destDir="${classes}" encodeing="UTF-8" source="1.5" classpath="${aspectj.dir}/tools/aspectj/lib/aspectjrt.jar"/> </target> </project>
<appender name="PERFORMANCE" class="org.apache.log4j.DailyRollingFileAppender"> <!-- デフォルトのログレベル --> <param name="threshold" value="info" /> <!-- ファイル情報 --> <param name="file" value="performance.csv" /> <param name="append" value="false" /> <param name="datePattern" value="'.'yyyy-MM-dd" /> <!-- レイアウトの指定 (メッセージだけ) --> <layout class="org.apache.log4j.PatternLayout"> <param name="ConversionPattern" value="%m%n" /> </layout> </appender> <category name="PerformanceLog"> <priority value="info" /> <appender-ref="PERFORMANCE" /> </category>
{呼び出しメソッド名},{処理時間}\n
Dim fs Dim srcFile Dim destFile Set fs = WScript.CreateObject("Scripting.FileSystemObject") ' 1:読込専用, 2:書込専用, 8:追加専用 Set srcFile = fs.OpenTextFile("performance.csv", 1) Set destFile = fs.CreateTextFile("report.csv", 2) Set cntDic = CreateObject("Scripting.Dictionary") '出現回数 Set sumDic = CreateObject("Scripting.Dictionary") '消費時間の和 Set sqrDic = CreateObject("Scripting.Dictionary") '消費時間の自乗和 Set avrDic = CreateObject("Scripting.Dictionary") '平均 Set sigDic = CreateObject("Scripting.Dictionary") '分散 '分散(σ)は、定義式のままだと、2回データを読まなければならないので '変形して、1回で済むようにする。 'σ= SQRT( Σ( (Xi - AVR(X)) / n )^2 ) // 定義式(1.平均を求る→2.分散を求める) ' = SQRT( Σ((Xi^2)/n) - Σ(Xi/n)^2 ) ' =========================================== ' データの読み込み ' =========================================== Do Until srcFile.AtEndOfLine Dim line line = srcFile.ReadLine() entrySet = Split(line, ",") method = entrySet(0) msec = entrySet(1) 'Wscript.echo( "READ:" & method ) if cntDic.Exists(method) then cnt = CDbl(cntDic.Item(method)) cntDic.Remove method cntDic.Add method,CStr(cnt+1) sum = CDbl(sumDic.Item(method)) sumDic.Remove method sumDic.Add method,CStr(sum+msec) sqrSum = CDbl(sqrDic.Item(method)) sqrDic.Remove method sqrDic.Add method,CStr(sqrSum + msec*msec) else cntDic.Add method,"1" sumDic.Add method,CStr(msec) sqrDic.Add method,CStr(msec*msec) end if Loop ' =========================================== ' 平均・分散を求める ' =========================================== For Each method in cntDic cnt = CDbl(cntDic.Item(method)) sum = CDbl(sumDic.Item(method)) sqrSum = CDbl(sqrDic.Item(method)) average = sum/cnt sigma = Sqr( sqrSum/cnt - average*average ) avrDic.Add method,CStr(average) sigDic.Add method,CStr(sigma) Next ' =========================================== ' レポートの出力 ' =========================================== destFile.WriteLine("メソッド,総処理時間,呼び出し回数,平均処理時間,分散") methodArray = avrDic.keys() ' 平均時刻順にソートする(Bubble Sort) For i = 0 to UBound(methodArray) - 1 For j = i+1 to UBound(methodArray) avr1 = CDbl(avrDic.item(methodArray(i))) avr2 = CDbl(avrDic.item(methodArray(j))) if avr1 < avr2 then tmp = methodArray(i) methodArray(i) = methodArray(j) methodArray(j) = tmp end if next next 'ファイル出力 For Each method in methodArray destLine = method destLine = destLine & "," & sumDic.Item(method) destLine = destLine & "," & cntDic.Item(method) destLine = destLine & "," & avrDic.Item(method) destLine = destLine & "," & sigDic.Item(method) destFile.WriteLine(destLine) Next Call srcFile.Close() Call destFile.Close() MsgBox( "できたよ" )