diff --git a/bin/r/stats.csv.r b/bin/r/stats.csv.r new file mode 100644 index 0000000000000000000000000000000000000000..6685418dc5438f25e9f40d84df70a68bb8f26e00 --- /dev/null +++ b/bin/r/stats.csv.r @@ -0,0 +1,94 @@ +#rm(list=ls(all=TRUE)) +#data_fn="tmp/" +#folder_fn="results-benchmark-binary" +#results_fn=paste(data_fn,folder_fn,"/raw",sep="") +#outtxt_fn=paste(data_fn,folder_fn,"/results-text.txt",sep="") +#results_fn="raw" +#outtxt_fn="results-text.txt" + +configs.threads=1 +#configs.loop=10 +#configs.recursion=c(10) +#configs.labels=c("No Probe","Inactive Probe","Collecting Data","Writing Data (ASCII)", "Writing Data (Bin)") +configs.count=length(configs.labels) +#results.count=2000000 +#results.skip=1000000 + +#bars.minval=500 +#bars.maxval=600 + + +throughput = array(list(),dim=c(length(configs.recursion),configs.count)) +## "[ recursion , config , loop ]" +resultsBIG <- array(dim=c(length(configs.recursion),configs.count,configs.threads*configs.loop*(results.count-results.skip)),dimnames=list(configs.recursion,configs.labels,c(1:(configs.threads*configs.loop*(results.count-results.skip))))) +for (cr in configs.recursion) { + for (cc in (1:configs.count)) { + recordsPerSecond = c() + rpsLastTime = 0 + rpsCount = 0 + for (cl in (1:configs.loop)) { + results_fn_temp=paste(results_fn, "-", cl, "-", cr, "-", cc, ".csv", sep="") + for (ct in (1:configs.threads)) { + results=read.csv2(results_fn_temp,nrows=(results.count-results.skip),skip=(ct-1)*results.count+results.skip,quote="",colClasses=c("NULL","numeric"),comment.char="",col.names=c("thread_id","duration_nsec"),header=FALSE) + resultsBIG[(1:length(configs.recursion))[configs.recursion==cr],cc,c(((cl-1)*configs.threads*(results.count-results.skip)+1):(cl*configs.threads*(results.count-results.skip)))] <- results[["duration_nsec"]]/(1000) + + for (timeForRecord in results[["duration_nsec"]]) { + if (rpsLastTime + timeForRecord >= 1000000000) { + recordsPerSecond <- c(recordsPerSecond, rpsCount) + rpsCount = 0 + rpsLastTime = 1000000000 - rpsLastTime + } + while (timeForRecord > 1000000000) { + recordsPerSecond <- c(recordsPerSecond, 0) + timeForRecord = timeForRecord - 1000000000 + } + rpsCount = rpsCount + 1 + rpsLastTime = rpsLastTime + timeForRecord + } + } + rm(results,results_fn_temp) + } + recordsPerSecond <- c(recordsPerSecond, rpsCount) + throughput[[(1:length(configs.recursion))[configs.recursion==cr],cc]] <- recordsPerSecond + rm(recordsPerSecond,rpsLastTime,rpsCount) + } +} + + +for (cr in configs.recursion) { + printvalues = matrix(nrow=7,ncol=configs.count,dimnames=list(c("mean","ci95%","md25%","md50%","md75%","max","min"),c(1:configs.count))) + printthrough = matrix(nrow=7,ncol=configs.count,dimnames=list(c("mean","ci95%","md25%","md50%","md75%","max","min"),c(1:configs.count))) + for (cc in (1:configs.count)) { + printvalues["mean",cc]=mean(resultsBIG[(1:length(configs.recursion))[configs.recursion==cr],cc,c(1:(results.count-results.skip))]) + printvalues["ci95%",cc]=qnorm(0.975)*sd(resultsBIG[(1:length(configs.recursion))[configs.recursion==cr],cc,c(1:(results.count-results.skip))])/sqrt(length(resultsBIG[(1:length(configs.recursion))[configs.recursion==cr],cc,c(1:(results.count-results.skip))])) + printvalues[c("md25%","md50%","md75%"),cc]=quantile(resultsBIG[(1:length(configs.recursion))[configs.recursion==cr],cc,c(1:(results.count-results.skip))],probs=c(0.25,0.5,0.75)) + printvalues["max",cc]=max(resultsBIG[(1:length(configs.recursion))[configs.recursion==cr],cc,c(1:(results.count-results.skip))]) + printvalues["min",cc]=min(resultsBIG[(1:length(configs.recursion))[configs.recursion==cr],cc,c(1:(results.count-results.skip))]) + printthrough["mean",cc]=mean(throughput[[(1:length(configs.recursion))[configs.recursion==cr],cc]]) + printthrough["ci95%",cc]=qnorm(0.975)*sd(throughput[[(1:length(configs.recursion))[configs.recursion==cr],cc]])/sqrt(length(throughput[[(1:length(configs.recursion))[configs.recursion==cr],cc]])) + printthrough[c("md25%","md50%","md75%"),cc]=quantile(throughput[[(1:length(configs.recursion))[configs.recursion==cr],cc]],probs=c(0.25,0.5,0.75)) + printthrough["max",cc]=max(throughput[[(1:length(configs.recursion))[configs.recursion==cr],cc]]) + printthrough["min",cc]=min(throughput[[(1:length(configs.recursion))[configs.recursion==cr],cc]]) + } + resultstext=formatC(printvalues,format="f",digits=4,width=8) + throughtext=formatC(printthrough,format="f",digits=1,width=12) + print(resultstext) + print(throughtext) + write(paste("Recursion Depth: ", cr),file=outtxt_fn,append=TRUE) + write("response time",file=outtxt_fn,append=TRUE) + write.table(resultstext,file=outtxt_fn,append=TRUE,quote=FALSE,sep="\t",col.names=FALSE) + write("Throughput",file=outtxt_fn,append=TRUE) + write.table(throughtext,file=outtxt_fn,append=TRUE,quote=FALSE,sep="\t",col.names=FALSE) + + concResult <- "" + headResult <- "" + for (cc in (1:(configs.count-1))) { + headResult <- paste(headResult, configs.labels[cc], ","); + concResult <- paste(concResult, printvalues["mean",cc], ",") + } + headResult <- paste(headResult, configs.labels[configs.count]) + concResult <- paste(concResult, printvalues["mean",configs.count]) + + write(headResult,file=outcsv_fn,append=TRUE) + write(concResult,file=outcsv_fn,append=TRUE) +} diff --git a/build.xml b/build.xml index f634a02fb14f0d81282d6dc5a25af4a7dd2213cf..06ebece212db954631dc4b59ff3d7a2b8713e56a 100644 --- a/build.xml +++ b/build.xml @@ -5,6 +5,7 @@ <target name="build-kieker" depends="clean,init,compile-kieker,jar" /> <target name="build-inspectit" depends="clean,init,compile-inspectit,jar" /> <target name="build-spassmeter" depends="clean,init,compile-spassmeter,jar" /> + <target name="build-kieker-ci" depends="clean,init,compile-kieker,jar,jar-kieker-ci" /> <target name="init" depends=""> <mkdir dir="build" /> @@ -87,6 +88,18 @@ <fileset dir="bin/r" /> </copy> </target> + + <target name="jar-kieker-ci" depends="jar"> + <copy file="frameworks/Kieker/bin/benchmark-ci.sh" todir="dist" /> + <mkdir dir="dist/MooBench" /> + <move todir="dist/MooBench"> + <fileset dir="dist"> + <exclude name="MooBench"/> + </fileset> + </move> + <delete file="dist/MooBench/lib/kieker-1.10-SNAPSHOT_aspectj.jar" /> + <copy file="continuous-integration/executeRemoteMicroBenchmark.sh" todir="dist" /> + </target> <target name="clean"> <delete dir="build" /> diff --git a/continuous-integration/README b/continuous-integration/README index b08bbccff6baa1f6d6d15f3b4f2d79c283b23e13..6aebfa44e79339bfc9987617c8cc182131f46eff 100644 --- a/continuous-integration/README +++ b/continuous-integration/README @@ -19,7 +19,7 @@ We recommend to use SSH keys for the access. The client server should contain a prepared folder with a pre-compiled version of MooBench, as created by the build script with the appropriate -build target, e.g., 'build-kieker' for Kieker. +build target, e.g., 'build-kieker-ci' for Kieker. Refer to the Kieker git (http://git.kieker-monitoring.net/kieker.git) in folder '/examples/OverheadEvaluationMicrobenchmark' for a full example diff --git a/continuous-integration/executeRemoteMicroBenchmark.sh b/continuous-integration/executeRemoteMicroBenchmark.sh index 52ef33da90d3623dd4639f1a84c0a59ae0c228d7..e2d78f5c272d4b6b127a8302faf715ad2b3dbc3e 100644 --- a/continuous-integration/executeRemoteMicroBenchmark.sh +++ b/continuous-integration/executeRemoteMicroBenchmark.sh @@ -22,7 +22,7 @@ scp -r ${MOOBENCH_FOLDER} ${REMOTE_NODE}:MooBench scp ${BENCHMARKED_JAR} ${REMOTE_NODE}:MooBench/lib # Execute MooBench -ssh ${REMOTE_NODE} 'cd MooBench; chmod +x benchmark.sh; ./benchmark.sh; exit' +ssh ${REMOTE_NODE} 'cd MooBench; chmod +x benchmark-ci.sh; ./benchmark-ci.sh; exit' # Copy results to workspace scp ${REMOTE_NODE}:MooBench/tmp/${RESULTS_FOLDER_NAME}/results-text.csv ${RESULTS_TARGET_FILE} diff --git a/frameworks/Kieker/bin/benchmark-ci.sh b/frameworks/Kieker/bin/benchmark-ci.sh new file mode 100644 index 0000000000000000000000000000000000000000..8124922afe67f0002ab791564492db18ad943169 --- /dev/null +++ b/frameworks/Kieker/bin/benchmark-ci.sh @@ -0,0 +1,213 @@ +#!/bin/bash + +JAVABIN="" + +RSCRIPTDIR=r/ +BASEDIR=./ +RESULTSDIR="${BASEDIR}tmp/results-kieker/" + +SLEEPTIME=30 ## 30 +NUM_LOOPS=10 ## 10 +THREADS=1 ## 1 +RECURSIONDEPTH=10 ## 10 +TOTALCALLS=2000000 ## 2000000 +METHODTIME=0 ## 500000 + +MOREPARAMS="--quickstart" +MOREPARAMS="${MOREPARAMS} -r kieker.Logger" + +TIME=`expr ${METHODTIME} \* ${TOTALCALLS} / 1000000000 \* 4 \* ${RECURSIONDEPTH} \* ${NUM_LOOPS} + ${SLEEPTIME} \* 4 \* ${NUM_LOOPS} \* ${RECURSIONDEPTH} + 50 \* ${TOTALCALLS} / 1000000000 \* 4 \* ${RECURSIONDEPTH} \* ${NUM_LOOPS} ` +echo "Experiment will take circa ${TIME} seconds." + +echo "Removing and recreating '$RESULTSDIR'" +(rm -rf ${RESULTSDIR}) && mkdir ${RESULTSDIR} +#mkdir ${RESULTSDIR}stat/ + +# Clear kieker.log and initialize logging +rm -f ${BASEDIR}kieker.log +touch ${BASEDIR}kieker.log + +RAWFN="${RESULTSDIR}raw" + +JAVAARGS="-server" +JAVAARGS="${JAVAARGS} -d64" +JAVAARGS="${JAVAARGS} -Xms1G -Xmx4G" +#JAVAARGS="${JAVAARGS} -verbose:gc -XX:+PrintCompilation" +#JAVAARGS="${JAVAARGS} -XX:+PrintInlining" +#JAVAARGS="${JAVAARGS} -XX:+UnlockDiagnosticVMOptions -XX:+LogCompilation" +#JAVAARGS="${JAVAARGS} -Djava.compiler=NONE" +JAR="-jar MooBench.jar -a mooBench.monitoredApplication.MonitoredClassSimple" + +JAVAARGS_NOINSTR="${JAVAARGS}" +JAVAARGS_LTW="${JAVAARGS} -javaagent:${BASEDIR}lib/kieker-1.10-SNAPSHOT_aspectj.jar -Dorg.aspectj.weaver.showWeaveInfo=false -Daj.weaving.verbose=false -Dkieker.monitoring.skipDefaultAOPConfiguration=true -Dorg.aspectj.weaver.loadtime.configuration=META-INF/kieker.aop.xml" +JAVAARGS_KIEKER_DEACTV="${JAVAARGS_LTW} -Dkieker.monitoring.enabled=false -Dkieker.monitoring.writer=kieker.monitoring.writer.DummyWriter" +JAVAARGS_KIEKER_NOLOGGING="${JAVAARGS_LTW} -Dkieker.monitoring.writer=kieker.monitoring.writer.DummyWriter" +JAVAARGS_KIEKER_LOGGING_ASCII="${JAVAARGS_LTW} -Dkieker.monitoring.writer=kieker.monitoring.writer.filesystem.AsyncFsWriter -Dkieker.monitoring.writer.filesystem.AsyncFsWriter.customStoragePath=${BASEDIR}tmp" +JAVAARGS_KIEKER_LOGGING_BIN="${JAVAARGS_LTW} -Dkieker.monitoring.writer=kieker.monitoring.writer.filesystem.AsyncBinaryFsWriter -Dkieker.monitoring.writer.filesystem.AsyncBinaryFsWriter.customStoragePath=${BASEDIR}tmp" +JAVAARGS_KIEKER_LOGGING_TCP="${JAVAARGS_LTW} -Dkieker.monitoring.writer=kieker.monitoring.writer.tcp.TCPWriter" + +## Write configuration +uname -a >${RESULTSDIR}configuration.txt +${JAVABIN}java ${JAVAARGS} -version 2>>${RESULTSDIR}configuration.txt +echo "JAVAARGS: ${JAVAARGS}" >>${RESULTSDIR}configuration.txt +echo "" >>${RESULTSDIR}configuration.txt +echo "Runtime: circa ${TIME} seconds" >>${RESULTSDIR}configuration.txt +echo "" >>${RESULTSDIR}configuration.txt +echo "SLEEPTIME=${SLEEPTIME}" >>${RESULTSDIR}configuration.txt +echo "NUM_LOOPS=${NUM_LOOPS}" >>${RESULTSDIR}configuration.txt +echo "TOTALCALLS=${TOTALCALLS}" >>${RESULTSDIR}configuration.txt +echo "METHODTIME=${METHODTIME}" >>${RESULTSDIR}configuration.txt +echo "THREADS=${THREADS}" >>${RESULTSDIR}configuration.txt +echo "RECURSIONDEPTH=${RECURSIONDEPTH}" >>${RESULTSDIR}configuration.txt +sync + +## Execute Benchmark +for ((i=1;i<=${NUM_LOOPS};i+=1)); do + j=${RECURSIONDEPTH} + k=0 + echo "## Starting iteration ${i}/${NUM_LOOPS}" + echo "## Starting iteration ${i}/${NUM_LOOPS}" >>${BASEDIR}kieker.log + + # No instrumentation + k=`expr ${k} + 1` + echo " # ${i}.${j}.${k} No instrumentation" + echo " # ${i}.${j}.${k} No instrumentation" >>${BASEDIR}kieker.log + # sar -o ${RESULTSDIR}stat/sar-${i}-${j}-${k}.data 5 2000 1>/dev/null 2>&1 & + ${JAVABIN}java ${JAVAARGS_NOINSTR} ${JAR} \ + --output-filename ${RAWFN}-${i}-${j}-${k}.csv \ + --totalcalls ${TOTALCALLS} \ + --methodtime ${METHODTIME} \ + --totalthreads ${THREADS} \ + --recursiondepth ${j} \ + ${MOREPARAMS} + #kill %sar + [ -f ${BASEDIR}hotspot.log ] && mv ${BASEDIR}hotspot.log ${RESULTSDIR}hotspot-${i}-${j}-${k}.log + echo >>${BASEDIR}kieker.log + echo >>${BASEDIR}kieker.log + sync + sleep ${SLEEPTIME} + + # Deactivated probe + k=`expr ${k} + 1` + echo " # ${i}.${j}.${k} Deactivated probe" + echo " # ${i}.${j}.${k} Deactivated probe" >>${BASEDIR}kieker.log + #sar -o ${RESULTSDIR}stat/sar-${i}-${j}-${k}.data 5 2000 1>/dev/null 2>&1 & + ${JAVABIN}java ${JAVAARGS_KIEKER_DEACTV} ${JAR} \ + --output-filename ${RAWFN}-${i}-${j}-${k}.csv \ + --totalcalls ${TOTALCALLS} \ + --methodtime ${METHODTIME} \ + --totalthreads ${THREADS} \ + --recursiondepth ${j} \ + ${MOREPARAMS} + #kill %sar + [ -f ${BASEDIR}hotspot.log ] && mv ${BASEDIR}hotspot.log ${RESULTSDIR}hotspot-${i}-${j}-${k}.log + echo >>${BASEDIR}kieker.log + echo >>${BASEDIR}kieker.log + sync + sleep ${SLEEPTIME} + + # No logging + k=`expr ${k} + 1` + echo " # ${i}.${j}.${k} No logging (null writer)" + echo " # ${i}.${j}.${k} No logging (null writer)" >>${BASEDIR}kieker.log + # sar -o ${RESULTSDIR}stat/sar-${i}-${j}-${k}.data 5 2000 1>/dev/null 2>&1 & + ${JAVABIN}java ${JAVAARGS_KIEKER_NOLOGGING} ${JAR} \ + --output-filename ${RAWFN}-${i}-${j}-${k}.csv \ + --totalcalls ${TOTALCALLS} \ + --methodtime ${METHODTIME} \ + --totalthreads ${THREADS} \ + --recursiondepth ${j} \ + ${MOREPARAMS} + # kill %sar + [ -f ${BASEDIR}hotspot.log ] && mv ${BASEDIR}hotspot.log ${RESULTSDIR}hotspot-${i}-${j}-${k}.log + echo >>${BASEDIR}kieker.log + echo >>${BASEDIR}kieker.log + sync + sleep ${SLEEPTIME} + + # Logging + k=`expr ${k} + 1` + echo " # ${i}.${j}.${k} Logging (ASCII)" + echo " # ${i}.${j}.${k} Logging (ASCII)" >>${BASEDIR}kieker.log + # sar -o ${RESULTSDIR}stat/sar-${i}-${j}-${k}.data 5 2000 1>/dev/null 2>&1 & + ${JAVABIN}java ${JAVAARGS_KIEKER_LOGGING_ASCII} ${JAR} \ + --output-filename ${RAWFN}-${i}-${j}-${k}.csv \ + --totalcalls ${TOTALCALLS} \ + --methodtime ${METHODTIME} \ + --totalthreads ${THREADS} \ + --recursiondepth ${j} \ + ${MOREPARAMS} + #pkill sar + du -h ${BASEDIR}tmp/kieker-* + rm -rf ${BASEDIR}tmp/kieker-* + [ -f ${BASEDIR}hotspot.log ] && mv ${BASEDIR}hotspot.log ${RESULTSDIR}hotspot-${i}-${j}-${k}.log + echo >>${BASEDIR}kieker.log + echo >>${BASEDIR}kieker.log + sync + sleep ${SLEEPTIME} + + k=`expr ${k} + 1` + echo " # ${i}.${j}.${k} Logging (Bin)" + echo " # ${i}.${j}.${k} Logging (Bin)" >>${BASEDIR}kieker.log + # sar -o ${RESULTSDIR}stat/sar-${i}-${j}-${k}.data 5 2000 1>/dev/null 2>&1 & + ${JAVABIN}java ${JAVAARGS_KIEKER_LOGGING_BIN} ${JAR} \ + --output-filename ${RAWFN}-${i}-${j}-${k}.csv \ + --totalcalls ${TOTALCALLS} \ + --methodtime ${METHODTIME} \ + --totalthreads ${THREADS} \ + --recursiondepth ${j} \ + ${MOREPARAMS} + #pkill sar + du -h ${BASEDIR}tmp/kieker-* + rm -rf ${BASEDIR}tmp/kieker-* + [ -f ${BASEDIR}hotspot.log ] && mv ${BASEDIR}hotspot.log ${RESULTSDIR}hotspot-${i}-${j}-${k}.log + echo >>${BASEDIR}kieker.log + echo >>${BASEDIR}kieker.log + sync + sleep ${SLEEPTIME} + + k=`expr ${k} + 1` + echo " # ${i}.${j}.${k} Logging (TCP)" + echo " # ${i}.${j}.${k} Logging (TCP)" >>${BASEDIR}kieker.log + # sar -o ${RESULTSDIR}stat/sar-${i}-${j}-${k}.data 5 2000 1>/dev/null 2>&1 & + ${JAVABIN}java -classpath MooBench.jar kieker.tcp.TestExperiment0 >> ${BASEDIR}kieker.tcp.log & + ${JAVABIN}java ${JAVAARGS_KIEKER_LOGGING_TCP} ${JAR} \ + --output-filename ${RAWFN}-${i}-${j}-${k}.csv \ + --totalcalls ${TOTALCALLS} \ + --methodtime ${METHODTIME} \ + --totalthreads ${THREADS} \ + --recursiondepth ${j} \ + ${MOREPARAMS} + #pkill sar + [ -f ${BASEDIR}hotspot.log ] && mv ${BASEDIR}hotspot.log ${RESULTSDIR}hotspot-${i}-${j}-${k}.log + echo >>${BASEDIR}kieker.log + echo >>${BASEDIR}kieker.log + sync + sleep ${SLEEPTIME} + + +done +#zip -jqr ${RESULTSDIR}stat.zip ${RESULTSDIR}stat +#rm -rf ${RESULTSDIR}stat/ +mv ${BASEDIR}kieker.log ${RESULTSDIR}kieker.log +[ -f ${RESULTSDIR}hotspot-1-${RECURSIONDEPTH}-1.log ] && grep "<task " ${RESULTSDIR}hotspot-*.log >${RESULTSDIR}log.log +[ -f ${BASEDIR}errorlog.txt ] && mv ${BASEDIR}errorlog.txt ${RESULTSDIR} + +## Generate Results file +R --vanilla --silent <<EOF +results_fn="${RAWFN}" +outtxt_fn="${RESULTSDIR}results-text.txt" +outcsv_fn="${RESULTSDIR}results-text.csv" +configs.loop=${NUM_LOOPS} +configs.recursion=c(${RECURSIONDEPTH}) +configs.labels=c("No Probe","Deactivated Probe","Collecting Data","Writer (ASCII)", "Writer (Bin)", "Writer (TCP)") +results.count=${TOTALCALLS} +results.skip=${TOTALCALLS}/2 +source("${RSCRIPTDIR}stats.csv.r") +EOF + +## Clean up raw results +zip -jqr ${RESULTSDIR}results.zip ${RAWFN}* +rm -f ${RAWFN}* +[ -f ${BASEDIR}nohup.out ] && cp ${BASEDIR}nohup.out ${RESULTSDIR} +[ -f ${BASEDIR}nohup.out ] && > ${BASEDIR}nohup.out