State Machine Issue

 In SIP INFO we send the extra digits in "subsequentDigit:" section but in our case digits were missing inside SIP INFO
SIP INFO is used to transmitt the dialed digits.

As per logs we were able to observe that digit got missing because our state machine was in CC_WAIT_FOR_PLAT_RESP instead of CC_SECOND_DIAL because MSG_STOP_SIGNAL_REQ is triggered but  MSG_STOP_SIGNAL_RESP is not receiving hence it's stuck in CC_WAIT_FOR_PLAT_RESP.

[2021-12-03 18:22:01:958][WARN]msg: MSG_EVT_DETECTED_IND
[2021-12-03 18:22:01:958][DEBUG][pal_msghandler, 3239] pal_fn_voipManagerMsgHandler: MSG_EVT_DETECTED_IND Received FOR TERMINAL:1, item_id=2002
[2021-12-03 18:22:01:958][DEBUG][pal_msghandler, 5117] pal_fn_voipManagerMsgHandler: MG_E_Digit Received:2
[2021-12-03 18:22:01:959][DEBUG][pal_fsm, 19173] CC FSM:CC_WAIT_FOR_PLAT_RESP: Event Pal_en_digitReceived received for CallId:5 on Terminal:1 dNextState=35
[2021-12-03 18:22:01:959][DEBUG][pal_msghandler, 6964] Exit pal_fn_voipManagerMsgHandler.
[2021-12-03 18:22:01:960][NOTICE][pal_msghandler, 743] Enter pal_fn_msghandler msg_id=560 orig_mod_id:5
[2021-12-03 18:22:01:960][DEBUG][pal_msghandler, 3075] -- Enter pal_fn_voipManagerMsgHandler msg_id:[MSG_STOP_SIGNAL_RESP(560)]
[2021-12-03 18:22:01:961][WARN]msg: MSG_STOP_SIGNAL_RESP
[2021-12-03 18:22:01:961][NOTICE][pal_msghandler, 5640] Received MSG_STOP_SIGNAL_RESP for Terminal: 1, result=1, err_code=0
[2021-12-03 18:22:01:962][DEBUG][pal_fsm, 19173] CC FSM:CC_WAIT_FOR_PLAT_RESP: Event Pal_en_stopSignalRespRecv received for CallId:5 on Terminal:1 dNextState=35
[2021-12-03 18:22:01:962][DEBUG][pal_fsm, 25547] CC FSM:CC_SECOND_DIAL: Event Pal_en_stopSignalRespRecv received for CallId:5 on Terminal:1 in CC_SECOND_DIAL
[2021-12-03 18:22:01:962][DEBUG][pal_util, 10271] pal_fn_processPendingMsg: Enter pal_fn_processPendingMsg.
[2021-12-03 18:22:01:963][DEBUG][pal_util, 10277] pal_fn_processPendingMsg: pPendingMsgis NULL.
[2021-12-03 18:22:01:963][DEBUG][pal_msghandler, 6964] Exit pal_fn_voipManagerMsgHandler.

To solve this we had pending queue mechanism in our framework

