/*=============================================================================
 *  AUTracer.cpp
 
	$Log: AUTracer.cpp,v $
	Revision 1.6  2004/08/24 00:21:21  bills
	fix warnings
	
	Revision 1.5  2004/08/23 19:13:14  bills
	HostTime API change
	
	Revision 1.4  2004/02/20 20:51:19  bills
	fix first trace
	
	Revision 1.3  2004/02/19 02:48:34  bills
	trace back a millisecond
	
	Revision 1.2  2004/01/13 01:16:45  baron
	Tweaks to overload tracer. <bills>
	
	Revision 1.1  2004/01/12 20:16:49  bills
	initial checkin
	
	Revision 1.4  2004/01/07 00:23:04  bills
	some tweaks to the tracing code
	
	Revision 1.3  2003/12/11 02:48:20  bills
	tweaks to profiling code
	
	Revision 1.2  2003/10/22 23:56:36  bills
	cvs log
	

 *  Created by William Stewart on 11 Jan, 2004.
 *  Copyright (c) 2004 Apple Computer Inc.. All rights reserved.
=============================================================================*/

#include "AUTracer.h"
#include "CAHostTimeBase.h"

static UInt64 s1msec = 0;
static UInt64 sTimeOut = 1000000000LL;

#include <sys/syscall.h>
#include <unistd.h>

static UInt32 startTrace = 0xDEADCA00;
static UInt32 endTrace = 0xDEADCA04;

AUTracer::~AUTracer ()
{
	if (mProfiler)
		delete mProfiler;
	
	if (mAU) {
		if (mSpikeLimit == 0) {
			AudioDeviceID theDevice;
			UInt32 theSize = sizeof (theDevice);
			AudioUnitGetProperty (mAU, kAudioOutputUnitProperty_CurrentDevice, 
													0, 0, &theDevice, &theSize);
			AudioDeviceRemovePropertyListener(theDevice, 0, false,
												kAudioDeviceProcessorOverload, 
												AUTracer::OverlaodListenerProc);
		} else {
			AudioUnitRemoveRenderNotify (mAU, AUTracer::CPUSpikeProfiler, this);
		}
		
		AudioUnitRemovePropertyListener (mAU,
										kAudioUnitProperty_SampleRate,
										AUTracer::SampleRateListener);
	}
}

OSStatus	AUTracer::Establish (AudioUnit inUnit, char* inFName, Float64 inSpikeLimit, UInt32 secsBetweenTraces)
{
	if (CALatencyLog::CanUse() == false)
		return -1;
	
	OSStatus result;

	if (s1msec == 0)
		s1msec = CAHostTimeBase::ConvertFromNanos (1000 * 1000);

			// listen for overloads
	if (inSpikeLimit == 0) 
	{
		AudioDeviceID theDevice;
		UInt32 theSize = sizeof (theDevice);
		require_noerr (result = AudioUnitGetProperty (inUnit, kAudioOutputUnitProperty_CurrentDevice, 
												0, 0, &theDevice, &theSize), home);
		if (mProfiler)
			delete mProfiler;
			
		mProfiler = new CALatencyLog (inFName, ".txt");
	
		require_noerr (result = AudioDeviceAddPropertyListener(theDevice, 0, false,
											kAudioDeviceProcessorOverload, 
											AUTracer::OverlaodListenerProc, this), home);
		
		require_noerr (result = AudioUnitAddRenderNotify (inUnit, AUTracer::OverloadTagger, this), home);
	}
	else // listen for spikes...
	{
		if (mProfiler)
			delete mProfiler;
		
		mProfiler = new CALatencyLog (inFName, ".txt");
		mSpikeLimit = inSpikeLimit;
  		
		require_noerr (result = AudioUnitAddRenderNotify (inUnit, AUTracer::CPUSpikeProfiler, this), home);
	}
			
	if (!result) {
		mAU = inUnit;
			
			// lets do this one to just load this code...
		mProfiler->Capture((CAHostTimeBase::GetTheCurrentTime() - s1msec), 
							CAHostTimeBase::GetTheCurrentTime(), 
							false, "DUMMY TRACE");


		require_noerr (result = AudioUnitAddPropertyListener (mAU,
										kAudioUnitProperty_SampleRate,
										AUTracer::SampleRateListener, this), home);
			
		sTimeOut *= secsBetweenTraces;
		
			// we start doing this straight away...
		mLastTimeWrote = CAHostTimeBase::ConvertFromNanos (CAHostTimeBase::ConvertToNanos (CAHostTimeBase::GetTheCurrentTime() - (sTimeOut * 2)));

		UInt32 dataSize = sizeof (Float64);
		require_noerr (result = AudioUnitGetProperty (inUnit, kAudioUnitProperty_SampleRate,
								kAudioUnitScope_Output, 0, &mSampleRate, &dataSize), home);
	}
		
home:
	return result;
}

