/* -*- mode: C++; tab-width: 4 -*- */
/* ================================================================================== */
/* Copyright (c) 1998-1999 3Com Corporation or its subsidiaries. All rights reserved. */
/* ================================================================================== */

#include "EmulatorCommon.h"
#include "Profiling.h"

#include "CPU_REG.h"			// IsSystemTrap
#include "Miscellaneous.h"		// StMemory, FindFunctionName, GetTrapName
#include "Platform.h"			// Platform::Debugger
#include "Strings.r.h"			// kStr_ values


/*
	P.S.  Here are some notes on interpreting the output

	Times are all theoretically in milliseconds.  Internally, POSEr is faking
	a clock by counting reads, writes, wait states, and extra cycles for many
	68K instructions.  I'd estimate this count is correct to within a few percent,
	and I have a list of known incorrect instructions I'm working on getting more
	accurate.  (Notable issues: JSR, RTS, RTE fall one read short each, for 6 or 8
	cycles each depending on ROM or RAM, ANDSR, ORSR, and other "SR" instructions
	are 2 reads short, for 12 or 16 cycles.)

	Anyway, the cycle counts are stored as 64-bit integers in the profiler output,
	and a multiplier is applied to scale the result to milliseconds based on a
	58.xxx MHz clock.  So a number like 5661.518 is a bit over 5 1/2 seconds, and
	1.255 is a bit over 1 1/4 milliseconds.  (In theory at least, I'm still
	validating the data, if you see anything that strikes you as inaccurate, please
	tell me about it!)

	The function names mostly come from the ROM.Map file, but there are a few
	special cases:

	"functions" is a top-level cover that includes all regular function calls
	"interrupts" is a top-level node that includes all interrupts (except the ones
				POSEr has patched out)
	"partial" means profiling was started in the middle of the function, so we
				don't have the address of the fn and consequently don't have a name.
	"overflow" is a lump of all functions called when we're out of space to track
				more unique calls, where unique means called from the same path to
				the "root" of the call tree.
	"unknown" is a function for which no name could be found.  Many functions in
				.prc files show up as unknown.

	The rest of the names all take the form "Name $address.x" where:
	   Name- is the name of the function or trap.
	   address-For regular functions, the 4 byte address.
 		   -For traps, the 2 byte trap number.
		   -For interrupts, the 1 byte interrupt number.
	   x- debugging info, where the name comes from. 
		't' = trap names table built in POSEr,
		'm'= the ROM.Map file
		'd'=the symbol built into the ROM by the compiler
		'i'=invalid address flag (usually due to POSERs implementation internals)

	The other columns are defined as follows.  Note MINIMUM and STACK SPACE are
	NOT what you expect:

	count				- the number of times the functions was called.
	only				- time spent in the function, not counting child fns or interrupts.
	% (by only)			- percentage of total profiling time spent in this fn/call.
	+Children			- time spent in the function including child fns, but not
						  including interrupts
	% (by +Children)	- percentage of total profiling time spent in the fn and its kids
	Average				- "Only" divided by "count"
	Maximum				- the maximum time (in msec) spent in any 1 call to the fn.
	Minimum				- NOT WHAT YOU EXPECT.  This is actually the time spent handling
						  interrupts for calls to that particlular instance of that fn.
						  Due to the way the "Summary" is calculated, this number won't
						  be correct in summary views.
	Stack space			- NOT WHAT YOU EXPECT.  More of a trap/interrupt counter plus
						  some debug info.  The number in that field for a particular
						  fn entry is incremented by 1 every time the fn is interrupted,
						  by 10000 if the fn call is made by a faked up RTS instead of
						  a JSR, and 1000 if the function was executing when an RTS
						  occurred that didn't return to it's called but instead returned
						  to some fn farther up the call chain.  Again, this will only
						  be useful in the detail view, since the summary does some
						  computation on it.


	Please respond to palm-dev-forum@ls.palm.com
	To:	palm-dev-forum@ls.palm.com
	Subject:	Re: RE: Emulator profiling...

	At 7:14 PM -0700 10/6/98, Kenichi Okuyama wrote:
	>I'll be pleased if you can give us any good information source
	>beside source code itself, about POSE's profiler. Like, byte
	>alignment size( is it 4? or 8 on Mac... I don't know about Mac
	>really ), etc. Those informations, we can't get them from source
	>code itself, and since I don't have Mac, I can't get them from
	>project file for Mac, you see.

	I don't think alignment matters much at all for virtually all of the structs.

	The only ones where alignment will be important are the ones written to be
	compatible with the MW profiler.  These are ProfFileHeader and FnCallRecord
	in Profiling.cpp.  All the elements of those structs are either 4 or 8
	bytes wide.

	The MW profiler file consists of 3 sections.  The first section is a
	header, incompletely described by ProfFileHeader in Profiling.cpp.

	The second section is a big tree of function call blocks.  Each block is
	described by the FnCallRecord struct.  The tree is maintained via two
	pointers in each record, called 'kid' and 'sib', which contain array
	indexes.  kid points to the first child of a given node, sib points to a
	given node's next sibling.  So to enumerate all the kids for a given node
	you go to that node's kid, then follow the sib links from kid to kid until
	you get a sib value of -1, which is the end of the sibling list.  The other
	fields in the function call record are pretty much self explanitory.  (Note
	however that the POSER profiler uses cyclesMax and stackUsed for other
	things!  They track trap dispatcher overhead right now.)

	The 3rd section contains the names of all the functions, stored in a string
	table.  The string table is just a concatenation of all the name strings,
	seperated only by the terminating nulls, with each unique name appearing
	only once.  The FnCallRecord's address field stores the offset of the start
	of that function's name into the string table.  (It's sort of a normalized
	char *)  That structure is a byte stream, there is no other alignment.  The
	function FindOrAddString is used to build the string table when dumping a
	profiler file.

	>Also, if possible, what kind of information is kept in that profile
	>file, like function name, call count, running time, etc.

	FnCallRecord should pretty much explain that.  The only other interesting
	thing to note is that the data isn't stored on a function by function basis.
	Rather, it's stored by unique occurrences of a function.  That is, say
	function A calls function C, and function B also calls function C.  There
	will be two nodes in the function tree (two records) for function C, one
	storing information from calls from function A, and a second storing
	information from calls from function B.  Recursive functions will create a
	whole bunch of nodes, one for each level of recursion.  ..but that's
	necessary to properly create the call tree that the MW profiler displays.

	...the MW profiler's "summary" mode does a lot of work!  It has to go
	through the whole tree and collect the data for each node that represents a
	given function call and summarize it.  That was one of the reasons I chose
	to try to output MW profiler files!

	I think if I had to make a windows profiler, I'd start with the ProfileDump
	function in Profiling.cpp.  You could change that routine to take the data
	collected and output whatever you wanted.

	You might look at ProfilePrint, which does a text dump of the gathered
	profile data.  RecursivePrintBlock will give you a good start on something
	that translates the MW function records into some other data format.

					--Bob


	Please respond to palm-dev-forum@3com.com
	To:	palm-dev-forum@ls.3com.com
	Subject:	POSER Profiling under Windows

	The #1 item on my to-do list post-Palm Computing Platform Developer
	Conference was to update the Windows emulator to enable profiling.  I'm
	happy to say this is done (more or less), and a build is now available.
	It's 2.1d23, and you can download it at
	http://palm.3com.com/devzone/pose/seed.html

	There still is no nice viewer for Windows.  Instead, the emulator now
	outputs both the MW Profiler format file and a tab delimited text file
	containing the same information.  Until a nice viewer exists for Windows,
	you can open the text file in a text editor or spreadsheet app and get at
	the profiling info.

	For convenience, the text file output is pre-sorted by the "time in
	function and all it's children" category.

	For inconvenience, all levels of function calls (down into the kernel and
	beyond) are displayed.  Typically this is WAY too much information.  The
	only advice I can offer is a strategy for getting rid of it:

	The first column contains the nesting level of the function -- it defines
	the "tree".  So if there's too much detail inside a particular function
	call, you can note the number in the fist column, then search downward for
	an equal number.   The intervening lines (often very many) are sub-calls
	from that first call, and you might want to simply delete them to make the
	output more readable.

	That is, say you get something like this:

	1	foo			...
	2	bar			...
	3	baz			...
	4	cj_fdkjqwfd	...
	5	kp_sdlsvbnf	...
	4	cj_aslkqwsd	...
	5	lkaflds		...
	6	cj_sdldsfdl	...
	7	tm_eouas	...
	6	cj_werofs	...
	3	qux			...

	If you're only interested in where function foo is spending it's time, you
	can note that baz and qux are both sub-calls, and everything in-between
	them are sub-sub-calls that baz made.  Anyway, just deleting the lines with
	nesting level 4 and above will considerably clean up the output and make it
	easier to read.

					--Bob

*/

