openbts/Control/L3TranEntry.cpp

/**@file TransactionTable and related classes. */

/*
* Copyright 2008, 2010 Free Software Foundation, Inc.
* Copyright 2010 Kestrel Signal Process, Inc.
* Copyright 2011, 2012, 2014 Range Networks, Inc.
*
* This software is distributed under multiple licenses;
* see the COPYING file in the main directory for licensing
* information for this specific distribution.
*
* This use of this software may be subject to additional restrictions.
* See the LEGAL file in the main directory for details.

    This program is distributed in the hope that it will be useful,
    but WITHOUT ANY WARRANTY; without even the implied warranty of
    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

*/

#define LOG_GROUP LogGroup::Control		// Can set Log.Level.Control for debugging
#include <sys/stat.h>
#include <sys/types.h>

#include "ControlCommon.h"
#include "L3TranEntry.h"
#include "L3MMLayer.h"

#include <GSMLogicalChannel.h>
#include <GSML3Message.h>
#include <GSML3CCMessages.h>
#include <GSML3RRMessages.h>
#include <GSML3MMMessages.h>
#include <GSML3CCElements.h>
#include <GSMConfig.h>
#include <ControlTransfer.h>

#include <Peering.h>

#include <sqlite3.h>
#include <sqlite3util.h>

//#include <SIPEngine.h>
//#include <SIPInterface.h>
#include <SIPUtility.h>

//#include <CallControl.h>

#include <Reporting.h>
#include <Logger.h>
#undef WARNING


// This is in the global namespace.
Control::NewTransactionTable gNewTransactionTable;

int gCountTranEntry = 0;



