std::ostream& operator<<(std::ostream& os, const FullMobileId&msid)
{
os <<LOGVAR2("Imsi",msid.mImsi.length()?msid.mImsi:"\"\"")
<<LOGVAR2("Tmsi",msid.mTmsi)
<<LOGVAR2("Imei",msid.mImei.length()?msid.mImei:"\"\"");
return os;
}
void ChannelTree::chConflict(Tier t1,unsigned ch1,Tier t2,unsigned ch2)
{
LOG(ALERT) << "Attempt to reserve channel:"
<<LOGVAR2("sf",tier2sf(t1))<<LOGVAR2("chcode",ch1)
<<" which conflicts with reserved channel:"
LOGVAR2("sf",tier2sf(t2))<<LOGVAR2("chcode",ch2);
//assert(0);
}
void PDCHL1FEC::mchDump(std::ostream&os, bool verbose)
{
os << " PDCH"<<LOGVAR2("ARFCN", ARFCN())
<< LOGVAR2("TN",TN()) << LOGVAR2("FER",fmtfloat2(100.0*FER())) << "%" << "\n";
if (verbose) {
os <<"\t"; dumpReservations(os);
os <<"\t"; usfDump(os);
os <<"\t"; mchTFIs->tfiDump(os);
}
}
// There can be a max of two simultaneous MO-SMS.
// The CM Service Request to start a new MO-SMS during an existing one may arrive before the final ACK of the previous MO-SMS, as per GSM 4.11 5.4
// Therefore there are two MO-SMS possible: MMContext::TE_MOSMS1 is the old one and TE_MOSMS2 is the new one.
void startMOSMS(const GSM::L3MMMessage *l3msg, MMContext *mmchan)
{
LOG(DEBUG) <<mmchan;
//now we allocate below: TranEntry *tran = TranEntry::newMO(dcch, L3CMServiceType::ShortMessage);
//MMContext *set = dcch->chanGetContext(true);
RefCntPointer<TranEntry> prevMOSMS = mmchan->mmGetTran(MMContext::TE_MOSMS1);
if (! prevMOSMS.self()) {
// happiness.
//set->setTran(MMContext::TE_MOSMS1,tran);
//tran->teConnectChannel(dcch,TE_MOSMS1);
} else {
// Check for perfidy on the part of the MS: it cannot start a new MO-SMS unless the previous is nearly finished.
//SmsState smsState = getCurrentSMSState();
MachineBase *base = prevMOSMS->currentProcedure();
bool badbunny = false;
if (base) { // This may happen if the MS is a bad bunny and sends two CM Sevice Requests effectively simultaneously.
MOSMSMachine *smssm = dynamic_cast<typeof(smssm)>(base);
if (! smssm || smssm->mSmsState != MoSmsWaitForAck) {
badbunny = true;
}
} else {
badbunny = true;
}
if (badbunny) {
LOG(ERR) << "Received new MO-SMS before previous MO-SMS completed"<<LOGVAR2("MOSMS",prevMOSMS.self())<<l3msg;
// Now what? We've already got an SMS running...
return; // Just ignore it.
}
RefCntPointer<TranEntry> prevMOSMS2 = mmchan->mmGetTran(MMContext::TE_MOSMS2);
if (prevMOSMS2.self()) {
LOG(ERR) <<"Received third simultaneous MO-SMS, which is illegal:"<<LOGVAR2("MO-SMS1",prevMOSMS.self())<<LOGVAR2("MO-SMS2",prevMOSMS2.self());
// Now what? We could kill the oldest one or reject the new one.
// Kill the oldest one, on the assumption that this indicates a bug in our code and that SMS is hung.
prevMOSMS->teCancel(TermCause::Local(L3Cause::SMS_Error)); // Promotes TE_MOSMS2 to TE_MOSMS1
devassert(mmchan->mmGetTran(MMContext::TE_MOSMS2) == NULL);
}
//mmchan->setTran(MMContext::TE_MOSMS2,tran);
//tran->teConnectChannel(mmchan,MMContext::TE_MOSMS2);
}
TranEntry *tran = TranEntry::newMOSMS(mmchan);
// Fire up an SMS state machine for this transaction.
MOSMSMachine *mocp = new MOSMSMachine(tran);
// The message is CMServiceRequest.
tran->lockAndStart(mocp,(GSM::L3Message*)l3msg);
}
// (pat 9-2014) Print out peering messages. We triage the messages depending on the log level.
// INFO level - Handover messages only.
// DEBUG level - all messages.
static void logMessage(const char*sendOrRecv, const struct sockaddr_in* peer, const char *message)
{
const char *arg1 = getPeeringMsgArg1(message);
if (0 == strncmp(arg1,"HANDOVER",8)) {
LOG(INFO) << "Peering "<<sendOrRecv <<LOGVAR2("peer",sockaddr2string(peer,true)) <<LOGVAR(message);
// We used to watch everything except REQ NEI messages: if (strncmp(message,"REQ NEI",7))
const char *eol = strchr(message,'\n');
WATCHLEVEL(INFO," Peering "<<sendOrRecv <<LOGVAR2("peer",sockaddr2string(peer,true))
<<LOGVAR2("message",string(message,eol?eol-message:strlen(message)))); // first line of message; they used to be long.
} else {
// At DEBUG level log all messages.
LOG(DEBUG) << "Peering "<<sendOrRecv<<LOGVAR2("peer",sockaddr2string(peer,true)) <<LOGVAR(message);
}
}
L3Frame * L2LogicalChannel::l2recv(unsigned timeout_ms)
{
LOG(DEBUG);
L3Frame *result = mL3Out.read(timeout_ms);
if (result) WATCHINFO("l2recv " << this <<LOGVAR2("sap",result->getSAPI()) <<LOGVAR(result));
return result;
}
void PeerInterface::process(const struct sockaddr_in* peer, const char* message)
{
logMessage("receive",peer,message);
// neighbor message?
if (strncmp(message+3," NEIGHBOR_PARAMS",16)==0)
return processNeighborParams(peer,message);
// must be handover related
string peerString = sockaddr2string(peer, true);
LOG(INFO) << "received from"<<LOGVAR2("peer",peerString) <<LOGVAR(message);
// Initial inbound handover request?
if (strncmp(message,"REQ HANDOVER ",13)==0)
return processHandoverRequest(peer,message);
// Handover response? ("Handover Accept" in the ladder.)
if (strncmp(message,"RSP HANDOVER ",13)==0)
return processHandoverResponse(peer,message);
// IND HANDOVER_COMPLETE
if (strncmp(message,"IND HANDOVER_COMPLETE ", 22)==0)
return processHandoverComplete(peer,message);
// IND HANDOVER_FAILURE
if (strncmp(message,"IND HANDOVER_FAILURE ", 21)==0)
return processHandoverFailure(peer,message);
// Other handover messages go into the FIFO map.
// (pat) It is an ACK message, and we need to queue it because the 'senduntilack' is running in a different thread.
// FIXME -- We need something here to spot malformed messages.
unsigned transactionID;
sscanf(message, "%*s %*s %u", &transactionID);
mFIFOMap.writeFIFO(transactionID,message);
}
void PDCHL1FEC::mchStart() {
getRadio()->setSlot(TN(),Transceiver::IGPRS);
// Load up the GPRS filler idle burst tables in the transceiver.
// We could use any consecutive bsn, but lets use ones around the current time
// just to make sure they get through in case someone is triaging somewhere.
// Sending all 12 blocks is 2x overkill because the modulus in Transceiver::setModulus
// for type IGPRS is set the same as type I which is only 26, not 52.
RLCBSN_t bsn = FrameNumber2BSN(gBTS.time().FN()) + 1;
for (int i = 0; i < 12; i++, bsn = bsn + 1) {
GPRSLOG(1) <<"sendIdleFrame"<<LOGVAR2("TN",TN())<<LOGVAR(bsn)<<LOGVAR(i);
mchDownlink->sendIdleFrame(bsn);
}
mchOldFec->setGPRS(true,this);
debug_test();
}
void rateMatchFunc(BitVector &in,BitVector &out, int eini)
{
int nin = in.size();
int nout = out.size();
if (nout == nin) {
in.copyTo(out);
return;
}
int eplus = 2 * nin; // eplus = a * Ni,j
int eminus = 2 * (nout - nin); // eminus = a * abs(deltaNi,j)
if (eminus < 0) { eminus = - eminus; }
float e = eini;
int m; // index of current bit, except zero-based as opposed to spec that is 1 based.
char *inp = in.begin(); // cheating just a bit for efficiency.
char *outp = out.begin();
char *outend = out.end();
if (nout < nin) {
// Puncture bits as necessary.
// Note from spec: loop termination Xi == Xij == number of bits before rate matching == nin.
for (m=0; m < nin && outp < outend; m++) {
e = e - eminus;
if (e <= 0) {
e = e + eplus;
continue; // skip the bit.
}
*outp++ = inp[m];
}
} else {
// Repeat bits as necessary.
for (m=0; m < nin && outp < outend; m++) {
e = e - eminus;
while (e <= 0) {
if (outp >= outend) goto failed;
*outp++ = inp[m]; // repeat the bit.
e = e + eplus;
}
*outp++ = inp[m];
}
}
if (m != nin || outp != outend) {
failed:
LOG(ERR) << "rate matching mis-calculation, results:"
<<LOGVAR(nin)<<LOGVAR(m)<<LOGVAR(nout)<<LOGVAR2(outp,outp-out.begin())
<<LOGVAR(e)<<LOGVAR(eplus)<<LOGVAR(eminus)<<LOGVAR(eini);
}
}
void L2LogicalChannel::writeToL3(L3Frame*frame)
{
LOG(DEBUG) <<this <<LOGVAR(*frame);
switch (frame->primitive()) {
case L3_ESTABLISH_INDICATION:
case L3_ESTABLISH_CONFIRM:
case HANDOVER_ACCESS:
case L3_DATA:
case L3_UNIT_DATA:
break;
case MDL_ERROR_INDICATION:
// Normal release procedure initiated by handset, or due to error at LAPDm level.
// An error is handled identically to a normal release, because the handset may still be listening to us
// even though we lost contact with it, and we want to tell it to release as gracefully as possible
// even though the channel condition may suck.
if (frame->getSAPI() == SAPI0) {
// Release on host chan sap 0 is a total release. We will start the release now.
// FIXME: Are we supposed to wait for any pending SMS requests on SACCH to clear first?
startNormalRelease();
} else {
// We dont kill the whole link for SAP3 release.
// Pass the message on to layer3 to abort whatever transaction is running on SAP3
}
break;
case L3_DATA_CONFIRM: // Sent from LAPDm when data delivered, but we dont care.
WATCHINFO(this <<LOGVAR2("sap",frame->getSAPI()) <<LOGVAR(frame));
delete frame;
return;
case L3_RELEASE_INDICATION:
case L3_RELEASE_CONFIRM: // Sent from LAPDm when link release is confirmed, but we dont care.
if (frame->getSAPI() == SAPI0) {
mT3109.reset();
mT3111.set();
}
break;
default:
assert(0);
}
mL3Out.write(frame);
}
ostream& operator<<(ostream& os, const SipTransaction&st)
{
os << " SipTransaction("<<LOGVAR2("method",st.mstMethod)<<LOGVAR2("seqNum",st.mstSeqNum)<<")";
return os;
}
// WARNING: This func runs in a separate thread.
void PDCHL1Uplink::writeLowSideRx(const RxBurst &inBurst)
{
float low, avg = inBurst.getEnergy(&low);
//if (avg > 0.7) { OBJLOG(DEBUG) << "PDCHL1Uplink " << inBurst; }
//ScopedLock lock(testlock);
int burstfn = inBurst.time().FN();
int mfn = (burstfn / 13); // how many 13-multiframes
int rem = (burstfn - (mfn*13)); // how many blocks within the last multiframe.
int B = rem % 4;
if (avg > 0.5) { GPRSLOG(256) << "FEC:"<<LOGVAR(B)<<" "<<inBurst<<LOGVAR(avg); }
ChannelCodingType cc;
BitVector *result = decodeLowSide(inBurst,B,mchCS14Dec,&cc);
if (B == 3) {
int burst_fn=burstfn-3; // First fn in rlc block.
RLCBSN_t bsn = FrameNumber2BSN(burst_fn);
if (GPRSDebug) {
PDCHL1FEC *pdch = parent();
short *qbits = mchCS14Dec.qbits;
BitVector cshead(mchCS14Dec.mC.head(12).sliced());
RLCBlockReservation *res = mchParent->getReservation(bsn);
int thisUsf = pdch->getUsf(bsn-2);
// If we miss a reservation or usf, print it:
int missedRes = avg>0.4 && !result && (res||thisUsf);
if (missedRes || (GPRSDebug & (result?4:256))) {
std::ostringstream ss;
char buf[30];
ss <<"writeLowSideRx "<<parent()
<<(result?" === good" : "=== bad")
<< (res?" res:" : "") <<(res ? res->str() : "")
//<<LOGVAR(cshead)
//<<LOGVAR2("cs",(int)mchCS14Dec.getCS())
<<LOGVAR(cc)
<<LOGVAR2("revusf",decodeUSF(mchCS14Dec.mC))
<<LOGVAR(burst_fn)<<LOGVAR(bsn)
<<LOGVAR2("RSSI",inBurst.RSSI()) <<LOGVAR2("TE",inBurst.timingError())
// But lets print out the USFs bracketing this on either side.
<<getAnsweringUsfText(buf,bsn)
//<<" AnsweringUsf="<<pdch->getUsf(bsn-2)<<" "<<pdch->getUsf(bsn-1)
//<<" ["<<pdch->getUsf(bsn)<<"] "<<pdch->getUsf(bsn+1)<<" "<<pdch->getUsf(bsn+2)
<<" qbits="<<qbits[0]<<qbits[1]<<qbits[2]<<qbits[3]
<<qbits[4]<<qbits[5]<<qbits[6]<<qbits[7]
<<LOGVAR(low)<<LOGVAR(avg)
;
if (missedRes) {
for (int i = 0; i < 4; i++) {
// There was an unanswered reservation or usf.
avg = mchCS14Dec.mI[i].getEnergy(&low);
GPRSLOG(1) << "energy["<<i<<"]:"<<LOGVAR(avg)<<LOGVAR(low)<<" "
<<mchCS14Dec.mI[i];
}
}
GLOG(DEBUG)<<ss.str();
// Make sure we see a decoder failure if it reoccurs.
if (missedRes) std::cout <<ss.str() <<"\n";
}
} // if GPRSDebug
if (result) {
// Check clock skew for debugging purposes.
static int cnt = 0;
if (bsn >= gBSNNext-1) {
if (cnt++ % 32 == 0) {
GLOG(ERR) << "Incoming burst at frame:"<<burst_fn
<<" is not sufficiently ahead of clock:"<<gBSNNext.FN();
if (GPRSDebug) {
std::cout << "Incoming burst at frame:"<<burst_fn
<<" is not sufficiently ahead of clock:"<<gBSNNext.FN()<<"\n";
}
}
}
countGoodFrame();
// The four frame radio block has been decoded and is in mD.
if (gConfig.getBool("Control.GSMTAP.GPRS")) {
// Send to GSMTAP. Untested.
gWriteGSMTAP(ARFCN(),TN(),gBSNNext.FN(), //GSM::TDMA_PACCH,
frame2GsmTapType(*result),
false, // not SACCH
true, // this is an uplink.
*result); // The data.
}
mchUplinkData.write(new RLCRawBlock(bsn,*result,inBurst.RSSI(),inBurst.timingError(),cc));
} else {
countBadFrame();
}
} else {
// We dont have a full 4 bursts yet, and we rarely care about these
// intermediate results, but here is a way to see them:
GPRSLOG(64) <<"writeLowSideRx "<<parent()<<LOGVAR(burstfn)<<LOGVAR(B)
<<" RSSI=" <<inBurst.RSSI() << " timing=" << inBurst.timingError();
}
}
// see: Control::MOSMSController
MachineStatus MOSMSMachine::machineRunState(int state, const GSM::L3Message *l3msg, const SIP::DialogMessage *sipmsg)
{
// See GSM 04.11 Arrow Diagram A5 for the transaction (pat) NO, A5 is for GPRS. Closest diagram is F1.
// SIP->Network message.
// Step 1 MS->Network CP-DATA containing RP-DATA with message
// Step 2 Network->MS CP-ACK
// 4.11 6.2.2 State wait-for-RP-ACK, timer TR1M
// Step 3 Network->MS CP-DATA containing RP-ACK or RP-Error
// Step 4 MS->Network CP-ACK
// LAPDm operation, from GSM 04.11, Annex F:
// """
// Case A: Mobile originating short message transfer, no parallel call:
// The mobile station side will initiate SAPI 3 establishment by a SABM command
// on the DCCH after the cipher mode has been set. If no hand over occurs, the
// SAPI 3 link will stay up until the last CP-ACK is received by the MSC, and
// the clearing procedure is invoked.
// """
WATCHF("MOSMS state=%x\n",state);
PROCLOG2(DEBUG,state)<<LOGVAR(l3msg)<<LOGVAR(sipmsg)<<LOGVAR2("imsi",tran()->subscriber());
switch (state) {
case L3CASE_MM(CMServiceRequest): {
timerStart(TCancel,30*1000,TimerAbortTran); // Just in case.
// This is both the start state and a request to start a new MO SMS when one is already in progress, as per GSM 4.11 5.4
const L3CMServiceRequest *req = dynamic_cast<typeof(req)>(l3msg);
const GSM::L3MobileIdentity &mobileID = req->mobileID(); // Reference ok - the SM is going to copy it.
// FIXME: We only identify this the FIRST time.
// The L3IdentifySM can check the MM state and just return.
// FIXME: check provisioning
return machPush(new L3IdentifyMachine(tran(),mobileID, &mIdentifyResult), stateIdentResult);
}
case stateIdentResult: {
if (! mIdentifyResult) {
//const L3CMServiceReject reject = L3CMServiceReject(L3RejectCause::Invalid_Mandatory_Information);
// (pat 6-2014) I think this is wrong, based on comment below, so changing it to the main channel:
// l3sendSms(L3CMServiceReject(L3RejectCause::Invalid_Mandatory_Information),SAPI0);
MMRejectCause rejectCause = L3RejectCause::Invalid_Mandatory_Information;
channel()->l3sendm(L3CMServiceReject(rejectCause),L3_DATA,SAPI0);
return MachineStatus::QuitTran(TermCause::Local(rejectCause));
}
// Let the phone know we're going ahead with the transaction.
// The CMServiceReject is on SAPI 0, not SAPI 3.
PROCLOG(DEBUG) << "sending CMServiceAccept";
// Update 8-6-2013: The nokia does not accept this message on SACCH SAPI 0 for in-call SMS;
// so I am trying moving it to the main channel.
//l3sendSms(GSM::L3CMServiceAccept(),SAPI0);
channel()->l3sendm(GSM::L3CMServiceAccept(),L3_DATA,SAPI0);
gReports.incr("OpenBTS.GSM.SMS.MOSMS.Start");
return MachineStatusOK;
}
#if FIXME
case L3CASE_ERROR: {
// (pat) TODO: Call this on parsel3 error...
// TODO: Also send an error code to the sip side, if any.
l3sendSms(CPError(getL3TI()));
return MachineStatusQuitTran;
}
#endif
case L3CASE_SMS(DATA): {
timerStop(TCancel);
timerStart(TR1M,TR1Mms,TimerAbortTran);
// Step 0: Wait for SAP3 to connect.
// The first read on SAP3 is the ESTABLISH primitive.
// That was done by our caller.
//delete getFrameSMS(LCH,GSM::ESTABLISH);
// Step 1: This is the first message: CP-DATA, containing RP-DATA.
unsigned L3TI = l3msg->TI() | 0x08;
tran()->setL3TI(L3TI);
const CPData *cpdata = dynamic_cast<typeof(cpdata)>(l3msg);
if (cpdata == NULL) { // Currently this is impossible, but maybe someone will change the code later.
l3sendSms(CPError(L3TI));
return MachineStatus::QuitTran(TermCause::Local(L3Cause::SMS_Error));
}
// Step 2: Respond with CP-ACK.
// This just means that we got the message and could parse it.
PROCLOG(DEBUG) << "sending CPAck";
l3sendSms(CPAck(L3TI));
// (pat) The SMS message has already been through L3Message:parseL3, which called SMS::parseSMS(source), which manufactured
// a CPMessage::CPData and called L3Message::parse() which called CPData::parseBody which called L3Message::parseLV,
// which called CPUserData::parseV to leave the result in L3Message::CPMessage::CPData::mData.
// As the mathemetician said after filling 3 blackboards with formulas: It is obvious!
// FIXME -- We need to set the message ref correctly, even if the parsing fails.
// The compiler gives a warning here. Let it. It will remind someone to fix it.
// (pat) Update: If we cant parse far enough to get the ref we send a CPError that does not need the ref.
#if 0
unsigned ref;
bool success = false;
try {
// (pat) hierarchy is L3Message::CPMessage::CPData; L3Message::parse calls CPData::parseBody.
CPData data;
data.parse(*CM);
LOG(INFO) << "CPData " << data;
// Transfer out the RPDU -> TPDU -> delivery.
ref = data.RPDU().reference();
// This handler invokes higher-layer parsers, too.
success = handleRPDU(transaction,data.RPDU());
}
catch (SMSReadError) {
LOG(WARNING) << "SMS parsing failed (above L3)";
// Cause 95, "semantically incorrect message".
LCH->l3sendf(CPData(L3TI,RPError(95,ref)),3); if you ever use this, it should call l3sendSms
delete CM;
throw UnexpectedMessage();
}
catch (GSM::L3ReadError) {
LOG(WARNING) << "SMS parsing failed (in L3)";
delete CM;
throw UnsupportedMessage();
}
delete CM;
#endif
// Step 3
// Send CP-DATA containing message ref and either RP-ACK or RP-Error.
// If we cant parse the message, we send RP-Error immeidately, otherwise we wait for the dialog to finish one way or the other.
const RLFrame &rpdu = cpdata->data().RPDU();
this->mRpduRef = rpdu.reference();
bool success = false;
try {
// This creates the outgoing SipDialog to send the message.
success = handleRPDU(rpdu);
} catch (...) {
LOG(WARNING) << "SMS parsing failed (above L3)";
}
if (! success) {
PROCLOG(INFO) << "sending RPError in CPData";
// Cause 95 is "semantically incorrect message"
l3sendSms(CPData(L3TI,RPError(95,mRpduRef)));
}
mSmsState = MoSmsWaitForAck;
LOG(DEBUG) << "case DATA returning";
return MachineStatusOK;
}
case L3CASE_SIP(dialogBye): { // SIPDialog sends this when the MESSAGE clears.
PROCLOG(INFO) << "SMS peer did not respond properly to dialog message; sending RPAck in CPData";
l3sendSms(CPData(getL3TI(),RPAck(mRpduRef)));
LOG(DEBUG) << "case dialogBye returning";
}
case L3CASE_SIP(dialogFail): {
PROCLOG(INFO) << "sending RPError in CPData";
// TODO: Map the dialog failure state to an RPError state.
// Cause 127 is "internetworking error, unspecified".
// See GSM 04.11 8.2.5.4 Table 8.4.
l3sendSms(CPData(getL3TI(),RPError(127,mRpduRef)));
LOG(DEBUG) << "case dialogFail returning";
}
case L3CASE_SMS(ACK): {
timerStop(TR1M);
// Step 4: Get CP-ACK from the MS.
const CPAck *cpack = dynamic_cast<typeof(cpack)>(l3msg);
PROCLOG(INFO) << "CPAck " << cpack;
gReports.incr("OpenBTS.GSM.SMS.MOSMS.Complete");
/* MOSMS RLLP request */
//if (gConfig.getBool("Control.SMS.QueryRRLP")) {
// Query for RRLP
//if (!sendRRLP(mobileID, LCH)) {
// LOG(INFO) << "RRLP request failed";
//}
//}
// Done.
mSmsState = MoSmsMMConnection;
// TODO: if (set) set->mmCallFinished();
LOG(DEBUG) << "case ACK returning";
// This attach causes any pending MT transactions to start now.
gMMLayer.mmAttachByImsi(channel(),tran()->subscriberIMSI());
return MachineStatus::QuitTran(TermCause::Local(L3Cause::SMS_Success));
}
default:
LOG(DEBUG) << "unexpected state";
return unexpectedState(state,l3msg);
}
}
// Return true if we send a block on the downlink.
bool PDCHL1Downlink::send1DataFrame( //SVGDBG
RLCDownEngine *engdown,
RLCDownlinkDataBlock *block, // block to send.
int makeres, // 0 = no res, 1 = optional res, 2 = required res.
MsgTransactionType mttype, // Type of reservation
unsigned *pcounter)
{
//ScopedLock lock(testlock);
TBF *tbf = engdown->getTBF();
if (! setMACFields(block,mchParent,tbf,makeres,mttype,pcounter)) { return false; }
// The rest of the RLC header is already set, but we did not know the tfi
// when we created the RLCDownlinkDataBlocks (because tbf not yet attached)
// so set tfi now that we know. Update 8-2012: Above comment is stale because we
// make the RLCDownlinkBlocks on the fly now.
block->mTFI = tbf->mtTFI;
// block->mPR = 1; // DEBUG test; made no diff.
tbf->talkedDown();
BitVector tobits = block->getBitVector(); // tobits deallocated when this function exits.
if (block->mChannelCoding == 0) { devassert(tobits.size() == 184); }
if (GPRSDebug & 1) {
RLCBlockReservation *res = mchParent->getReservation(gBSNNext);
std::ostringstream sshdr;
block->text(sshdr,false); //block->RLCDownlinkDataBlockHeader::text(sshdr);
ByteVector content(tobits);
GPRSLOG(1) << "send1DataFrame "<<parent()<<" "<<tbf<<LOGVAR(tbf->mtExpectedAckBSN)
<< " "<<sshdr.str()
<<" "<<(res ? res->str() : "")
<< LOGVAR2("content",content);
//<< " enc="<<tbf->mtChannelCoding <<" "<<os.str() << "\nbits:" <<bits.str();
//<<" " <<block->str() <<"\nbits:" <<tobits.hexstr();
}
#if FEC_DEBUG
BitVector copybits; copybits.clone(tobits);
#endif
send1Frame(tobits,block->mChannelCoding,0);
#if FEC_DEBUG
BitVector *result = debugDecoder.getResult();
devassert(result);
devassert(copybits == tobits);
if (result && !(*result == tobits)) {
int diffbit = -1;
char thing[500];
for (int i = 0; i < (int)result->size(); i++) {
thing[i] = '-';
if (result->bit(i) != tobits.bit(i)) {
if (diffbit == -1) diffbit = i;
thing[i] = '0' + result->bit(i);
}
}
thing[result->size()] = 0;
GPRSLOG(1) <<"encoding error" <<LOGVAR2("cs",(int)debugDecoder.getCS())
<<LOGVAR(diffbit)
<<LOGVAR2("in:size",tobits.size()) <<LOGVAR2("out:size",result->size())
<<"\n"<<tobits
<<"\n"<<*result
<<"\n"<<thing;
} else {
//GPRSLOG(1) <<"encoding ok" <<LOGVAR2("cs",(int)debugDecoder.getCS());
}
#endif
return true;
}
// pats TODO: We should check for conflicts when we start up.
// pats TODO: Check for more than 31 ARFCNs and report.
// pats TODO: We should check for ARFCN+BSIC conflicts among the neighbors. That implies sucking the whole neighbor table in,
// but dont worry about now it because the whole thing should move to SR imho.
void PeerInterface::processNeighborParams(const struct sockaddr_in* peer, const char* message)
{
try {
// Create a unique id so we can tell if we send a message to ourself.
static uint32_t btsid = 0;
while (btsid == 0) { btsid = (uint32_t) random(); }
// (pat) This is the original format, which I now call version 1.
static const char rspFormatV1[] = "RSP NEIGHBOR_PARAMS %u %u"; // C0 BSIC
// (pat) This is the 3-2014 format. Extra args are ignored by older versions of OpenBTS.
//static const char rspFormat[] = "RSP NEIGHBOR_PARAMS %u %u %u %d %u %u %u"; // C0 BSIC uniqueID noise numArfcns tchavail tchtotal
LOG(DEBUG) << "got message " << message;
if (0 == strncmp(message,"REQ ",4)) {
// REQ? Send a RSP.
char rsp[150];
if (! strchr(message,'=')) {
// Send version 1.
snprintf(rsp, sizeof(rsp), rspFormatV1, gTRX.C0(), gBTS.BSIC());
} else {
// Send version 2.
int myNoise = gTRX.ARFCN(0)->getNoiseLevel();
unsigned tchTotal = gBTS.TCHTotal();
unsigned tchAvail = tchTotal - gBTS.TCHActive();
snprintf(rsp, sizeof(rsp), "RSP NEIGHBOR_PARAMS V=2 C0=%u BSIC=%u btsid=%u noise=%d arfcns=%d TchAvail=%u TchTotal=%u",
gTRX.C0(), gBTS.BSIC(), btsid, myNoise, (int)gConfig.getNum("GSM.Radio.ARFCNs"), tchAvail, tchTotal);
sendMessage(peer,rsp);
}
return;
}
if (0 == strncmp(message,"RSP ",4)) {
// RSP? Digest it.
NeighborEntry newentry;
if (! strchr(message,'=')) {
// Version 1 message.
int r = sscanf(message, rspFormatV1, &newentry.mC0, &newentry.mBSIC);
if (r != 2) {
logAlert(format("badly formatted peering message: %s",message));
return;
}
} else {
SimpleKeyValue keys;
keys.addItems(message + sizeof("RSP NEIGHBOR_PARAMS")); // sizeof is +1 which is ok - we are skipping the initial space.
{ bool valid;
unsigned neighborID = keys.getNum("btsid",valid);
if (valid && neighborID == btsid) {
LOG(ERR) << "BTS is in its own GSM.Neighbors list.";
return;
}
}
newentry.mC0 = keys.getNumOrBust("C0");
newentry.mBSIC = keys.getNumOrBust("BSIC");
newentry.mNoise = keys.getNumOrBust("noise");
newentry.mNumArfcns = keys.getNumOrBust("arfcns");
newentry.mTchAvail = keys.getNumOrBust("TchAvail");
newentry.mTchTotal = keys.getNumOrBust("TchTotal");
}
newentry.mIPAddress = sockaddr2string(peer, false);
if (newentry.mIPAddress.size() == 0) {
LOG(ERR) << "cannot parse peer socket address for"<<LOGVAR2("C0",newentry.mC0)<<LOGVAR2("BSIC",newentry.mBSIC);
return;
}
// Did the neighbor list change?
bool change = gNeighborTable.ntAddInfo(newentry);
// no change includes unsolicited RSP NEIGHBOR_PARAMS. drop it.
if (!change) return;
// It there a BCC conflict?
int ourBSIC = gBTS.BSIC();
if (newentry.mC0 == (int)gTRX.C0()) {
if (newentry.mBSIC == ourBSIC) {
logAlert(format("neighbor with matching ARFCN.C0 + BSIC [Base Station Identifier] codes: C0=%d BSIC=%u",newentry.mC0,newentry.mBSIC));
} else {
// Two BTS on the same ARFCN close enough to be neighbors, which is probably a bad idea, but legal.
// Is it worth an ALERT?
LOG(WARNING) << format("neighbor with matching ARFCN.C0 but different BSIC [Base Station Identifier] code: C0=%d, BSIC=%u, my BSIC=%u",
newentry.mC0,newentry.mBSIC,gTRX.C0());
}
}
// 3-2014: Warn for overlapping ARFCN use. Fixes ticket #857
int myC0 = gTRX.C0();
int myCEnd = myC0 + gConfig.getNum("GSM.Radio.ARFCNs") - 1;
int neighborCEnd = newentry.mC0 + newentry.mNumArfcns - 1;
bool overlap = myC0 <= neighborCEnd && myCEnd >= (int) newentry.mC0;
if (overlap) {
LOG(WARNING) << format("neighbor IP=%s BSIC=%d ARFCNs=%u to %d overlaps with this BTS ARFCNs=%d to %d",
newentry.mIPAddress.c_str(), newentry.mBSIC, newentry.mC0, neighborCEnd, myC0, myCEnd);
}
// Is there an NCC conflict?
// (pat) ARFCN-C0 (the one carrying BCCH) and BSIC consisting of NCC (Network Color Code) and BCC. (Base station Color Code)
int neighborNCC = newentry.mBSIC >> 3;
int NCCMaskBit = 1 << neighborNCC;
int ourNCCMask = gConfig.getNum("GSM.CellSelection.NCCsPermitted");
ourNCCMask |= 1 << gConfig.getNum("GSM.Identity.BSIC.NCC");
if ((NCCMaskBit & ourNCCMask) == 0) {
//LOG(ALERT) << "neighbor with NCC " << neighborNCC << " not in NCCsPermitted";
logAlert(format("neighbor with NCC=%u not in NCCsPermitted",neighborNCC));
}
// There was a change, so regenerate the beacon
gBTS.regenerateBeacon();
return;
}
LOG(ALERT) << "unrecognized Peering message: " << message;
} catch (SimpleKeyValueException &e) {
MachineStatus MTSMSMachine::machineRunState1(int state,const L3Frame*frame,const L3Message*l3msg, const SIP::DialogMessage*sipmsg)
{
// Step 1 Network->MS CP-DATA containing RP-DATA with message
// Step 2 MS->Network CP-ACK
// 4.11 6.2.2 State wait-to-send-RP-ACK, timer TR2M
// Step 3 MS->Network CP-DATA containing RP-ACK or RP-Error
// Step 4 Network->MS CP-ACK
// Network->SIP response.
PROCLOG2(DEBUG,state)<<LOGVAR(l3msg)<<LOGVAR(sipmsg)<<LOGVAR2("imsi",tran()->subscriber());
switch(state) {
case stateStart: {
// There is no dialog for a SMS initiated on this BTS.
if (getDialog() && getDialog()->isFinished()) {
// SIP side closed already.
// We can no longer inform the SIP side whether we succeed or not.
// Should we continue and deliver the message to the MS or not?
return MachineStatus::QuitTran(TermCause::Local(L3Cause::SMS_Timeout)); // could be a sip internal error?
}
timerStart(TR2M,TR2Mms,TimerAbortTran);
// Allocate Transaction Identifier
unsigned l3ti = channel()->chanGetContext(true)->mmGetNextTI();
tran()->setL3TI(l3ti);
setGSMState(CCState::SMSDelivering);
this->mRpduRef = random() % 255;
gReports.incr("OpenBTS.GSM.SMS.MTSMS.Start");
// pat 6-2014. We just send the ESTABLISH_REQUEST no matter what now.
// The LAPDm will respond with ESTABLISH_INDICATION immediately if
SAPI_t sap = getSmsSap();
//L3LogicalChannel *smschan = getSmsChannel();
//if (smschan->multiframeMode(3)) { goto step1; } // If already established.
// if (channel()->multiframeMode(sap)) { goto step1; } // If already established.
// Start ABM in SAP3.
//smschan->l3sendp(GSM::L3_ESTABLISH_REQUEST,SAPI3);
channel()->l3sendp(GSM::L3_ESTABLISH_REQUEST,sap);
// Wait for SAP3 ABM to connect.
// The next read on SAP3 should be the ESTABLISH primitive.
// This won't return NULL. It will throw an exception if it fails.
// (pat) WARNING: Previous code waited for a return ESTABLISH,
// but I think the l3sendp(ESTABLISH) will hang until this happens so it is now a no-op.
// delete getFrameSMS(LCH,GSM::ESTABLISH);
LOG(DEBUG) << "case start returning, after sending ESTABLISH";
return MachineStatusOK; // Wait for the ESTABLISH on the uplink.
}
// We use ESTABLISH_INDICATION instead of ESTABLISH_CONFIRM to indicate establishment.
// We would have to accept both ESTABLISH_CONFIRM and ESTABLISH_INDICATION here anyway in case
// SABM was started by us and handset simultaneously, so we just dont bother with making ESTABLISH_CONFIRM separate.
case L3CASE_PRIMITIVE(L3_ESTABLISH_INDICATION):
case L3CASE_PRIMITIVE(L3_ESTABLISH_CONFIRM): {
// Step 1
// Send the first message.
// CP-DATA, containing RP-DATA.
RPData rp_data;
int l3ti = getL3TI();
if (! createRPData(rp_data)) { // NULL can be returned
l3sendSms(CPData(l3ti,RPError(95,this->mRpduRef)));
// TODO: Is this correct?
// TODO: Make sure MachineStatusQuitTran sends a failure code to SIP.
if (getDialog()) getDialog()->MTSMSReply(400, "Bad Request");
return MachineStatus::QuitTran(TermCause::Local(L3Cause::SMS_Error));
}
CPData deliver(l3ti,rp_data);
PROCLOG(INFO) << "sending " << deliver;
// WORKING: MS Does not respond to this message.
// (pat) FIXME: The MS may send a DELIVER_REPORT which is discarded by parseTPDU.
l3sendSms(deliver);
LOG(DEBUG) << "case ESTABLISH returning, after receiving ESTABLISH";
return MachineStatusOK; // Wait for CP-ACK message.
}
// Step 2
// Get the CP-ACK.
case L3CASE_SMS(ACK): {
// FIXME -- Check reference and check for RPError.
return MachineStatusOK; // Now we are waiting for CP-DATA.
}
// Step 3
// Get CP-DATA containing RP-ACK and message reference.
case L3CASE_SMS(DATA): {
timerStop(TR2M);
PROCLOG(DEBUG) << "MTSMS: data from MS " << *l3msg;
// FIXME -- Check L3 TI.
// Parse to check for RP-ACK.
// We already called parsel3 on the message.
//CPData data;
//try {
// data.parse(*CM);
// LOG(DEBUG) << "CPData " << data;
//}
//catch (SMSReadError) {
// LOG(WARNING) << "SMS parsing failed (above L3)";
// // Cause 95, "semantically incorrect message".
// LCH->l2sendf(CPError(L3TI,95),3);
// throw UnexpectedMessage();
//}
//catch (GSM::L3ReadError) {
// LOG(WARNING) << "SMS parsing failed (in L3)";
// throw UnsupportedMessage();
//}
//delete CM;
const CPData *cpdata = dynamic_cast<typeof(cpdata)>(l3msg);
// FIXME -- Check SMS reference.
bool success = true;
if (cpdata->RPDU().MTI()!=RPMessage::Ack) {
PROCLOG(WARNING) << "unexpected RPDU " << cpdata->RPDU();
success = false;
}
gReports.incr("OpenBTS.GSM.SMS.MTSMS.Complete");
// Step 4
// Send CP-ACK to the MS.
PROCLOG(INFO) << "MTSMS: sending CPAck";
l3sendSms(CPAck(getL3TI()));
// Ack in SIP domain.
if (!getDialog()) {
LOG(DEBUG) << "No dialog found for MTSMS; could be welcome message, CLI SMS, or Dialog pre-destroyed error";
} else if (success) {
getDialog()->MTSMSReply(200,"OK");
} else {
getDialog()->MTSMSReply(400, "Bad Request");
}
LOG(DEBUG) << "case DATA returning";
return MachineStatus::QuitTran(TermCause::Local(L3Cause::SMS_Success)); // Finished.
}
default:
return unexpectedState(state,l3msg);
}
}
string SipMessage::text(bool verbose) const
{
std::ostringstream ss;
ss << "SipMessage(";
{ int code = smGetCode(); ss <<LOGVAR(code); }
if (!msmReqMethod.empty()) ss <<LOGVAR2("ReqMethod",msmReqMethod);
if (!msmReason.empty()) ss <<LOGVAR2("reason",msmReason);
if (!msmCSeqMethod.empty()) ss<<" CSeq="<<msmCSeqNum<< " "<<msmCSeqMethod;
if (!msmCallId.empty()) ss <<LOGVAR2("callid",msmCallId);
if (!msmReqUri.empty()) ss << LOGVAR2("ReqUri",msmReqUri);
{ string To = msmTo.value(); if (!To.empty()) ss << LOGVAR(To); }
{ string From = msmFrom.value(); if (!From.empty()) ss<<LOGVAR(From); }
if (!msmVias.empty()) ss <<LOGVAR2("Vias",msmVias);
if (!msmRoutes.empty()) ss <<LOGVAR2("Routes",msmRoutes);
if (!msmRecordRoutes.empty()) ss <<LOGVAR2("RecordRoutes",msmRecordRoutes);
if (!msmContactValue.empty()) ss <<LOGVAR2("Contact",msmContactValue);
//list<SipBody> msmBodies;
if (!msmContentType.empty()) ss<<LOGVAR2("ContentType",msmContentType);
if (!msmBody.empty()) ss<<LOGVAR2("Body",msmBody);
//if (!msmAuthenticateValue.empty()) ss<<LOGVARM(msmAuthenticateValue);
if (!msmAuthorizationValue.empty()) ss<<LOGVARM(msmAuthorizationValue);
for (SipParamList::const_iterator it = msmHeaders.begin(); it != msmHeaders.end(); it++) {
ss <<" header "<<it->mName <<"="<<it->mValue;
}
if (verbose) { ss << LOGVARM(msmContent); } else { ss << LOGVAR2("firstLine",smGetFirstLine()); }
ss << ")";
return ss.str();
}
// Return true if we send a block on the downlink.
bool PDCHL1Downlink::send1MsgFrame(
TBF *tbf, // The TBF sending the message, or NULL for an idle frame.
RLCDownlinkMessage *msg, // The message.
int makeres, // 0 = no res, 1 = optional res, 2 = required res.
MsgTransactionType mttype, // Type of reservation
unsigned *pcounter) // If non-null, incremented if a reservation is made.
{
if (! setMACFields(msg,mchParent,msg->mTBF,makeres,mttype,pcounter)) {
delete msg; // oh well.
return false; // This allows some other tbf to try to use this downlink block.
}
bool dummy = msg->mMessageType == RLCDownlinkMessage::PacketDownlinkDummyControlBlock;
bool idle = dummy && msg->isMacUnused();
if (idle && 0 == gConfig.getNum("GPRS.SendIdleFrames")) {
delete msg; // Let the transceiver send an idle frame.
return false; // This return value will not be checked.
}
if (tbf) { tbf->talkedDown(); }
// Convert to a BitVector. Messages always use CS-1 encoding.
BitVector tobits(RLCBlockSizeInBits[ChannelCodingCS1]);
msg->write(tobits);
// The possible downlink debug things we want to see are:
// 2: Only non-dummy messages.
// 32: include messages with non-idle MAC header, means mUSF or mSP.
// 1024: all messages including dummy ones.
if (GPRSDebug) {
if ((!dummy && (GPRSDebug&2)) || (!idle && (GPRSDebug&32)) || (GPRSDebug&1024)) {
ByteVector content(tobits);
GPRSLOG(2|32|1024) << "send1MsgFrame "<<parent()
<<" "<<msg->mTBF<< " "<<msg->str()
<< " " <<LOGVAR2("content",content);
// The res is unrelated to the message, and confusing, so dont print it:
//<<" "<<(res ? res->str() : "");
}
}
#if 0
// The below is what went out in release 3.0:
if (GPRSDebug & (1|32)) {
//RLCBlockReservation *res = mchParent->getReservation(gBSNNext);
//std::ostringstream ssres;
//if (res) ssres << res;
if (! idle || (GPRSDebug & 1024)) {
//ostringstream bits;
//tobits.hex(bits);
//GPRSLOG(1) << "send1MsgFrame "<<msg->mTBF<< " "<<msg->str() << "\nbits:"<<tobits.hexstr();
ByteVector content(tobits);
GPRSLOG(1) << "send1MsgFrame "<<parent()<<" "<<msg->mTBF<< " "<<msg->str() <<" "
<< LOGVAR2("content",content);
// This res is unrelated to the message, and confusing, so dont print it:
//<<" "<<(res ? res->str() : "");
} else if (msg->mUSF) {
GPRSLOG(32) << "send1MsgFrame "<<parent()<<" "<<msg->mTBF<< " "<<msg->str() <<" ";
//<<" "<<(res ? res->str() : "");
}
}
#endif
delete msg;
send1Frame(tobits,ChannelCodingCS1,idle);
return true;
}