// sizes of buffers to use
#define AVGNAMELENGTH			  64
#define MAXROMFNS				3000
#define MAXNESTEDINTERRUPTS		   8

// shared values exported via Profiling.h
SInt64 gClockCycles;
SInt64 gReadCycles;
SInt64 gWriteCycles;

long gReadMismatch;		// debug
long gWriteMismatch;	// debug

int gProfilingEnabled;
int gProfilingOn;
int gProfilingCounted;
int gProfilingDetailed;

uaecptr gProfilingEnterAddress;
uaecptr gProfilingReturnAddress;
uaecptr gProfilingExitAddress;

// Internal stuff

SInt64 gCyclesCounted;		// cycles actually counted against functions

static int gMaxCalls;
static int gMaxDepth;

#define PROFILE_ONE_FN		0	// set to 1 to profile on a particular fn enter/exit
#define FNTOPROFILE			sysTrapDmGetNextDatabaseByTypeCreator

#define NOADDRESS			0x00000000
#define ROOTADDRESS			0xFFFFFFFF
#define INTERRUPTADDRESS	0xFFFFFFFE
#define OVERFLOWADDRESS		0xFFFFFFFD
#define NORECORD			-1

struct ProfFileHeader {
	SInt32	proF;			// 'proF'
	SInt32	version;		// 0x00040002
	SInt32	fnCount;		// number of unique fns (records) in log
	SInt32	four;			// 0x00000004

	SInt32	zeros1;			// 0x00000000
	SInt32	zeros2;			// 0x00000000
	SInt32	unknown;		// 0xB141A3A9	- maybe timebase data
	SInt32	recordsSize;	// size of header plus size of data (or offset to string table)
	
	SInt32	stringTableSize;// size of string table in bytes
	SInt64	overhead;		// count for overhead
	SInt32	rootRec;		// record number of root of tree
	
	SInt32	sixtyfour1;		// 0x00000064
	SInt32	sixtyfour2;		// 0x00000064
	SInt32	countsPerTime;  // translation between counts at nodes and integers in column
							// 0x00FD0000 = 16.580608 MHz with display in seconds
							// 0x000040C4 = 16.580608 MHz with display in milliseconds
	SInt32	oddstuff0;		// seems like it can be 0, set by profiler tool itself
	
	SInt32	oddstuff1;		// seems like it can be 0, set by profiler tool itself
	SInt32	oddstuff2;		// seems like it can be 0, set by profiler tool itself
	SInt32	oddstuff3;		// seems like it can be 0, set by profiler tool itself
	SInt32	oddstuff4;		// seems like it can be 0, set by profiler tool itself

	Byte	unused[0x200 - 0x50];	// for 0x200 bytes
};

struct FnCallRecord {
	SInt32	address;		// address of fn, also offset from start of name table to this fn's name
	SInt32	entries;		// times function was called
	SInt64	cyclesSelf;		// profiling data for this fn alone 
	SInt64	cyclesPlusKids;	// profiling data for this fn with kids
	SInt64	cyclesMin;		// profiling data for this fn alone, min
	SInt64	cyclesMax;		// profiling data for this fn alone, max
	SInt32	sib;			// record number of sib, -1 for no sibs
	SInt32	kid; 			// record number of kid, -1 for no kids
	SInt32	stackUsed;		// bytes of stack used by fn, we use it to count unmatched returns
};

struct FnStackRecord {
	int call;						// fn data block for fn being called
	uaecptr returnAddress;			// return address aka (SP) to calling fn
	SInt64 cyclesAtEntry;			// cycle count when fn was called
	SInt64 cyclesAtInterrupt;		// cycle count when fn was interrupted
	SInt64 cyclesInKids;				// number of cycles spent in subroutines and interrupts
	SInt64 cyclesInInterrupts;		// number of cycles spent in interrupts for this fn alone
	SInt64 cyclesInInterruptsInKids;		// how much of cyclesInKids is interrupts
	uae_s16 opcode;					// cached opcode for instruction profiling
};

// call tree
static FnCallRecord* calls = NULL;
static int firstFreeCallRec;
static int rootRecord;
static int exceptionRecord;
static int overflowRecord;

// call stack (interrupts and calls in interrupts on same stack)
static FnStackRecord* callStack = NULL;
static int callSP;

// interrupt tracking, interrupt stack is callSP when interrupt happened
static int interruptDepth;
static int interruptStack[MAXNESTEDINTERRUPTS];
static SInt64 interruptCount;
static SInt64 interruptCycles;

static unsigned long missedCount;		// debug
static unsigned long extraPopCount;		// debug
static int interruptMismatch;			// debug

// for detailed (instruction level) profiling
static int inInstruction;
static FILE *profilingDetailLog;
static SInt64 clockCyclesLast;
static SInt64 clockCyclesSaved;
static SInt64 readCyclesSaved;
static SInt64 writeCyclesSaved;
uaecptr detailStartAddr;
uaecptr detailStopAddr;



//---------------------------------------------------------------------
// Get function name out of debug symbols compiler produces
//---------------------------------------------------------------------