namespace Control {
using namespace std;
using namespace GSM;
using namespace SIP;
using namespace Peering;	// for sockaddr2string - remove me
CdrService gCdrService;


#if EXTERNAL_TRANSACTION_TABLE
// (pat) This external transaction table is obsolete and we will not support it any more.
// The code implementing it has eroded and would not work if enabled.
// It is retained here until we release version 4 in the remote off-chance that some important customer
// has built legacy applications that use this, so we can help migrate that customer to something different.
// This is extremely unlikely, since we have no customers.
static const char* createNewTransactionTable = {
	"CREATE TABLE IF NOT EXISTS TRANSACTION_TABLE ("
		"ID INTEGER PRIMARY KEY, "		// internal transaction ID
		"CHANNEL TEXT DEFAULT NULL,"	// channel description string (cross-refs CHANNEL_TABLE)
		"CREATED INTEGER NOT NULL, "	// Unix time of record creation
		"CHANGED INTEGER NOT NULL, "	// time of last state change
		"TYPE TEXT, "					// transaction type
		"SUBSCRIBER TEXT, "				// IMSI, if known
		"L3TI INTEGER, "				// GSM L3 transaction ID, +0x08 if generated by MS
		"SIP_CALLID TEXT, "				// SIP-side call id tag
		"SIP_PROXY TEXT, "				// SIP proxy IP
		"CALLED TEXT, "					// called party number
		"CALLING TEXT, "				// calling party number
		"GSMSTATE TEXT, "				// GSM/Q.931 state
		"SIPSTATE TEXT "				// SIP state
	")"
};
#endif



static std::list< RefCntPointer<TranEntry> > sDeletedTranEntrys;



HandoverEntry::HandoverEntry(const TranEntry *tran) :
	mMyTranID(tran->tranID()),
	mHandoverOtherBSTransactionID(0)
{
	memset(&mInboundPeer,0,sizeof(mInboundPeer));
	memset(&mOutboundPeer,0,sizeof(mOutboundPeer));
};

HandoverEntry *TranEntry::getHandoverEntry(bool create) const	// It is not const, but we want C++ to be a happy compiler.
{
	if (!mHandover && create) { mHandover = new HandoverEntry(this); }
	return mHandover;
}

// class base initialization goes here.
void TranEntry::TranEntryInit()
{
	mID = gNewTransactionTable.ttNewID();
	mL3TI = cL3TIInvalid;	// Until we know better.
	mDialog = 0;
	mHandover = NULL;
	//mGSMState = CCState::NullState;	moved to TranEntryProtected
	mNumSQLTries = gConfig.getNum("Control.NumSQLTries");	// will be increased later by the SOS constructor.
	mContext = NULL;
	//mChannel = NULL;
	//mNextChannel = NULL;
	mMMData = NULL;
	//initTimers();
}

//#include <execinfo.h>

TranEntry::TranEntry(
	SipDialog *wDialog,
	//const L3MobileIdentity& wSubscriber,
	const L3CMServiceType& wService)
{
	gCountTranEntry++;
	TranEntryInit();
	if (wDialog) setDialog(wDialog);
	//mSubscriber = wSubscriber;
	mService = wService;
	mTerminationRequested.value = 0;	// redundant; it inits itself to 0

	/*****
	if (0) {
	   const int elements = 100;
	   void *buffer[elements];
	   int nptrs = backtrace(buffer, elements);
	   char **strings = backtrace_symbols(buffer, nptrs);
	   if (strings == NULL) { perror("backtrace_symbols"); }
	   else
	   {
	       for (int j = 0; j < nptrs; j++) printf("%s\n", strings[j]);
		   free(strings);
	   }
	}
	***/

	mStartTime = time(NULL);
	mConnectTime = 0;	// Means never connected.
	//mEndTime = 0;
	//gNewTransactionTable.ttAdd(this);
}

// For MO the channel is always known.
TranEntry *TranEntry::newMO(MMContext *wChan, const GSM::L3CMServiceType& wService)
{
	//L3MobileIdentity unknownId;
	//TranEntry *result = new TranEntry(proxy,unknownId,wChannel,wService,CCState::NullState);
	TranEntry *result = new TranEntry(NULL,wService);	// No SipDialog yet for MO transactions.
	LOG(DEBUG);
	wChan->mmConnectTran(result);
	gNewTransactionTable.ttAdd(result);
	return result;
}

void TranEntry::setDialog(SIP::SipDialog *dialog) { mDialog = dialog; dialog->setTranId(mID); }
void TranEntry::txFrame(SIP::AudioFrame* frame, unsigned numFlushed) { getDialog()->txFrame(frame,numFlushed); }
SIP::AudioFrame *TranEntry::rxFrame() { return getDialog()->rxFrame(); }	// Crashes if rtp not established.

unsigned TranEntry::getRTPPort() const
{
	if (SipDialog *dialog = getDialog()) { return dialog->RTPPort(); }
	return 0;
}


TranEntry *TranEntry::newMOSSD(MMContext* wChannel)
{
	return newMO(wChannel,L3CMServiceType::SupplementaryService);
}

TranEntry *TranEntry::newMOC(MMContext* wChannel, CMServiceTypeCode serviceType)
{
	devassert(serviceType == L3CMServiceType::MobileOriginatedCall);
	return newMO(wChannel,serviceType);
}

TranEntry *TranEntry::newMOSMS(MMContext* wChannel)
{
	return newMO(wChannel,L3CMServiceType::ShortMessage);
}

TranEntry *TranEntry::newMOMM(MMContext* wChannel)
{
	return newMO(wChannel,L3CMServiceType::LocationUpdateRequest);
}

// The transaction is created without an assigned channel.
TranEntry *TranEntry::newMTC(
	SipDialog *dialog,
	const FullMobileId& msid,
	const GSM::L3CMServiceType& wService, // MobileTerminatedCall or UndefinedType for generic page from CLI.
	const string wCallerId)
	//const L3CallingPartyBCDNumber& wCalling)
{
	//L3MobileIdentity subscriber(toImsiDigits.c_str());
	//TranEntry *result = new TranEntry(dialog,subscriber, wService);
	TranEntry *result = new TranEntry(dialog, wService);
	result->mSubscriber = msid;
	result->mCalling = GSM::L3CallingPartyBCDNumber(wCallerId.c_str());
	LOG(DEBUG) <<LOGVAR2("callerid",result->mCalling.digits());
	gNewTransactionTable.ttAdd(result);
	return result;
}


// post-l3-rewrite
TranEntry *TranEntry::newMTSMS(
	SipDialog *dialog,
	const FullMobileId& msid,
	const L3CallingPartyBCDNumber& wCalling,
	string smsBody,			// (pat) The recommendation for C++11 is to pass-by-value parameters that will be copied.
	string smsContentType)
{
	//TranEntry *result = new TranEntry(dialog,subscriber,GSM::L3CMServiceType::MobileTerminatedShortMessage);
	TranEntry *result = new TranEntry(dialog,GSM::L3CMServiceType::MobileTerminatedShortMessage);
	result->mSubscriber = msid;
	// The the L3TI is assigned when the transaction starts running.  If ever.
	result->mCalling = wCalling;
	result->mMessage = smsBody;
	result->mContentType = smsContentType;
	gNewTransactionTable.ttAdd(result);
	return result;
}



// Form for inbound handovers.
TranEntry *TranEntry::newHandover(
	const struct sockaddr_in* peer,
	unsigned wInboundHandoverReference,
	SimpleKeyValue &params,
	L3LogicalChannel *wChannel,
	unsigned wHandoverOtherBSTransactionID)
{
	MMContext *mmchan = wChannel->chanGetContext(true);	// This is where we create the MMContext for a handover.
	//TranEntry *result = new TranEntry(proxy,imsi,wChannel,GSM::L3CMServiceType::HandoverCall,CCState::HandoverInbound);
	// We dont want to open the dialog before receiving the handover.
	// The proxy is not used until the dialog is created so it is no longer a parameter.
	TranEntry *result = newMO(mmchan, GSM::L3CMServiceType::HandoverCall);

	result->setGSMState(CCState::HandoverInbound);
	const char* IMSI = params.get("IMSI");
	if (IMSI) result->mSubscriber = FullMobileId(IMSI);

	const char* called = params.get("called");
	if (called) {
		// TODO: Do we need to call setCalled() which will update sql?
		result->mCalled = GSM::L3CalledPartyBCDNumber(called);
		result->mService = GSM::L3CMServiceType::MobileOriginatedCall;
	}

	const char* calling = params.get("calling");
	if (calling) {
		result->mCalling = GSM::L3CallingPartyBCDNumber(calling);
		result->mService = GSM::L3CMServiceType::MobileTerminatedCall;
	}

	const char* L3TI = params.get("L3TI");
	if (L3TI) {
		result->mL3TI = strtol(L3TI,NULL,10);
	} else {
		// TODO: And what should l3ti be otherwise?
		result->mL3TI = 7;		// (pat) Not sure what this should be if not in inbound handover parameters.
	}

	const char* codec = params.get("codec");
	// TODO: Is this an RTP codec number or a CodecSet number?
	// Assuming this information came from a peer OpenBTS unit it is our internal CodecSet number.
	if (codec) result->mCodecs = CodecSet((CodecType)atoi(codec));

	// Set the SIP state.
	//result->mSIP->setSipState(SIP::HandoverInbound);

	//const char * callId = params.get("CallID");
	//result->mSIP->setCallId(callId);


	// This is used for inbound handovers.
	// We are "BS2" in the handover ladder diagram.
	// The message string was formed by the handoverString method.
	result->getHandoverEntry(true)->initHandoverEntry(peer,wInboundHandoverReference,wHandoverOtherBSTransactionID,params);

	return result;
}

void HandoverEntry::initHandoverEntry(
	const struct sockaddr_in* peer,
	unsigned wInboundHandoverReference,
	unsigned wHandoverOtherBSTransactionID,
	SimpleKeyValue &params)
{
	// FIXME: This is also in the params.  Which do we want to use?  (pat) This one.
	mInboundReference = wInboundHandoverReference;
	mHandoverOtherBSTransactionID = wHandoverOtherBSTransactionID;

	// Save the peer address.
	memcpy(&mInboundPeer,peer,sizeof(mInboundPeer));

	const char* refer = params.get("REFER");
	if (refer) {
		// We changed spaces to tabs to get the REFER message through the peering interface.
		// Since we are sending it through the SIP parser, it does not matter very much,
		// however the tabs are preserved in a few places, especially the SDP strings,
		// so change all the tabs back to spaces to be safe.
		const char *inp; char *outp, *outbuf = (char*)alloca(strlen(refer)+1);
		for (inp = refer, outp = outbuf; *inp; inp++, outp++) {
			*outp = (*inp == '\t') ? ' ' : *inp;
		}
		*outp = 0;
		mSipReferStr = string(outbuf);
	}
}


TranEntry::~TranEntry()
{
	gCountTranEntry--;
	// This lock should go out of scope before the object is actually destroyed.
	//ScopedLock lock(mLock,__FILE__,__LINE__);

	// This is the l3-rewrite stack of procedures running for this transaction.
	while (mProcStack.size()) {
		MachineBase *pb = mProcStack.back();
		mProcStack.pop_back();
		delete pb;
	}

	// Remove any FIFO from the gPeerInterface.
	gPeerInterface.removeFIFO(tranID());

	if (mMMData) { delete mMMData; }
	if (mHandover) { delete mHandover; }

#if EXTERNAL_TRANSACTION_TABLE
	// Delete the SQL table entry.  (pat) There wont be any for LocationUpdating procedure, or transactions that did not run until they got an IMSI.
	char query[100];
	sprintf(query,"DELETE FROM TRANSACTION_TABLE WHERE ID=%u",tranID());
	runQuery(query);
#endif
}


bool TranEntryProtected::clearingGSM() const
{
	//ScopedLock lock(mLock,__FILE__,__LINE__);
	return (mGSMState==CCState::ReleaseRequest) || (mGSMState==CCState::DisconnectIndication);
}


bool TranEntryProtected::isStuckOrRemoved() const
{
	unsigned age = mStateTimer.elapsed();

	// 180-second tests
	if (age < 180*1000) return false;
	// Dead if someone requested removal >3 min ago.
	// (pat) Post-l3-rewrite we dont need to wait to delete TranEntrys,
	// because nothing points back to them permanently, only currently running functions, for example,
	// Peering gets a TranEntry pointer and immediately modifies it.  One second would be over-kill.
	// But having TranEntrys stick around a while  may still be useful for debugging to see them in the CLI,
	// so I did not change this.
	// Any GSM state other than Active for >3 min?
	if (getGSMState() !=CCState::Active) { return true; }
	// Any SIP stte other than active for >3 min?
	//if (lSIPState !=SIP::Active) return true;
	return false;
}

bool TranEntry::deadOrRemoved() const
{
	//ScopedLock lock(mLock,__FILE__,__LINE__);
	if (isStuckOrRemoved()) {
		LOG(NOTICE)<<"Transaction in state "<<getGSMState() <<" for >3 minutes; "<<*this;
		return true;
	}
	SipDialog *dialog = getDialog();
	if (dialog && dialog->sipIsStuck()) return true;
	return false;	// still going
}

//SIP::SipState TranEntry::getSipState() const
//{
//	if (mDialog) { return mDialog->getSipState(); }					// post-l3-rewrite
//	return SIP::NullState;
//}


#if UNUSED
bool TranEntry::teDead() const
{
	// Get the state information and release the locks.

	// If it's locked, we assume someone has locked it,
	// so it's not dead.
	// And if someone locked in permanently,
	// the resulting deadlock would spread through the whole system.

	//if (!mLock.trylock()) return false;
	if (mDialog && mDialog->sipIsStuck()) return true;
	//mLock.unlock();

#if 0
	// (pat) You cannot check the sip state here based on the transaction state-age because the state
	// age is not updated for sip-side state changes.
	// 30-second tests
	if (age < 30*1000) return false;
	// Failed?
	if (lSIPState==SIP::Fail) return true;
	// Bad handover?
	if (lSIPState==SIP::HandoverInbound) return true;
	// SIP Null state?
	if (lSIPState==SIP::NullState) return true;
	// SIP stuck in proceeding?
	if (lSIPState==SIP::Proceeding) return true;
	// SIP cancelled?
	if (lSIPState==SIP::Canceled) return true;
	// SIP Cleared?
	if (lSIPState==SIP::Cleared) return true;
#endif
	
	// If we got here, the state-vs-timer relationship
	// appears to be valid.
	return false;
}
#endif


void TranEntryProtected::stateText(ostream &os) const
{
	os << " GSMState=" << mGSMState;	// Dont call getGSMState(), it asserts 0 if the transaction has been removed;
	if (isStuckOrRemoved()) os << " [defunct]";
}


void TranEntry::text(ostream& os) const
{
	//ScopedLock lock(mLock,__FILE__,__LINE__);
	os << " TranEntry(";
	os <<LOGVAR2("tid",tranID());
	stateText(os);
	if (! isStuckOrRemoved()) {
		// Nothing else I am willing to risk saying about a removed transaction, for fear of trigging an exception.
		if (channel()) os << " chan=(" << *channel() <<")";
		else os << " chan=none";
		os <<LOGVARP2("Subscriber",mSubscriber);
		os <<LOGVARM(mL3TI);
		//if (mSIP) {
		//	os << " SIP-call-id=" << mSIP->callId();
		//	os << " SIP-proxy=" << mSIP->proxyIP() << ":" << mSIP->proxyPort();
		//	os << " SIPState=" << mSIP->sipState();
		//}
		os << LOGVARM(mService);
		if (mCalled.digits()[0]) os << " to=" << mCalled.digits();
		if (mCalling.digits()[0]) os << " from=" << mCalling.digits();
		os << " stateAge=(" << (stateAge()+500)/1000 << " sec)";
		if (currentProcedure()) {
			os << " stack=(";
			for (list<MachineBase*>::const_iterator it = mProcStack.begin(); it != mProcStack.end(); it++) {
				(*it)->machText(os);
			}
			os << ")";
		}
		L3TimerList::text(os);
		if (mMessage.size()) os << " message=\"" << mMessage << "\"";
	}
	os << ")";
}

string TranEntry::text() const
{
	ostringstream os;
	text(os);
	return os.str();
}

ostream& operator<<(ostream& os, const TranEntry& entry)
{
	entry.text(os);
	return os;
}

ostream& operator<<(ostream& os, const TranEntry* entry)
{
	if (entry == NULL) { os << "(null TranEntry)"; return os; }
	entry->text(os);
	return os;
}


#if EXTERNAL_TRANSACTION_TABLE
void TranEntry::runQuery(const char* query) const
{
	// Caller should hold mLock and should have already checked isRemoved()..
	for (unsigned i=0; i<mNumSQLTries; i++) {
		if (sqlite3_command(gNewTransactionTable.getDB(),query)) return;
	}
	LOG(ALERT) << "transaction table access failed after " << mNumSQLTries << "attempts. query:" << query << " error: " << sqlite3_errmsg(gNewTransactionTable.getDB());
}
#endif



// (pat) David says: No more external reporting tables.
//void TranEntry::insertIntoDatabase()
//{
//	if (mDialog == NULL) { return; }	// TODO: We might want to see the LUR transactions, which also do not have an mSIP.
//
//	// This should be called only from gNewTransactionTable::add.
//	// Caller should hold mLock.
//
//	ostringstream serviceTypeSS;
//	serviceTypeSS << mService;
//
//	ostringstream sipStateSS;
//	mPrevSipState = mDialog->getSipState();
//	sipStateSS << mPrevSipState;
//
//	string subscriber = mSubscriber.fmidUsername();
//
//	const char* stateString = CCState::callStateString(getGSMState());
//	assert(stateString);
//
//	// FIXME -- This should be done in a single SQL transaction.
//
//	char query[500];
//	unsigned now = (unsigned)time(NULL);
//	sprintf(query,"INSERT INTO TRANSACTION_TABLE "
//		        "(ID,CREATED,CHANGED,TYPE,SUBSCRIBER,L3TI,CALLED,CALLING,GSMSTATE,SIPSTATE,SIP_CALLID,SIP_PROXY) "
//		"VALUES  (%u,%u,     %u,     '%s','%s',      %u,'%s',  '%s',   '%s',    '%s',      '%s',      '%s')",
//		tranID(),now,now,
//		serviceTypeSS.str().c_str(),
//		subscriber.c_str(),
//		mL3TI,
//		mCalled.digits(),
//		mCalling.digits(),
//		stateString,
//		sipStateSS.str().c_str(),
//		mDialog->callId().c_str(),
//		mDialog->proxyIP().c_str()
//	);
//
//	runQuery(query);
//
//	if (!channel()) return;
//	sprintf(query,"UPDATE TRANSACTION_TABLE SET CHANNEL='%s' WHERE ID=%u",
//			channel()->descriptiveString(), tranID());
//	runQuery(query);
//}



#if UNUSED
void TranEntry::setChannel(L3LogicalChannel* wChannel)
{
	//ScopedLock lock(mLock,__FILE__,__LINE__);
	mChannel = wChannel;

	char query[500];
	if (mChannel) {
		sprintf(query,"UPDATE TRANSACTION_TABLE SET CHANGED=%u,CHANNEL='%s' WHERE ID=%u",
				(unsigned)time(NULL), mChannel->descriptiveString(), tranID());
	} else {
		sprintf(query,"UPDATE TRANSACTION_TABLE SET CHANGED=%u,CHANNEL=NULL WHERE ID=%u",
				(unsigned)time(NULL), tranID());
	}

	runQuery(query);
}
#endif


void TranEntry::setSubscriberImsi(string imsi, bool andAttach)
{
	mSubscriber.mImsi = imsi;
	// Now that we have an imsi we can hook up the MMUser.
	if (andAttach) {
		gMMLayer.mmAttachByImsi(channel(),imsi);
	}
}

L3LogicalChannel* TranEntry::channel()
{
	MMContext *ts = teGetContext();
	return ts ? ts->tsChannel() : NULL;
}

const L3LogicalChannel* TranEntry::channel() const
{
	MMContext *ts = Unconst(this)->teGetContext();	// gotta love it.
	return ts ? ts->tsChannel() : NULL;
}

//bool TranEntry::isChannelMatch(const L3LogicalChannel *lch)
//{
//	// The void* compares pointers even if someone defines operator== on L3LogicalChannel.
//	return ((void*)this->channel() == (void*)lch || (void*)this->getL2Channel()->SACCH() == (void*)lch ||
//			(this->mNextChannel && ((void*)this->mNextChannel == (void*)lch || (void*)this->mNextChannel->getL2Channel()->SACCH() == (void*)lch)));
//}

L2LogicalChannel* TranEntry::getL2Channel() const
{
	L3LogicalChannel *chan = Unconst(channel());	// what a pathetic language
	return chan ? dynamic_cast<L2LogicalChannel*>(chan) : NULL;
}


// This is used after the channel() is changed from SDCCH to to TCHFACCH just to be safe.
L3LogicalChannel* TranEntry::getTCHFACCH() {
	devassert(channel()->chtype()==FACCHType);	// This is the type returned by the TCHFACCHLogicalChannel, even though it is TCH too.
	return channel();
}



unsigned TranEntry::getL3TI() const
{
	return mL3TI;
}

CallState TranEntryProtected::getGSMState() const
{
	//ScopedLock lock(mLock,__FILE__,__LINE__);		// redundant
	return mGSMState;
}


void TranEntryProtected::setGSMState(CallState wState)
{
	if (mGSMState == CCState::TranDeleted) {
		// Shouldnt happen but be sure: never change state from deleted to anything else.
		return;
	}
	//ScopedLock lock(mLock,__FILE__,__LINE__);
	mStateTimer.now();

	mGSMState = wState;
#if UNUSED	// We are removing the transaction table, so I'm just taking this out.
	const char* stateString = CCState::callStateString(wState);
	assert(stateString);

	unsigned now = mStateTimer.sec();
	char query[150];
	sprintf(query,
		"UPDATE TRANSACTION_TABLE SET GSMSTATE='%s',CHANGED=%u WHERE ID=%u",
		stateString,now, tranID());
	runQuery(query);
#endif
}

SIP::SipState TranEntry::echoSipState(SIP::SipState state) const
{
	// Caller should hold mLock.
	if (mPrevSipState==state) return state;
	mPrevSipState = state;

	const char* stateString = SIP::SipStateString(state);
	devassert(stateString);

#if EXTERNAL_TRANSACTION_TABLE
	unsigned now = time(NULL);
	char query[150];
	sprintf(query,
		"UPDATE TRANSACTION_TABLE SET SIPSTATE='%s',CHANGED=%u WHERE ID=%u",
		stateString,now,tranID());
	runQuery(query);
#endif

	return state;
}



void TranEntry::setCalled(const L3CalledPartyBCDNumber& wCalled)
{
	//ScopedLock lock(mLock,__FILE__,__LINE__);
	mCalled = wCalled;

#if EXTERNAL_TRANSACTION_TABLE
	char query[151];
	snprintf(query,150,
		"UPDATE TRANSACTION_TABLE SET CALLED='%s' WHERE ID=%u",
		mCalled.digits(), tranID());
	runQuery(query);
#endif
}


// Does this ti reported by the MS match this transaction?
bool TranEntry::matchL3TI(unsigned ti, bool fromMS)
{
	// Old incorrect way:
	//return l3TISigBits(mL3TI) == l3TISigBits(ti);
	if (fromMS) {
		// If the ti argument came from the MS flip the TI flag.
		if (ti & 0x8) { ti &= ~0x8; } else { ti |= 0x8; }
	}
	return mL3TI == ti;
}


void TranEntry::setL3TI(unsigned wL3TI)
{
	//ScopedLock lock(mLock,__FILE__,__LINE__);
	mL3TI = wL3TI;

#if EXTERNAL_TRANSACTION_TABLE
	char query[151];
	snprintf(query,150,
		"UPDATE TRANSACTION_TABLE SET L3TI=%u WHERE ID=%u",
		mL3TI, tranID());
	runQuery(query);
#endif
}


L3Cause::AnyCause TranEntry::terminationRequested()
{
	ScopedLock lock(mAnotherLock,__FILE__,__LINE__);
	L3Cause::AnyCause retVal = mTerminationRequested;
	mTerminationRequested.value = 0;
	return retVal;
}


// The handover is from BS1 to BS2.
// This is run in BS1 to create the handover string to send to BS2.
// The string must contain everything about the SIP side of the session.
// Everything needed to be known about the radio side of the session was transferred as an L3 HandoverCommand.
string TranEntry::handoverString(string peer,string cause) const
{
	// This string is a set of key-value pairs.
	// It needs to carry all of the information of the GSM Abis Handover Request message,
	// as well as all of the information of the SIP REFER message.
	// We call this as "BS1" in the handover ladder diagram.
	// It is decoded at the other end by a TransactionEnty constructor.

	//ScopedLock lock(mLock,__FILE__,__LINE__);
	ostringstream os;
	os << tranID();
	os << " IMSI=" << mSubscriber.mImsi;
	// We dont need these.
	//HandoverEntry *handover = getHandoverEntry(true);
	//if (getGSMState()==CCState::HandoverInbound) os << " inbound-ref=" << handover->mInboundReference;
	//if (getGSMState()==CCState::Handover_Outbound) os << " outbound-ref=" << handover->mOutboundReference.value();
	os << " L3TI=" << mL3TI;
	if (mCalled.digits()[0]) os << " called=" << mCalled.digits();
	if (mCalling.digits()[0]) os << " calling=" << mCalling.digits();
	if (cause.size()) os << " cause=" << cause;

	const SipBase *sip = Unconst(this)->getDialog();
	os << " REFER=" << sip->dsHandoverMessage(peer);

	// remote ip and port  (pat) This is where we send the re-INVITE, but subsequent messages
	// are sent to our proxy IP.  This is wrong, but our SIP response routing for other messages is wrong too.
	// RFC3261 section 4 page 16 describes routing as follows:
	// 1. The INVITE is necessarily sent via proxies, which add their own "via" headers.
	// 2.  The reply to the INVITE must include the "via" headers so it can get back.
	// 3. Subsequently, if there is a Contact field, all messages bypass the proxies and are sent directly to the Contact.
	// 4. But the proxies might want to see the messages too, so they can add a "required-route" parameter which trumps
	// the "contact" header and specifies that messages are sent there instead.  This is called "Loose Routing."  What a mess.
	// And I quote: "These procedures separate the destination of the request (present in the Request-URI) from
	//			the set of proxies that need to be visited along the way (present in the Route header field)."
	// In contrast, A Strict Router "follows the Route processing rules of RFC 2543 and many prior work in
	//			progress versions of this RFC. That rule caused proxies to destroy the contents of the Request-URI
	//			when a Route header field was present."
	// 8.1.1.1: Normally the request-URI is equal to the To: field.  But if there is a configured proxy (our case)
	// this is called a "pre-existing route set" and we must follow 12.2.1.1 using the request-URI as the
	// remote target URI(???)
	// 12.2: The route-set is immutably defined by the initial INVITE.  You can change the remote-URI in a re-INVITE
	// (aka target-refresh-request) but not the route-set.
	// Remote-URI: Intial request remote-URI must == To: field.


	// Functional but unused.  See comments in SIP::inboundHandoverSendINVITE()
	//os << " RTPState=" <<
	//	sip->RTPSession()->rtp.snd_time_offset << "," <<
	//	sip->RTPSession()->rtp.snd_ts_offset << "," <<
	//	sip->RTPSession()->rtp.snd_rand_offset << "," <<
	//	sip->RTPSession()->rtp.snd_last_ts << "," <<
	//	sip->RTPSession()->rtp.rcv_time_offset << "," <<
	//	sip->RTPSession()->rtp.rcv_ts_offset << "," <<
	//	sip->RTPSession()->rtp.rcv_query_ts_offset << "," <<
	//	sip->RTPSession()->rtp.rcv_last_ts << "," <<
	//	sip->RTPSession()->rtp.rcv_last_app_ts << "," <<
	//	sip->RTPSession()->rtp.rcv_last_ret_ts << "," <<
	//	sip->RTPSession()->rtp.hwrcv_extseq << "," <<
	//	sip->RTPSession()->rtp.hwrcv_seq_at_last_SR << "," <<
	//	sip->RTPSession()->rtp.hwrcv_since_last_SR << "," <<
	//	sip->RTPSession()->rtp.last_rcv_SR_ts << "," <<
	//	sip->RTPSession()->rtp.last_rcv_SR_time.tv_sec << "," << sip->RTPSession()->rtp.last_rcv_SR_time.tv_usec << "," << 
	//	sip->RTPSession()->rtp.snd_seq << "," <<
	//	sip->RTPSession()->rtp.last_rtcp_report_snt_r << "," <<
	//	sip->RTPSession()->rtp.last_rtcp_report_snt_s << "," <<
	//	sip->RTPSession()->rtp.rtcp_report_snt_interval << "," <<
	//	sip->RTPSession()->rtp.last_rtcp_packet_count << "," <<
	//	sip->RTPSession()->rtp.sent_payload_bytes;

	return os.str();
}

void NewTransactionTable::ttInit()
{
	//if (! l3rewrite()) return;		// Only one of TransactionTable::init or NewTransactionTable::ttInit
	LOG(DEBUG);
	// This assumes the main application uses sdevrandom.
	//mIDCounter = random();
	mIDCounter = 100;	// pat changed.  0 is reserved.  Start it high enough so it cannot possibly be confused with an L3TI.

#if EXTERNAL_TRANSACTION_TABLE
	// Connect to the database.
	const char *path = gConfig.getStr("Control.Reporting.TransactionTable").c_str();
	int rc = sqlite3_open(path,&mDB);
	if (rc) {
		LOG(ALERT) << "Cannot open Transaction Table database at " << path << ": " << sqlite3_errmsg(mDB);
		sqlite3_close(mDB);
		mDB = NULL;
		return;
	}
	// Create a new table, if needed.
	if (!sqlite3_command(mDB,createNewTransactionTable)) {
		LOG(ALERT) << "Cannot create Transaction Table";
	}
	// Clear any previous entires.
	if (!sqlite3_command(gNewTransactionTable.getDB(),"DELETE FROM TRANSACTION_TABLE"))
		LOG(WARNING) << "cannot clear previous transaction table";
#endif
}



#if EXTERNAL_TRANSACTION_TABLE
NewTransactionTable::~NewTransactionTable()
{
	// Don't bother disposing of the memory,
	// since this is only invoked when the application exits.
	if (mDB) sqlite3_close(mDB);
}
#endif




unsigned NewTransactionTable::ttNewID()
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	return mIDCounter++;
}


