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
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
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
Thank you Jeff, that appears to be our issue. We will get a unit replaced.