struct ROMMapRecord {
	uaecptr	address;
	char *	name;
};
ROMMapRecord *ROMMap = NULL;
int ROMMapEnd = 0;


// DOLATER 
// We need to handle shared library routines, which are called by
// trap dispatcher.  They start at 0x0000A800

#define kOpcode_ADD		0x0697	// ADD.L X, (A7)
#define kOpcode_LINK	0x4E50
#define kOpcode_RTE		0x4E73
#define kOpcode_RTD		0x4E74
#define kOpcode_RTS		0x4E75
#define kOpcode_JMP		0x4ED0

#define FIRSTTRAP 0x0000A000UL
#define LASTTRAP (FIRSTTRAP + 0x0001000)

#define LAST_EXCEPTION	0x100

#define IS_TRAP_16(addr)			(((addr) >= FIRSTTRAP) && ((addr) < LASTTRAP))
#define IS_TRAP_32(addr)			IS_TRAP_16((addr) >> 16)
#define PACK_TRAP_INFO(trap, extra)	((((uae_u32) (trap)) << 16) | ((uae_u16) (extra)))
#define TRAP_NUM(field)				(((field) >> 16) & 0x0FFFF)
#define TRAP_EXTRA(field)			((field) & 0x0FFFF)


// Llamagraphics, Inc:  Rather than passing in a buffer of unknown length,
// GetRoutineName now returns a statically allocated string that's good
// until the next time GetRoutineName is called.  This eliminates the need
// for dynamically allocating space in the heap for this string, and makes
// it easier to ensure that the buffer isn't overrun.

static char * GetRoutineName (uaecptr addr)
{
	static char buffer[256];
	uaecptr startAddr;
	
	// if it's a dummy function header, say so
	if (addr == NOADDRESS)
	{
		strcpy(buffer, Platform::GetString (kStr_ProfPartial).c_str ());
		return buffer;
	}

	if (addr == ROOTADDRESS)
	{
		strcpy(buffer, Platform::GetString (kStr_ProfFunctions).c_str ());
		return buffer;
	}

	if (addr == INTERRUPTADDRESS)
	{
		strcpy(buffer, Platform::GetString (kStr_ProfInterrupts).c_str ());
		return buffer;
	}

	if (addr == OVERFLOWADDRESS)
	{
		strcpy(buffer, Platform::GetString (kStr_ProfOverflow).c_str ());
		return buffer;
	}

	if (addr < LAST_EXCEPTION)
	{
		sprintf(buffer, Platform::GetString (kStr_ProfInterruptX).c_str (), addr);
		return buffer;
	}

	// check for traps
	if (IS_TRAP_32(addr))
	{
		sprintf(buffer, Platform::GetString (kStr_ProfTrapNameAddress).c_str (),
					::GetTrapName (TRAP_NUM(addr), TRAP_EXTRA(addr), true), TRAP_NUM(addr));
		return buffer;
	}

	// look up address in the ROM map
	if (ROMMap != NULL)
	{
		int i = 0;
		// DOLATER   use binary search, since ROMMap is sorted by address
		while (i < ROMMapEnd && addr > ROMMap[i].address)
			i++;
		if (i < ROMMapEnd && addr == ROMMap[i].address)
		{
			sprintf(buffer, Platform::GetString (kStr_ProfROMNameAddress).c_str (), ROMMap[i].name, addr);
			return buffer;
		}
	}

	// if not in the map, try to get the symbol out of the ROM itself
	// Llamagraphics, Inc:  Pass in the size of the buffer to FindFunctionName,
	// which prevents it from truncating the name at 31 characters.
	::FindFunctionName (addr, buffer, &startAddr, NULL, sizeof(buffer));

	if (strlen (buffer) == 0)
	{
		// no symbol in ROM or invalid address, just output address
		sprintf (buffer, Platform::GetString (kStr_ProfUnknownName).c_str (), addr);
	}
	else
	{
		if (startAddr != addr)
			sprintf(&buffer[strlen(buffer)], "+$%04lX", addr-startAddr);

		// hack the address onto the end
		sprintf(&buffer[strlen(buffer)], " [$%08lX]", addr);
	}
	
	return buffer;
}





//---------------------------------------------------------------------
// Converting addresses to human readable names
//---------------------------------------------------------------------

char *stringTable = NULL;
int stringTableEnd;
int stringTableCapacity;
static void InitStringTable()
{
	// allocate the string table
	// Llamagraphics, Inc:  Since the stringTable can now grow dynamically,
	// the initial value for stringTableCapacity isn't so crucial as it once
	// was.  AVGNAMELENGTH * MAXUNIQUEFNS may be overkill.
	stringTableCapacity = AVGNAMELENGTH * MAXUNIQUEFNS;
	stringTable = (char*) Platform::AllocateMemory (stringTableCapacity);
	stringTableEnd = 0;
}

static void CleanupStringTable()
{
	Platform::DisposeMemory (stringTable);
}

static int FindOrAddString(char *newS)
{
	int offset = 0;
	while (offset < stringTableEnd)
		if (strcmp(&stringTable[offset], newS) == 0)
			return offset;
		else
			offset += strlen(&stringTable[offset])+1;
	
	// Llamagraphics, Inc:  Added code to automatically increase the size of
	// the stringTable as needed.  This is part of the solution for handling
	// long mangled C++ function names.
	stringTableEnd = offset + strlen(newS) + 1;
	if (stringTableEnd > stringTableCapacity) {
		// We need to increase the capacity of the stringTable.  Note that
		// even though we've modified stringTableEnd, offset contains the
		// previous value of stringTableEnd.
		stringTableCapacity = (stringTableEnd * 8) / 5;	// a moderately bigger number
		char * newTable = (char*) Platform::AllocateMemory(stringTableCapacity);
		memcpy(newTable, stringTable, offset);
		Platform::DisposeMemory(stringTable);
		stringTable = newTable;
	}
	strcpy(&stringTable[offset], newS);
	return (offset);
}


// Llamagraphics, Inc:  This routine used to be recursive, but we rewrote
// it to be linear because the recursive version was blowing the stack
// on the Macintosh.
static void LinearAddressToStrings()
{
	for (int i = 0; i < firstFreeCallRec; ++i) {
		// Not all addresses are valid. For instance, I've seen the value
		// 0x011dec94 in calls[x].address, which is either the address of the
		// TRAP $C instruction used to regain control in ATrap::DoCall, or
		// December 11, 1994.
		//  ...but that's OK, GetRoutineName handles that (calls valid_address)

		calls[i].address = FindOrAddString(GetRoutineName(calls[i].address));
	}
}


#if 0

// Llamagraphics, Inc:  We wrote this routine to sanity check the calls
// tree and make sure that the kid and sib links were consistant.  It
// didn't turn up any problems, but might come in handy in the future.
// It did help us understand that recursing on siblings is a bad idea...