void NewTransactionTable::ttAdd(TranEntry* value)
{
	LOG(DEBUG);
	LOG(INFO) << "new transaction " << *value;
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	//clearDeadEntries();		// This the only call to clearDeadEntries that really matters.
	mTable[value->tranID()]=value;
}


bool TranEntry::teIsTalking()
{
	LOG(DEBUG) << LOGVAR2("GSMState",this->getGSMState());
	if (this->getGSMState() == CCState::Active) {
		//WATCHINFO(LOGVAR2("GSMState",this->getGSMState()) <<LOGVAR2("meas",this->channel()->getL2Channel()->getSACCH()->measurementResults()));
		if (L3LogicalChannel *l3chan = this->channel()) {
			L2LogicalChannel *l2chan = l3chan->getL2Channel();
			GSM::L3MeasurementResults meas = l2chan->getSACCH()->measurementResults();
			if (meas.isServingCellValid()) { return true; }
		}
	}
	return false;
}

bool NewTransactionTable::ttIsTalking(TranEntryId tranid)
{
	bool result = false;
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	if (TranEntry *tran = ttFindById(tranid)) { result = tran->teIsTalking(); }
	return result;
}

TranEntry* NewTransactionTable::ttFindById(TranEntryId key)
{
	// Since this is a log-time operation, we don't screw that up by calling clearDeadEntries.

	// ID==0 is a non-valid special case.
	LOG(DEBUG) << "by key: " << key;
	devassert(key);
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	NewTransactionMap::iterator itr = mTable.find(key);
	if (itr==mTable.end()) return NULL;
	if (itr->second->deadOrRemoved()) return NULL;
	return (itr->second);
}

