\chapter{Performance Tuning Process}\label{ch:tuning}
This chapter introduces a series of steps aiming to improve the performance of a JStar program. The process basically
follows the quality improvement cycle: assess-measure-modify-evaluate. First, \keyword{assess} the program and establish
the performance index. Second, \keyword{measure} the performance and analyze the problems to find the bottleneck. Third,
\keyword{modify} the implementation and conduct trial experiments. Last, \keyword{evaluate} the performance after the
modification and check whether the change has improved the performance. Repeat these above four steps until the
performance becomes better.
\section{Performance Tuning Procedure}
After experimenting with this process for a number of times, we summarize the strategy in the following steps:
\begin{enumerate}
  \item Analyze the task dependencies and identify tuple options.
  \begin{enumerate}
    \item Generate the task dependency graph.
    \item In-line the Delta tuples : Look at the graph and add a \flag{-noDelta T} flag to for every table $T$ that is
    NOT used as a trigger.
    \item In-line the Gamma tuples: Look at the graph and add a \flag{-noGamma T} flag to every table T that is
    never queried.
  \end{enumerate}
  \item Translate the JStar program to the equivalent Java implementation.\\
  Compile the JStar program into a Java parallel program by specifying the above options and the sequential (\flag{-seq})
  / parallel (\flag{-par}) mode to the JStar compiler.
  Then the Java compiler is used to convert all the Java source code(.java) into the byte-code(.class).
  \item Reduce the amount of the messages.\\
  Make sure that the program does not display the unnecessary messages as the \method{println} method bottlenecks the
  performance. Reduce the output to a few lines/second if possible.
  \item Repeat the experiment.\\
  Make sure that the program runs 30 times (\flag{--benchmark=30}) or more to let the Hotspot compiler settle down, and
  get the reliable average by ignoring at least the first 6 measurement.
  \item Vary the number of threads.\\
  Run the program by varying the Fork/Join pool size (\flag{--threads=N}) from 1\ldots8 or 1\ldots15. Plot the speedup
  curve and stop if the speedup is good enough.
  \item Avoid the performance bottleneck from Java garbage collection.\\
  Run the Java program with the \flag{-verbose:gc} option to print out the information of Java garbage collector.
  Look at the GC times to see if they take up a large percentage of the total running time.  If so, try running the
  program with a larger heap. Or think about how to change the program so that fewer tuples are generated or garbage collected.
  \item Tune the performance of Java virtual machine (JVM).\\
  Run the program with a single thread and the \keyword{HotSpot} profiler (\flag{-Xprof}). And Investigate what part of
  the program takes up most of the CPU time.
  \begin{enumerate}
    \item If it is in one of the data structure methods, think about how to make that generic data structure more
    efficient for this particular program, e.g. using a fixed size array instead of the \class{HashTable}.
    \item If it is in one of the rules, check whether that rule is being executed in parallel, or is it a sequential
    bottleneck.  If the latter, rewrite the JStar program so that rule is done in smaller parts, so that it can be done
    in parallel.
  \end{enumerate}