static void CheckTree()
{
	assert(firstFreeCallRec <= gMaxCalls);
	
	bool * isUsed = new bool[gMaxCalls];
	int * pending = new int[gMaxDepth];
	
	assert(isUsed != 0);
	assert(pending != 0);
	
	for (int i = 0; i < gMaxCalls; ++i) isUsed[i] = false;
	for (int i = 0; i < gMaxDepth; ++i) pending[i] = NORECORD;
	
	int depth = 0;
	int maxDepth = 0;
	int recordsProcessed = 0;
	
	// To start with, just the root node is pending
	pending[depth++] = rootRecord;
	while (depth > 0) {
		
		// Pop off the current record
		int current = pending[--depth];
		
		// If the current record is NORECORD, then we're done
		// at this level and can continue popping to the next level.
		if (current == NORECORD) continue;
		assert((current >= 0) && (current < firstFreeCallRec));
		
		++recordsProcessed;
		
		// Make sure that this is the first time that we've processed
		// this record.
		assert(! isUsed[current]);
		isUsed[current] = true;
		
		// If we have a sibling, push it on the stack.
		if (calls[current].sib != NORECORD) {
			assert(depth < gMaxDepth);
			pending[depth++] = calls[current].sib;
			if (depth > maxDepth) maxDepth = depth;
		}
		
		// If we have a kid, push it on the stack.
		if (calls[current].kid != NORECORD) {
			assert(depth < gMaxDepth);
			pending[depth++] = calls[current].kid;
			if (depth > maxDepth) maxDepth = depth;
		}
	}
	
	// Make sure that all of the records were used.
	for (int i = 0; i < firstFreeCallRec; ++i) {
		assert(isUsed[i]);
	}
	assert(recordsProcessed == firstFreeCallRec);
	
	delete [] isUsed;
	delete [] pending;
}
			
#endif

//---------------------------------------------------------------------
// debugging routine to print profiling stuff to a log file
//---------------------------------------------------------------------

#if defined (_WINDOWS)
#define LINE_FORMAT_SPEC "%d\t%d\t%d\t%s\t%ld\t%I64d\t%.3f\t%.1f\t%I64d\t%.3f\t%.1f\t%.3f\t%.3f\t%.3f\t%ld\n"
#else	// MAC
#define LINE_FORMAT_SPEC "%d\t%d\t%d\t%s\t%ld\t%lld\t%.3f\t%.1f\t%lld\t%.3f\t%.1f\t%.3f\t%.3f\t%.3f\t%ld\n"
#endif

#define MAXNESTING	80
static void RecursivePrintBlock(FILE *resultsLog, int i, int depth, int parent)
{
	while (i != NORECORD)
	{
		// Use statics in this function to reduce stack frame size
		// from 272 bytes to 160 bytes.  Printing each number by itself
		// instead of with one long formatting string further reduces
		// the stack frame size to 96 bytes.
		//
		// And, yes, these efforts are important.  We were easly using
		// 190K of stack space, blowing the space allocated on the Mac.

		static double cyclesSelfms;
		static double cyclesSelfpct;
		static double cyclesKidsms;
		static double cyclesKidspct;
		
		cyclesSelfms = calls[i].cyclesSelf / kCyclesPerMilliSecond;
		cyclesSelfpct = calls[i].cyclesSelf / gCyclesCounted * 100;
		cyclesKidsms = calls[i].cyclesPlusKids / kCyclesPerMilliSecond;
		cyclesKidspct = calls[i].cyclesPlusKids / gCyclesCounted * 100;
		
		static double temp1;
		static double temp2;
		static double temp3;
		
		temp1 = (double)calls[i].cyclesSelf / (double)calls[i].entries / (double)kCyclesPerMilliSecond;
		temp2 = (double)calls[i].cyclesMax / (double)kCyclesPerMilliSecond;
		temp3 = (double)calls[i].cyclesMin / (double)kCyclesPerMilliSecond;

		fprintf(resultsLog, "%d", i);
		fprintf(resultsLog, "\t%d", parent);
		fprintf(resultsLog, "\t%d", depth);
		fprintf(resultsLog, "\t%s", GetRoutineName (calls[i].address));
		fprintf(resultsLog, "\t%ld", calls[i].entries);
		fprintf(resultsLog, "\t%lld", calls[i].cyclesSelf);
		fprintf(resultsLog, "\t%.3f", cyclesSelfms);
		fprintf(resultsLog, "\t%.1f", cyclesSelfpct);
		fprintf(resultsLog, "\t%lld", calls[i].cyclesPlusKids);
		fprintf(resultsLog, "\t%.3f", cyclesKidsms);
		fprintf(resultsLog, "\t%.1f", cyclesKidspct);
		fprintf(resultsLog, "\t%.3f", temp1);
		fprintf(resultsLog, "\t%.3f", temp2);
		fprintf(resultsLog, "\t%.3f", temp3);
		fprintf(resultsLog, "\t%ld\n", calls[i].stackUsed);

		RecursivePrintBlock(resultsLog, calls[i].kid, depth+1, i);

		// Was:
		//
		//		RecursivePrintBlock(resultsLog, calls[i].sib, depth, parent);
		//
		// Recoded to manually force tail-recursion.  Doing this bumped
		// the stack frame size back up to 112 bytes, but hopefully this is
		// greatly offset by not recursing as much.

		i = calls[i].sib;
	}
}

static void PrintBlock(FILE *resultsLog, int i)
{
	RecursivePrintBlock(resultsLog, i, 0, NORECORD);
}

static void RecursiveSortKids(int parent)
{
	if (parent != NORECORD)
	{
		int i = calls[parent].kid;
		int iprev = NORECORD;

		while (i != NORECORD)
		{
			// sort the kids of each node
			RecursiveSortKids(i);
						
			// start at root, examine each node until insertion point is found
			int j = calls[parent].kid;
			int jprev = NORECORD;
			
			while (j != NORECORD && j != i
				   && calls[i].cyclesPlusKids < calls[j].cyclesPlusKids)
			{
				jprev = j;
				j = calls[j].sib;
			}
			
			// assuming inserting eariler in list, update pointers.
			if (j != NORECORD)
				if (j == i)
					// no need to insert, since it's in the right place, so just go on
					iprev = i;
				else
				{
					// moving i, so first remove i from list
					if (iprev == NORECORD) Platform::Debugger();	// should never happen, i replacing itself!
					calls[iprev].sib = calls[i].sib;
					
					// insert i before j
					if (jprev == NORECORD)
					{
						calls[i].sib = calls[parent].kid;
						calls[parent].kid = i;
					}
					else
					{
						calls[i].sib = calls[jprev].sib;
						calls[jprev].sib = i;
					}
				}
				
			// go on to next node
			i = calls[iprev].sib;
		}
			
	}
}


//---------------------------------------------------------------------
// Call stack and call record management routines
//---------------------------------------------------------------------

