% Template article for preprint document class `elsart'
% SP 2001/01/05

\documentclass[11pt]{article}

% Use the option doublespacing or reviewcopy to obtain double line spacing
% \documentclass[doublespacing]{elsart}

% if you use PostScript figures in your article
% use the graphics package for simple commands
% \usepackage{graphics}
% or use the graphicx package for more complicated commands
\usepackage{graphicx}
% or use the epsfig package if you prefer to use the old commands
% \usepackage{epsfig}

% The amssymb package provides various useful mathematical symbols
\usepackage{amssymb}

%\usepackage{geometry}
%\geometry{verbose,letterpaper, dvips,
%          lmargin=1in, rmargin=1in,
%          tmargin=0.0in, bmargin=1.5in,
%          head=12pt, headsep=0.834in, nofoot}

\topmargin=-0.5in
\topmargin=0in
\textwidth=6.5in
\textheight=9in
\footskip=13pt
\oddsidemargin=0pt
\evensidemargin=0pt
\parindent=1em

\begin{document}


\newcommand{\code}[1]{\texttt{#1}}
\newcommand{\vn}[1]{\textit{#1}}

\bibliographystyle{plain}


\baselineskip=26pt


\begin{center}
{\LARGE QQ: Nanoscale Timing and Profiling}

	\vspace{13pt}

{\large James Frye$^{+*}$ James G. King$^{+*}$
	Christine J Wilson$^{\diamond *}$ \\
	Frederick C. Harris, Jr.$^{+*}$ \\
	\vspace{13pt}
	$^{+}$Department of Computer Science and Engineering \\
	$^{*}$Brain Computation Lab \\
	$^{\diamond}$Biomedical Engineering \\
	University of Nevada, Reno NV 89557}

\end{center}

\begin{abstract}
	\noindent
	QQ is set of tools for timing and memory profiling capable
	of analysis at nanoscale time resolution.  It is platform
	independent and useful for either sequential, distributed, or
	parallel programs.  The output can be visualized using various
	graphics packages.  Currently QQ utilizes the IA32 hardware
	architecture to monitor performance but can be readily ported
	to other hardware.  QQ can be implemented and customized quickly
	and is scalable.

	\noindent
	{\bf Keywords:} profiling, nanoscale resolution, memory use
\end{abstract}
% main text



\section{Introduction}
	\hspace*{1em}
	When developing a complex program that requires massive
	computational power, proper tracking of performance is crucial
	for development.  Effective optimization requires some means quickly
	and accurately measuring the effects of code changes.

	The NeoCortical Simulator
	(NCS)~\cite{thesis:ecwilson,wgh01:ncs-siam,whg01:ncs-sc} is such
	a complex system.  It is a large-scale biologically realistic
	simulator of cortical neurons. It has successfully simulated
	biological neural networks with $10^6$ cells and $10^9$ synaptic
	connections~\cite{matt1}.  One aim of NCS is to run simulations
	at speeds approaching real-time.  Since NCS utilizes the fastest
	available hardware for processing and internodal communication,
	the code was the only place where we could make significant
	performance improvements.  Therefore, considerable effort has
	been devoted to optimizing the code for both speed and memory
	utilization~\cite{thesis:jf}.

	The available performance monitors that were reviewed included
	TAU Portable Profiling Package \cite{tau}, and SvPablo: A 
	multi-Language Performance Analysis System\cite{derose98svpablo}.
	Both of these packages had steep learning curves and were not
	easily integrated in NCS.  TAU is compact and able to trace
	individual user-defined code blocks.  It also utilizes hardware
	counters, but relies on pre-compiling code to embed the timing
	commands using a pre-compiler that is not compatible with gcc.
	SvPablo utilizes hardware counters like QQ, but the graphical
	interface and meta-meta-format output was more than what was
	necessary for our analysis.

	QQ was developed as a set of tools that can accurately measure
	either elapsed time or number of machine instructions executed
	and memory usage with a minimum of overhead.  The name QQ is
	not an acronym but was chosen as a name prefix simply because
	the letter Q is seldom used as the first letter of a variable or
	function name and would minimize potential conflicts with existing
	code.  QQ was used extensively in optimization
	of NCS, and has been applied to a number of other programs.

	The organization of this paper is as follows:  Section 2 will
	address the design considerations and implementation.  Section 3
	covers the analysis routines and defines QQ's features.  Section 4
	covers examples of QQ's use in a sequential and parallel example
	programs.  Section 5 gives some concluding remarks and defines the
	future work and direction of development of QQ.

\section {QQ Design}

   \subsection{Nanoscale Timing}

	\hspace*{1em}
	Straightforward measurement of NCS elements is difficult.
	Different algorithms contribute varying numbers of elements
	in an input-dependent sequence.  This makes NCS unlike other
	compute-intensive programs that mainly consist of a few loops
	iterating many times over the same code.  Performance is
	not adequately measured by a relatively coarse-grained
	tool such as gprof \cite{gprof}. The documented gprof
	resolution is approximately a hundredth of a millisecond or
	$10^{-5}$ seconds.  And current system timing routines (Linux
	\code{gettimeofday}, \code{MPI\_Wtime}, etc.) typically measure
	to an accuracy of, at best, microseconds ($10^{-6}$ seconds).
	At current processor speeds, this translates to a granularity
	of several thousands of instructions.

	NCS demanded precise timing measurements on the order of tens
	or hundreds of machine cycles, or $10^{-9}$ seconds.  Therefore,
	without the resolution provide by the QQ tools, the effect of
	a change to any single element may have been overlooked.


   \subsection{Hardware Time Stamp Counter}

	\hspace*{1em}
	Most modern microprocessors include a hardware based time
	stamp counter.	NCS is currently compiled for use on the Intel
	IA32 (Pentium) architecture.  Each processor contains a 64-bit
	hardware counter, which is zeroed when the processor is booted,
	and thereafter increments every clock cycle.  
	At current processor speeds a
	64-bit counter would roll over about once a century.  The IA32
	instruction set provides the \code {RDTSC} instruction, which
	stores the time stamp counter contents into the \code {edx:eax}
	register pair.	Subtracting the values of two successive calls
	to this instruction thus gives a count of processor cycles.
	The actual elapsed time is derived by division by the clock
	frequency and is theoretically accurate to the processor clock
	frequency, or (at current CPU speeds) a fraction of a nanosecond.

	Factors such as pipelining and out-of-order execution reduce 
	this theoretical 
	accuracy to several tens of clock cycles.  Although steps such
	as issuing serializing instructions bracketing a code section
	will eliminate this factor.  This serializing will 
	alter the timing of the code being measured.

	By itself, the \code {RDTSC} instruction, or its cognates in
	other architectures, provides a simple means of measuring the
	elapsed time between two points in a program.  In itself, this
	is a useful and important performance measurement.


   \subsection {Sequential Profiling}

	\hspace*{1em} Frequently, detailed information is desired, for
	example, marking the time at which a particular event occurs,
	or tracing the amount of time spent within a repeatedly called
	section of code.  It is also desirable to somehow label or
	mark the different timed event.  naturally, we would like to
	do this with a minimum of overhead both in programmer workload
	and execution time.  Instrumentation calls were designed to be
	included in a non-obtrusive way and included in the code via a
	simple compile flag \code{QQ\_ENABLE}.

	QQ is based on the notion of tracing named events.  Each event
	is characterized by a key, which identifies the particular event,
	and an event time.  In addition, depending on the type of event,
	a value, count or state flag may be recorded.	The different
	event types are combined into an event union.

	When the profiler is initialized by calling the \code{QQInit}
	function, it allocates memory for a user-specified number of
	events, initializes the event pointer to the first event, and
	sets the base time to the current \code{RDTSC} value.

	After initialization, one or more of the \code{QQAdd*} functions
	are called to add event types to the internal name table.
	Each function is passed a name (character string) identifying the
	event, and returns the integer key for the event.  These keys
	are variables in the program space, and are the only remnants of
	QQ that remain in code when compiled with the \code{QQ\_ENABLE}
	flag off.

	The individual event recording functions are thus reduced to a
	minimum: each checks to see if the event pointer has overflowed
	the allocated buffer.  If not, the \code{RDTSC} instruction is
	called, the key, count, and any other information is written to
	the current event, and the event counter is incremented.

	The \code{QQRecord} function allows event recording to be turned
	off and on under program control.  It does this by caching the
	current event pointer and replacing it with a value greater
	than the maximum allocated, thus allowing the event recording
	functions to use a single test to determine whether or not an
	event is to be recorded.

	When profiling has finished, the \code{QQOut} function is called
	to write the saved event information to a file.


   \subsection {Parallel Profiling}

	\hspace*{1em}
	For parallel programs, QQ takes some additional steps.
	First, \code{QQInit} will do an \code{MPI\_Barrier}
	call to synchronize, as nearly as possible, timings on all nodes.
	Each node has its own event buffer, which records an independent set
	of events.  On output, the buffers from all nodes are combined
	into a single file, along with information to identify which
	event belongs to which node.

   \subsection{Profiling Memory Use}

   \subsubsection{Profiling Memory Allocation}

	\hspace*{1em}
	Profiling memory usage is more difficult than profiling
	execution time.  At this time a completely satisfactory solution
	seems impossible.  However, QQ manages to gather much useful
	information.  For example, in a Linux system, it is possible
	to obtain the total memory allocated to a process at any point
	in time by reading the \code{statm} pseudo-file in the process
	directory of the \code{/proc} filesystem.  From this file, the
	number of 4 KByte pages allocated to the process can be read.
	While this number includes both code and data space, and may
	include the total memory allocated rather than what is currently
	in use, this value can be considered an upper boundary value.

	The \code{GetMemoryUsed} function uses this 
	method to return the total memory allocated to the program
	at the time when the function is called.  By recording memory
	usage values before and after a block of code, one can obtain the
	number of pages being used by that block.
	However, it does not allow for direct measurements on the scale
	of structures or objects.

	The system allocates memory to a program in units of pages.
	It is up to the internal memory allocator (generally in
	the \code{malloc} library) to parcel the pages into smaller
	units.	If this memory allocation is done directly by calls to
	\code{malloc} library functions, it is easily measured by using
	the preprocessor to redefine the function call to a different
	function, which records allocation information and passes the
	operation through to the actual allocation function.

	Thus, for example, the \code{malloc} function can be redefined
	to be:
	
	\baselineskip=13pt
	{\small
	     \begin{verbatim}
	     #ifdef MEM_STATS
	         #define malloc(arg) MemMalloc (MEM_KEY, arg)
	     #endif
	\end{verbatim}
	}
	\baselineskip=26pt

	Each call to malloc in the code now becomes a call to the
	\code{MemMalloc} function, and the new call contains an additional
	argument, which is the key under which the allocated memory will
	be recorded.  Each chunk of allocated memory is stored in a C++
	\code{map} object, indexed by its address (the pointer value
	returned by the malloc call). The call to \code{free} is redefined
	to remove the item corresponding to the address from the map.
	In this way, a consistent record of all currently-allocated
	memory is maintained, and the record for each item may contain
	information on the type of object, what routine allocated it,
	and so forth.


   \subsubsection{Monitoring Object Creation}

	\hspace*{1em}
	In principle it should be possible to do something similar to the
	above for objects by overloading the new and delete operators,
	although we have not yet done so.  Instead, a simpler method
	was used.

	Each object constructor must have calls to the \code{MEMADDOBJECT}
	and \code{MEMFREEOBJECT} routines added to them.  When memory
	profiling is turned off, these calls evaluate to empty statements;
	when it is on, they evaluate to calls to the memory recording
	functions and contain the object's this pointer and the 
	\code{sizeof(this)} value as arguments.

	These functions allow most explicitly allocated memory and
	objects defined in the code, to be recorded.  Memory that is
	allocated internally by various library functions or standard
	C++ objects can not be recorded, however.  The information
	available, although not complete, is still quite useful.
	If nothing else, the amount recorded as allocated by the profiler
	can be compared to the total memory allocated to the program.
	If the two quantities are significantly different, the memory
	is probably being allocated somewhere internally.

\section {Analysis Routines}

	\hspace*{1em}
	The timing interface for QQ includes many functions for tracing
	temporal events.  Figure~\ref{fig:qqapi} shows the complete
	application programing interface currently available.

	\begin{figure}[h]
	{\center
	{\small
	\begin{tabular}{|l|l|}\hline
	Prototype & Description \\ \hline \hline

	\code{void QQInit (int nEvents);} &
	Initialize the package, specifying the max number of events \\
	& to be recorded.
	\\ \hline

	\code{void QQBaseTime (void);} &
	Reset the base RDTSC value in QQInit. This might be done if \\
	& for instance there was a substantial amount of time in program \\
	& initialization before the section of interest begins.
	\\ \hline

        \code{int QQAddMark (char *);} &
        Add a mark type event to the table. The simplest QQ event \\
	& type.  Marks the time the event \\
        & occurred.
        \\ \hline

	\code{int QQAddState (char *);} &
        Add a state type event to the table. Keep track of a state, \\
	& either on or off. Useful for monitoring when a code block \\
	& is entered (state on),  then exited (state off).
	\\ \hline

	\code{int QQAddCount (char *);} &
        Add a count type event to the table. Records the event time \\
	& along with an associated integer.
	\\ \hline

	\code{int QQAddValue (char *);} &
	Add a value type event to the table. Records the event time \\
	& along with an associated floating point value.
	\\ \hline

        \code{void QQMark (int key);} &
        For use by Mark type events, records the current time. 
        \\ \hline

	\code{void QQStateOn (int key);} &
        For use by State type events, indicates that the event has \\
        & begun along with the current time.
	\\ \hline

	\code{void QQStateOff (int key);} &
        For use by State type events, indicate that the event has \\
        & finished along with the current time.
	\\ \hline

	\code{void QQCount } &
        For use by Count type events, record the current time along \\
        \code{ (int key, int count);}
        & with an integer relevant to the event.
	\\ \hline

	\code{void QQValue } &
        For use by Value type events, record the current time along\\
        \code{ (int key, double value);}
        & with a floating point value relevant to the event.
	\\ \hline

	\code{void QQRecord (int flag);} &
        Allows for the recording of events to be turned on/off \\
        & (flag=TRUE or FALSE) during program execution. \\
        & Recording is on by default.
	\\ \hline

	\code{void QQOut } &
        Event information should be output to the specified filename,\\
        \code{ ( char *filename, int, int );}
        & indicating this node's rank among the node count.
	\\ \hline
	\end{tabular}
	}
	}
	\caption{QQ API}
	\label{fig:qqapi}
	\end{figure}

	Since the QQ tools are intended for programmers, the output was
	formatted to be flexible.  Most programmers prefer to write their
	own custom analysis code, or pipe the output to a general purpose
	tool such as gnuplot \cite{gnuplot}, for example.  Unlike similar
	applications, the output was created to be flexible, precise and
	detailed, rather than processed via predefined functions.  To this
	end, the output is stored in binary in the following format.

	Each event to be traced is given a key.  In the output
	file, the number of keys \code{nkeys(int)} is followed by the
	length of the key name string, \code{keylen (int)}.  Then for
	each key, the following information is output, the index of the
	key, the key type and its name.  Then, the information regarding
	the nodes is output.  The number of nodes \code{nnodes(int)}
	is defined.  For each node the following information is output,
	the offset or index in file at which the data for the node starts,
	the number of entries for the node, the base tick count for the
	node and the frequency of the node in MHz.  Once this information
	has been defined, the data for each node is output.

	During the evaluation of NCS the following two programs were
	created and are included as examples:
		\begin{itemize}
		\item Summary statistics is a simple C program which
		reads the QQ output file and produces a summary report
		of the time spent in each state, the number of times
		each event or state, etc.

		\item Profile viewer is a simple graphical application.
		Data is read from the output file, and piped to
		\code{gnuplot} for display.  A simple interface allows
		the user to select which nodes, events, and time ranges
		are displayed.
		\end{itemize}


\section  {Examples}

	\hspace*{1em}
	Now that we have given an overview of QQ, some examples will
	help show how it can be used to profile and optimize code.
	In this section we present two examples, a sequential piece of
	code and a large parallel piece of code.  The first will show how
	the code must be modified to be used and the second will give
	a big picture overview of what we were able to accomplish with QQ.

   \subsection{Sequential Code: BCS}


	\hspace*{1em}
	BCS, the Brain Communication Server, is a companion program
	intended to coordinate data flow between NCS and a separate
	client.  These clients under development make use of NCS in
	some way such as a virtual organism in a virtual environment,
	or eventually robotic actuators maneuvering in the real world.


	Ideally, this server should have minimal impact on the
	simulation's execution while transferring the necessary
	information securely and accurately, so it also needs profiling
	for optimum performance.  Even though BCS is a sequential program,
	it can still use QQ to evaluate code sections even without QQ's
	parallel features.


	Inserting QQ into the program is easily done.  Certain profiling
	needs to be performed in the main file of the program as it
	started.  The code segment in Figure~\ref{fig:QQmain} shows 
	the few lines needed to perform the profiling.

	\begin{figure}[h]
	\vspace{0.25in}
        {\tt \footnotesize
        \begin{center}
        \baselineskip=12pt
	\underline{\hspace{\textwidth}}
        \begin{verbatim}
        QQInit(1000); //create space for large number of possible events 
        QQBaseTime(0); //reset timer 
        	
        //create new event to monitor load functions 
        QQload = QQAddState( "load" ); 

        QQStateOn (QQload);  //Begin monitoring 

        loadAppList(); 

        loadScriptList(); 

        QQStateOff (QQload); //End monitoring 
	\end{verbatim}
	\underline{\hspace{\textwidth}}
	\end{center}
	}         
	\caption{Basic QQ profiling}
        \label{fig:QQmain}
	\end{figure}

	BCS makes use of an Object Oriented design,
	and the example code given in Figure~\ref{fig:QQclass} show how 
	a QQ event can
	be declared once in the main routine, but used in a class defined
	elsewhere.  By putting the event declaration in the main file,
	we ensure that multiple class instances don't try to add the
	same event multiple times and we acquire a single event key to
	be shared by all instances of the class.  This shared event key
        could also be created using a static class member variable, but
        this example is not shown in order to be concise.


	\begin{figure}[h]
	\vspace{0.25in}
        {\tt \footnotesize
        \begin{center}
        \baselineskip=12pt

	\underline{\hspace{\textwidth}}
        \begin{verbatim}
        // from main file: 
         
        int gatherTime;  //global scope 
        ... 
        gatherTime = QQAddState( ``gather'' );  //inside a main function
	\end{verbatim}

	\underline{\hspace{\textwidth}}

        \begin{verbatim}
        // from class file: 
         
        extern int gatherTime; //declared in main file 
         
        class function() \{ 
           QQStateOn( gatherTime ); //turn on state at start of block 
           ... 
           QQStateOff( gatherTime ); //turn off state at end of block 
        } 
	\end{verbatim}
	\underline{\hspace{\textwidth}}
	\end{center}
	}         
	\caption{QQ Events in classes: Create and Use separately}
        \label{fig:QQclass}
	\end{figure}

	When the profiling is complete, the QQ output file is generated
	with a single function call.  This is illustrated in
	Figure~\ref{fig:QQoutput}.


	\begin{figure}[h]
	\vspace{0.25in}
        {\tt \footnotesize
        \begin{center}
        \baselineskip=12pt
	\underline{\hspace{\textwidth}}
        \begin{verbatim}
        // when monitoring is finished: 
        QQOut( "myProfile", 0, 1 ); 
	\end{verbatim}
	\underline{\hspace{\textwidth}}
	\end{center}
	}         
	\caption{Code for QQ Output illustrated}
        \label{fig:QQoutput}
	\end{figure}


	The simple and consistent layout of the QQ output file allows for
	the collected data to be extracted easily.  Once the time values
	are read, they can be manipulated in whatever way the programmer
	prefers.  Using all data, or selecting only a portion to view,
	it is easy to handle and forward to an appropriate process. In 
	Figure~\ref{fig:stout} they are put into a table by the 
	previously mentioned Summary statistics program.  In the case of BCS,
        some of the events take up more time than the similar "gather" event.
        The events in question can be further broken down to better profile
        within the code blocks and pinpoint where inefficient code exists.


	\begin{figure}[h]
	\vspace{0.25in}
        {\tt \footnotesize
        \begin{center}
        \baselineskip=12pt
	\underline{\hspace{\textwidth}}
        \begin{verbatim}
        File myProfile:   1 nodes 
	
        Node   0:  2592.403 MHz, 10 keys, 122 states, ticks from 15956 to 105435813502 
        
                   ET = 40.671068 sec 
        
        State outputs: Counts are millions of cycles 
        	
              Hits        Time    Percent      Name 
         1:      2     0.000889   0.002%  'load' 
         2:     46     0.562092   1.382%  'setpath' 
         3:      8     0.159862   0.393%  'getdata' 
         4:      8     0.166010   0.408%  'gettime' 
         5:      2     0.000241   0.001%  'setpattern' 
         6:     20     0.953694   2.345%  'launch' 
         7:      8     0.158786   0.390%  'reportcount' 
         8:     20     0.385492   0.948%  'mkdir' 
         9:      8     0.000237   0.001%  'gather' 
	\end{verbatim}
	\underline{\hspace{\textwidth}}
	\end{center}
	}         
	\caption{QQ output displayed by st}
        \label{fig:stout}
	\end{figure}

	When performing the profiling, the program should be compiled
	with the value \code{QQ\_ENABLE} defined (in gcc this is done by adding
	\code{-DQQ\_ENABLE} to the command line).  Later, by removing 
	\code{QQ\_ENABLE},
	the profiling functions can stay in the source code, but will
	perform no operations.	Even though a large number of events
	may have been originally declared for initialization of QQ, the
	events will no longer take up that amount of memory.  In fact,
	the only remnants are the integers declared by the user to store
	the event keys.



   \subsection{Parallel Code: NCS}
	
	\hspace*{1em}
	For our parallel example we will discuss QQ's usage with NCS, the
	application that actually led to the design and implementation of
	QQ~\cite{thesis:jf}.  NCS is a neocortical-neural network simulator which
	incorporates laboratory-determined synaptic and membrane parameters into
	a large-scale, biologically realistic model of cortical modules.  Results
	to date have demonstrated biological accuracy in synaptic and membrane
	dynamics, and suggested that computational models of this scope can
	produce realistic spike encoding of human speech~\cite{jcm1,jbm}.
	Efficient parallel processing of this very large-scale program is crucial
	to a realistic model which executes in a practical time frame.

	NCS has gone through a number of development cycles.  Here we discuss
	optimizations done between NCS3, the first parallel, cluster-based code,
	and NCS5, the current working version.

	\subsubsection{Optimization Targets}

	Four factors affect the performance of NCS: load imbalance,
	message-passing overhead, and synchronization on the parallel side, and
	the sequential performance of the code executing on each compute node.
	All of these areas were addressed in the optimization process.  This
	section describes that process and the solutions that were developed.

	\paragraph{Load Balancing}
	For many applications load balancing is a simple matter of assigning an
	equal number of work units to each node.  Version 3 of NCS (NCS3) used
	this method, but it proved less than satisfactory in practice, due to the
	rather unusual characteristics of the process being modeled.

	Unlike many parallel models which operate over a grid of similar
	entities, NCS contains algorithms which model many different neural
	components.  These components may be combined in different ways to create
	many different types of cells, and those  cells may be connected in fairly
	arbitrary ways.  There are thus few if any points in the code where we
	can measure the repeated execution of a single component type. 

	Much of the computation time is devoted to modeling individual synapses.
	Factoring these into the load-balancing process is complicated by the
	fact that the computation takes place on a particular synapse only when
	the synapse is in a firing state.  Only a small fraction of synapses will
	be in this state at any particular timestep, and it is not possible to
	predict which synapses will fire, because firing is determined by the
	input stimuli.

	This unpredictability applies to memory usage as well: the amount of
	memory needed to construct a brain is the sum of its components, but a
	running brain needs significant additional memory to hold dynamic
	information for synapse firing states.  The exact amount required is
	impossible to predict, but in practice the current implementation seems
	to require about equal amounts of memory for static and dynamic data.

	The total amount of computation is determined by assigning some weight,
	say 1.0 for simplicity, to a basic cell and ratios of this amount to
	other components that may be added.  Using QQ we were able to time
	individual components and create a weight/cost table for them.  Thus a
	simple summation gives a total compute weight for each cluster of cells.
	These clusters can then be assigned to nodes according to some scheme
	which balances the compute load according to the computing power
	available on each processor.

	In order to run the largest models it is necessary to balance memory use,
	rather than compute load, and accept the resulting inefficiency.
	Distribution follows a similar algorithm, merely substituting the memory
	footprint of each component for its compute weight.

	\paragraph{Message-Passing Overhead}
	\hspace*{1em}
	Initial profiling of NCS3 determined that much time and memory were
	devoted to message passing.  More detailed examination disclosed a number
	of inefficiencies in the message passing scheme.  The most notable was
	the pre-allocation of messages, with a 60-byte message object allocated
	for every synapse.  On a large model of a billion synapses or so, this
	consumes nearly a quarter of the 256 GBytes of memory on our current
	cluster.  Since only a small fraction of synapses (typically less than
	1\%) are actively firing (and thus transmitting a message) during any
	particular timestep, most of this memory was actually unused.

	Other inefficiencies related to the use of the same communicator and
	message format for distributing stimulus and report data and the synapse
	firing messages.  This required the inclusion of a message type field in
	the message packet, as well as additional overhead needed to distribute
	messages of different kinds to the proper destinations.

	NCS5 separates the three functions.  Stimulus messages and reports
	(excepting real-time I/O) are now produced locally on each node, which
	reduces the traffic on the network and, along with other optimizations,
	allows the size of the individual synapse firing message to be reduced
	from 60 to 20 bytes.  In the NCS3 message packaging scheme, each message
	transmitted about 40 bytes of unnecessary information, resulting in a
	200\% overhead.

	While these changes improved performance significantly, further analysis
	showed that yet more improvement was possible.  The old algorithm passed
	message objects through several layers, so that a typical message was
	being read and written perhaps five times or more in its progress from
	source to destination.

	In the optimized scheme, the message has no existence as an individual
	object.  It is instead a logical entity within a packet containing many
	individual messages.  so that the bulk of the information in a message
	can be written once, when sent, and read once, when it is received at its
	destination.  Instead of individual messages, the program deals with
	packets containing many messages.  Not only does this eliminate much
	overhead, it means that the packet size can be chosen to match the most
	efficient transfer size of the underlying hardware.

	\paragraph{Synchronization}

	\hspace*{1em}
	Most of the computation in NCS is devoted to determining the effects of
	synapse firings on the receiving compartments.  These firings are
	essentially unpredictable, being determined by the brain's reactions to
	stimulus propagating through a highly nonlinear feedback network.
	Therefore it can be expected that, regardless of how well the number of
	synapses is balanced between nodes, the actual amount of computation will
	vary both between nodes and over time.

	As a consequence, one node, and probably not the same node at each
	timestep, will take the longest amount of time to finish its
	computations.  If a simple end of timestep barrier is used for
	synchronization, then all the other nodes will be idle for some part of
	the timestep.Figure \ref{fig:idle} shows an example of this idle time,
	indicated by the horizontal lines at Y=1.  Node 1 has (for the displayed
	timesteps) the heaviest load, and so displays little or no idle time
	(labeled \code{MessageBus::Sync} in the figure), while the others display
	more, with the amount varying between nodes and between timesteps.

	\begin{figure}
	{\center
	%\begin{minipage}[b]{0.75\textwidth}
	%	\includegraphics[width=0.75\textwidth,
	%	height=0.27\textwidth]{node0.eps}
		\includegraphics[height=0.3\textwidth]{node0.eps}
		\includegraphics[height=0.3\textwidth]{node1.eps}

		\includegraphics[height=0.3\textwidth]{node2.eps}
		\includegraphics[height=0.3\textwidth]{node3.eps}
	%	\end{minipage} \\ [1pt]

	%\begin{minipage}[b]{0.75\textwidth}
%		\includegraphics[width=0.75\textwidth,
%		height=0.27\textwidth]{node1.eps}
	%	\end{minipage} \\ [1pt]

	%\begin{minipage}[b]{0.75\textwidth}
%		\includegraphics[width=0.75\textwidth,
%		height=0.27\textwidth]{node2.eps}
	%	\end{minipage} \\ [1pt]
	%\begin{minipage}[b]{0.75\textwidth}
%		\includegraphics[width=0.75\textwidth,
%		height=0.27\textwidth]{node3.eps}
	%	\end{minipage} \\
	}
	\caption{Idle Time Due to Load Imbalance.}
	\label{fig:idle}                          
	\end{figure}                                

	We used this data to redesign the MessageBus.
	Recall from basic biology that the electrochemical pulse from
	a firing cell propagates along its synapses at a relatively
	slow speed, so that the transmission time between the sending
	and receiving cells typically translates to several tens of
	simulation timesteps.  Thus for each node there is an event
	horizon, which depends on the minimum synapse propagation time of
	the nodes with which it communicates.  If this minimum time is
	\vn{dt}, then nothing other nodes do at time \vn{T} can affect
	this node until time \vn{T+dt}.  Therefore, a barrier mechanism
	constructed to utilize this event horizon can allow some of
	the end-of-timestep idle time to be used.  A node may
	simply continue to work until it reaches \vn{T+dt}.  Meanwhile,
	messages have continued to arrive from the other nodes, and
	unless the node is consistently under-loaded, these messages
	will contain \code{SYNC} flags indicating that their nodes have
	progressed to another timestep.

	Synchronization now becomes a relatively simple matter.
	On initialization, a \code {NodeTime} array is allocated, with
	entries for each node from which the node receives messages.
	As \code {SYNC} packets are received, these times are updated.
	When the node reaches the end of each timestep, these NodeTimes
	fields are checked.  If the other nodes are within the minimum
	time difference, then the node can proceed to the next timestep;
	if not, it must wait for more packets to be received and check
	again.

	\subsubsection{Results}

	\hspace*{1em}
	In addition to the algorithmic improvements described in the
	preceding subsection, many other optimizations have been made in
	the process of creating version 5 of the NCS program.  
	These are too numerous
	to describe individually.  Indeed, most are obvious, and of no
	great theoretic interest.  This section describes the cumulative
	effect of all optimizations.

	It is difficult if not impossible to define a simple performance
	metric for NCS.  For a number of reasons, the time a particular
	NCS brain takes to process some input file is only a useful
	performance measure for that particular brain design and input.

	One reason is that NCS defines many different components, which
	the user may include in fairly arbitrary proportions and connect
	in a large number of ways.  Since the behavior of NCS is highly
	non-linear, these differences can result in large variations
	in processing time for models which might appear superficially
	similar.

	The approach we take here is to measure the performance of particular
	functional areas, or groups of operations with similar characteristics.
	Because the groups share common performance features, the effect of a
	change in the area on the whole program can be estimated.  The area's
	speed change can be compared between program revisions.  We then relate
	the changes to total run time on the same input.

	We have tested with many models but due to space we will only present
	some of the results from the simple model \code{1Column} model.  This
	model has a single column of three layers, each having two cell types,
	\code {excitatory} and \code {inhibitory}.  Input is from an artificial
	pulse stimulus, which causes it to exhibits an unrealistically high cell
	firing rate.  Figure \ref{fig:Share_1Col} shows the time usage of the
	components in a one simulated second run of the 1Column model just
	described.  Note that we have expanded the figure portion for NCS5 since
	the optimization was quite successful.

	\begin{figure}
	\centering
	\includegraphics[width=0.8\textwidth]{Share_1Col.eps}
	\caption{Share of CPU Time Used by Functional Areas, 1Column Model.}
	\label{fig:Share_1Col}
	\end{figure}



\section {Conclusions and Future Work}

	\hspace*{1em}
	In conclusion, we have developed and tested an new profiling tool that
	allows nanoscale timing of code segments, profiling, and memory usage
	analysis.  Using this tool, we have decreased NCS run time by nearly two
	orders of magnitude, and improved memory utilization several-fold.  
	This optimization is not complete: we have observed remaining memory
	access patterns and code bottlenecks whose improvement we expect to yield
	a further order of magnitude improvement.


	Although developed specifically to optimize NCS, QQ has proven
	to be of value in the profiling and optimization of a number of other
	programs.  The temporal resolution allows for fine-grained measurements
	of specific events or blocks of code.  It can be used on sequential
	and parallel programs without modification.

	Accessing the hardware time stamp counters of other architectures
	would extend the usability of these tools.  Also, the ability
	to measure memory at an object or event level with a small
	memory and performance footprint, is an area that requires
	additional work.  Currently however, we have added only those
	features we actually use and can implement easily since our focus
	is on NCS development.	We believe this has kept QQ both simple
	and effective.

\baselineskip=13pt
\bibliography{bib}
\end{document}