void 		AUTracer::SampleRateListener (void			*inRefCon, 
									AudioUnit			ci, 
									AudioUnitPropertyID inID, 
									AudioUnitScope		inScope, 
									AudioUnitElement	/*inElement*/)
{
	if (inScope == kAudioUnitScope_Output && inID == kAudioUnitProperty_SampleRate) {
		AUTracer* This = static_cast<AUTracer*>(inRefCon);
		UInt32 dataSize = sizeof (Float64);
		AudioUnitGetProperty (ci, kAudioUnitProperty_SampleRate,
								kAudioUnitScope_Output, 0, &This->mSampleRate, &dataSize);
	}
}

OSStatus 	AUTracer::OverloadTagger (void 							*inRefCon, 
										AudioUnitRenderActionFlags  *ioActionFlags, 
										const AudioTimeStamp 		* /*inTimeStamp*/, 
										UInt32 						inBusNumber, 
										UInt32 						/*inNumberFrames*/, 
										AudioBufferList 			* /*ioData*/)
{
	if (inBusNumber == 0) {
		if ((*ioActionFlags & kAudioUnitRenderAction_PreRender)) {
			AUTracer* This = static_cast<AUTracer*>(inRefCon);
			syscall(180, startTrace, 0, 0, 0, 0);
			This->mProfileRenderStartTime = CAHostTimeBase::GetTheCurrentTime();
		}
	}
	return noErr;
}


OSStatus 	AUTracer::OverlaodListenerProc(	AudioDeviceID	/*inDevice*/,
									UInt32					/*inChannel*/,
									Boolean					/*isInput*/,
									AudioDevicePropertyID	/*inPropertyID*/,
									void*					inClientData)
{
	AUTracer* This = static_cast<AUTracer*>(inClientData);
	This->DoOverload();
	return noErr;
}

void			AUTracer::DoOverload ()
{
	UInt64 now = CAHostTimeBase::GetTheCurrentTime();

	UInt64 isWindow = CAHostTimeBase::ConvertToNanos (mLastTimeWrote) + sTimeOut;
	if (isWindow > CAHostTimeBase::CAHostTimeBase::ConvertToNanos(now))
		return;
	
	syscall(180, endTrace, 0, 0, 0, 0);

//	UInt64 elapseTime = UInt64 ((1024.0 / GetSampleRate()) * 1000000000.0);
//	UInt64 htElapseTime = CAHostTimeBase::ConvertFromNanos (elapseTime);

	mLastTimeWrote = CAHostTimeBase::GetTheCurrentTime();
	
	mProfiler->Capture((mProfileRenderStartTime - s1msec), mLastTimeWrote, true, "Captured Latency Log for I/O Cycle Overload\n");
}



  
OSStatus 		AUTracer::CPUSpikeProfiler (void 			*inRefCon, 
								AudioUnitRenderActionFlags 	*ioActionFlags, 
								const AudioTimeStamp 		* /*inTimeStamp*/, 
								UInt32 						inBusNumber, 
								UInt32 						inNumberFrames, 
								AudioBufferList 			* /*ioData*/)
{		
	if (inBusNumber == 0) {
		if ((*ioActionFlags & kAudioUnitRenderAction_PreRender)) {
			AUTracer *This = (AUTracer*)inRefCon;
			syscall(180, startTrace, 0, 0, 0, 0);
			This->mProfileRenderStartTime = CAHostTimeBase::GetTheCurrentTime();
		} else if (*ioActionFlags & kAudioUnitRenderAction_PostRender) {
			AUTracer *This = (AUTracer*)inRefCon;
			This->DoSpikeAnalysis (inNumberFrames);
		}
	}
	return noErr;
}

void		AUTracer::DoSpikeAnalysis (UInt32 inNumberFrames)
{
	UInt64 now = CAHostTimeBase::GetTheCurrentTime();
	Float64 iocycleTime = inNumberFrames / GetSampleRate() * 1000000000.0;
	Float64 nanosUsage = CAHostTimeBase::ConvertToNanos(now - mProfileRenderStartTime);
	Float64 usage = nanosUsage / iocycleTime;

	if (usage > mSpikeLimit) {
		UInt64 isWindow = CAHostTimeBase::ConvertToNanos (mLastTimeWrote) + sTimeOut;
		if (isWindow > CAHostTimeBase::CAHostTimeBase::ConvertToNanos(now))
			return;

		syscall(180, endTrace, 0, 0, 0, 0);
	
		static char string[1024];
		double howLongAgoWrote = CAHostTimeBase::ConvertToNanos (now - mLastTimeWrote) / 1000000000.0;
		
		sprintf (string, "Captured Latency Log for Spiked I/O Cyclye: time taken=%.2lf%% (%.2lf mics), spikeLimit=%d%% (%.2lf mics)\n\tnumFrames=%ld, sampleRate=%d, duty cycle=%.2lf mics, last Wrote=%.0lf secs\n\n", 
				(usage*100.0), (nanosUsage / 1000.0), 
				int(mSpikeLimit * 100 + 0.5), (iocycleTime * mSpikeLimit / 1000.0), 
				inNumberFrames, (int)GetSampleRate(), (iocycleTime / 1000.0), howLongAgoWrote);
		
		mLastTimeWrote = CAHostTimeBase::GetTheCurrentTime();
		mProfiler->Capture ((mProfileRenderStartTime - s1msec), mLastTimeWrote, true, string);
		
		printf ("%s", string);
	}
}