static SInt64 PopCallStackFn(Boolean normalReturn)
{
	assert (callSP >= 0);

	// cyclesThisCall includes all interrupts and kids
	SInt64 cyclesThisCall = S64Subtract(gClockCycles, callStack[callSP].cyclesAtEntry);
	
	// cyclesInMe does not include interrupts or kids
	SInt64 cyclesInMe = S64Subtract(cyclesThisCall, callStack[callSP].cyclesInKids);
	
	SInt64 totalCyclesInInterrupts = S64Add(callStack[callSP].cyclesInInterrupts,
												 callStack[callSP].cyclesInInterruptsInKids);
	
	int exiter = callStack[callSP].call;

	calls[exiter].entries++;

	calls[exiter].cyclesPlusKids = S64Add(calls[exiter].cyclesPlusKids, cyclesThisCall);
	calls[exiter].cyclesPlusKids = S64Subtract(calls[exiter].cyclesPlusKids,
															 totalCyclesInInterrupts);

	calls[exiter].cyclesSelf = S64Add(calls[exiter].cyclesSelf, cyclesInMe);

	// using cyclesMin to count time in interrupt handlers
	calls[exiter].cyclesMin = S64Add(calls[exiter].cyclesMin,
												callStack[callSP].cyclesInInterrupts);

	if (S64Compare(cyclesInMe, calls[exiter].cyclesMax) > 0)
		calls[exiter].cyclesMax = cyclesInMe;
	
	if (!normalReturn)
		calls[exiter].stackUsed += 10000;

	--callSP;
	if (callSP >= 0) {
		callStack[callSP].cyclesInKids = S64Add(callStack[callSP].cyclesInKids,
															 cyclesThisCall);
		callStack[callSP].cyclesInInterruptsInKids =
							S64Add(callStack[callSP].cyclesInInterruptsInKids,
									 totalCyclesInInterrupts);
	}
	
	return cyclesThisCall;
}


static int FindOrAddCall(int head, uaecptr address)
{
	int newR;
	int current;
	int prev;
	
	if (head == overflowRecord)
		return overflowRecord;

	if (head == NORECORD)
		newR = firstFreeCallRec++;	// head is empty, just create record
	else
	{
		// look for existing
		current = head;
		while (current != NORECORD && calls[current].address != address)
		{
			// Because of the "head == NORECORD" test above, we are guaranteed
			// to enter the loop body at least once, thus initializing "prev".
			// This is important, because we use "prev" later.

			prev = current;
			current = calls[current].sib;
		}
		
		if (current != NORECORD)	// also returns if current == overflowRecord, good!
			return current;

		newR = firstFreeCallRec++;
		if (newR >= gMaxCalls)
			return overflowRecord;
		calls[prev].sib = newR;
	}

	if (newR >= gMaxCalls)
		return overflowRecord;

	assert (address == ROOTADDRESS ||
			address == INTERRUPTADDRESS ||
			address == OVERFLOWADDRESS ||
			IS_TRAP_32(address) ||
			valid_address (address, 2));

	// fill record
	calls[newR].sib = NORECORD;
	calls[newR].kid = NORECORD;
	calls[newR].address = address;
	calls[newR].entries = 0;
	calls[newR].cyclesSelf = S64Set(0);
	calls[newR].cyclesPlusKids = S64Set(0);
	calls[newR].cyclesMin = S64Set(0);	// 0xFFFFFFFFFFFFFFFF;
	calls[newR].cyclesMax = S64Set(0);
	calls[newR].stackUsed = 0;

	return newR;
}


//---------------------------------------------------------------------
// Main entry points, exported via Profiling.h
//---------------------------------------------------------------------

void ProfileInit(int maxCalls, int maxDepth)
{
	// initialize globals
	gClockCycles = S64Set(0);
	gReadCycles = S64Set(0);
	gWriteCycles = S64Set(0);

	gReadMismatch = 0;		// debug
	gWriteMismatch = 0;		// debug

	gProfilingEnabled = true;
	gProfilingOn = false;
	gProfilingCounted = false;
	gProfilingDetailed = false;
	interruptCycles = S64Set(0);
	interruptCount = 0;
	gMaxCalls = maxCalls;
	gMaxDepth = maxDepth;
	
	missedCount = 0;		// debug
	extraPopCount = 0;		// debug
	interruptMismatch = 0;	// debug

	// initialize call tree
	// Llamagraphics, Inc: Dispose of old calls rather than calling Debugger()
	Platform::DisposeMemory (calls);
	calls = (FnCallRecord*) Platform::AllocateMemory (sizeof (FnCallRecord) * gMaxCalls);
	firstFreeCallRec = 0;
	exceptionRecord = FindOrAddCall(NORECORD, INTERRUPTADDRESS);
	overflowRecord = FindOrAddCall(NORECORD, OVERFLOWADDRESS);
	
	// initialize call stack
	// Llamagraphics, Inc: Dispose of old callStack rather than calling Debugger()
	Platform::DisposeMemory (callStack);
	callStack = (FnStackRecord*) Platform::AllocateMemory (sizeof (FnStackRecord) * gMaxDepth);
	callSP = 0;
	callStack[callSP].call = rootRecord = FindOrAddCall(NORECORD, NOADDRESS);
	callStack[callSP].returnAddress = NOADDRESS;
	callStack[callSP].cyclesAtEntry = gClockCycles;
	callStack[callSP].cyclesInKids = S64Set(0);
	callStack[callSP].cyclesInInterrupts = S64Set(0);
	callStack[callSP].cyclesInInterruptsInKids = S64Set(0);
	
	profilingDetailLog = NULL;
	
	//  for testing
	// ProfileDetailFn(0x10CA68A0, true);
}


void ProfileCleanup()
{
	if (gProfilingOn)
		return;	//  DOLATER throw some error

	gProfilingEnabled = false;

	Platform::DisposeMemory (calls);
	Platform::DisposeMemory (callStack);

	if (profilingDetailLog != NULL)
		fclose(profilingDetailLog);
}



void ProfileStart()
{
	if (!gProfilingEnabled)
		Platform::Debugger();				// should be an exception
	if (gProfilingOn)
		return;
	if (callSP != 0)			// debug check
		Platform::Debugger();
	gProfilingOn = true;
	interruptDepth = -1;
	inInstruction = false;
}



void ProfileStop()
{
	if (!gProfilingEnabled)
		Platform::Debugger();
	if (!gProfilingOn)
		return;

	// pop any functions on stack, updating cycles on the way up
	// stop when callSP == 0, which matches fake "root" fn

	while (interruptDepth >= 0)		// means we stopped profiling in an interrupt...
		ProfileInterruptExit(NOADDRESS);
		
	while (callSP > 0)
		PopCallStackFn(false);		// doesn't gather stats on the way out

	gProfilingOn = false;
}