Pal_ty_retVal pal_fn_ccWaitForPlatResponse(
    Pal_st_termprofile*       pTermProfile,
    Pal_st_callData*          pCallData,
    Pal_ty_callStateEvents dInputEvent,
    Pal_st_error*             pErr)
{

  case Pal_en_digitReceived:

        { 
         if (pCallContext->dCallControlState.dLastEventRecvd
                == Pal_en_digitReceived)
            {
                INFORMATIONAL_PRINT(VOIP_BRIEF_TRACE,
                                    "[pal_fsm, %u] "
                                    "CC FSM:CC_WAIT_FOR_PLAT_RESP: "
                                    "Pal_en_digitReceived is re-posted",
                                    __LINE__);
                pal_fn_savePendingMsg(pTermProfile, pCallData->pMsg,GLB_MSGQ, Pal_en_maximumEvent, pErr);
            }
            else if((pCallContext->dCallControlState.dLastEventRecvd
                == Pal_en_alertInfoInd) || (pCallContext->dCallControlState.dLastEventRecvd
                == Pal_en_infoRespRecv))   // For last 2 previous events were infoResp & alertInfoInd
            {

       //  voipMsgHeader_t *pMsgHeader = (voipMsgHeader_t *)pCallData->pMsg;

                INFORMATIONAL_PRINT(VOIP_BRIEF_TRACE,

                                    "[pal_fsm, %u] "

                                    "CC FSM:CC_WAIT_FOR_PLAT_RESP: "

                                    "Pal_en_digitReceived is re-posted",

                                    __LINE__);

                    if (pTermEvt->ppm_param.item_id == MG_0) // Digit(item_id) was getting altered hence again rectification

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_0;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_1)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_1;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_2)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_2;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_3)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_3;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_4)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_4;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_5)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_5;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_6)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_6;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_7)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_7;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_8)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_8;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_9)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_E_9;

                    }

               pal_fn_savePendingMsg(pTermProfile, pCallData->pMsg, GLB_MSGQ, Pal_en_maximumEvent, pErr); // Saving in Global message queue

            }   /* End of If (digitreceived==dLastEvent)*/

        }

        break;

Digit alteration happening just here