// In l3-rewrite this is called ONLY from teRemove.
bool NewTransactionTable::ttRemove(TranEntryId key)
{
	LOG(DEBUG) <<LOGVAR(key);
	// ID==0 is a non-valid special case, and it shouldn't be passed here.
	if (key==0) {
		LOG(ERR) << "called with key==0";
		return false;
	}

	ScopedLock lock(mttLock,__FILE__,__LINE__);
	NewTransactionMap::iterator itr = mTable.find(key);
	if (itr==mTable.end()) return false;
	mTable.erase(itr);
	return true;
}

// Return true if we found it, or false if not found.
// This is called from a separate thread, so we set the flag and wait for the service loop to handle it.
bool NewTransactionTable::ttTerminate(TranEntryId tid, L3Cause::BSSCause cause)
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	NewTransactionMap::iterator itr = mTable.find(tid);
	if (itr==mTable.end()) { return false; }
	TranEntry *tran = itr->second;
	ScopedLock lock2(tran->mAnotherLock,__FILE__,__LINE__);
	tran->mTerminationRequested = cause;
	return true;
}

// Does the TranEntry referenced by this id still pointer to its SipDialog?
// We use the TranEntryId so we can delete the TranEntry completely separately from the SipDialog.
// However, the TranEntry has a pointer to the SipDialog, so we dont delete that until its gone.
bool NewTransactionTable::ttIsDialogReleased(TranEntryId tid)
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	NewTransactionMap::iterator itr = mTable.find(tid);
	if (itr==mTable.end()) { return true; }	// TranEntry no longer exists.
	return itr->second->mDialog == 0;
}

bool NewTransactionTable::ttSetDialog(TranEntryId tid, SipDialog *dialog)
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	NewTransactionMap::iterator itr = mTable.find(tid);
	if (itr==mTable.end()) { return false; }	// TranEntry no longer exists.
	itr->second->setDialog(dialog);
	return true;
}



#if UNUSED
TranEntry* NewTransactionTable::ttFindByTypeAndOffset(GSM::TypeAndOffset desc)
{
	LOG(DEBUG) << "by type and offset: " << desc;

	ScopedLock lock(mttLock,__FILE__,__LINE__);

	// Yes, it's linear time.
	// Since clearDeadEntries is also linear, do that here, too.
	clearDeadEntries();

	// Brute force search.
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if (itr->second->deadOrRemoved()) continue;
		const L3LogicalChannel* thisChan = itr->second->channel();
		if (thisChan->typeAndOffset()!=desc) continue;
		return itr->second;
	}
	//LOG(DEBUG) << "no match for " << *chan << " (" << chan << ")";
	return NULL;
}
#endif


#if UNUSED
TranEntry* NewTransactionTable::ttFindByMobileIDState(const L3MobileIdentity& mobileID, CallState state)
{
	LOG(DEBUG) << "by ID and state: " << mobileID << " in " << state;

	ScopedLock lock(mttLock,__FILE__,__LINE__);

	// Yes, it's linear time.
	// Since clearDeadEntries is also linear, do that here, too.
	clearDeadEntries();

	// Brute force search.
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if (itr->second->deadOrRemoved()) continue;
		if (itr->second->getGSMState() != state) continue;
		if (itr->second->subscriber() != mobileID) continue;
		return itr->second;
	}
	return NULL;
}
#endif

#if UNUSED
bool NewTransactionTable::isBusy(const L3MobileIdentity& mobileID)
{
	LOG(DEBUG) << "id: " << mobileID << "?";

	ScopedLock lock(mttLock,__FILE__,__LINE__);

	// Yes, it's linear time.
	// Since clearDeadEntries is also linear, do that here, too.
	clearDeadEntries();

	// Brute force search.
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if (itr->second->deadOrRemoved()) continue;
		if (itr->second->subscriber() != mobileID) continue;
		GSM::L3CMServiceType::TypeCode service = itr->second->servicetype();
		bool speech =
			service==GSM::L3CMServiceType::EmergencyCall ||
			service==GSM::L3CMServiceType::MobileOriginatedCall ||
			service==GSM::L3CMServiceType::MobileTerminatedCall;
		if (!speech) continue;
		// OK, so we found a transaction for this call.
		bool inCall = CCState::isInCall(itr->second->getGSMState());
		if (inCall) return true;
	}
	return false;
}
#endif