void ProfilePrint(const char* fileName)
{
	if (!gProfilingEnabled)
		Platform::Debugger();
	if (gProfilingOn)
		return;
		
	gCyclesCounted = S64Add(
						S64Add(calls[rootRecord].cyclesPlusKids,
							   calls[exceptionRecord].cyclesPlusKids),
						calls[overflowRecord].cyclesPlusKids);
	
	if (fileName == NULL)
		fileName = DEFAULT_RESULTS_TEXT_FILENAME;
	FILE *resultsLog = fopen(fileName, "w");

	fputs("index\tparent\tdepth\tfunction name\tcount\tonly cycles\tonly msec\tonly %\tplus kids cycles\tplus kids msec\tplus kids %\taverage msec\tmax msec\tinterrupt msec\tinterrupt count/debug\n", resultsLog);

	RecursiveSortKids(rootRecord);
	RecursiveSortKids(exceptionRecord);
	
	PrintBlock(resultsLog, rootRecord);
	
	// in case ProfilePrint was called on its own, dump out exception and overflow nodes
	// (these will be sibs of rootRecord if called from ProfileDump)
	if (calls[rootRecord].sib == NORECORD)
		PrintBlock(resultsLog, exceptionRecord);
	if (calls[exceptionRecord].sib == NORECORD)
		PrintBlock(resultsLog, overflowRecord);


#if defined (_WINDOWS)
	fprintf(resultsLog, "\tcycles counted:\t\t%I64d\n", gCyclesCounted);
	fprintf(resultsLog, "\ttotal clocks:\t\t%I64d\n", gClockCycles);
	fprintf(resultsLog, "\ttotal reads:\t\t%I64d\n", gReadCycles);
	fprintf(resultsLog, "\ttotal writes:\t\t%I64d\n", gWriteCycles);
#else // MAC
	fprintf(resultsLog, "\tcycles counted:\t\t%lld\n", gCyclesCounted);
	fprintf(resultsLog, "\ttotal clocks:\t\t%lld\n", gClockCycles);
	fprintf(resultsLog, "\ttotal reads:\t\t%lld\n", gReadCycles);
	fprintf(resultsLog, "\ttotal writes:\t\t%lld\n", gWriteCycles);
#endif

	fprintf(resultsLog, "\treturn level mis-matches:\t\t%ld\n", extraPopCount);
	fprintf(resultsLog, "\tnon-matching returns:\t\t%ld\n", missedCount);

	fclose(resultsLog);
}


void ProfileDump(const char* fileName)
{
	if (!gProfilingEnabled)
		Platform::Debugger();
	if (gProfilingOn)
		return;

	if (fileName == NULL)
		fileName = DEFAULT_RESULTS_FILENAME;

	// read in the ROM.map file
	if (ROMMap != NULL)
		Platform::Debugger();
	ROMMap = (ROMMapRecord*) Platform::AllocateMemory (sizeof (ROMMapRecord) * MAXROMFNS);
	ROMMapEnd = 0;
	
	StMemory	names (36 * MAXROMFNS);
	char *namesEnd = names.Get();
	char name[36];
	uaecptr addr;

	FILE *ROMMapFile = fopen("ROM.map", "r");
	if (ROMMapFile)
	{
		while (!feof(ROMMapFile) && (ROMMapEnd < MAXROMFNS))
		{
			if (fscanf(ROMMapFile, " %35s $%lx \n", name, &addr) != 2)
				Platform::Debugger();
			ROMMap[ROMMapEnd].address = addr;
			ROMMap[ROMMapEnd++].name = namesEnd;
			strcpy(namesEnd, name);
			namesEnd += strlen(name) + 1;
		}
		fclose(ROMMapFile);
	}

	// fix up trees a bit (sum cycle counts for root nodes)
	calls[rootRecord].address = ROOTADDRESS;
	int current = calls[rootRecord].kid;
	while (current != NORECORD)
	{
		calls[rootRecord].cyclesPlusKids =
			S64Add(calls[rootRecord].cyclesPlusKids, calls[current].cyclesPlusKids);
		current = calls[current].sib;
	}

	current = calls[exceptionRecord].kid;
	while (current != NORECORD)
	{
		calls[exceptionRecord].cyclesPlusKids =
			S64Add(calls[exceptionRecord].cyclesPlusKids, calls[current].cyclesPlusKids);
		current = calls[current].sib;
	}

	// compute total cycles counted
	gCyclesCounted = S64Add(
						S64Add(calls[rootRecord].cyclesPlusKids,
							   calls[exceptionRecord].cyclesPlusKids),
						calls[overflowRecord].cyclesPlusKids);
	
	// debugging
	if (calls[rootRecord].sib != NORECORD
	|| calls[exceptionRecord].sib != NORECORD
	|| calls[overflowRecord].sib != NORECORD
	|| calls[overflowRecord].kid != NORECORD)
		Platform::Debugger();

	// fix up top-level records
	calls[rootRecord].sib = exceptionRecord;
	calls[exceptionRecord].sib = overflowRecord;

	// free pointer could be really large...
	if (firstFreeCallRec > gMaxCalls)
		firstFreeCallRec = gMaxCalls;

	// dump out a plain text file too
	char	textName[256];
	strcpy (textName, fileName);
	if (::EndsWith (textName, ".mwp"))
		textName[strlen (textName) - 4] = 0;
	strcat (textName, ".txt");
	ProfilePrint(textName);

	// munge all the addresses to produce the string table
	InitStringTable();

	// Llamagraphics, Inc:  Replaced RecursiveAddressToString() with
	// LinearAddressToString(), since the recursive version was blowing
	// the stack on the Macintosh.
	LinearAddressToStrings();

	// do a little cleanup now
	Platform::DisposeMemory (ROMMap);

	// create the header blocks
	ProfFileHeader header;

	header.proF = 'proF';
	header.version = 0x00040002;
	header.fnCount = firstFreeCallRec;
	header.four = 0x00000004;

	header.zeros1 = 0x00000000;
	header.zeros2 = 0x00000000;
	header.unknown = 0x00000000;
	header.recordsSize = sizeof(ProfFileHeader) + firstFreeCallRec * sizeof(FnCallRecord);

	header.stringTableSize = stringTableEnd;
	header.overhead = S64Subtract(gClockCycles, gCyclesCounted);
	header.rootRec = rootRecord;

	header.sixtyfour1 = 0x00000064;
	header.sixtyfour2 = 0x00000064;
	header.countsPerTime = kCyclesPerSecond/100;	// times will be shown in milliseconds
	header.oddstuff0 = 0x00000000;

	header.oddstuff1 = 0x00000000;
	header.oddstuff2 = 0x00000000;
	header.oddstuff3 = 0x00000000;
	header.oddstuff4 = 0x00000000;

	for (int i=0; i < sizeof(header.unused); i++)
		header.unused[i] = 0x00;

	FileReference fr(fileName);
	FileHandle	outputFile (fr,
							kCreateAlways | kOpenReadWrite,
							'proF', 'proF');

	outputFile.Write (sizeof(ProfFileHeader), &header);
	outputFile.Write (sizeof(FnCallRecord) * firstFreeCallRec, calls);
	outputFile.Write (stringTableEnd, stringTable);

	// cleanup
	CleanupStringTable();
	
	// Llamagraphics, Inc:  After dumping, the calls[i].address slots are
	// offsets into the string table rather than machine addresses.  This
	// means that the profiling information can't continue to be used, so
	// let's dispose of it now and remove the danger of it being misinterpreted.
	ProfileCleanup();
}