Pal_ty_void pal_fn_voipManagerMsgHandler(Pal_ty_pvoid pMsg)
{

     switch (pMsgHeader->msg_id)

    {  case  MSG_EVT_DETECTED_IND:

        {

            Pal_ty_s32bit dTermId = 0;

            Pal_ty_u32bit dLineId = INVALID_LINEID;/*modified by sjg for ANTmt44982*/

            Pal_st_termprofile* pTermProfile;

            Pal_ty_u32bit dCount = 0;

            Pal_st_callContext* pCallContext = Pal_co_null;

            msg_evt_detected_ind_t* pTermEvt =

                (msg_evt_detected_ind_t*)

                ((Pal_ty_char*)pMsg + sizeof(voipMsgHeader_t));

            g_pCallData->pPlatformData = (Pal_ty_pvoid)pTermEvt;

            dTermId = pTermEvt->ppm_param.term_id;

  INFORMATIONAL_PRINT(VOIP_DETAILED_TRACE,

                                        "[pal_msghandler, %u] %s: MG_E_Digit Received:%d",

                                        __LINE__, __FUNCTION__, pTermEvt->ppm_param.item_id - MG_E_ITEM_START);

                    if (pTermEvt->ppm_param.item_id == MG_E_0)  // Digit altered here

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_0; // Digit value changed

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_E_1)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_1;

                    }

                    else if (pTermEvt->ppm_param.item_id == MG_E_2)

                    {

                        pTermEvt->ppm_param.item_id = (mg_item_id_et)MG_2;

                    }

   Logs with digit alteration(pushing in pending queue)  :-

[2021-12-08 15:07:28:303][DEBUG][pal_msghandler, 3239] pal_fn_voipManagerMsgHandler: MSG_EVT_DETECTED_IND Received FOR TERMINAL:1, item_id=2008
[2021-12-08 15:07:28:303][DEBUG][pal_msghandler, 5117] pal_fn_voipManagerMsgHandler: MG_E_Digit Received:8
[2021-12-08 15:07:28:304][DEBUG][pal_fsm, 19173] CC FSM:CC_WAIT_FOR_PLAT_RESP: Event Pal_en_digitReceived received for CallId:2 on Terminal:1 dNextState=35
[2021-12-08 15:07:28:304][DEBUG][dp_fsm, 19393] CC FSM:CC_WAIT_FOR_PLAT_RESP: Event Pal_en_digitReceived received for CallId:2 on Terminal:1 dNextState=35 pCallContext->dCallControlState.dLastEventRecvd=141
[2021-12-08 15:07:28:305][DEBUG][pal_fsm, 19407] CC FSM:CC_WAIT_FOR_PLAT_RESP: Pal_en_digitReceived is re-posted
[2021-12-08 15:07:28:305][DEBUG][pal_msghandler, 6964] Exit pal_fn_voipManagerMsgHandler.
[2021-12-08 15:07:28:330][DEBUG]receive MSG_START_SIGNAL_REQ from PAL.
[2021-12-08 15:07:28:330][DEBUG]start_signal_req, term-id 1, tone/term_type 2
[2021-12-08 15:07:28:331][DEBUG]start_signal_req, tone-id 18
[2021-12-08 15:07:28:331][DEBUG]sipw_getToneSide, tone-side(PAL) 2,tone-side(SIPW) 1
[2021-12-08 15:07:28:332][DEBUG][SipWrapper.c][2002]enter get_tone_id
[2021-12-08 15:07:28:332][DEBUG][SipWrapper, 2006] Enter get_tone_id item_id=18
[2021-12-08 15:07:28:332][DEBUG][SipWrapper, 2014] get_tone_id: tone_id=GEN_TONE_DIAL_TONE(66)
[2021-12-08 15:07:28:333][DEBUG][SipWrapper.c][2451]normal exit get_tone_id tone id is 66
[2021-12-08 15:07:28:333][DEBUG][SipWrapper.c][2467]enter get_term_id
[2021-12-08 15:07:28:333][DEBUG][SipWrapper.c][2496]normal exit get_term_id term id is 1
[2021-12-08 15:07:28:334][DEBUG]start_signal_req, hookState 1
[2021-12-08 15:07:28:334][DEBUG]start_signal_req, guiToneDuration = 121, toneDuration = 121
[2021-12-08 15:07:28:335][DEBUG]sipw_playTone
[2021-12-08 15:07:28:335][DEBUG]Resource has allocated.
[2021-12-08 15:07:28:336][DEBUG]sipw_playTone termId 1, streamId 0x0, toneId 66, side 1, connId 0, dsp type 1, toneDuration = 121
[2021-12-08 15:07:28:336][INFO]gvhw_onu_adapter::playTone entry connId_i=0 toneIndex_i=66 side_i=1 stopSide=255
[2021-12-08 15:07:28:336][INFO]gvhw_onu_adapter::playTone ZL  entry connId_i=0 toneIndex_i=66 side_i=1 stopSide=255
[2021-12-08 15:07:28:337][INFO][MTKW]: genToneId = 66, toneName = DialT, mtkToneId=1
[2021-12-08 15:07:28:337][INFO][MTKW]: Exit get_Joint_MtkTone_Num genToneId = 66, jointNum=1
[2021-12-08 15:07:28:338][INFO]configure callWtgDelay patternId = 66
[2021-12-08 15:07:28:338][INFO]setCallWtgDelay(): The pattern ID is not call waiting related !
[2021-12-08 15:07:28:339][CRIT][MTKW] (0,0): start_tone. chanId = 1, toneId = 66, genside = 1, toneType = -1, toneRptCnt = -1, toneDuration = 0
[2021-12-08 15:07:28:340][CRIT][MTKW] (0): InfcId 0, mEvent EVENT_CODE_TONE_START, edge 0, dspTick 0
[2021-12-08 15:07:28:340][INFO][MTKW]:Interface (0), tone start detected
[2021-12-08 15:07:28:340][CRIT][MTKW]: eventProcess: report event [8192] with value [1] in lineId [1] to up layer
[2021-12-08 15:07:28:341][DEBUG]dialToneState is 1, flashNotDigit is 0, tone_i is 66
[2021-12-08 15:07:28:341][INFO]gvhw_onu_adapter::maskLineEvents entry connId_i=0 events_i=0.
 [2021-12-08 15:07:28:342][DEBUG]sipw_playTone success.
[2021-12-08 15:07:28:342][DEBUG]start_signal_req, term-id 1 tone id 66
[2021-12-08 15:07:28:342][DEBUG][SipWrapper.c][276]enter send_msg_to_upperlayer
[2021-12-08 15:07:28:343][DEBUG][SipWrapper.c][229]enter send_msg_to_ppu
[2021-12-08 15:07:28:343][DEBUG][SipWrapper.c][249]normal exit send_msg_to_ppu, ret value is 0
[2021-12-08 15:07:28:344][DEBUG][SipWrapper.c][280]normal exit send_msg_to_upperlayer, ret value is 0
[2021-12-08 15:07:28:344][DEBUG][SipWrapper.c][861]enter sipw_displayDspStreamByTerm
[2021-12-08 15:07:28:344][DEBUG][SipWrapper, 875] ** Enter sipw_displayDspStreamByTerm termId=1, dspNum=1, streamNum=1
[2021-12-08 15:07:28:345][DEBUG]pDsp: termId=1, streamId=0x0, connId=0, refCnt=1, type=1, AnalogToneId=66, NetToneId=255
[2021-12-08 15:07:28:345][DEBUG]    pStream: termId=1, streamId=0x2, T38Port=0, streamMode=1, voicePath=3
[2021-12-08 15:07:28:346][DEBUG]        pStreamDsp: termId=1, streamId=0x0, connId=0, refCnt=1, type=1, AnalogToneId=66, NetToneId=255
[2021-12-08 15:07:28:346][DEBUG][SipWrapper.c][913]normal exit sipw_displayDspStreamByTerm
[2021-12-08 15:07:28:350][CRIT][MTKW] (0): InfcId 0, mEvent EVENT_CODE_TONE, edge 1, dspTick 0
[2021-12-08 15:07:28:352][CRIT][sipudp,1]
Send the sip message:
source address: 40.0.0.168:5060;transport=udp
destination address: 40.0.0.156:5060;transport=udp
sip message: PRACK sip:133@40.0.0.156;user=phone SIP/2.0
Via: SIP/2.0/UDP 40.0.0.168:5060;branch=z9hG4bK*002e-00000013-0aeb-61b0ca30-7b9e4bb7
From: "101" <sip:101@40.0.0.156;user=phone>;tag=0082-00000002-0038
To: "133" <sip:133@40.0.0.156;user=phone>;tag=sbc0403nsr0vxv2-CC-27222
Call-ID: 00000002-6573ffff-000061b0ca2f-3c537600-77278fac@sipua
CSeq: 3 PRACK
Max-Forwards: 70
RAck: 2 1 INVITE
Content-Length: 0


[2021-12-08 15:07:28:360][CRIT][sipudp,1]
Rcvd sip message:
source address: 40.0.0.156:5060;transport=udp
destionation address: 40.0.0.168:5060;transport=udp
sip message: SIP/2.0 200 OK
Via: SIP/2.0/UDP 40.0.0.168:5060;branch=z9hG4bK*002e-00000013-0aeb-61b0ca30-7b9e4bb7
From: 101 <sip:101@40.0.0.156;user=phone>;tag=0082-00000002-0038
To: 133 <sip:133@40.0.0.156;user=phone>;tag=sbc0403nsr0vxv2-CC-27222
Call-ID: 00000002-6573ffff-000061b0ca2f-3c537600-77278fac@sipua
CSeq: 3 PRACK
Content-Length: 0


[2021-12-08 15:07:28:361][NOTICE][pal_msghandler, 743] Enter pal_fn_msghandler msg_id=558 orig_mod_id:5
[2021-12-08 15:07:28:362][DEBUG][pal_msghandler, 3075] -- Enter pal_fn_voipManagerMsgHandler msg_id:[MSG_START_SIGNAL_RESP(558)]
[2021-12-08 15:07:28:362][WARN]msg: MSG_START_SIGNAL_RESP
[2021-12-08 15:07:28:363][DEBUG][pal_msghandler, 5453] pal_fn_voipManagerMsgHandler: MSG_START_SIGNAL_RESP Event Received for dTermId=1, dLineId=0
[2021-12-08 15:07:28:363][NOTICE][pal_msghandler, 5466] Received MSG_START_SIGNAL_RESP for Terminal:1
[2021-12-08 15:07:28:363][DEBUG][pal_msghandler, 5516] pal_fn_voipManagerMsgHandler: dIsSet=0, dFSMtype=3
[2021-12-08 15:07:28:364][DEBUG][pal_fsm, 19173] CC FSM:CC_WAIT_FOR_PLAT_RESP: Event Pal_en_startSignalRespRecv received for CallId:2 on Terminal:1 dNextState=35
[2021-12-08 15:07:28:364][DEBUG][pal_fsm, 25558] CC FSM:CC_SECOND_DIAL: Event Pal_en_startSignalRespRecv received for CallId:2 on Terminal:1 in CC_SECOND_DIAL
[2021-12-08 15:07:28:365][DEBUG][pal_fsm, 25776] pal_fn_ccSecondDial: startTimer Pal_en_RingBackToneTimer dSecondDialDuration=121000 for dLineId=0
[2021-12-08 15:07:28:365][DEBUG][pal_timer, 286] pal_fn_startTimer: dTimerListId=2, dTimerValue=121000, dLineId=0, dCallId=2, dModuleId=2, dTimerType:[Pal_en_RingBackToneTimer(35)]
[2021-12-08 15:07:28:366][NOTICE][pal_timer, 262] pal_fn_startTimerExt: Timer Started: Cyclic=0, Type:[Pal_en_RingBackToneTimer], Value=121000, TimerList=2
[2021-12-08 15:07:28:366][NOTICE]    TimerID=15, addr=0x772d89b8, Lineid=0, Callid=2
[2021-12-08 15:07:28:366][DEBUG][pal_util, 10271] pal_fn_processPendingMsg: Enter pal_fn_processPendingMsg.
[2021-12-08 15:07:28:367][DEBUG][pal_util, 10155] pal_fn_sendUrgentMsg Send msg data, function:1999721368, id:20, length:164
[2021-12-08 15:07:28:367][DEBUG][pal_msghandler, 6964] Exit pal_fn_voipManagerMsgHandler.
[2021-12-08 15:07:28:368][NOTICE][pal_msghandler, 743] Enter pal_fn_msghandler msg_id=556 orig_mod_id:5
[2021-12-08 15:07:28:368][DEBUG][pal_msghandler, 3075] -- Enter pal_fn_voipManagerMsgHandler msg_id:[MSG_EVT_DETECTED_IND(556)]
[2021-12-08 15:07:28:369][WARN]msg: MSG_EVT_DETECTED_IND
[2021-12-08 15:07:28:370][DEBUG][pal_msghandler, 3239] pal_fn_voipManagerMsgHandler: MSG_EVT_DETECTED_IND Received FOR TERMINAL:1, item_id=256
[2021-12-08 15:07:28:371][DEBUG][pal_msghandler, 5117] pal_fn_voipManagerMsgHandler: MG_E_Digit Received:-1744
[2021-12-08 15:07:28:371][CRIT][PAL,/home/dbhowal/hg/G240GE/BBD_R2104/apps/private/appkgs/voip/dsl/source13/VoiceComPack/SIP_PAL/pal/pal_msghandler.cpp,5210]:Wrong Event received

           Logs with inverting the digit alteration(pushing in pending queue)  :-

[1970-03-14 01:23:02:423][DEBUG][pal_msghandler, 5129] pal_fn_voipManagerMsgHandler: MG_E_Digit Received:3

[1970-03-14 01:23:02:423][DEBUG][pal_fsm, 19173] CC FSM:CC_WAIT_FOR_PLAT_RESP: Event Pal_en_digitReceived received for CallId:18 on Terminal:1 dNextState=35

[1970-03-14 01:23:02:423][DEBUG][pal_fsm, 19392] CC FSM:CC_WAIT_FOR_PLAT_RESP: dLastEventRecvd: 141

[1970-03-14 01:23:02:423][DEBUG][pal_fsm, 19404] CC FSM:CC_WAIT_FOR_PLAT_RESP: Pal_en_digitReceived is re-posted

[1970-03-14 01:23:02:423][DEBUG][pal_fsm, 19477] CC FSM:CC_WAIT_FOR_PLAT_RESP: MG_E_Digit Received:3, Term id: 1

[1970-03-14 01:23:02:423][DEBUG][pal_util, 10220] pal_fn_savePendingMsg: pal_fn_savePendingMsg : pMsgHeader->length= 164 size of voipMsgHeader_t= 32.

[1970-03-14 01:23:02:423][DEBUG][pal_util, 10224] pal_fn_savePendingMsg: pal_fn_savePendingMsg : pMsgHeader 0xf6c864b8 pMsg = 0xf6c864b8.

[1970-03-14 01:23:02:423][DEBUG][pal_fsm, 10245] CC FSM:CC_WAIT_FOR_PLAT_RESP: MG_E_Digit Received:3

[1970-03-14 01:23:02:423][DEBUG][pal_msghandler, 6976] Exit pal_fn_voipManagerMsgHandler.

[1970-03-14 01:23:02:446][DEBUG]receive MSG_START_SIGNAL_REQ from PAL.

[1970-03-14 01:23:02:446][DEBUG]start_signal_req, term-id 1, tone/term_type 2

[1970-03-14 01:23:02:447][DEBUG]start_signal_req, tone-id 18

[1970-03-14 01:23:02:447][DEBUG]sipw_getToneSide, tone-side(PAL) 2,tone-side(SIPW) 1

[1970-03-14 01:23:02:447][DEBUG][SipWrapper.c][2002]enter get_tone_id

[1970-03-14 01:23:02:447][DEBUG][SipWrapper, 2006] Enter get_tone_id item_id=18

[1970-03-14 01:23:02:447][DEBUG][SipWrapper, 2014] get_tone_id: tone_id=GEN_TONE_DIAL_TONE(66)

[1970-03-14 01:23:02:447][DEBUG][SipWrapper.c][2451]normal exit get_tone_id tone id is 66

[1970-03-14 01:23:02:447][DEBUG][SipWrapper.c][2467]enter get_term_id

[1970-03-14 01:23:02:447][DEBUG][SipWrapper.c][2496]normal exit get_term_id term id is 1

[1970-03-14 01:23:02:447][DEBUG]start_signal_req, hookState 1

[1970-03-14 01:23:02:447][DEBUG]start_signal_req, guiToneDuration = 121, toneDuration = 121

[1970-03-14 01:23:02:447][DEBUG]sipw_playTone

[1970-03-14 01:23:02:447][DEBUG]Resource has allocated.

[1970-03-14 01:23:02:447][DEBUG]sipw_playTone termId 1, streamId 0x0, toneId 66, side 1, connId 0, dsp type 1, toneDuration = 121

[1970-03-14 01:23:02:447][DEBUG]dialToneState is 1, flashNotDigit is 0, tone_i is 66

[1970-03-14 01:23:02:447][DEBUG]sipw_playTone success.

[1970-03-14 01:23:02:447][DEBUG]start_signal_req, term-id 1 tone id 66

[1970-03-14 01:23:02:447][DEBUG][SipWrapper.c][276]enter send_msg_to_upperlayer

[1970-03-14 01:23:02:447][DEBUG][SipWrapper.c][229]enter send_msg_to_ppu

[1970-03-14 01:23:02:447][DEBUG][SipWrapper.c][249]normal exit send_msg_to_ppu, ret value is 0

[1970-03-14 01:23:02:448][DEBUG][SipWrapper.c][280]normal exit send_msg_to_upperlayer, ret value is 0

[1970-03-14 01:23:02:448][DEBUG][SipWrapper.c][861]enter sipw_displayDspStreamByTerm

[1970-03-14 01:23:02:448][DEBUG][SipWrapper, 875] ** Enter sipw_displayDspStreamByTerm termId=1, dspNum=1, streamNum=1

[1970-03-14 01:23:02:448][DEBUG]pDsp: termId=1, streamId=0x0, connId=0, refCnt=1, type=1, AnalogToneId=66, NetToneId=255

[1970-03-14 01:23:02:448][DEBUG]    pStream: termId=1, streamId=0x12, T38Port=0, streamMode=1, voicePath=3

[1970-03-14 01:23:02:448][DEBUG]        pStreamDsp: termId=1, streamId=0x0, connId=0, refCnt=1, type=1, AnalogToneId=66, NetToneId=255

[1970-03-14 01:23:02:448][DEBUG][SipWrapper.c][913]normal exit sipw_displayDspStreamByTerm

[1970-03-14 01:23:02:461][NOTICE][pal_msghandler, 743] Enter pal_fn_msghandler msg_id=558 orig_mod_id:5

[1970-03-14 01:23:02:462][DEBUG][pal_msghandler, 2994] -- Enter pal_fn_voipManagerMsgHandler Message Length = 88 , pMsg Memory=0xf6c865c0

[1970-03-14 01:23:02:462][DEBUG][pal_msghandler, 3087] -- Enter pal_fn_voipManagerMsgHandler msg_id:[MSG_START_SIGNAL_RESP(558)]

[1970-03-14 01:23:02:462][WARN]msg: MSG_START_SIGNAL_RESP

[1970-03-14 01:23:02:462][DEBUG][pal_msghandler, 5465] pal_fn_voipManagerMsgHandler: MSG_START_SIGNAL_RESP Event Received for dTermId=1, dLineId=0

[1970-03-14 01:23:02:462][NOTICE][pal_msghandler, 5478] Received MSG_START_SIGNAL_RESP for Terminal:1

[1970-03-14 01:23:02:462][DEBUG][pal_msghandler, 5528] pal_fn_voipManagerMsgHandler: dIsSet=0, dFSMtype=3

[1970-03-14 01:23:02:462][DEBUG][pal_fsm, 19173] CC FSM:CC_WAIT_FOR_PLAT_RESP: Event Pal_en_startSignalRespRecv received for CallId:18 on Terminal:1 dNextState=35

[1970-03-14 01:23:02:462][DEBUG][pal_fsm, 25630] CC FSM:CC_SECOND_DIAL: Event Pal_en_startSignalRespRecv received for CallId:18 on Terminal:1 in CC_SECOND_DIAL

[1970-03-14 01:23:02:462][DEBUG][pal_fsm, 25848] pal_fn_ccSecondDial: startTimer Pal_en_RingBackToneTimer dSecondDialDuration=121000 for dLineId=0

[1970-03-14 01:23:02:462][DEBUG][pal_timer, 286] pal_fn_startTimer: dTimerListId=2, dTimerValue=121000, dLineId=0, dCallId=18, dModuleId=2, dTimerType:[Pal_en_RingBackToneTimer(35)]

[1970-03-14 01:23:02:462][NOTICE][pal_timer, 262] pal_fn_startTimerExt: Timer Started: Cyclic=0, Type:[Pal_en_RingBackToneTimer], Value=121000, TimerList=2

[1970-03-14 01:23:02:462][NOTICE]    TimerID=24, addr=0xf6c4f7b0, Lineid=0, Callid=18

[1970-03-14 01:23:02:462][DEBUG][pal_util, 10290] pal_fn_processPendingMsg: Enter pal_fn_processPendingMsg.

[1970-03-14 01:23:02:463][DEBUG][pal_util, 10307] pal_fn_processPendingMsg: pPendingMsg Length id 164.

[1970-03-14 01:23:02:463][DEBUG][pal_fsm, 10315] CC FSM:CC_WAIT_FOR_PLAT_RESP: MG_E_Digit Received:3

[1970-03-14 01:23:02:463][DEBUG][pal_util, 10155] pal_fn_sendUrgentMsg Send msg data, function:-154639704, id:20, length:164

[1970-03-14 01:23:02:463][DEBUG][pal_msghandler, 6976] Exit pal_fn_voipManagerMsgHandler.

[1970-03-14 01:23:02:463][NOTICE][pal_msghandler, 743] Enter pal_fn_msghandler msg_id=556 orig_mod_id:5

[1970-03-14 01:23:02:463][DEBUG][pal_msghandler, 2994] -- Enter pal_fn_voipManagerMsgHandler Message Length = 164 , pMsg Memory=0xf6c862a8

[1970-03-14 01:23:02:463][DEBUG][pal_msghandler, 3087] -- Enter pal_fn_voipManagerMsgHandler msg_id:[MSG_EVT_DETECTED_IND(556)]

[1970-03-14 01:23:02:463][WARN]msg: MSG_EVT_DETECTED_IND

[1970-03-14 01:23:02:463][DEBUG][pal_msghandler, 3251] pal_fn_voipManagerMsgHandler: MSG_EVT_DETECTED_IND Received FOR TERMINAL:1, item_id=2003

[1970-03-14 01:23:02:463][DEBUG][pal_msghandler, 5129] pal_fn_voipManagerMsgHandler: MG_E_Digit Received:3