#if UNUSED
// Find the TranEntry that wants to receive this l3msg, if any.
// Look at the PD and the TI.
// TODO: Fix this.  When we start a MOC there is no TI yet so the Setup message TI will not match the TranEntry.
//		If no TranEntry matches the TI, we should call, um, we cant just call the default TranEntry
//		because the message may be for an old dead TranEntry.  Maybe should just special-case Setup.
//		Maybe the TranEntry should expectCC(Setup).
// 		Another way to fix might be to add a default TranEntry for each L3PD, but again that would get dead TIs.
//		What we really want is a separate MM manager to route the messages.
TranEntry *NewTransactionTable::ttFindByL3Msg(GSM::L3Message *l3msg, L3LogicalChannel *lch)
{
	GSM::L3PD pd = l3msg->PD();
	ScopedLock lock(gNewTransactionTable.mttLock,__FILE__,__LINE__);
	for (NewTransactionMap::iterator itr = gNewTransactionTable.mTable.begin(); itr!=gNewTransactionTable.mTable.end(); ++itr) {
		TranEntry *tran = itr->second;
		if (tran->deadOrRemoved()) continue;
		if (! tran->isChannelMatch(lch)) continue;
		GSM::L3CMServiceType service = tran->service();
		switch (pd) {
			case L3CallControlPD:
				return tran;	// Only one for now.
				//if (service.isCC() && tran->getL3TI() == dynamic_cast<L3CCMessage*>(l3msg)->TI()) { return tran; }
				continue;
			case L3SMSPD:
				return tran;	// Only one for now.
				//if (service.isSMS() && tran->getL3TI() == dynamic_cast<L3CPMessage*>(l3msg)->TI()) { return tran; }
				continue;
			case L3MobilityManagementPD:
			case L3RadioResourcePD:
				// We dont yet have a separate MobilityManagement layer, so MM and RR messages are handled by the primary TranEntry,
				// which is either the LocationUpdateRequest or the in-progress CC TranEntry, which needs RR messages
				// to modify the channel for the voice call.
				if (service.isMM()) { return tran; }
				if (service.isSMS()) continue;
				// For now, just assume there is only one transaction, so this must be it.
				return tran;
			default:
				LOG(ERR) << "unrecognized L3"<<LOGVAR(pd);
				return NULL;	// hopeless.
		}
	}
	return NULL;
}
#endif


// (pat added) Add a message to the TranEntry inbox.
void NewTransactionTable::ttAddMessage(TranEntryId tranid,SIP::DialogMessage *dmsg)
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	TranEntry* tran = ttFindById(tranid);
	if (tran) {
		tran->mTranInbox.write(dmsg);
	} else {
		// This is ok - the SIP dialog and L3 transaction side are completely decoupled so it is quite
		// possible that the transaction was deleted (for example, MS signal failure) while
		// a SIP dialog is still running.
		LOG(DEBUG) << "info: SIP Dialog message to non-existent"<<LOGVAR(tranid);
		delete dmsg;
	}
}

CallState NewTransactionTable::ttGetGSMStateById(TranEntryId tranid)
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	TranEntry *tran = ttFindById(tranid);
	CallState result = tran ? tran->getGSMState() : CCState::NullState;
	return result;
}

// This is an external interface so we dont have to include L3TranEntry.h just to access this function.
void NewTransactionTable_ttAddMessage(TranEntryId tranid,SIP::DialogMessage *dmsg)
{
	gNewTransactionTable.ttAddMessage(tranid,dmsg);
}


TranEntry* NewTransactionTable::ttFindHandoverOther(const L3MobileIdentity& mobileID, unsigned otherBS1TranId)
{
	LOG(DEBUG) <<LOGVAR2("ID",mobileID) <<LOGVAR(otherBS1TranId);

	// Yes, it's linear time.
	// Since clearDeadEntries is also linear, do that here, too.
	//clearDeadEntries();

	// Brute force search.
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		TranEntry *tran = itr->second;
		LOG(DEBUG) << "comparing "<<tran<<LOGVAR2("HandoverOtherBSTransactionID",(tran->mHandover?tran->mHandover->mHandoverOtherBSTransactionID:-1));
		if (tran->deadOrRemoved()) continue;
		if (!tran->mHandover) {
			LOG(DEBUG) "no match, no handover"<<tran;
			continue;
		}
		if (tran->mHandover->mHandoverOtherBSTransactionID != otherBS1TranId) {
			LOG(DEBUG) "no match "<<tran->mHandover->mHandoverOtherBSTransactionID<<"!="<<otherBS1TranId;
			continue;
		}
		if (! mobileID.fmidMatch(&tran->subscriber())) {
			LOG(DEBUG) "no match"<<LOGVAR(tran->subscriber()) <<LOGVAR(mobileID);
			continue;
		}
		return tran;
	}
	return NULL;
}



#if UNUSED
// Currently unused
L3LogicalChannel* NewTransactionTable::findChannel(const L3MobileIdentity& mobileID)
{
	// Yes, it's linear time.
	// Even in a 6-ARFCN system, it should rarely be more than a dozen entries.

	ScopedLock lock(mttLock,__FILE__,__LINE__);

	// Since clearDeadEntries is also linear, do that here, too.
	clearDeadEntries();

	// Brute force search.
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if (itr->second->deadOrRemoved()) continue;
		if (! itr->second->subscriber().fmidMatch(mobileID)) continue;
		L3LogicalChannel* chan = itr->second->channel();
		if (!chan) continue;
		if (chan->chtype() == FACCHType) return chan;
		if (chan->chtype() == SDCCHType) return chan;
		// (pat) What other channel type could there be?  The SACCH are not returned by channel().
		assert(0);		// Alert pat if you get this assertion.
	}
	return NULL;
}
#endif


#if UNUSED
unsigned NewTransactionTable::countChan(const L3LogicalChannel* chan)
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	clearDeadEntries();
	unsigned count = 0;
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if (itr->second->deadOrRemoved()) continue;
		if (itr->second->channel() == chan) count++;
	}
	return count;
}
#endif



size_t NewTransactionTable::dump(ostream& os, bool showAll) const
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	size_t sz = 0;
	for (NewTransactionMap::const_iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if ((!showAll) && itr->second->deadOrRemoved()) continue;
		sz++;
		os << *(itr->second) << endl;
	}
	return sz;
}


TranEntryId NewTransactionTable::findLongestCall()
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	//clearDeadEntries();
	long longTime = 0;
	NewTransactionMap::iterator longCall = mTable.end();
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if (itr->second->deadOrRemoved()) continue;
		if (!(itr->second->channel())) continue;
		if (itr->second->getGSMState() != CCState::Active) continue;
		long runTime = itr->second->stateAge();
		if (runTime > longTime) {
			runTime = longTime;
			longCall = itr;
		}
	}
	if (longCall == mTable.end()) return 0;
	return longCall->second->tranID();
}

/**
	Return an even UDP port number for the RTP even/odd pair.
*/
unsigned allocateRTPPorts()
{
	const unsigned base = gConfig.getNum("RTP.Start");
	const unsigned range = gConfig.getNum("RTP.Range");
	const unsigned top = base+range;
	static Mutex lock;
	// Pick a random starting point.  (pat) Why?  Because there is a bug and we are trying to avoid it?
	static unsigned port = base + 2*(random()%(range/2));
	unsigned retVal;
	lock.lock();
	//This is a little hacky as RTPAvail is O(n)
	do {
		retVal = port;
		port += 2;
		if (port>=top) port=base;
	} while (!gNewTransactionTable.RTPAvailable(retVal));
	lock.unlock();
	return retVal;
}

/* linear, we should move the actual search into this structure */
// (pat) Speed entirely irrelevant; this is done once per call.
bool NewTransactionTable::RTPAvailable(unsigned rtpPort)
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	//clearDeadEntries();
	bool avail = true;
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if (itr->second->deadOrRemoved()) continue;
		if (itr->second->getRTPPort() == rtpPort){
			avail = false;
			break;
		}
	}
	return avail;
}




#if 0
bool NewTransactionTable::outboundReferenceUsed(unsigned ref)
{
	// Called is expected to hold mttLock.
	for (NewTransactionMap::iterator itr = mTable.begin(); itr!=mTable.end(); ++itr) {
		if (itr->second->deadOrRemoved()) continue;
		if (itr->second->getGSMState() != GSM::Handover_Outbound) continue;
		if (itr->second->handoverReference() == ref) return true;
	}
	return false;
}

unsigned NewTransactionTable::generateHandoverReference(TranEntry *transaction)
{
	ScopedLock lock(mttLock,__FILE__,__LINE__);
	clearDeadEntries();
	unsigned ref = random() % 256;
	while (outboundReferenceUsed(ref)) { ref = (ref+1) % 256; }
	transaction->handoverReference(ref);
	return ref;
}
#endif

MachineBase *TranEntry::tePopMachine()
{
	if (mProcStack.size() == 0) { return NULL; }
	MachineBase *top = mProcStack.back();
	mProcStack.pop_back();
	return top;
}

void TranEntry::tePushProcedure(MachineBase *it)
{
	mProcStack.push_back(it);
}


// Replace the current procedure with that specified.
// We dont delete the current procedure when switching between sub-procedures of an over-all procedure, for example,
// when switching from LUIdentication to LUAuthentication with L3ProcedureLocationUpdate.
// Update: the above case does not exist any more.
void TranEntry::teSetProcedure(MachineBase *wProc, bool wDeleteCurrent)
{
	if (currentProcedure() == wProc) { return; }
	MachineBase *old = tePopMachine();
	wDeleteCurrent = true;	// 9-24-2013: We always delete except when pusing into a procedure and that is handled by tePushProcedure.
	if (wDeleteCurrent && old) { delete old; }
	tePushProcedure(wProc);
}