void ProfileFnEnter(uaecptr destAddress, uaecptr returnAddress)
{
	if (!gProfilingOn)
#if PROFILE_ONE_FN
		if (address == FNTOPROFILE)
			ProfileStart();
		else
			return;
#else
		return;
#endif

	if (inInstruction)
		ProfileInstructionExit(NOADDRESS);

	// If destAddress contains a trapword, save the trapword along
	// with some other information that might be useful (like the
	// library reference number if we're calling a library function).
	if (IS_TRAP_16(destAddress))
	{
		if (IsSystemTrap (destAddress))
		{
			uae_u16	trapWord = 0xA000 | SysTrapIndex (destAddress);

			if (trapWord == sysTrapIntlDispatch		||
				trapWord == sysTrapOmDispatch			||
				trapWord == sysTrapTsmDispatch		||
				trapWord == sysTrapFlpDispatch		||
				trapWord == sysTrapFlpEmDispatch		||
				trapWord == sysTrapSerialDispatch)
			{
				destAddress = PACK_TRAP_INFO(destAddress, m68k_dreg (regs, 2));
			}
			else
			{
				destAddress = PACK_TRAP_INFO(destAddress, 0);
			}
		}
		else
		{
			destAddress = PACK_TRAP_INFO(destAddress, get_word (m68k_areg (regs, 7)));
		}
	}


	// get the caller fn 
	int caller = callStack[callSP].call;
	
	// debug check, watch for overflow
	if (callSP >= gMaxDepth-1)
		Platform::Debugger();

	// push record for callee
	callStack[++callSP].returnAddress = returnAddress;
	callStack[callSP].cyclesAtEntry = gClockCycles;
	callStack[callSP].cyclesInKids = S64Set(0);
	callStack[callSP].cyclesInInterrupts = S64Set(0);
	callStack[callSP].cyclesInInterruptsInKids = S64Set(0);
	callStack[callSP].call = FindOrAddCall(calls[caller].kid, destAddress);
	
	// check if this was first kid and update parent
	if (calls[caller].kid == NORECORD && callStack[callSP].call != overflowRecord)
		calls[caller].kid = callStack[callSP].call;
}



void ProfileFnExit(uaecptr returnAddress, uaecptr oldAddress)
{
	if (!gProfilingOn)
		return;

	if (inInstruction)
		ProfileInstructionExit(NOADDRESS);

	// sanity check, try to make sure the returns match the calls we think they do
	if (callStack[callSP].returnAddress != NOADDRESS
	&& callStack[callSP].returnAddress != returnAddress)
	{
		int trySP = callSP;
		while (--trySP >= 0)
			if (returnAddress == callStack[trySP].returnAddress)
				break;

		if (trySP >= 0)
			// found a match on stack, so pop up to it
			while (callSP > trySP)
			{
				extraPopCount++;		// debug, count extra pops
				PopCallStackFn(false);
			}
		else if (callSP != 0)
		// could be a longjump disguised as an RTS, so push instead
		{
			ProfileFnEnter(returnAddress, oldAddress);
			calls[callStack[callSP].call].stackUsed += 100000;	// mark it as wierdly called
			missedCount++;				// debug, count unmatched returns
			return;
		}
	}

	PopCallStackFn(true);

#if PROFILE_ONE_FN
	// if we started on entering a function, stop when it exits
	if (callSP == 0)
		ProfileStop();
#else		
	// or an alternate thing to do if we pop too far, re-root and continue
	if (callSP < 0)
	{
		// uh oh, we must have exited the fn we started profiling in!
		// make a new root to handle the new enclosing function
		rootRecord = FindOrAddCall(NORECORD, NOADDRESS);
		if (rootRecord == overflowRecord)
			Platform::Debugger();
		calls[rootRecord].kid = callStack[0].call;	// old root
		callStack[0].returnAddress = NOADDRESS;
		callStack[0].call = rootRecord;
		// callStack[0].cyclesAtEntry = ... don't change, it's the time profiling was started
		callStack[0].cyclesInKids = S64Subtract(gClockCycles, callStack[0].cyclesAtEntry);
		callStack[0].cyclesInInterrupts = S64Set(0);
		callStack[0].cyclesInInterruptsInKids = S64Set(0);
		callSP = 0;
	}
#endif
}



void ProfileInterruptEnter(uae_s32 iException, uaecptr returnAddress)
{
	if (!gProfilingOn)
		return;

	if (inInstruction)
		ProfileInstructionExit(NOADDRESS);

	// get the caller fn 
	callStack[callSP].cyclesAtInterrupt = gClockCycles;
	interruptCount++;
	interruptStack[++interruptDepth] = callSP;	// mark the fn that was interrupted
	
	// debug check, watch for overflow
	if (callSP >= gMaxDepth-1)
		Platform::Debugger();

	// push record for callee
	callStack[++callSP].returnAddress = returnAddress;
	callStack[callSP].cyclesAtEntry = gClockCycles;
	callStack[callSP].cyclesInKids = S64Set(0);
	callStack[callSP].cyclesInInterrupts = S64Set(0);
	callStack[callSP].cyclesInInterruptsInKids = S64Set(0);
	callStack[callSP].call = FindOrAddCall(calls[exceptionRecord].kid, iException);
	// check if this was first exception and update exceptionRecord
	if (calls[exceptionRecord].kid == NORECORD && callStack[callSP].call != overflowRecord)
		calls[exceptionRecord].kid = callStack[callSP].call;
}



void ProfileInterruptExit(uaecptr returnAddress)
{
	uae_s32 needsFakeCall = NOADDRESS;
	
	if (!gProfilingOn)
		return;
	
	if (inInstruction)
		ProfileInstructionExit(NOADDRESS);

	if (interruptDepth < 0)		// means we started profiling in an interrupt... oh well
		return;

	if (callSP <= interruptStack[interruptDepth])
		Platform::Debugger();

	while (callSP > interruptStack[interruptDepth]+1)
	{
		// mismatched jsr/rts set inside interrupt handler, deal with it
		extraPopCount++;		// debug, count extra pops
		PopCallStackFn(false);
	}
		
	// sanity check, try to make sure the returns match the calls we think they do
	if (callStack[callSP].returnAddress != returnAddress)
		// trap handler is sneaky, and pushes stuff on the stack so that the RTE jumps
		// to the implementation of the trap.  Detect this by noticing the RTE address didn't
		// match and generating a fake function call.
		if (calls[callStack[callSP].call].address == 0x2F)
			needsFakeCall = callStack[callSP].returnAddress + 2;	// +2 to skip trap word
		else
			interruptMismatch++;
	
	// pop the interrupt block
	SInt64 cyclesThisCall = PopCallStackFn(true);
	assert(callSP >= 0);
	
	interruptDepth--;
	interruptCycles = S64Add(interruptCycles, cyclesThisCall);

	// store interrupt time so we can subtract it later from the cycles for the function itself
	callStack[callSP].cyclesInInterrupts = S64Add(callStack[callSP].cyclesInInterrupts,
																 cyclesThisCall);
	calls[callStack[callSP].call].stackUsed += 1;	// count other interrupts this way

	// trap interrupt
	if (needsFakeCall != NOADDRESS)
		ProfileFnEnter(returnAddress, needsFakeCall);
	
}



