2 Replies Latest reply on Mar 6, 2018 7:36 AM by mhemstreet

    RTP Errors from FXO interface

    mhemstreet New Member

      Customers unit just started experiencing this issue.  Calls come in from FXO ports and I can see them ringing into the AutoAttendart (700) or an individual extension (when I manually changed it from 700 to 210 for testing).  Getting the following debugs and just need help making heads\tails of the information.

       

       

      NV7100#

      13:53:02.897 TM.T03 01 Idle - Tism_seize()

      13:53:02.897 TM.T03 01 Idle -> Active

      13:53:02.898 TA.T03 01 TAIdle               rcvd: appearance on from TM

      13:53:02.898 TA.T03 01 State change      >> TAIdle->TAAppearance (TAS_Active)

      13:53:02.898 TM.T03 01 Active - tachg_Active

      13:53:02.899 TM.T03 01 Active -> GetCID

      13:53:02.899 TONESERVICES.EVENTS fxo 1/1 - empty - Caller-ID Detection: Request resource

      13:53:02.899 TONESERVICES.EVENTS unknown - fxs 0/1.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.900 TONESERVICES.EVENTS unknown - fxs 0/2.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.900 TONESERVICES.EVENTS unknown - fxo 0/1.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.900 TONESERVICES.EVENTS unknown - fxo 0/2.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.900 TONESERVICES.EVENTS unknown - fxo 1/1.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.900 TONESERVICES.EVENTS unknown - fxo 1/2.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.901 TONESERVICES.EVENTS unknown - fxo 1/3.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.901 TONESERVICES.EVENTS unknown - fxo 1/4.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.901 TONESERVICES.EVENTS unknown - fxo 2/1.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.901 TONESERVICES.EVENTS unknown - fxo 2/2.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.901 TONESERVICES.EVENTS unknown - fxo 2/3.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.901 TONESERVICES.EVENTS unknown - fxo 2/4.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:02.902 TONESERVICES.EVENTS fxo 1/1 - empty - Caller-ID Detection: No DSP channel could be allocated for the resource

      13:53:02 TRKPORT.01:01 01:01  Ringing

      2018.03.05 13:53:02 FXO.1/1 ringing on 10706512 ms

      2018.03.05 13:53:02 FXO.1/1 FxoPortStateOnhookReverse -> FxoPortStateRinging 10706512 ms

      2018.03.05 13:53:04 FXO.1/1 ringing off 10708492 ms

      2018.03.05 13:53:04 FXO.1/1 FxoPortStateRinging -> FxoPortStateOnhook 10708492 ms

      13:53:04 TRKPORT.01:01 01:01  Reverse Loop Current Feed

      2018.03.05 13:53:04 FXO.1/1 FxoPortStateOnhook -> FxoPortStateOnhookReverse 10708558 ms

      13:53:08.902 TM.T03 01 GetCID - Tism_getCIDResponse(FAIL)

      13:53:08.902 TM.T03 01 GetCID -> Calling

      13:53:08.902 TA.T03 01 TAAppearance         rcvd: inboundCall from TM

      13:53:08.903 TA.T03 01 State change      >> TAAppearance->TAInboundCall (TAS_Calling)

      13:53:08.903 TA.T03 01 DID not enabled - using trunk-number: 700

      13:53:08.903 TA.T03 01 TAAppearance         sent: call to SB

      13:53:08.903 SB.CALL 47 Idle                 Called the call routine with 700

      13:53:08.904 SB.CCM isMappable:

      13:53:08.904 SB.CCM  :  Call Struct 0x5e4f410 :   Call-ID = 47

      13:53:08.904 SB.CCM  :  Org Acct = T03    Dst Acct = AutoAttendantAcct

      13:53:08.904 SB.CCM  :  Org Port ID = 1/1.0   Dst Port ID = 0/0.0

      13:53:08.904 SB.CCM  :  Org TID = Fxo   Dst TID =

      13:53:08.904 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

      13:53:08.905 SB.CCM isMappable: Unable to reserve RTP Channel

      13:53:08.905 SB.CALL 47 Idle                 Call sent from T03 to AutoAttendantAcct (700)

      13:53:08.906 SB.CALL 47 State change      >> Idle->Delivering

      13:53:08.906 RTP.MANAGER fxo 1/1 - empty - RTP: Request resource

      13:53:08.906 RTP.MANAGER unknown - fxs 0/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.906 RTP.MANAGER unknown - fxs 0/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.907 RTP.MANAGER unknown - fxo 0/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.907 RTP.MANAGER unknown - fxo 0/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.907 RTP.MANAGER unknown - fxo 1/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.907 RTP.MANAGER unknown - fxo 1/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.907 RTP.MANAGER unknown - fxo 1/3.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.908 RTP.MANAGER unknown - fxo 1/4.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.908 RTP.MANAGER unknown - fxo 2/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.908 RTP.MANAGER unknown - fxo 2/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.908 RTP.MANAGER unknown - fxo 2/3.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.908 RTP.MANAGER unknown - fxo 2/4.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:53:08.908 RTP.MANAGER fxo 1/1 - empty - RTP: No DSP channel could be allocated for the resource

      13:53:08.909 TA.T03 01 TAInboundCall        CallResp event accepted

      13:53:08.909 TA.T03 01 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

      13:53:08.909 AUTOATTENDANT.ACCT  Cleared Due to RTP Resource Flag

      13:53:08.909 SB.CALL 47 Delivering           Called the clearCall routine from Delivering

      13:53:08.909 SB.CALL 47 Delivering           Call Cleared on call from AutoAttendantAcct to T03

      13:53:08.910 SB.CALL 47 State change      >> Delivering->Clearing

      13:53:08.910 TA.T03 01 TAConnectWaitIn      ClearCall event accepted

      13:53:08.910 TA.T03 01 State change      >> TAConnectWaitIn->TAClearingComplete (TAS_Clearing)

      13:53:08.910 TM.T03 01 Calling - tachg_Clearing

      13:53:08.911 TM.T03 01 Calling -> FarEndAbandon

      13:53:08.911 SB.CALL 47 Clearing             Called the clearResponse routine

      13:53:08.911 SB.CALL 47 State change      >> Clearing->CallIdlePending

      13:53:08.911 SB.CCM release:

      13:53:08.911 SB.CCM  :  Call Struct 0x5e4f410 :   Call-ID = 47

      13:53:08.911 SB.CCM  :  Org Acct = T03    Dst Acct = AutoAttendantAcct

      13:53:08.912 SB.CCM  :  Org Port ID = 1/1.0   Dst Port ID = 0/0.0

      13:53:08.912 SB.CCM  :  Org TID = Fxo   Dst TID = PbxVirtual

      13:53:08.912 SB.CCM release: Call Connection Type is TDM_TO_RTP

      13:53:08.912 SB.CALL 47 CallIdlePending      ClearResponse sent from T03 to AutoAttendantAcct

      13:53:08.912 AUTOATTENDANT.ACCT ERROR! clearResponse ignored

      13:53:08 TRKPORT.01:01 01:01  Ringing

      2018.03.05 13:53:08 SB.CALL 47 RTP resource unavailable or SDP negotiation failed. Call from () to (700).

      2018.03.05 13:53:08 FXO.1/1 ringing on 10712518 ms

      2018.03.05 13:53:08 FXO.1/1 FxoPortStateOnhookReverse -> FxoPortStateRinging 10712518 ms

      2018.03.05 13:53:09 SMDR 47         03/05/2018 13:53:08      0.0 0    E  01/01                                 00/00 AutoAttendantAc 700             0 N

      2018.03.05 13:53:10 FXO.1/1 ringing off 10714498 ms

      2018.03.05 13:53:10 FXO.1/1 FxoPortStateRinging -> FxoPortStateOnhook 10714498 ms

      13:53:10 TRKPORT.01:01 01:01  Reverse Loop Current Feed

      2018.03.05 13:53:10 FXO.1/1 FxoPortStateOnhook -> FxoPortStateOnhookReverse 10714564 ms

      13:53:14 TRKPORT.01:01 01:01  Ringing

      2018.03.05 13:53:14 FXO.1/1 ringing on 10718524 ms

      2018.03.05 13:53:14 FXO.1/1 FxoPortStateOnhookReverse -> FxoPortStateRinging 10718524 ms

      2018.03.05 13:53:16 FXO.1/1 ringing off 10720438 ms

      2018.03.05 13:53:16 FXO.1/1 FxoPortStateRinging -> FxoPortStateOnhook 10720438 ms

      13:53:16 TRKPORT.01:01 01:01  Reverse Loop Current Feed

      2018.03.05 13:53:16 FXO.1/1 FxoPortStateOnhook -> FxoPortStateOnhookReverse 10720504 ms

      13:53:20 TRKPORT.01:01 01:01  Ringing

      2018.03.05 13:53:20 FXO.1/1 ringing on 10724464 ms

      2018.03.05 13:53:20 FXO.1/1 FxoPortStateOnhookReverse -> FxoPortStateRinging 10724464 ms

      2018.03.05 13:53:22 FXO.1/1 ringing off 10726444 ms

      2018.03.05 13:53:22 FXO.1/1 FxoPortStateRinging -> FxoPortStateOnhook 10726444 ms

      13:53:22 TRKPORT.01:01 01:01  Reverse Loop Current Feed

      2018.03.05 13:53:22 FXO.1/1 FxoPortStateOnhook -> FxoPortStateOnhookReverse 10726510 ms

      13:53:23.918 TM.T03 01 FarEndAbandon - sendBusyTimerExpired()

      13:53:23.918 TM.T03 01 FarEndAbandon -> SendBusyTone

      13:53:23.919 TONESERVICES.EVENTS fxo 1/1 - empty - Busy Generation: Request resource

      13:53:23.919 TONESERVICES.EVENTS fxo 1/1 - fxo 1/1.1 - Busy Generation: DSP channel allocated for the resource

      13:53:23.919 TONESERVICES.EVENTS fxo 1/1 - fxo 1/1.1 - Busy Generation: constructed

      13:53:23.919 TONESERVICES.EVENTS fxo 1/1 - fxo 1/1.1 - Busy Generation: starting

      13:53:23.919 TONESERVICES.EVENTS fxo 1/1 - fxo 1/1.1 - Busy Generation: TDM map

      2018.03.05 13:53:23 FXO.1/1 offhook 10727523 ms

      2018.03.05 13:53:23 FXO.1/1 FxoPortStateOnhookReverse -> FxoPortStateOffhook 10727523 ms

      13:53:24 TRKPORT.01:01 01:01  Reverse Loop Current Feed

      2018.03.05 13:53:24 FXO.1/1 reverse battery 10727753 ms

      2018.03.05 13:53:24 FXO.1/1 FxoPortStateOffhook -> FxoPortStateOffhookReverse 10727753 ms

      13:53:24.219 TM.T03 01 ERROR! SendBusyTone - offhookResponse() ignored

      13:53:24.721 TONESERVICES.EVENTS fxo 1/1 - empty - Bridged Dialtone Detector: Request resource

      13:53:24.721 TONESERVICES.EVENTS unknown - fxs 0/1.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.721 TONESERVICES.EVENTS unknown - fxs 0/2.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.722 TONESERVICES.EVENTS unknown - fxo 0/1.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.722 TONESERVICES.EVENTS unknown - fxo 0/2.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.722 TONESERVICES.EVENTS fxo 1/1 - fxo 1/1.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 1, 2, 0, 0

      13:53:24.722 TONESERVICES.EVENTS unknown - fxo 1/2.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.722 TONESERVICES.EVENTS unknown - fxo 1/3.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.722 TONESERVICES.EVENTS unknown - fxo 1/4.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.723 TONESERVICES.EVENTS unknown - fxo 2/1.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.723 TONESERVICES.EVENTS unknown - fxo 2/2.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.723 TONESERVICES.EVENTS unknown - fxo 2/3.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.723 TONESERVICES.EVENTS unknown - fxo 2/4.1 - Bridged Dialtone Detector: debug info: , 30, 0, 0, 0, 0, 0

      13:53:24.723 TONESERVICES.EVENTS fxo 1/1 - empty - Bridged Dialtone Detector: No DSP channel could be allocated for the resource

      13:53:28.723 TM.T03 01 ERROR! SendBusyTone - offhookResponse() ignored

      13:53:31 TRKPORT.01:01 01:01  Loop Current Feed Open

      2018.03.05 13:53:31 FXO.1/1 loop feed open 10735475 ms

      2018.03.05 13:53:31 FXO.1/1 FxoPortStateOffhookReverse -> FxoPortStateLoopfeedOpen 10735475 ms

      13:53:32.375 TM.T03 01 SendBusyTone - Tism_clear()

      13:53:32.375 TM.T03 01 SendBusyTone -> Clearing

      13:53:32.375 TONESERVICES.EVENTS fxo 1/1 - fxo 1/1.1 - Busy Generation: stopping

      13:53:32.375 TONESERVICES.EVENTS fxo 1/1 - fxo 1/1.1 - Busy Generation: TDM unmap

      13:53:32.376 RTP.CHANNEL fxo 1/1 - fxo 1/1.1 - Busy Generation: releasing RTP resource

      13:53:32.376 TONESERVICES.EVENTS fxo 1/1 - fxo 1/1.1 - Busy Generation: release

      13:53:32 TRKPORT.01:01 01:01  LCFO - far end disconnect

      2018.03.05 13:53:32 FXO.1/1 onhook 10735976 ms

      2018.03.05 13:53:32 FXO.1/1 FxoPortStateOnhookPending -> FxoPortStateOnhook 10735976 ms

      2018.03.05 13:53:32 FXO.1/1 FxoPortStateOnhookPending -> FxoPortStateOnhook 10735976 ms

      13:53:32 TRKPORT.01:01 01:01  Loop Current Feed

      2018.03.05 13:53:32 FXO.1/1 FxoPortStateOnhook -> FxoPortStateOnhookNormal 10736036 ms

      13:53:32 TRKPORT.01:01 01:01  Reverse Loop Current Feed

      2018.03.05 13:53:32 FXO.1/1 FxoPortStateOnhookNormal -> FxoPortStateOnhookReverse 10736366 ms

      13:53:32.976 TM.T03 01 Clearing - Tism_clearResponse(PASS)

      13:53:32.976 TM.T03 01 Clearing -> Idle

      13:53:32.976 TM.T03 01 Idle - Tism_idleResponse(PASS)

      13:53:32.976 TA.T03 01 TAClearingComplete   rcvd: appearance off from TM

      13:53:32.976 TA.T03 01 TAClearingComplete   Clear Local Variables

      13:53:32.977 TA.T03 01 State change      >> TAClearingComplete->TAIdle (TAS_Idle)

      13:53:32.977 TM.T03 01 Idle - tachg_Idle

      2018.03.05 13:53:32 FXO.1/1 FxoPortStateOnhookReverse::onhook() 10736577 ms

      13:53:38.926 TM.T03 01 Idle - TMTimerExpired() no action required

      13:53:55.623 TM.T09 01 Idle - Tism_seize()

      13:53:55.623 TM.T09 01 Idle -> Active

      13:53:55.624 TA.T09 01 TAIdle               rcvd: appearance on from TM

      13:53:55.624 TA.T09 01 State change      >> TAIdle->TAAppearance (TAS_Active)

      13:53:55.624 TM.T09 01 Active - tachg_Active

      13:53:55.625 TM.T09 01 Active -> GetCID

      13:53:55.625 TONESERVICES.EVENTS fxo 2/3 - empty - Caller-ID Detection: Request resource

      13:53:55.625 TONESERVICES.EVENTS unknown - fxs 0/1.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.625 TONESERVICES.EVENTS unknown - fxs 0/2.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.626 TONESERVICES.EVENTS unknown - fxo 0/1.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.626 TONESERVICES.EVENTS unknown - fxo 0/2.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.626 TONESERVICES.EVENTS unknown - fxo 1/1.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.626 TONESERVICES.EVENTS unknown - fxo 1/2.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.626 TONESERVICES.EVENTS unknown - fxo 1/3.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.627 TONESERVICES.EVENTS unknown - fxo 1/4.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.627 TONESERVICES.EVENTS unknown - fxo 2/1.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.627 TONESERVICES.EVENTS unknown - fxo 2/2.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.627 TONESERVICES.EVENTS unknown - fxo 2/3.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.627 TONESERVICES.EVENTS unknown - fxo 2/4.1 - Caller-ID Detection: debug info: , 30, 0, 0, 0, 0, 0

      13:53:55.627 TONESERVICES.EVENTS fxo 2/3 - empty - Caller-ID Detection: No DSP channel could be allocated for the resource

      13:53:55 TRKPORT.02:03 02:03  Ringing

      2018.03.05 13:53:55 FXO.2/3 ringing on 10759214 ms

      2018.03.05 13:53:55 FXO.2/3 FxoPortStateOnhookReverse -> FxoPortStateRinging 10759214 ms

      2018.03.05 13:53:57 FXO.2/3 ringing off 10761194 ms

      2018.03.05 13:53:57 FXO.2/3 FxoPortStateRinging -> FxoPortStateOnhook 10761194 ms

      13:53:57 TRKPORT.02:03 02:03  Reverse Loop Current Feed

      2018.03.05 13:53:57 FXO.2/3 FxoPortStateOnhook -> FxoPortStateOnhookReverse 10761260 ms

      13:54:01.628 TM.T09 01 GetCID - Tism_getCIDResponse(FAIL)

      13:54:01.628 TM.T09 01 GetCID -> Calling

      13:54:01.628 TA.T09 01 TAAppearance         rcvd: inboundCall from TM

      13:54:01.628 TA.T09 01 State change      >> TAAppearance->TAInboundCall (TAS_Calling)

      13:54:01.628 TA.T09 01 DID not enabled - using trunk-number: 600

      13:54:01.629 TA.T09 01 TAAppearance         sent: call to SB

      13:54:01.629 SB.CALL 48 Idle                 Called the call routine with 600

      13:54:01.629 SB.CCM isMappable:

      13:54:01.629 SB.CCM  :  Call Struct 0x5d84210 :   Call-ID = 48

      13:54:01.629 SB.CCM  :  Org Acct = T09    Dst Acct = 600

      13:54:01.630 SB.CCM  :  Org Port ID = 2/3.0   Dst Port ID = 0/0.0

      13:54:01.630 SB.CCM  :  Org TID = Fxo   Dst TID =

      13:54:01.630 SB.CCM isMappable: Call Connection Type is TDM_TO_RG

      13:54:01.631 SB.CCM isMappable: Unable to reserve RTP Channel

      13:54:01.631 SB.CALL 48 Idle                 Call sent from T09 to 600 (600)

      13:54:01.631 SB.CALL 48 State change      >> Idle->Delivering

      13:54:01.631 RTP.MANAGER virtual 0/0.0 - empty - RTP: Request resource

      13:54:01.631 RTP.MANAGER unknown - fxs 0/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.632 RTP.MANAGER unknown - fxs 0/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.632 RTP.MANAGER unknown - fxo 0/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.632 RTP.MANAGER unknown - fxo 0/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.632 RTP.MANAGER unknown - fxo 1/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.633 RTP.MANAGER unknown - fxo 1/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.633 RTP.MANAGER unknown - fxo 1/3.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.633 RTP.MANAGER unknown - fxo 1/4.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.633 RTP.MANAGER unknown - fxo 2/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.633 RTP.MANAGER unknown - fxo 2/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.634 RTP.MANAGER unknown - fxo 2/3.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.634 RTP.MANAGER unknown - fxo 2/4.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.634 RTP.MANAGER virtual 0/0.0 - empty - RTP: No DSP channel could be allocated for the resource

      13:54:01.634 TA.T09 01 TAInboundCall        CallResp event accepted

      13:54:01.634 TA.T09 01 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

      13:54:01.635 SB.CALL 48 Delivering           Called the clearCall routine from Delivering

      13:54:01.635 SB.CALL 48 Delivering           Call Cleared on call from 600 to T09

      13:54:01.635 SB.CALL 48 State change      >> Delivering->Clearing

      13:54:01.635 TA.T09 01 TAConnectWaitIn      ClearCall event accepted

      13:54:01.635 TA.T09 01 TAConnectWaitIn      Processing a forward

      13:54:01.636 TA.T09 01 TAConnectWaitIn      sent: call to SB

      13:54:01.636 TA.T09 01 State change      >> TAConnectWaitIn->TAInboundCall (TAS_Calling)

      13:54:01.636 SB.CALL 48 Clearing             Called the clearResponse routine

      13:54:01.636 SB.CALL 48 State change      >> Clearing->CallIdlePending

      13:54:01.636 SB.CCM release:

      13:54:01.637 SB.CCM  :  Call Struct 0x5d84210 :   Call-ID = 48

      13:54:01.637 SB.CCM  :  Org Acct = T09    Dst Acct = 600

      13:54:01.637 SB.CCM  :  Org Port ID = 2/3.0   Dst Port ID = 0/0.0

      13:54:01.637 SB.CCM  :  Org TID = Fxo   Dst TID = PbxRingGroup

      13:54:01.637 SB.CCM release: Call Connection Type is TDM_TO_RG

      13:54:01.637 SB.CALL 48 CallIdlePending      ClearResponse sent from T09 to 600

      13:54:01.638 SB.CALL 49 Idle                 Called the call routine with 0

      13:54:01.638 SB.CCM isMappable:

      13:54:01.638 SB.CCM  :  Call Struct 0x5d99010 :   Call-ID = 49

      13:54:01.638 SB.CCM  :  Org Acct = T09    Dst Acct = 0

      13:54:01.638 SB.CCM  :  Org Port ID = 2/3.0   Dst Port ID = 0/0.0

      13:54:01.638 SB.CCM  :  Org TID = Fxo   Dst TID =

      13:54:01.639 SB.CCM isMappable: Call Connection Type is TDM_TO_RG

      13:54:01.639 SB.CCM isMappable: Unable to reserve RTP Channel

      13:54:01.639 SB.CALL 49 Idle                 Call sent from T09 to 0 (0)

      13:54:01.640 SB.CALL 49 State change      >> Idle->Delivering

      13:54:01.640 RTP.MANAGER virtual 0/0.0 - empty - RTP: Request resource

      13:54:01.640 RTP.MANAGER unknown - fxs 0/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.640 RTP.MANAGER unknown - fxs 0/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.640 RTP.MANAGER unknown - fxo 0/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.641 RTP.MANAGER unknown - fxo 0/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.641 RTP.MANAGER unknown - fxo 1/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.641 RTP.MANAGER unknown - fxo 1/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.641 RTP.MANAGER unknown - fxo 1/3.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.641 RTP.MANAGER unknown - fxo 1/4.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.642 RTP.MANAGER unknown - fxo 2/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.642 RTP.MANAGER unknown - fxo 2/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.642 RTP.MANAGER unknown - fxo 2/3.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.642 RTP.MANAGER unknown - fxo 2/4.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.642 RTP.MANAGER virtual 0/0.0 - empty - RTP: No DSP channel could be allocated for the resource

      13:54:01.643 TA.T09 01 TAInboundCall        CallResp event accepted

      13:54:01.643 TA.T09 01 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

      13:54:01.643 SB.CALL 49 Delivering           Called the clearCall routine from Delivering

      13:54:01.643 SB.CALL 49 Delivering           Call Cleared on call from 0 to T09

      13:54:01.644 SB.CALL 49 State change      >> Delivering->Clearing

      13:54:01.644 TA.T09 01 TAConnectWaitIn      ClearCall event accepted

      13:54:01.644 TA.T09 01 TAConnectWaitIn      Redelivering a call

      13:54:01.644 TA.T09 01 TAConnectWaitIn      sent: call to SB

      13:54:01.645 TA.T09 01 State change      >> TAConnectWaitIn->TAInboundCall (TAS_Calling)

      13:54:01.645 SB.CALL 49 Clearing             Called the clearResponse routine

      13:54:01.645 SB.CALL 49 State change      >> Clearing->CallIdlePending

      13:54:01.645 SB.CCM release:

      13:54:01.645 SB.CCM  :  Call Struct 0x5d99010 :   Call-ID = 49

      13:54:01.645 SB.CCM  :  Org Acct = T09    Dst Acct = 0

      13:54:01.645 SB.CCM  :  Org Port ID = 2/3.0   Dst Port ID = 0/0.0

      13:54:01.646 SB.CCM  :  Org TID = Fxo   Dst TID = PbxRingGroup

      13:54:01.646 SB.CCM release: Call Connection Type is TDM_TO_RG

      13:54:01.646 SB.CALL 49 CallIdlePending      ClearResponse sent from T09 to 0

      13:54:01.646 SB.CALL 50 Idle                 Called the call routine with 600

      13:54:01.646 SB.CCM isMappable:

      13:54:01.647 SB.CCM  :  Call Struct 0x5dd8c10 :   Call-ID = 50

      13:54:01.647 SB.CCM  :  Org Acct = T09    Dst Acct = 600

      13:54:01.647 SB.CCM  :  Org Port ID = 2/3.0   Dst Port ID = 0/0.0

      13:54:01.647 SB.CCM  :  Org TID = Fxo   Dst TID =

      13:54:01.647 SB.CCM isMappable: Call Connection Type is TDM_TO_RG

      13:54:01.648 SB.CCM isMappable: Unable to reserve RTP Channel

      13:54:01.648 SB.CALL 50 Idle                 Call sent from T09 to 600 (600)

      13:54:01.648 SB.CALL 50 State change      >> Idle->Delivering

      13:54:01.648 RTP.MANAGER virtual 0/0.0 - empty - RTP: Request resource

      13:54:01.649 RTP.MANAGER unknown - fxs 0/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.649 RTP.MANAGER unknown - fxs 0/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.649 RTP.MANAGER unknown - fxo 0/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.649 RTP.MANAGER unknown - fxo 0/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.649 RTP.MANAGER unknown - fxo 1/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.650 RTP.MANAGER unknown - fxo 1/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.650 RTP.MANAGER unknown - fxo 1/3.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.650 RTP.MANAGER unknown - fxo 1/4.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.650 RTP.MANAGER unknown - fxo 2/1.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.650 RTP.MANAGER unknown - fxo 2/2.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.650 RTP.MANAGER unknown - fxo 2/3.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.651 RTP.MANAGER unknown - fxo 2/4.1 - RTP: debug info: , 30, 0, 0, 0, 0, 0

      13:54:01.651 RTP.MANAGER virtual 0/0.0 - empty - RTP: No DSP channel could be allocated for the resource

      13:54:01.651 TA.T09 01 TAInboundCall        CallResp event accepted

      13:54:01.651 TA.T09 01 State change      >> TAInboundCall->TAConnectWaitIn (TAS_Calling)

      13:54:01.651 SB.CALL 50 Delivering           Called the clearCall routine from Delivering

      13:54:01.652 SB.CALL 50 Delivering           Call Cleared on call from 600 to T09

      13:54:01.652 SB.CALL 50 State change      >> Delivering->Clearing

      13:54:01.652 TA.T09 01 TAConnectWaitIn      ClearCall event accepted

      13:54:01.652 TA.T09 01 State change      >> TAConnectWaitIn->TAClearingComplete (TAS_Clearing)

      13:54:01.653 TM.T09 01 Calling - tachg_Clearing

      13:54:01.653 TM.T09 01 Calling -> FarEndAbandon

      13:54:01.653 SB.CALL 50 Clearing             Called the clearResponse routine

      13:54:01.653 SB.CALL 50 State change      >> Clearing->CallIdlePending

      13:54:01.653 SB.CCM release:

      13:54:01.654 SB.CCM  :  Call Struct 0x5dd8c10 :   Call-ID = 50

      13:54:01.654 SB.CCM  :  Org Acct = T09    Dst Acct = 600

      13:54:01.654 SB.CCM  :  Org Port ID = 2/3.0   Dst Port ID = 0/0.0

      13:54:01.654 SB.CCM  :  Org TID = Fxo   Dst TID = PbxRingGroup

      13:54:01.654 SB.CCM release: Call Connection Type is TDM_TO_RG

      13:54:01.655 SB.CALL 50 CallIdlePending      ClearResponse sent from T09 to 600

      13:54:01 TRKPORT.02:03 02:03  Ringing

      2018.03.05 13:54:01 SB.CALL 48 RTP resource unavailable or SDP negotiation failed. Call from () to (600).

      2018.03.05 13:54:01 SB.CALL 49 RTP resource unavailable or SDP negotiation failed. Call from () to (0).

      2018.03.05 13:54:01 SB.CALL 50 RTP resource unavailable or SDP negotiation failed. Call from () to (600).

      2018.03.05 13:54:01 FXO.2/3 ringing on 10765220 ms

      2018.03.05 13:54:01 FXO.2/3 FxoPortStateOnhookReverse -> FxoPortStateRinging 10765220 ms

      2018.03.05 13:54:02 SMDR 48         03/05/2018 13:54:01      0.0 0    E  02/03                                 00/00 GASCARD         600             0 N

      2018.03.05 13:54:02 SMDR 49         03/05/2018 13:54:01      0.0 0    E  02/03                                 00/00 Operator Group  0               0 F

      2018.03.05 13:54:03 FXO.2/3 ringing off 10767134 ms

      2018.03.05 13:54:03 FXO.2/3 FxoPortStateRinging -> FxoPortStateOnhook 10767134 ms

      13:54:03 TRKPORT.02:03 02:03  Reverse Loop Current Feed

      2018.03.05 13:54:03 FXO.2/3 FxoPortStateOnhook -> FxoPortStateOnhookReverse 10767200 ms

      13:54:07 TRKPORT.02:03 02:03  Ringing

      2018.03.05 13:54:07 FXO.2/3 ringing on 10771160 ms

      2018.03.05 13:54:07 FXO.2/3 FxoPortStateOnhookReverse -> FxoPortStateRinging 10771160 ms

      2018.03.05 13:54:09 FXO.2/3 ringing off 10773140 ms

      2018.03.05 13:54:09 FXO.2/3 FxoPortStateRinging -> FxoPortStateOnhook 10773140 ms

      13:54:09 TRKPORT.02:03 02:03  Reverse Loop Current Feed

      2018.03.05 13:54:09 FXO.2/3 FxoPortStateOnhook -> FxoPortStateOnhookReverse 10773206 ms

      13:54:13 TRKPORT.02:03 02:03  Ringing

      2018.03.05 13:54:13 FXO.2/3 ringing on 10777166 ms

      2018.03.05 13:54:13 FXO.2/3 FxoPortStateOnhookReverse -> FxoPortStateRinging 10777166 ms

      2018.03.05 13:54:15 FXO.2/3 ringing off 10779146 ms

      2018.03.05 13:54:15 FXO.2/3 FxoPortStateRinging -> FxoPortStateOnhook 10779146 ms

      13:54:15 TRKPORT.02:03 02:03  Reverse Loop Current Feed

      2018.03.05 13:54:15 FXO.2/3 FxoPortStateOnhook -> FxoPortStateOnhookReverse 10779212 ms

      13:54:16.660 TM.T09 01 FarEndAbandon - sendBusyTimerExpired()

      13:54:16.661 TM.T09 01 FarEndAbandon -> SendBusyTone

      13:54:16.661 TONESERVICES.EVENTS fxo 2/3 - empty - Busy Generation: Request resource

      13:54:16.661 TONESERVICES.EVENTS fxo 2/3 - fxo 2/3.1 - Busy Generation: DSP channel allocated for the resource

      13:54:16.661 TONESERVICES.EVENTS fxo 2/3 - fxo 2/3.1 - Busy Generation: constructed

      13:54:16.661 TONESERVICES.EVENTS fxo 2/3 - fxo 2/3.1 - Busy Generation: starting

      13:54:16.662 TONESERVICES.EVENTS fxo 2/3 - fxo 2/3.1 - Busy Generation: TDM map

      2018.03.05 13:54:16 FXO.2/3 offhook 10780242 ms

      2018.03.05 13:54:16 FXO.2/3 FxoPortStateOnhookReverse -> FxoPortStateOffhook 10780242 ms

      13:54:16 TRKPORT.02:03 02:03  Reverse Loop Current Feed

        • Re: RTP Errors from FXO interface
          jephph New Member

          Have you checked to see if your DSP's are healthy/present?   Sounds like you may have lost them.  Run "Show Version", and immediately after the System Uptime, you should see something that looks like this:

           

          slot 0, DSP 1

            DSP software version: G2.R10.8.M.4b

            DSP hardware version: Freescale MSC7119

            Total channels: 30

           

             If you don't see this, that's bad news.  Power-cycle the unit to see if they come back. If they don't then the box will need to be replaced, as the DSP's aren't field-replaceable.

           

          Good luck,

           

          Jeff