// Note: handleRecursion returns a MachineStatus and is meant to be used when within a state machine.
// handleMachineStatus returns a bool and is the final status-handler called when all state machines have processed the current state to completion.
MachineStatus TranEntry::handleRecursion(MachineStatus status)
{
	while (status == MachineStatusPopMachine) {	// return to previous procedure on stack
		// Special case: we do not return, we immediately invoke the popped-to method.
		delete tran()->tePopMachine();
		LOG(DEBUG) "popped to "<<currentProcedure()->debugName()<<" at state "<<currentProcedure()->mPopState;
		status = currentProcedure()->machineRunState(currentProcedure()->mPopState);
	}
	return status;
}

// Return TRUE if the status indicates the message or whatever had a message handler, regardless of the success/fail result.
bool TranEntry::handleMachineStatus(MachineStatus status)
{
	//MMContext *set = teGetContext();
	OBJLOG(DEBUG) <<LOGVAR(status.msCode);
	status = handleRecursion(status);	// Harmless overkill if called again.

	switch (status.msCode) {
	case MachineStatus::MachineCodePopMachine:	// aka MachineStatusPopMachine
		devassert(0);	// We just checked this case above.
	case MachineStatus::MachineCodeOK:
		// continue the procedure, meaning return to L3 message handler and wait for the next message.
		return true;
	case MachineStatus::MachineCodeQuitChannel:	// aka MachineStatusQuitChannel
		// Drop the channel.
		// Normally the user called closeChannel which does the actual work, but we will make sure:
		// Just in case we get here without closeChannel having been 
		// (pat) Update: Now the cause is passed to us in the transaction result MachineStatus.
		// If the caller already called chanRelease then channel will already be null.
		if (channel() && ! channel()->isReleased()) {
			// If the caller did not already call this, we dont know what the heck happened, so do a RELEASE instead of HARDRELEASE.
			channel()->chanRelease(L3_RELEASE_REQUEST,status.msCause);
		}
		return true;
	case MachineStatus::MachineCodeQuitTran:	// aka MachineStatusQuitTran
		// Pop all procedures from stack and remove the transaction.  Procedure already sent messages.
		// This is the normal exit from a completed procedure.
		// In all cases the caller was supposed to already send termination messages toward both layer2 (the handset)
		// and SIP Dialog (the network) however, we will perform additional termination to make sure.
		teRemove(status.msCause);		// Danger will robinson!!!!  Deletes the Transaction we are running.
		return true;
	case MachineStatus::MachineCodeUnexpectedState:	// aka MachineStatusUnexpectedState
		return false;		// The message or state was unrecognized by this state machine.
	//default:
		//return true;	// All others; Message was handled by the current Procedure.
	}

#if 0
	switch (status) {
	case MachineStatusUnexpectedState:			// Invalid procRun argument; very unlikely internal error.
		LOG(ERR) << "unexpected state";
		return false;	// unhandled.  Should we keep going anyway?  probably not.
	case MachineStatusUnexpectedMessage:		// error message printed by caller.
		LOG(ERR) << "unsupported message";
		return false;	// unhandled but keep going.
	case MachineStatusQuit:
		while (currentProcedure()) {
			delete tran()->tePopMachine();
		}
		teClose();		// Danger will robinson!!!!
		return true;
	case MachineStatusUnexpectedPrimitive:
		LOG(ERR) << "unexpected primitive";	// Dont think this MachineStatus is used anywhere.
		return false;
	default:
		return true;	// All others; Message was handled by the current Procedure.
	}
#endif
	return true;	// unnecessary but makes gcc happy.
}


// The 'lockAnd...' methods are used to initially start or restart a Procedure.
// Update: This locking is no longer needed or relevant.
// (pat 5-13-2014) Update update: Yes the locks appear to be used - I got the "waiting more than one second" emssage from lockAndInvokeFrame;
//   the situation was starting then cancelling a call on the same handset.  This may have been in the midst of a reassignment procedure
//   so messages were arriving simultaneously on both channels.  Looks like the CC Disconnect was sent on the SDCCH right before the
//   reassign procedure, then a dialog cancel came in too.
//	 The phone misbehaved - it looked like it stayed connected after pressing disconnect?  check again.
// When jumping between procedures we dont use these, although it would not matter since the locks can be recursive.
// Start a procedure by calling stateStart:
// If no proc is specified here, assume that teSetProcedure was called previously and start the currentProcedure.
bool TranEntry::lockAndStart(MachineBase *wProc)
{
	bool result = false;
	RefCntPointer<TranEntry> saver = this;
	{	ScopedLock lock(mL3RewriteLock,__FILE__,__LINE__);
		if (wProc) {
			teSetProcedure(wProc,false);
			devassert(wProc == currentProcedure());
		} else {
			wProc = currentProcedure();
			devassert(wProc);	// Someone set the currentProcedure before calling this method.
		}
		result = handleMachineStatus(wProc->callMachStart(wProc));
	}
	return result;
}


// Start a procedure by passing it this L3 message:
bool TranEntry::lockAndStart(MachineBase *wProc, GSM::L3Message *l3msg)
{
	bool result = false;
	RefCntPointer<TranEntry> saver = this;
	{	ScopedLock lock(mL3RewriteLock,__FILE__,__LINE__);
		teSetProcedure(wProc,false);
		devassert(wProc == currentProcedure());
		result = handleMachineStatus(wProc->dispatchL3Msg(l3msg));
	}
	return result;
}

#if UNUSED
// Send a message to the current Procedure, either l3msg or lch.
// lch is the channel this message arrived on.  It is information we have, but I dont think it is useful.
// I wonder if there are any cases where lch may not be the L3LogicalChannel that initiated the Procedure?
// It probably doesnt matter - we use the L3LogicalChannel to send return messages to the MS,
// and the initial channel that created the Procedure is probably the correct one.
// For example if lch is FACCH, we cannot send anything downstrem on that.
bool TranEntry::lockAndInvokeL3Msg(const GSM::L3Message *l3msg /*, const L3LogicalChannel *lch*/)
{
	if (this->getGSMState() == CCState::TranDeleted) { return false; }	// (pat) Paranoid check that TranEntry still extant.
	LOG(DEBUG);
	bool result = false;
	RefCntPointer<TranEntry> saver = this;
	{	ScopedLock lock(mL3RewriteLock,__FILE__,__LINE__);
		if (MachineBase *proc = currentProcedure()) {
			LOG(DEBUG) <<"sending l3msg to"<<LOGVAR(proc) <<LOGVAR(l3msg);
			result = handleMachineStatus(proc->dispatchL3Msg(l3msg));
		}
	}
	return result;
}
#endif

// l3msg may be NULL for primitives or unparseable messages.
bool TranEntry::lockAndInvokeFrame(const L3Frame *frame, const L3Message *l3msg)
{
	if (this->getGSMState() == CCState::TranDeleted) { return false; }	// (pat) Paranoid check that TranEntry still extant.
	LOG(DEBUG) << l3msg;
	bool result = false;
	RefCntPointer<TranEntry> saver = this;
	{
		ScopedLock lock(mL3RewriteLock,__FILE__,__LINE__);
		if (MachineBase *proc = currentProcedure()) {
			LOG(DEBUG) <<"sending frame to"<<LOGVAR(proc) <<LOGVAR(frame);
			result = handleMachineStatus(proc->dispatchFrame(frame,l3msg));
		} else {
			LOG(INFO) <<"Received message for transaction with no state machine. "<<this<<*frame;	// Should never happen.
		}
	}
	return result;
}

// Return true if the message had a handler.
// Caller responsible for deleting the sipmsg.
bool TranEntry::lockAndInvokeSipMsg(const SIP::DialogMessage *sipmsg)
{
	if (this->getGSMState() == CCState::TranDeleted) { return false; }	// (pat) Paranoid check that TranEntry still extant.
	bool result = false;
	RefCntPointer<TranEntry> saver = this;
	{	ScopedLock lock(mL3RewriteLock,__FILE__,__LINE__);
		if (MachineBase *proc = currentProcedure()) {
			result = handleMachineStatus(proc->dispatchSipDialogMsg(sipmsg));
		}
	}
	return result;
}

bool TranEntry::lockAndInvokeSipMsgs()
{
	// SIP Message processing is blocked during the AssignTCHF procedure.
	// Now that is handled by checking for sip state changes when the AssignTCHF procedure is finished.
	//if (mSipDialogMessagesBlocked) { return false; }
	if (DialogMessage*dmsg = this->mTranInbox.readNoBlock()) {
		lockAndInvokeSipMsg(dmsg);
		delete dmsg;
		// Since the message can result in the transaction being killed, only process one message
		// then we return to let the caller invoke us again if the transaction is still active.
		return true;
	}
	return false;
}

bool TranEntry::lockAndInvokeTimeout(L3Timer *timer)
{
	if (this->getGSMState() == CCState::TranDeleted) { return false; }	// (pat) Paranoid check that TranEntry still extant.

	// handleMachineStatus may unlink the transaction; this reference prevents the transaction
	// from being deleted until this routine exists.  Without this, the ScopedLock tries to reference the deleted transaction.
	bool result = false;
	RefCntPointer<TranEntry> saver = this;

	LOG(DEBUG) << LOGVAR2("timer",timer->tName()) << this;
	{	ScopedLock lock(mL3RewriteLock,__FILE__,__LINE__);
		if (MachineBase *proc = currentProcedure()) {
			result = handleMachineStatus(proc->dispatchTimeout(timer));
		}
	}
	return result;
}