void ProfileDetailFn(uaecptr addr, int logInstructions)
{
	::FindFunctionName(addr, NULL, &detailStartAddr, &detailStopAddr, 0);

	gProfilingDetailed = true;
	
	if (logInstructions && profilingDetailLog == NULL)
	{
		profilingDetailLog = fopen("ProfilingDetail.txt", "w");
		fputs("PC\topcode\tinstruction:\tclocks\treads\twrites\ttotal:\tclocks\treads\twrites\t", profilingDetailLog);
	}
}



void ProfileInstructionEnter(uaecptr instructionAddress)
{
	if (!gProfilingOn)
		return;

	if (instructionAddress < detailStartAddr ||
		 instructionAddress > detailStopAddr)
		return;

	// get the caller fn 
	int caller = callStack[callSP].call;
	
	// debug check, watch for overflow
	if (callSP >= gMaxDepth-1)
		Platform::Debugger();

	// push record for instruction
	callStack[++callSP].returnAddress = instructionAddress;
	callStack[callSP].cyclesAtEntry = gClockCycles;
	callStack[callSP].cyclesInKids = S64Set(0);
	callStack[callSP].cyclesInInterrupts = S64Set(0);
	callStack[callSP].cyclesInInterruptsInKids = S64Set(0);
	callStack[callSP].call = FindOrAddCall(calls[caller].kid, instructionAddress);
	callStack[callSP].opcode = get_iword(0);
	
	// check if this was first kid and update parent
	if (calls[caller].kid == NORECORD && callStack[callSP].call != overflowRecord)
		calls[caller].kid = callStack[callSP].call;
	
	clockCyclesSaved = gClockCycles;
	readCyclesSaved = gReadCycles;
	writeCyclesSaved = gWriteCycles;
	
	inInstruction = true;
}


void ProfileInstructionExit(uaecptr instructionAddress)
{
	if (!gProfilingOn)
		return;
	
	if (!inInstruction)
		return;

	if (instructionAddress == NOADDRESS)
		instructionAddress = callStack[callSP].returnAddress;
		
	// sanity check, try to make sure the returns match the calls we think they do
	if (callStack[callSP].returnAddress != instructionAddress)
		Platform::Debugger();

	if (profilingDetailLog != NULL)
	{
		char hackBuffer[512];
		sprintf(hackBuffer,
			"$%08lX\t$%04lX\t \t%lld\t%lld\t%lld\t \t%lld\t%lld\t%lld\n",
				instructionAddress,
				callStack[callSP].opcode,
				S64Subtract(gClockCycles, clockCyclesSaved),
				S64Subtract(gReadCycles, readCyclesSaved), 
				S64Subtract(gWriteCycles, writeCyclesSaved),
				gClockCycles,
				gReadCycles,
				gWriteCycles);
		
		if (S64Compare(clockCyclesLast, clockCyclesSaved) != 0)
			fputs("\n", profilingDetailLog);
		
		if (instructionAddress == detailStartAddr)
			fputs("\t-->\tJSR\n", profilingDetailLog);
			
		fputs(hackBuffer, profilingDetailLog);

	if (callStack[callSP].opcode  == kOpcode_RTS)	// RTS
		fputs("\t<--\tRTS\n", profilingDetailLog);
			
		clockCyclesLast = gClockCycles;
	}
	
	PopCallStackFn(true);
	
	inInstruction = false;
}



void ProfileTest()
{
	ProfileInit(15,5);
	ProfileStart();
	ProfileIncrementClock(110 * kCyclesPerSecond);
	
	ProfileInterruptExit(0x55555555);
	ProfileIncrementClock(110 * kCyclesPerSecond);
	
	ProfileFnEnter(0xAAAAAAAA, 0);	// new
		ProfileIncrementClock(100 * kCyclesPerSecond);
		ProfileFnEnter(0xBBBBBBBB, 0);	// new kid
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnEnter(0xCCCCCCCC, 0);		// new kid
				ProfileIncrementClock(1 * kCyclesPerSecond);
				ProfileFnExit(0, 0);
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnEnter(0xDDDDDDDD, 0);		// new sib at end
				ProfileIncrementClock(1 * kCyclesPerSecond);
				ProfileFnExit(0, 0);
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnEnter(0xCCCCCCCC, 0);		// same kid
				ProfileIncrementClock(1 * kCyclesPerSecond);
				ProfileFnExit(0, 0);
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnExit(0, 0);
		ProfileIncrementClock(100 * kCyclesPerSecond);
		ProfileFnEnter(0xBBBBBBBB, 0);	// same kid
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnEnter(0xCCCCCCCC, 0);		// new kid
				ProfileIncrementClock(1 * kCyclesPerSecond);
				ProfileFnExit(0, 0);
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnExit(0, 0);
		ProfileIncrementClock(100 * kCyclesPerSecond);
		ProfileFnEnter(0xDDDDDDDD, 0);	// new sib at end
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnEnter(0xCCCCCCCC, 0);		// new kid
				ProfileIncrementClock(1 * kCyclesPerSecond);
				ProfileFnExit(0, 0);
	
	ProfileIncrementClock(120 * kCyclesPerSecond);
	ProfileInterruptEnter(0x11111111, 0);	// interrupt
		ProfileIncrementClock(10 * kCyclesPerSecond);
		ProfileFnEnter(0x22222222, 0);		// new kid
			ProfileIncrementClock(1 * kCyclesPerSecond);
			ProfileFnExit(0, 0);
		ProfileIncrementClock(10 * kCyclesPerSecond);
		ProfileInterruptExit(0);

			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnExit(0, 0);
		ProfileIncrementClock(100 * kCyclesPerSecond);
		ProfileFnEnter(0xCCCCCCCC, 0);	// new kid in middle
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnExit(0, 0);
		ProfileIncrementClock(100 * kCyclesPerSecond);
		ProfileFnEnter(0xAAAAAAAA, 0);	// new kid at beginning
			ProfileIncrementClock(10 * kCyclesPerSecond);
			ProfileFnExit(0, 0);
		ProfileIncrementClock(100 * kCyclesPerSecond);
		ProfileFnExit(0, 0);
	ProfileIncrementClock(100 * kCyclesPerSecond);
	// ProfileFnExit(0);
	// ProfileIncrementClock(100 * kCyclesPerSecond);
	// ProfileFnExit(0);

	ProfileInterruptEnter(0x99999999, 0);	// interrupt
	ProfileIncrementClock(10 * kCyclesPerSecond);

	ProfileStop();
	ProfileDump(NULL);
	ProfileCleanup();
}