\end{enumerate}
\section{Performance Tuning Tools}
We developed some tools to ease the burden of the performance tuners. As investigating the bottlenecks is not easy and
sometimes time-consuming, our tools provides some graphs or text messages to shorten the time of finding out the tuple
strategy and improving the performance of a JStar program. These tools are described in the following sections.
\subsection{Task Dependency Graph}
Tuple transactions during the execution of a JStar program can be logged in a plain text file by enabling the \flag{log}
option (\flag{--log=log.txt}). There are two types of transactions: \keyword{PUT} and \keyword{GET}. After a tuple is
inserted into the Delta tree, the logger writes out a \keyword{PUT} message. When a rule queries tuples from the Gamma
database, the logger writes a \keyword{GET} message. The \keyword{GET} and \keyword{PUT} messages contain the
triggered rule name, input and output tuple names. The following list is the snippet of the log file of the JStar
PvWattsGamma program.
\begin{lstlisting}
PUT,CmdLineArg,Gamma
rule1,CmdLineArg
PUT,GenTuples,Delta
...
PUT,GenTuples,Delta
PUT,GenTuples,Gamma
..
\end{lstlisting}
\begin{figure}[h]
\centering
\begin{tabular}{c}
\includegraphics[height=0.3\textheight]{./tuneperformance/figure/dependency.eps}\\
\hfill \keyword{TRIGGER}(Rule):$\boldsymbol{\longrightarrow}$\hspace{5mm}\keyword{PUT}(Gamma Database):{\color{red}${-\rightarrow}$}\\
\hfill \keyword{PUT}(Delta Tree):{\color{red}$\longrightarrow$}\hspace{5mm}\keyword{GET}(Gamma Database):{\color{blue}$-\rightarrow$}\\
\end{tabular}
\caption[Task dependency graph of the JStar PvWattsGamma Program]
{The task dependency graph of the JStar PvWattsGamma Program.}
\label{fig:PvWattsGammaTaskDependencyGraph}
\end{figure}
\par The JStar dependency program reads this log file and outputs the task dependency graph (output.dot), which shows
the table usage. As the task dependency graphs are written in the \keyword{DOT} language, the \class{Graphviz} is used
to view these graphs and to convert them to other graphics file formats, such as EPS (Ecapsulated PostScript)
file.\cite{Ellson03graphvizand} The following command can generate a task dependency graph from the log file (log.txt),
and convert it from the dot file (output.dot) to a EPS file (dependency.eps).
Figure~\ref{fig:PvWattsGammaTaskDependencyGraph} is the task dependency graph of the JStar PvWattsGamma program.
\begin{lstlisting}
java -cp Dependency.jar jstar.example.dependency.Main log.txt
dot -Tps output.dot -o dependency.eps
\end{lstlisting}
\subsection[Debug Trace Output]{Debug Trace Output for Delta Tree, CPU Usage and JStar Tuple Timing Graph}
Debugging is commonly used in any programming language. By printing out messages, programmers can easily track the value
of a variable in each state and verify the correctness of the program. But a multiple threading programs introduces many
potential bugs. For example, the JStar Delta tree is shared among all threads in the ForkJoinPool, but is allowed only
one task (thread) to add the Delta nodes at one time. If a task incorrectly locks the Delta tree, then other tasks have
to spend lots of time waiting for \keyword{stall} (a delay in the execution time) to be free.
To avoid this potential bug, we can implement the synchronization of the Delta tree by using the Java \keyword{Lock}
object or by retrying the lock-free data structure.
Two debug flags have been implemented on the JStar runtime to display the Delta tree information, such as the
delta tree size and the CPU usage. In addition, we developed the tuple timing graph to visualize the tuple processing
time.
\begin{description}
\item [Delta Tree Size] (\flag{--debug=delta})
flag enables the JStar runtime to display the total number of tuples in each leaf node of
the Delta tree.
\item [CPU Usage] (\flag{--debug=cpu})
flag enables the JStar runtime to display the time that a tuple has been processed by a thread
and its CPU time. This flag outputs the tuple timing for each tuple in the Delta set, including the \keyword{CPU usage},
the \keyword{starting and ending wall clock time}, and \keyword{the tuple}. The starting wall clock time of a tuple is
the time which the JStar runtime takes it out from the Delta tree and starts to process its rules; the ending time is
when the JStar runtime finishes its task and moves this tuple to the table in the Gamma database. The CPU usage is a
ratio of the time which the thread spends on executing the tuple's tasks and moving to Gamma, which tells us the
computation time versus the wall time. The formula is shown in the follows:
$$CPU\_Usage(\%)=\dfrac{CPU\_Time}{Wall\_Clock\_Time}$$
The CPU usage is a performance index, indicating how efficient the
CPU processes a tuple in the Delta tree. Thus, the cpu usage of a totally efficient task should be very close to 1.0.
\pagebreak
The example output line of the \flag{--debug=cpu} message is shown as follows:\\
\texttt{DeltaTime: 1220/4424 1369351017581..1369351022005 GenTuples(3, 1999998, 2666664)}\\
This message contain 4 parts, separated by the \keyword{Tab}. The first is the the message title, followed by the
CPU usage, the starting and ending wall time (separated by the \flag{\ldots}), and the tuple.
All of debug messages can be printed out to the console or output into a log file. To investigate the tuple time, the
log file will be analyzed with the tuple timing graph tool, described next.
\item [JStar Tuple Timing Graph]
is a visualization tool for displaying the activities of JStar runtime on a time-line.
It is implemented with the Google Apps Engine\footnote{https://developers.google.com/appengine/}, HTML 5 and Java script.
Since the JStar tuple timing graph tool is a web-based application, users can access this service on the internet without
any installation. By deploying the tools to Google Apps market place or to a local machine (http://localhost:8888/),
the JStar tuple timing graph tool is able to display the tuple timing results from a JStar log file in a timeline graph.
To generate this graph, the CPU debug flag is enabled to print out the real clock time and CPU time, and
then the generated log file is dragged onto the Tuple Timing Graph web site.
\begin{figure}[h]
\centering
\includegraphics[width=1.0\textwidth]{./tuneperformance/figure/TupleTimingGraph_New.eps}
\caption[The JStar tuple timing graph.]
{The JStar tuple timing graph of the JStar PvWattsGamma program with \class{PvWattsHashTable} Gamma table
(\class{ConcurrentHashMap}) and 4 threads in the Fork/Join pool.}
\label{fig:TupleTimingGraph}
\end{figure}
\par Figure~\ref{fig:TupleTimingGraph} is the tuple timing graph of the JStar PvWattsGamma program with the
\class{PvWatts} table implemented by the \class{PvWattsHashTable} plus the \class{ConcurrentHashMap} and 4 threads.
Each task was plotted on the time line with its duration. The graph shows that 4 tuples were taken out from the Delta
tree each time and executed in parallel. Then the program ended when the last tuple was processed and finished.
\end{description}
\pagebreak
\section{Summary}
\begin{table}[h]
\centering
\begin{tabularx}{\textwidth}{|l|X|X|}
\toprule
\textbf{Option} & \textbf{Description} & \textbf{Example of Usage}\\
\midrule
Benchmark & repeats the program for a fixed number of times and prints out each execution time.
For benchmarking purposes.&
\flag{--benchmark=30}\linebreak
runs the same program 30 times.\\
\hline
Thread & creates a specified number of threads in the Fork/Join pool. &
\flag{--threads=2}\linebreak runs the program with two threads.\\
\hline
Debug &prints out debug messages. &
\flag{--debug=delta}\linebreak
prints out the time which the JStar runtime spends on a set of tuples in the Delta tree.\\ %(Verbosity = 1
&& \flag{--debug=cpu}\linebreak
prints out the time which JStar runtime spends on a group of tuples in the Delta tree. \\ %(Verbosity = 2)
\hline
Log & logs the transaction messages among rules, the Delta tree and the Gamma database.&%The messages include the \keyword{PUT}, \keyword{GET}, \keyword{TRIGGER}
\flag{--log=PvWatts.log}\\
\hline
Data structure&enables the JStar runtime to choose the data structure and set up its initial
capacity (if supported) for a specified table in the Gamma database.&
\flag{--table,PvWatts,\allowbreak gamma=ConcurrentHashMap,\allowbreak estimated=16000000}\linebreak constructs the
\class{PvWatts} table in the Gamma database with a \class{ConcurrentHashMap} and sets its initial capacity to be 16 million.\\
\hline
Group Size &sets up the group size for a specified tuple type.&
\flag{--table,SumMonth,\allowbreak group=1}\linebreak
sets the group size of \class{SumMonth} tuples to be 1.\linebreak
Since each group is processed as one recursive task, this means
that every \class{SumMonth} tuple in the Delta tree will be a separate Fork/Join task.\\\hline
\end{tabularx}
\caption{The JStar program option list.}
\label{tab:JStarProgramOption}
\end{table}
The JStar runtime supports several program options to assist the JStar programmers to do benchmarks or tune the
performance easily, plus several tools for analyzing the log files. Table~\ref{tab:JStarProgramOption} lists these
options and their usages.
\cleardoublepage