void TranEntry::terminateHook()
{
	LOG(INFO) "SIP term info terminateHook";
	if (MachineBase *proc = currentProcedure()) {
		proc->handleTerminationRequest();
	}
}


void TranEntry::teCloseDialog(TermCause cause)
{
	CallState state = getGSMState();

	LOG(INFO) << "SIP term info teCloseDialog cancel cause: " << cause /*<< " l3Cause : " << l3Cause*/ ;  // SVGDBG
	// An MO transaction may not have a dialog yet.
	// The dialog can also be NULL because the phone will send a DISCONNECT first thing if a previous call did not close correctly.
	SipDialog *dialog = getDialog();

	if (dialog) {
		// For the special case of outbound handover we must destroy the dialog immediately
		// in case a new handover comes back to us in the reverse direction.
		// just drop the dialog, dont send a BYE.
		if (state == CCState::HandoverOutbound) {
			cause = TermCause::Local(L3Cause::Handover_Outbound);
		}
		LOG(INFO) << "SIP term info dialogCancel called in teCloseDialog";
		dialog->dialogCancel(cause);		// Does nothing if dialog not yet started.
	}
}


// Used by MMLayer to immediately remove the transaction, without notifying MM layer.
// An assumption is that the dialog pointer is valid as long as the transaction exists,
// so we dont zero out the dialog pointer until we kill the dialog.
void TranEntry::teRemove(TermCause cause)
{
	if (mFinalDisposition.tcIsEmpty()) {
		mFinalDisposition = cause;
	}
	SipDialog *dialog = getDialog();
	CallState state = getGSMState();
	if (dialog) {
		if (state == CCState::HandoverOutbound) {
			// FIXME: Sigh, it could be NoUserResponding from the default timer handler.
			devassert(cause.tcGetValue() == L3Cause::Handover_Outbound || cause.tcIsEmpty());
			cause = TermCause::Local(L3Cause::Handover_Outbound);
		}
		if (cause.tcIsEmpty() && dialog->getLastResponseCode()) {
			// Both transaction and dialog are already cancelled, so this cause is for reporting purposes.
			cause = dialog2TermCause(dialog);
		}
		LOG(INFO) << "SIP term info dialogCancel called in teRemove cancel cause: " << cause;
		dialog->dialogCancel(cause);		// Does nothing if dialog not yet started.
	}

	//GSM::CCCause l3Cause = GSM::L3Cause::UnknownL3Cause;
	//if (dialog) {
	//	int SIPerror = dialog->getLastResponseCode();
	//	// For the special case of outbound handover we must destroy the dialog immediately
	//	// in case a new handover comes back to us in the reverse direction.
	//	// just drop the dialog, dont send a BYE.
	//	if (state == CCState::Handover_Outbound) {
	//		devassert(cause == TermCauseHandoverOutbound);
	//		cause = TermCauseHandoverOutbound;
	//	}

	//	if (cause == TermCauseNoAnswerToPage)
	//		l3Cause = GSM::L3Cause::NoUserResponding;
	//	else if (cause == TermCauseBusy)
	//		l3Cause = GSM::L3Cause::UserBusy;
	//	else if (cause == TermCauseCongestion)
	//		l3Cause = GSM::L3Cause::SwitchingEquipmentCongestion;

	//	if (l3Cause == GSM::L3Cause::UnknownL3Cause) {
	//		// Translate SIP error to L3Cause
	//		switch (SIPerror) {
	//		case 408: l3Cause = L3Cause::NoUserResponding; break;
	//		case 480: l3Cause = L3Cause::UserAlertingNoAnswer; break;
	//		case 404: l3Cause = L3Cause::UnassignedNumber; break;
	//		default: break;
	//		}
	//	}

	//	LOG(INFO) << "SIP term info dialogCancel called in teRemove cancel cause: " << cause << " L3Cause: " << l3Cause << " SIPerror: " << SIPerror;
	//	dialog->dialogCancel(cause, l3Cause);		// Does nothing if dialog not yet started.
	//}

	// (pat 9-29-2014) Harry was seeing intermittent crashes in the code below.
	// Crash was inside sqlite when calling gConfig.getStr() from cdrServiceStart(), which would appear to be a memory corruption
	// in something immediately preceding, but unknown what it could be.
	// I cannot find any problems, but this is the only new addition, so to be safe, we will completely avoid this code
	// unless specifically enabled by setting Control.CDR.Dirname.
	if (gConfig.getStr("Control.CDR.Dirname").size()) {
		if (L3CDR *cdr = this->createCDR(true,cause)) {
			gCdrService.cdrServiceStart();
			gCdrService.cdrAdd(cdr);
		}
	}

	// It is important to make this transaction no longer point at the dialog, because the dialog
	// will not destroy itself while a transaction still points at it.  Taking the transaction
	// out of the TransactionTable prevents the dialog from finding the transaction any longer.
	// However to prevent a race we must do this after using the dialog, which we did above.
	setGSMState(CCState::TranDeleted);	// (pat 10-10-2014) Now we use this to mark the TranEntry as deleted.
	gNewTransactionTable.ttRemove(this->tranID());

	while (currentProcedure()) {
		delete this->tePopMachine();
	}

	// If the TranEntry never got into an MMContext, ie, deleted from MMUser::MMFree, this is the first time it has been
	// put under RefCntPointer control - from this point on it will be deleted when the last reference count disappears,
	// which is the pop_front out of the sDeletedTranEntrys below.
	sDeletedTranEntrys.push_back(RefCntPointer<TranEntry>(this));

	if (mContext) { mContext->mmDisconnectTran(this); }	// DANGER: this deletes the transaction as a side effect.
	mContext = NULL;

	while (sDeletedTranEntrys.size() > 100) {
		RefCntPointer<TranEntry> tran = sDeletedTranEntrys.front();
		sDeletedTranEntrys.pop_front();
		// The act of moving it from the list deletes the reference count and causes it to be deleted.
		LOG(DEBUG) << "Deleting transaction:"<<tran->tranID();
	}
}

// Send closure messages for a transaction that is known to be a CS transaction, using the specified CC cause.
// Must only call from the thread running the channel.
// To close all transactions on a channel, see L3LogicalChannel::chanClose()
void TranEntry::teCloseCallNow(TermCause cause, bool sendCause)
{
	//LOG(INFO) << "SIP term info closeCallNow cause: " << cause; // SVGDBG
	WATCHINFO("CloseCallNow"<<LOGVAR2("cause",cause)<<" "<<channel()->descriptiveString());
	LOG(DEBUG) <<LOGVAR(cause) << this << gMMLayer.printMMInfo();
	if (tran()->getGSMState() == CCState::TranDeleted) { 	// (pat) Paranoid check that TranEntry still extant.
		LOG(ERR) << "detected closeCall on deleted transaction";
		return;
	}

	tran()->teCloseDialog(cause); // Redundant with teRemove, but I want to be sure we terminate the dialog regardless of bugs.
	if (isL3TIValid() && tran()->getGSMState() != CCState::NullState && tran()->getGSMState() != CCState::ReleaseRequest) {
		unsigned l3ti = getL3TI();
		// 24.008 5.4.2: Permitted method to close call immediately.
		if (sendCause) {
			channel()->l3sendm(GSM::L3ReleaseComplete(l3ti,cause.tcGetCCCause()));	// This is a CC message that releases this Transaction immediately.
		} else {
			channel()->l3sendm(GSM::L3ReleaseComplete(l3ti));	// This is a reply that confirms transaction was released.
		}
	}
	setGSMState(CCState::NullState);	// redundant, we are deleting this transaction.
}

void writePrivateHeaders(SipMessage *msg, const L3LogicalChannel *l3chan)
{
	// P-PHY-Info
	// This is a non-standard private header in OpenBTS.
	// TODO: If we add the MSC params to this, especially L3TI, the SIP message will completely encapsulate handover.
	// TA=<timing advance> TE=<TA error> UpRSSI=<uplink RSSI> TxPwr=<MS tx power> DnRSSIdBm=<downlink RSSI>
	// Get the values.
	if (l3chan) {
		char phy_info[200];
		// (pat) TODO: This is really cheating.
		const GSM::L2LogicalChannel *chan = l3chan->getL2Channel();
		MSPhysReportInfo *phys = chan->getPhysInfo();
		// (pat 5-2014) Adding the imsi to the info, since it is sometimes not possible to know which of the
		// two handsets involved in the dialog initiated the SIP message.
		string imsi = l3chan->chanGetImsi(true);
		snprintf(phy_info,200,"OpenBTS; IMSI=%s TA=%d TE=%f UpRSSI=%f TxPwr=%d DnRSSIdBm=%d time=%9.3lf",
			imsi.c_str(),
			phys->actualMSTiming(), phys->timingError(),
			phys->getRSSI(), phys->actualMSPower(),
			chan->measurementResults().RXLEV_FULL_SERVING_CELL_dBm(),
			phys->timestamp());
		static const string cPhyInfoString("P-PHY-Info");
		msg->smAddHeader(cPhyInfoString,phy_info);
	}

	// P-Access-Network-Info
	// See 3GPP 24.229 7.2.  This is a genuine specified header.
	char cgi_3gpp[256];
	snprintf(cgi_3gpp,256,"3GPP-GERAN; cgi-3gpp=%s%s%04x%04x",
		gConfig.getStr("GSM.Identity.MCC").c_str(),gConfig.getStr("GSM.Identity.MNC").c_str(),
		(unsigned)gConfig.getNum("GSM.Identity.LAC"),(unsigned)gConfig.getNum("GSM.Identity.CI"));
	static const string cAccessNetworkInfoString("P-Access-Network-Info");
	msg->smAddHeader(cAccessNetworkInfoString, cgi_3gpp);
 
	// FIXME -- Use the subscriber registry to look up the E.164
	// and make a second P-Preferred-Identity header.
}

void TranInit()
{
	SipCallbacks::setcallback_ttAddMessage( & NewTransactionTable_ttAddMessage);
	SipCallbacks::setcallback_writePrivateHeaders( & writePrivateHeaders);
}

// Look up the phone number, if any, passed to us from the Registrar when this imsi registered.
static string lookupPhoneNumber(string imsi)
{
	string number, unused;
	gTMSITable.getSipIdentities(imsi,number,unused);
	int len = number.size();
	if (len >= 2 && number[0] == '<') { number = number.substr(1,len-2); }
	if (0 == strncasecmp(number.c_str(),"tel:",4)) { number = number.substr(4); }
	return number;
}

L3CDR *TranEntry::createCDR(bool makeCMR, TermCause cause)	// If true, make a CMR instead of a CDR.  CMRs have more info.
{
	L3CDR *cdrp = new L3CDR(), &cdr = *cdrp;	// Gotta love this language.
	cdr.cdrToNumber = string(this->called().digits());
	cdr.cdrFromNumber = string(this->calling().digits());

	switch (this->service().type()) {
		case L3CMServiceType::MobileOriginatedCall:
			cdr.cdrType = "MOC";
			labelmoc:
			if (mConnectTime == 0 && ! makeCMR) { goto labelIgnore; }
			cdr.cdrFromImsi = this->subscriber().mImsi;
			if (SipDialog *dialog = this->getDialog()) {
				// MOC do not know the IMSI of the phone number they are calling.
				//cdr.cdrToImsi = dialog->sipRemoteUsername();	// This is the phone number, not the imsi.
				if (dialog->dsPeer()) cdr.cdrPeer = dialog->dsPeer()->mipName;
			}
			if (cdr.cdrFromNumber.empty()) {
				cdr.cdrFromNumber = lookupPhoneNumber(cdr.cdrFromImsi);
			}
			break;
		case L3CMServiceType::EmergencyCall:
			cdr.cdrType = "Emergency";
			goto labelmoc;
			break;
		case L3CMServiceType::ShortMessage:
			if (this->mMessage.size() == 0 && ! makeCMR) { goto labelIgnore; }
			cdr.cdrType = "MOSMS";
			goto labelmoc;
			break;
		case L3CMServiceType::MobileTerminatedShortMessage:
			if (this->mMessage.size() == 0 && ! makeCMR) { goto labelIgnore; }
			cdr.cdrType = "MTSMS";
			goto labelmtc;
			break;

		case L3CMServiceType::LocationUpdateRequest:
			if (! makeCMR) { goto labelIgnore; }
			cdr.cdrType = "LUR";
			cdr.cdrFromImsi = this->subscriber().mImsi;
			break;

		case L3CMServiceType::UndefinedType:
		case L3CMServiceType::SupplementaryService:
		case L3CMServiceType::VoiceCallGroup:
		case L3CMServiceType::VoiceBroadcast:
		case L3CMServiceType::LocationService:
		case L3CMServiceType::HandoverCall: // The handover code sets the type to MobileOriginatedCall or MobileTerminatedCall so we should not see this.
			break;

		case L3CMServiceType::MobileTerminatedCall:
			cdr.cdrType = "MTC";
			labelmtc:
			if (mConnectTime == 0 && ! makeCMR) { goto labelIgnore; }
			cdr.cdrToImsi = this->subscriber().mImsi;
			if (SipDialog *dialog2 = this->getDialog()) {
				cdr.cdrFromImsi = dialog2->sipRemoteUsername();
				if (0 == strncasecmp(cdr.cdrFromImsi.c_str(),"IMSI",4)) {
					cdr.cdrFromImsi = cdr.cdrFromImsi.substr(4);
				}
				if (dialog2->dsPeer()) cdr.cdrPeer = dialog2->dsPeer()->mipName;
			}
			if (cdr.cdrToNumber.empty()) {
				cdr.cdrToNumber = lookupPhoneNumber(cdr.cdrToImsi);
			}
			break;
	};

	if (cdr.cdrType == "") {
		LOG(ERR) << "Unrecognized service, no CDR generated:"<<this->service();
		labelIgnore:
		delete cdrp;
		return NULL;
	}

	cdr.cdrTid = this->tranID();
	cdr.cdrConnectTime = this->mConnectTime;
	cdr.cdrDuration = cdr.cdrConnectTime ? time(NULL) - cdr.cdrConnectTime : 0;
	cdr.cdrMessageSize = this->mMessage.size();
	cdr.cdrCause = this->mFinalDisposition;
	if (HandoverEntry *hp = this->getHandoverEntry(false)) {
		cdr.cdrFromHandover = sockaddr2string(&hp->mInboundPeer,false);
		cdr.cdrToHandover = sockaddr2string(&hp->mOutboundPeer,false);
	}
	return cdrp;
}

void L3CDR::cdrWriteHeader(FILE *pf)
{
	// Fields must match type and order in cdrWriteEntry()
	typedef struct {const char *name; const char *type;} Field;
	static Field fields[] = {
		{"Type","string"},
		{"Transaction-id","integer"},
		{"To-IMSI","string"},	// usually empty for MOC.
		{"From-IMSI","string"},
		{"To-number","string"},
		{"From-number","string"},
		{"Peer","string"},
		{"Start-time","integer"},	// standard unix time.
		// Connect duration, as opposed to total time, in seconds.  0 means call never successfully connected.
		{"Connect-Duration","integer"},
		{"Message-size","integer"},	// Only for SMS.
		{"To-Handover","string"},	// TODO
		{"From-Handover","string"},
		{"Termination-Side","char"},		// R or L for remote or local side.
		{"Termination-Cause","integer"},
		{NULL,NULL}
	};
	// Print the field names.
	for (Field *field = fields; field->name; field++) {
		if (field != fields) fputc(',',pf);
		fprintf(pf,"%s",field->name);
	}
	fputc('\n',pf);
	// Print the field types.
	for (Field *field = fields; field->type; field++) {
		if (field != fields) fputc(',',pf);
		fprintf(pf,"%s",field->type);
	}
	fputc('\n',pf);
	fflush(pf);
}

void L3CDR::cdrWriteEntry(FILE *pf)
{
	fprintf(pf,"%s,%u,",cdrType.c_str(),cdrTid);
	fprintf(pf,"%s,%s,",cdrToImsi.c_str(),cdrFromImsi.c_str());
	fprintf(pf,"%s,%s,",cdrToNumber.c_str(),cdrFromNumber.c_str());
	fprintf(pf,"%s,",cdrPeer.c_str());
	fprintf(pf,"%lu,%lu,",cdrConnectTime,cdrDuration);
	fprintf(pf,"%d,",cdrMessageSize);
	fprintf(pf,"%s,%s,",cdrToHandover.c_str(),cdrFromHandover.c_str());	// handover to, from
	fprintf(pf,"%c,",(cdrCause.mtcInstigator == TermCause::SideLocal) ? 'L' : 'R');	// termination side
	fprintf(pf,"%d",cdrCause.tcGetValue());	// termination cause
	fprintf(pf,"\n");
	fflush(pf);	// Write to disk in case OpenBTS crashes.
}

// Open a new file whenever the date changes.
void CdrService::cdrOpenFile()
{
	time_t now = time(NULL);
	struct tm tm;
	localtime_r(&now,&tm);
	if (tm.tm_yday == cdrCurrentDay) {
		// We already tried to open the file.  Either we succeeded or not, but we wont try to open it on every transaction.
		return;
	}
	if (mpf) { fclose(mpf); mpf = NULL; }
	string dirname = gConfig.getStr("Control.CDR.Dirname");
	if (0 == dirname.size()) { return; }	// Disabled if the Control.CDR.Dirname is empty.

	cdrCurrentDay = tm.tm_yday;
	string date = format("%04d-%02d-%02d", tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday);

	mkdir(dirname.c_str(),0777);	// Doesnt hurt to do this even if unnecessary.

	string btsid = gConfig.getStr("SIP.Local.IP");	// Default bts id to the local IP address.
	string filename = format("%s/OpenBTS_%s_%s.cdr",dirname,btsid,date);
	mpf = fopen(filename.c_str(),"a");
	// Dont re-write the header if we are appending to an existing file.
	if (mpf && 0 == ftell(mpf)) { L3CDR::cdrWriteHeader(mpf); }
}

void*CdrService::cdrServiceLoop(void*arg)
{
	CdrService *self = static_cast<CdrService*>(arg);
	while (!gBTS.btsShutdown()) {
		L3CDR *cdr = self->mCdrQueue.read();	// Blocking read.
		if (!cdr) { continue; }	// paranoid, but maybe happens during shutdown.
		self->cdrOpenFile();	// We may have to open a new file if the date changed.
		if (self->mpf) { cdr->cdrWriteEntry(self->mpf); }
		delete cdr;
	}
	return NULL;
}

void CdrService::cdrServiceStart()
{
	bool startme = false;
	{	ScopedLock lock(cdrLock);	// This is probably paranoid overkill.
		if (!cdrServiceRunning) {
			startme = cdrServiceRunning = true;
		}
	}
	if (startme) {
		cdrServiceThread.start(cdrServiceLoop,this);
	}
}

};	// namespace

// vim: ts=4 sw=4