Hi
I am having a problem with inbound calls from an Avaya S8500 to DMG2120 (this is also connected to an OCS 2007 R1 mediation server.
Backgound
Heres is the error from the call log on the gateway
49 3/15 13:53:45 3/15 13:53:45 From TDM Network TDM: Not Accepted 1:12 441342410912,->68001,->28100, [Rsn=FwdAll]
48 3/15 13:45:42 3/15 13:45:42 From TDM Network TDM: Not Accepted 1:11 441342410912,->68001,->28100, [Rsn=FwdAll]
47 3/15 13:45:38 3/15 13:45:38 From TDM Network TDM: Not Accepted 1:10 441342410912,->68001,->28100, [Rsn=FwdAll]
46 3/15 13:45:35 3/15 13:45:35 From TDM Network TDM: Not Accepted 1:9 441342410912,->68001,->28100, [Rsn=FwdAll]
It looks as though the destination number is being remapped to 28100 so I have set up a route to handle this but it still doesn’t work.
Heres the entry on the Trace diagnostics logging on the gateway
rtGetOutboundRoute() failed 4657a94
Any Ideas
Justin
Can you please collect the following and post the trace:
Tel Code
Tel Event
VoIP Code
VoiP Prot
Teldrv ALL MASKS
RouteTable ALL MASKS
Leave the column of “Init” checked as well
Thanks
Vince
Thanks - here is the trace
I couldnt find all the elements to configure in the diagnostics log but I think I came quite close
000:04.848 [System ] Init Application Status000:04.848 [System ] Init ==================================000:04.848 [System ] Init Starttype: 0x0000:04.848 [System ] Init Gateway: 0.0.0.0000:04.848 [System ] Init MAC 1: 00-a0-e6-89-b0-ad000:04.848 [System ] Init LAN 1 IP: 192.168.223.2000:04.848 [System ] Init LAN 1 Subnet Mask: 255.255.255.0000:04.848 [System ] Init MAC 2: 00-a0-e6-89-b0-ae000:04.848 [System ] Init LAN 2 IP: 0.0.0.0000:04.848 [System ] Init LAN 2 Subnet Mask: 255.255.255.0000:04.848 [System ] Init Management available on All LAN's000:04.848 [System ] Init ==================================000:04.848 [System ] Init Start System Initialization000:04.864 [System ] Init No BOOTP file list is available000:04.864 [System ] Init Attempting to load INI from HAL000:04.864 [System ] Init INI is available: |AUTO| |NONE| 17292:17292 bytes000:06.160 [System ] Init Attempting to load MSD from HAL000:06.752 [System ] Init MSD is available: |T1E1_MR11.msd| |T1E1_MR11| 1738256:1738256 bytes000:06.752 [System ] Init Attempting to load XML from HAL000:06.752 [System ] Init XML is available: |AUTO| |NONE| 7753:7753 bytes000:06.752 [System ] Init Application Status000:06.752 [System ] Init ==================================000:06.752 [System ] Init Starttype: 0x0000:06.752 [System ] Init Gateway: 0.0.0.0000:06.752 [System ] Init MAC 1: 00-a0-e6-89-b0-ad000:06.752 [System ] Init LAN 1 IP: 192.168.223.2000:06.752 [System ] Init LAN 1 Subnet Mask: 255.255.255.0000:06.752 [System ] Init MAC 2: 00-a0-e6-89-b0-ae000:06.752 [System ] Init LAN 2 IP: 0.0.0.0000:06.752 [System ] Init LAN 2 Subnet Mask: 255.255.255.0000:06.752 [System ] Init Management available on All LAN's000:06.752 [System ] Init ==================================000:06.768 [Cfg ] Init Loading settings from the NVRam000:06.960 [Tel ] Init nimSysInitialize000:06.960 [Tel ] Init t1e1CfgInitialize - Span[0] Interface Side 1000:06.960 [Tel ] Init t1e1CfgInitialize - Span[1] Interface Side 1000:06.960 [Tel ] Init t1e1CfgInitialize - Span[2] Interface Side 1000:06.960 [Tel ] Init t1e1CfgInitialize - Span[3] Interface Side 1000:06.960 [Tel ] Init t1e1CfgInitialize000:06.960 [Tel ] Init tenimInitialize() Failover Capability=FALSE000:06.960 [Tel ] Init Initializing Channel-Map.000:06.960 [Tel ] Init Adding span[0] to map, channels [0->22]000:06.960 [Tel ] Init Adding span[1] to map, channels [23->45]000:06.960 [Tel ] Init Adding span[2] to map, channels [46->68]000:06.960 [Tel ] Init Adding span[3] to map, channels [69->91]000:06.960 [Tel ] Init 'tenimInitialize' success000:06.960 [DspIf ] Init dspSysCreate() Initializing [VAPI Library Release 2.3.2, API Version 3.1]000:06.960 [Gtl ] Init GTL_Init(5c5fbc)000:06.960 [DspIf ] Init USR_QueryDeviceEnumerate()000:06.960 [DspIf ] Init DSP Ethernet[ixe0]000:06.960 [DspIf ] Init dspSysCreate() set dspif Host MAC: 00:A0:E6:01:02:01000:06.960 [DspIf ] Init DSP Device type set to 1000:06.960 [Gtl ] Init GTL_QueryInterface(0)000:06.960 [DspIf ] Init dspSysLoad()000:06.960 [OAM ] Init _oamTaskMain running000:06.960 [System ] Init Low Priority task started000:08.880 [DspIf ] Init dspSysBoot() Loading [T1E1_MR11.msd]000:09.856 [System ] Init MIB-II ALARM |1| - txt:[Link Up: (0)]000:12.704 [DspIf ] Init DSP Model=0x9000:12.720 [DspIf ] Init VAPI_SetDeviceIpAddr(0xC0A8DF02).000:12.720 [EthMgr ] Init ethmgrOpen()000:12.720 [DspIf ] Init Setting CP Tone Country.000:12.752 [OAM ] Init oamLoadLanguage() [lang_english.xml] length = 204323000:13.056 [Pbn ] Init trlInitialize000:13.056 [Pbn ] Init RTP Port Pool: Start=49000 Entries=500000:13.088 [Gcc ] Init gccInitializeDevices() init dev |voip|000:13.104 [DspIf ] Init toneInterfaceOpen000:13.104 [Alarm ] Init ALARM - id:[1152] port:[0x0] txt:[T.38 Channels Supported = 92]000:13.104 [CadDet ] Init cadenceDetectorInitialize()000:13.104 [CadDet ] Init Creating Cadence statemachines for 6 Tones000:13.104 [CadDet ] Init _cadDetTaskMain started000:13.104 [DspIf ] Init dspifLiCadenceGenerationInitialize()000:13.104 [Pamd ] Init dspifPamdInitialize() for 92 channels000:13.104 [Pamd ] Init _pamdTaskMain started000:13.120 [Tel ] Init T1E1 Config: Setting up 4 span(s)000:13.120 [Tel ] Init T1E1 Config: CCS Signaling (ISDN PRI)000:13.120 [Tel ] Init T1E1 Config: T1 Line Mode000:13.120 [Tel ] Init T1E1 Config: QSIG000:13.120 [Tel ] Init T1E1 Config Span[0]: Terminal Side000:13.120 [Tel ] Init T1E1 Config Span[1]: Terminal Side000:13.120 [Tel ] Init T1E1 Config Span[2]: Terminal Side000:13.120 [Tel ] Init T1E1 Config Span[3]: Terminal Side000:13.168 [Gcc ] Init gccInitializeDevices() init dev |pri0|000:13.168 [Gcc ] Init gccInitializeDevices() init dev |pri1|000:13.168 [Gcc ] Init gccInitializeDevices() init dev |pri2|000:13.168 [Gcc ] Init gccInitializeDevices() init dev |pri3|000:13.168 [Gcc ] Init gccInitializeDevices() = 5000:13.168 [RouteTable] Init rtInitialize()000:13.168 [RouteTable] Init rtInitialize() number of devices = 4000:13.168 [RouteTable] Init rtInitialize() device[0].uNumBearerChannels[23]000:13.168 [RouteTable] Init rtInitialize() device[1].uNumBearerChannels[23]000:13.168 [RouteTable] Init rtInitialize() device[2].uNumBearerChannels[23]000:13.168 [RouteTable] Init rtInitialize() device[3].uNumBearerChannels[23]000:13.168 [RouteTable] Init rtInitialize() 23 max channels000:13.168 [RouteTable] Init _rtConfigInitialize()000:13.232 [Alarm ] Init ALARM - id:[900] port:[0x1]000:13.232 [Alarm ] Init ALARM - id:[842] port:[0x2]000:13.232 [Alarm ] Init ALARM - id:[900] port:[0x2]000:13.232 [Alarm ] Init ALARM - id:[841] port:[0x3]000:13.232 [Alarm ] Init ALARM - id:[900] port:[0x3]000:13.232 [Alarm ] Init ALARM - id:[841] port:[0x4]000:13.232 [RouteTable] Init _rtConfigLoad()000:13.280 [DspIf ] Init mediaInterfaceOpen000:13.280 [Alarm ] Init ALARM - id:[128] port:[0x0] txt:[Application [Router] Started]000:13.280 [Diags ] Init Trace Log Allocated [22407213 bytes]000:13.280 [Diags ] Init Trace Log Allocated [22407213 bytes]000:13.344 [Alarm ] Init ALARM - id:[840] port:[0x1]000:13.344 [Alarm ] Init ALARM - id:[840] port:[0x2]000:13.344 [Alarm ] Init ALARM - id:[840] port:[0x3]000:13.408 [Alarm ] Init ALARM - id:[129] port:[0x0]000:13.456 [Alarm ] Init ALARM - id:[899] port:[0x1]000:13.568 [Alarm ] Init ALARM - id:[899] port:[0x2]000:13.680 [Alarm ] Init ALARM - id:[899] port:[0x3]000:41.264 [Gw ] Error rtGetOutboundRoute() failed 462ff84 1037:53.920 [Gw ] Error rtGetOutboundRoute() failed 4630884 1253:30.544 [Gw ] Error rtGetOutboundRoute() failed 460bc60 1275:26.592 [Alarm ] Init ALARM - id:[128] port:[0x0] txt:[Application [TDM Test] Started]275:26.592 [System ] Init PBX Test application started.275:26.624 [Gw ] Error rtGetOutboundRoute() failed 45e823c 1275:27.792 [Alarm ] Init ALARM - id:[128] port:[0x0] txt:[Application [TDM Test] Stopped]275:27.792 [System ] Init PBX Test application stopped.275:51.488 [Alarm ] Init ALARM - id:[128] port:[0x0] txt:[Application [TDM Test] Started]275:51.488 [System ] Init PBX Test application started.275:51.504 [Gw ] Error rtGetOutboundRoute() failed 45e943c 1275:52.768 [Alarm ] Init ALARM - id:[128] port:[0x0] txt:[Application [TDM Test] Stopped]275:52.768 [System ] Init PBX Test application stopped.276:09.120 [Alarm ] Init ALARM - id:[128] port:[0x0] txt:[Application [TDM Test] Started]276:09.120 [System ] Init PBX Test application started.276:09.152 [teldrv-1 ] Error Unrecognized Layer 3 packet [3328]276:10.320 [Alarm ] Init ALARM - id:[128] port:[0x0] txt:[Application [TDM Test] Stopped]276:10.320 [System ] Init PBX Test application stopped.283:44.368 [Gw ] Error rtGetOutboundRoute() failed 45ea63c 1441:09.904 [Gw ] Error rtGetOutboundRoute() failed 45eca3c 1441:48.464 [Gw ] Error rtGetOutboundRoute() failed 460c560 1443:40.384 [Gw ] Error rtGetOutboundRoute() failed 460ce60 1755:13.632 [Gw ] Error rtGetOutboundRoute() failed 2761:43.424 [Gw ] Error rtGetOutboundRoute() failed 2776:20.960 [Gw ] Error rtGetOutboundRoute() failed 4631a84 1780:33.840 [Gw ] Error rtGetOutboundRoute() failed 2791:26.096 [Alarm ] Init ALARM - id:[384] port:[0x0] txt:[Call Leg not found]791:56.736 [Alarm ] Init ALARM - id:[384] port:[0x0] txt:[Cancel Timer Expiry ]800:10.288 [Gw ] Error rtGetOutboundRoute() failed 2800:12.512 [Gw ] Error rtGetOutboundRoute() failed 2342:50.752 [teldrv-3 ] Prot [1332] NLS<-SETUP: 08 02 13 32 05 A1 04 03 90 90 A2 18 03 A9 83 87 1E 02 82 81 1E 02 A4 90 6C 0E 01 83 34 34 31 33 34 32 34 31 30 39 31 32 70 06 80 32 38 31 30 30 342:50.752 [Tel-3 ] Event l4_appl N_CALL_PRES_IN connid:29 cause[00:00] datalen:74342:50.752 [Tel-3 ] Event l4_appl N_STAT_IN connid:29 cause[08:01] datalen:0342:50.752 [Tel-3 ] Event l4_appl N_STAT_IN connid:29 cause[08:16] datalen:0342:50.752 [Tel-3 ] Event l4_appl N_STAT_IN connid:29 cause[33:00] datalen:0342:50.752 [Tel-3 ] Code _isdnLiOnConnectionIndication() isdn conn:29 tdm:7342:50.752 [Tel-3 ] Code _isdnLiAssignTdmChannel(7)342:50.752 [Tel-3 ] Code calling party number342:50.752 [Tel-3 ] Code numbering plan: [ISDN:0x1]342:50.752 [Tel-3 ] Code type of number: [Unknown:0x0]342:50.752 [Tel-3 ] Code pres ind [Allowed:0x0]342:50.752 [Tel-3 ] Code screening ind: [Network:0x3]342:50.752 [Tel-3 ] Code number digits: [441342410912]342:50.752 [Tel-3 ] Code called party number342:50.752 [Tel-3 ] Code numbering plan: [Unknown:0x0]342:50.752 [Tel-3 ] Code type of number: [Unknown:0x0]342:50.752 [Tel-3 ] Code number digits: [28100]342:50.752 [Tel-3 ] Code isdnLiAppOnConnectionIndication(29,7)342:50.752 [Tel-3 ] Code isdnGccAllocateConnection: Call allocated 4634784342:50.752 [Tel-3 ] Event _isdnLiOnConnectionStatus() PROGRESS_IND [08:01]342:50.752 [Tel-3 ] Event PROGRESS = Call is not end-to-end ISDN, further call progress information may be available in-band342:50.752 [Tel-3 ] Code isdnLiAppOnProgressInband(29)342:50.752 [Tel-3 ] Event _isdnLiOnConnectionStatus() PROGRESS_IND [08:16]342:50.752 [Tel-3 ] Event PROGRESS = Interworking with a public network342:50.752 [Tel-3 ] Event _isdnLiOnConnectionStatus() SEND_COMPLETE [33:00]342:50.752 [Tel-3 ] Code isdnLiAppOnSendingComplete(29)342:50.752 [Tel-3 ] Code ISDN Task(2) eISDN_MSG_IND_INBOUND342:50.752 [Tel-3 ] Code (4634784) eISDN_MSG_IND_INBOUND in eSTATE_IDLE342:50.752 [Tel-3 ] Code _condOverlapRcvNotSupported: NO342:50.752 [Tel-3 ] Code _condMinCalledDigitsRcvd: YES (5 digits: '28100')342:50.752 [Tel-3 ] Code _actSendProceeding342:50.752 [Tel-3 ] Code conn:29 isdnLiSendProceedingRequest()342:50.752 [teldrv-3 ] Code L4->N_CALL_PROC_RQ342:50.752 [Tel-3 ] Code _actSetCallIncoming342:50.752 [Tel-3 ] Code isdnGccChangeCallState: 4634784 INCOMING342:50.752 [Tel ] Code (4634784) Connection has new timeout -1342:50.752 [Tel-3 ] Code _entryInboundAlertingState342:50.752 [Tel-3 ] Code (4634784) eSTATE_INBOUND_ALERTING from eSTATE_IDLE342:50.752 [Tel-3 ] Code ISDN Task(2) eISDN_MSG_IND_PROGRESS_INBAND342:50.752 [Tel-3 ] Code (4634784) eISDN_MSG_IND_PROGRESS_INBAND in eSTATE_INBOUND_ALERTING342:50.752 [Tel-3 ] Code (4634784) eISDN_MSG_IND_PROGRESS_INBAND in eSTATE_INBOUND_ALERTING no transition found.342:50.752 [Tel-3 ] Code ISDN Task(2) eISDN_MSG_IND_SEND_COMPLETE342:50.752 [Tel-3 ] Code (4634784) eISDN_MSG_IND_SEND_COMPLETE in eSTATE_INBOUND_ALERTING342:50.752 [Tel-3 ] Code (4634784) remaining in eSTATE_INBOUND_ALERTING342:50.752 [teldrv-3 ] Prot [1332] NLS->CALL_PROC: 08 02 93 32 02 18 03 A9 83 87 342:50.752 [RouteTable] Code rtGetOutboundRoute()342:50.752 [RouteTable] Code inbound device: TDM (intfc|chn) 3|7342:50.752 [RouteTable] Code inbound call info: [441342410912,]->[28100,]->[,] [Rsn=1]342:50.752 [RouteTable] Code _rtRuleManager() checking inbound tdm rule [Inbound 5 digit starting with 2] for a match342:50.752 [RouteTable] Code _rtRuleManager() checking trunk group [TdmAll] for a match342:50.752 [RouteTable] Code rtMatchTdmTrunkGroup() tdm device idx:0 (intfc|chan) 3|7342:50.752 [RouteTable] Code rtMatchTdmTrunkGroup() channel map[7fffff] matched342:50.752 [RouteTable] Code rtMatchCpid()342:50.752 [RouteTable] Code calling number [441342410912]342:50.752 [RouteTable] Code calling name []342:50.752 [RouteTable] Code called number [28xxx][28100]342:50.752 [RouteTable] Code called name []342:50.752 [RouteTable] Code redirect number []342:50.752 [RouteTable] Code redirect name []342:50.752 [RouteTable] Code rtGetOutboundRoute() inbound tdm rule match: Inbound 5 digit starting with 2 342:50.752 [RouteTable] Code _rtRouteDetermination() number of outbound routes: 1342:50.752 [RouteTable] Code _rtRouteDetermination() outbound route idx:0 device-type:2342:50.752 [RouteTable] Code _rtFindVoipRoute()342:50.752 [RouteTable] Code _rtFindVoipRoute() URIs in group: 1342:50.752 [RouteTable] Code _rtFindVoipRoute() URI[0]: 192.168.223.3342:50.752 [RouteTable] Code rtGetOutboundRoute() outbound voip route found[idx:0]342:50.752 [RouteTable] Code outbound device: VOIP (user@host:port) @192.168.223.3:0342:50.752 [RouteTable] Code rtManipulateCallInfo()342:50.752 [RouteTable] Code calling number [441342410912] [441342410912]342:50.752 [RouteTable] Code calling name [] []342:50.752 [RouteTable] Code called number [28100] ["+1302429"+rext(D,4)] [+13024298100]342:50.752 [RouteTable] Code called name [] []342:50.752 [RouteTable] Code redirect number [] [R] []342:50.752 [RouteTable] Code redirect name [] [R] []342:50.752 [RouteTable] Code rtGetOutboundRoute() outbound call info: [441342410912,]->[+13024298100,]->[,] [Rsn=1]342:50.752 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_ui.c:2433 342:50.752 [VoIP ] Code 342:50.752 [VoIP ] Code SSAP(0) -- SoUiSotConReq --> SIP: EVENT(INVITE) spConnId(0) suConnId(-2147483632) CallLegId(80000006) TransId(80000006) 342:50.752 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_ua.c:579 soUaInviteReq: 342:50.752 [VoIP ] Code Outgoing Invite: spId : 0; suConnId : -2147483632Call Leg Id : 80000006; Trans Id : 80000006 342:50.752 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_core.c:1259 342:50.752 [VoIP ] Code [CORE ] CALL Created => Call (17)342:50.752 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:658 342:50.752 [VoIP ] Code [Dialog] DIALOG Created => Entity(0) Call(17) CallLeg(80000006)[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:564 342:50.752 [VoIP ] Code [TRANS ] TCB Created => Call(17), CallLeg(80000006), Trans(80000006)342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:7287 342:50.768 [VoIP ] Code [Dialog] Call State Updated: Call(17), CallLeg(80000006) Prev State(0) to New State(1)[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:5048 342:50.768 [VoIP ] Code [Dialog] Outgoing INVITE Request For Transaction:Call(17), CallLeg(80000006), State(1)[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:2932 342:50.768 [VoIP ] Code [TRANS] Sending Invite[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:2933 342:50.768 [VoIP ] Code [TRANS] --TransType(1), State(0), Id(80000006), Transport(2), CSeq(1), Method(1)-- 342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 67 Action 1 Value 150 CB 0x4dc0fc4342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tcm.c:5122 soTptOpenClient: Opening New Client Connection suConnId (28), Protocol(2)342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_ptli.c:696 SoLiHitConReq(pst, spId(0), suConId(28), remAddr.type(4), remAddr.port(5060), remAddr.address(C0A8DF03),localAddr.type(4), localAddr.port(0), localAddr.address(C0A8DF02), tpar, srvcType (1))342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 98 Action 1 Value 340 CB 0x51a4474342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 9 Action 2 Value 0 CB 0x51a4ffc342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 9 Action 1 Value 1200 CB 0x51a4ffc342:50.768 [VoIP ] Code [TCP_UDP_CONVERGENCE_LAYER 0x75:0] k://scimitar//pimg//sw//src//pbn//trl//tucl_1.5//hi_bdy1.c:1688 HiUiHitConReq(pst, spId(0), suConId(28), remAddr(0x5226888), localAddr(0x5226870), tPar(0x52266e8), srvcType(1))342:50.768 [VoIP ] Code [TCP_UDP_CONVERGENCE_LAYER 0x75:0] k://scimitar//pimg//sw//src//pbn//trl//tucl_1.5//hi_ptui.c:1085 HiUiHitConCfm(pst, suId(0), suConId(28)), spConId(21), localAddr(0x4dbfb38)342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_li.c:366 SoLiHitConCfm(pst, suId(0), suConnId(28), spConnId(21),localAddr.type(4), localAddr.port(1030), localAddr.address(C0A8DF02))342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 67 Action 2 Value 0 CB 0x4dc0fc4342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 66 Action 1 Value 300 CB 0x4dc0fc4342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 66 Action 3 Value 300 CB 0x4dc0fc4342:50.768 [VoIP ] Prot 342:50.768 [VoIP ] Prot <----INVITE sip:+13024298100@192.168.223.3;transport=tcp SIP/2.0342:50.768 [VoIP ] Prot From:<sip:441342410912@192.168.223.2:5060>;vnd.pimg.port=53;tag=0FB9324631353641000CCE6E342:50.768 [VoIP ] Prot To:<sip:+13024298100@192.168.223.3>342:50.768 [VoIP ] Prot Content-Type:application/sdp342:50.768 [VoIP ] Prot Supported:replaces,100rel342:50.768 [VoIP ] Prot Allow:INVITE,ACK,OPTIONS,BYE,CANCEL,REGISTER,INFO,COMET,PRACK,REFER,SUBSCRIBE,NOTIFY,MESSAGE342:50.768 [VoIP ] Prot Expires:120342:50.768 [VoIP ] Prot Call-ID:01B228546181400000000006@pbxgw.default.com342:50.768 [VoIP ] Prot CSeq:1 INVITE342:50.768 [VoIP ] Prot Max-Forwards:70342:50.768 [VoIP ] Prot User-Agent:PBX-IP Media Gateway342:50.768 [VoIP ] Prot Contact:sip:441342410912@192.168.223.2:5060;transport=tcp342:50.768 [VoIP ] Prot Via:SIP/2.0/TCP 192.168.223.2:5060;branch=z9hG4bKBE91695ABCE3AA9CDA611354DB4A4F44342:50.768 [VoIP ] Prot Content-Length:302342:50.768 [VoIP ] Prot 342:50.768 [VoIP ] Prot v=0342:50.768 [VoIP ] Prot o=phone 29386 0 IN IP4 192.168.223.2342:50.768 [VoIP ] Prot s=-342:50.768 [VoIP ] Prot c=IN IP4 192.168.223.2342:50.768 [VoIP ] Prot t=0 0342:50.768 [VoIP ] Prot m=audio 49032 RTP/AVP 0 8 101342:50.768 [VoIP ] Prot a=rtpmap:0 PCMU/8000/1342:50.768 [VoIP ] Prot a=rtpmap:8 PCMA/8000/1342:50.768 [VoIP ] Prot a=rtpmap:101 telephone-event/8000342:50.768 [VoIP ] Prot a=fmtp:101 0-15342:50.768 [VoIP ] Prot m=image 0 udptl t38342:50.768 [VoIP ] Prot a=T38FaxRateManagement:transferredTCF342:50.768 [VoIP ] Prot a=T38FaxUdpEC:t38UDPRedundancy342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_ptli.c:780 SoLiHitDatReq(pst, spId(0), spConId(21), mBuf(0x4bebe54)342:50.768 [VoIP ] Code [TCP_UDP_CONVERGENCE_LAYER 0x75:0] k://scimitar//pimg//sw//src//pbn//trl//tucl_1.5//hi_bdy1.c:2123 HiUiHitDatReq(pst, spId(0), spConId(21), mBuf(0x4bebe54)))342:50.768 [VoIP ] Code [TCP_UDP_CONVERGENCE_LAYER 0x75:0] k://scimitar//pimg//sw//src//pbn//trl//tucl_1.5//hi_ptui.c:1251 HiUiHitDatInd(pst, suId(0), suConId(28), mBuf(0x4bebe54))342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_li.c:982 SoLiHitDatInd(pst, suId(0), suConnId(28), mBuf(0x4bebe54)342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 66 Action 3 Value 300 CB 0x4dc0fc4342:50.768 [VoIP ] Prot 342:50.768 [VoIP ] Prot ---->SIP/2.0 100 Trying342:50.768 [VoIP ] Prot FROM: <sip:441342410912@192.168.223.2:5060>;tag=0FB9324631353641000CCE6E;vnd.pimg.port=53342:50.768 [VoIP ] Prot TO: <sip:+13024298100@192.168.223.3>342:50.768 [VoIP ] Prot CSEQ: 1 INVITE342:50.768 [VoIP ] Prot CALL-ID: 01B228546181400000000006@pbxgw.default.com342:50.768 [VoIP ] Prot VIA: SIP/2.0/TCP 192.168.223.2:5060;branch=z9hG4bKBE91695ABCE3AA9CDA611354DB4A4F44342:50.768 [VoIP ] Prot CONTENT-LENGTH: 0342:50.768 [VoIP ] Prot 342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:3062 342:50.768 [VoIP ] Code [TRANS] 1XX (Inv) From Peer[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:3063 342:50.768 [VoIP ] Code [TRANS] --TransType(1), State(1), Id(80000006), Transport(2), CSeq(1), Method(1)-- 342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 98 Action 2 Value 0 CB 0x51a4474342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_core.c:735 342:50.768 [VoIP ] Code [Dialog] Found Dialog For Response: Call(17), CallLeg(80000006), State(1)[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:7360 342:50.768 [VoIP ] Code [Dialog] Call State Updated: Call(17) CallLeg(80000006) Prev State(1) to New State(2)342:50.768 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:1871 342:50.768 [VoIP ] Code [Dialog] 100 Response to INVITE Received: Call(17), CallLeg(80000006)[TCP_UDP_CONVERGENCE_LAYER 0x75:0] k://scimitar//pimg//sw//src//pbn//trl//tucl_1.5//hi_ptui.c:1251 HiUiHitDatInd(pst, suId(0), suConId(28), mBuf(0x4bebe54))342:51.520 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_li.c:982 SoLiHitDatInd(pst, suId(0), suConnId(28), mBuf(0x4bebe54)342:51.520 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 66 Action 3 Value 300 CB 0x4dc0fc4342:51.520 [VoIP ] Prot 342:51.520 [VoIP ] Prot ---->SIP/2.0 183 Session Progress342:51.520 [VoIP ] Prot FROM: <sip:441342410912@192.168.223.2:5060>;tag=0FB9324631353641000CCE6E;vnd.pimg.port=53342:51.520 [VoIP ] Prot TO: <sip:+13024298100@192.168.223.3>;epid=0B881C76CA;tag=41a78a9b99342:51.520 [VoIP ] Prot CSEQ: 1 INVITE342:51.520 [VoIP ] Prot CALL-ID: 01B228546181400000000006@pbxgw.default.com342:51.520 [VoIP ] Prot VIA: SIP/2.0/TCP 192.168.223.2:5060;branch=z9hG4bKBE91695ABCE3AA9CDA611354DB4A4F44342:51.520 [VoIP ] Prot CONTENT-LENGTH: 0342:51.520 [VoIP ] Prot SERVER: RTCC/3.0.0.0 MediationServer342:51.520 [VoIP ] Prot 342:51.520 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:3164 342:51.520 [VoIP ] Code [TRANS] 1XX (Inv) From Peer[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:3165 342:51.520 [VoIP ] Code [TRANS] --TransType(1), State(2), Id(80000006), Transport(2), CSeq(1), Method(1)-- 342:51.520 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 98 Action 2 Value 0 CB 0x51a4474342:51.520 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_core.c:735 342:51.520 [VoIP ] Code [Dialog] Found Dialog For Response: Call(17), CallLeg(80000006), State(2)[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:7360 342:51.520 [VoIP ] Code [Dialog] Call State Updated: Call(17) CallLeg(80000006) Prev State(2) to New State(3)342:51.520 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:1871 342:51.520 [VoIP ] Code [Dialog] 183 Response to INVITE Received: Call(17), CallLeg(80000006)[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_ui.c:4516 342:51.520 [VoIP ] Code 342:51.520 [VoIP ] Code SSAP(0) <-- SoUiSotCnStInd -- SIP: EVENT(INVITE) spConnId(17) suConnId(-2147483632) CallLegId(80000006) TransId(80000006) 342:51.584 [VoIP ] Code [TCP_UDP_CONVERGENCE_LAYER 0x75:0] k://scimitar//pimg//sw//src//pbn//trl//tucl_1.5//hi_ptui.c:1251 HiUiHitDatInd(pst, suId(0), suConId(28), mBuf(0x4bebfe4))342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_li.c:982 SoLiHitDatInd(pst, suId(0), suConnId(28), mBuf(0x4bebfe4)342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 66 Action 3 Value 300 CB 0x4dc0fc4342:51.584 [VoIP ] Prot 342:51.584 [VoIP ] Prot ---->SIP/2.0 480 Temporarily Unavailable342:51.584 [VoIP ] Prot FROM: <sip:441342410912@192.168.223.2:5060>;tag=0FB9324631353641000CCE6E;vnd.pimg.port=53342:51.584 [VoIP ] Prot TO: <sip:+13024298100@192.168.223.3>;epid=0B881C76CA;tag=41a78a9b99342:51.584 [VoIP ] Prot CSEQ: 1 INVITE342:51.584 [VoIP ] Prot CALL-ID: 01B228546181400000000006@pbxgw.default.com342:51.584 [VoIP ] Prot VIA: SIP/2.0/TCP 192.168.223.2:5060;branch=z9hG4bKBE91695ABCE3AA9CDA611354DB4A4F44342:51.584 [VoIP ] Prot CONTENT-LENGTH: 0342:51.584 [VoIP ] Prot 342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:3542 342:51.584 [VoIP ] Code [TRANS] 3-6XX (Inv) From Peer[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:3543 342:51.584 [VoIP ] Code [TRANS] --TransType(1), State(2), Id(80000006), Transport(2), CSeq(1), Method(1)-- 342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 98 Action 2 Value 0 CB 0x51a4474342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:7003 342:51.584 [VoIP ] Code [TRANS] ACK Send[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:7004 342:51.584 [VoIP ] Code [TRANS] --TransType(1), State(2), Id(80000006), Transport(2), CSeq(1), Method(1)-- 342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tcm.c:5031 soTptOpenClient: Re-Using Client Connection suConnId (28), Protocol(2)342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 66 Action 3 Value 300 CB 0x4dc0fc4342:51.584 [VoIP ] Prot 342:51.584 [VoIP ] Prot <----ACK sip:+13024298100@192.168.223.3;transport=tcp SIP/2.0342:51.584 [VoIP ] Prot Call-ID:01B228546181400000000006@pbxgw.default.com342:51.584 [VoIP ] Prot CSeq:1 ACK342:51.584 [VoIP ] Prot From:<sip:441342410912@192.168.223.2:5060>;vnd.pimg.port=53;tag=0FB9324631353641000CCE6E342:51.584 [VoIP ] Prot To:<sip:+13024298100@192.168.223.3>;epid=0B881C76CA;tag=41a78a9b99342:51.584 [VoIP ] Prot Via:SIP/2.0/TCP 192.168.223.2:5060;branch=z9hG4bKBE91695ABCE3AA9CDA611354DB4A4F44342:51.584 [VoIP ] Prot Max-Forwards:70342:51.584 [VoIP ] Prot User-Agent:PBX-IP Media Gateway342:51.584 [VoIP ] Prot Content-Length:0342:51.584 [VoIP ] Prot 342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_ptli.c:780 SoLiHitDatReq(pst, spId(0), spConId(21), mBuf(0x4bec8a4)342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:909 342:51.584 [VoIP ] Code [TRANS ] TCB Deleted => Call(17), CallLeg(80000006), Trans(80000006)342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_trans.c:911 342:51.584 [VoIP ] Code [TRANS] --TransType(1), State(4), Id(80000006), Transport(2), CSeq(1), Method(1)-- 342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_core.c:735 342:51.584 [VoIP ] Code [Dialog] Found Dialog For Response: Call(17), CallLeg(80000006), State(3)[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:7360 342:51.584 [VoIP ] Code [Dialog] Call State Updated: Call(17) CallLeg(80000006) Prev State(3) to New State(8)342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:1871 342:51.584 [VoIP ] Code [Dialog] 480 Response to INVITE Received: Call(17), CallLeg(80000006)[SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 9 Action 2 Value 0 CB 0x51a4ffc342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 15 Action 2 Value 0 CB 0x51a4ffc342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_ui.c:4453 342:51.584 [VoIP ] Code 342:51.584 [VoIP ] Code SSAP(0) <-- SoUiSotConCfm -- SIP: EVENT(INVITE) spConnId(17) suConnId(-2147483632) CallLegId(80000006) TransId(80000006) 342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_dlg.c:701 342:51.584 [VoIP ] Code [Dialog] DIALOG Deleted => Entity (0) Call (17) Dialog (80000006) 342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 12 Action 2 Value 0 CB 0x51a4ffc342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 13 Action 2 Value 0 CB 0x51a4ffc342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 9 Action 2 Value 0 CB 0x51a4ffc342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 15 Action 2 Value 0 CB 0x51a4ffc342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_tmr.c:326 TIMER: Evnt 17 Action 2 Value 0 CB 0x51a4ffc342:51.584 [VoIP ] Code [SIP_LAYER 0x99:0] k://scimitar//pimg//sw//src//pbn//trl//so//so_core.c:1453 342:51.584 [VoIP ] Code [CORE ] CALL Deleted => Call (17)342:51.584 [VoIP ] Code [TCP_UDP_CONVERGENCE_LAYER 0x75:0] k://scimitar//pimg//sw//src//pbn//trl//tucl_1.5//hi_bdy1.c:2123 HiUiHitDatReq(pst, spId(0), spConId(21), mBuf(0x4bec8a4)))342:51.584 [RouteTable] Code rtReportUnavailableRoute()342:51.584 [RouteTable] Code rtGetOutboundRoute()342:51.584 [RouteTable] Code inbound device: TDM (intfc|chn) 3|7342:51.584 [RouteTable] Code inbound call info: [441342410912,]->[28100,]->[,] [Rsn=1]342:51.584 [RouteTable] Code inbound request option: RETRY342:51.584 [RouteTable] Code rtGetOutboundRoute() inbound tdm rule match: Inbound 5 digit starting with 2 342:51.584 [RouteTable] Code _rtRouteDetermination() number of outbound routes: 1342:51.584 [RouteTable] Code _rtRouteDetermination() using preferred outbound route[idx:0]342:51.584 [RouteTable] Code _rtRouteDetermination() outbound route idx:0 device-type:2342:51.584 [RouteTable] Code _rtFindVoipRoute()342:51.584 [RouteTable] Code _rtFindVoipRoute() cannot retry without fault tolerence342:51.584 [RouteTable] Code _rtRouteDetermination() outbound route failure[idx:0]342:51.584 [RouteTable] Warn rtGetOutboundRoute() _rtRouteDetermination failed 2342:51.584 [Gw ] Error rtGetOutboundRoute() failed 2342:51.584 [Tel-3 ] Code _isdnGccCallReject: (4634784)342:51.584 [Tel-3 ] Code ISDN Task(2) eISDN_MSG_REQUEST_DROP342:51.584 [Tel-3 ] Code (4634784) eISDN_MSG_REQUEST_DROP in eSTATE_INBOUND_ALERTING342:51.584 [Tel-3 ] Code _actSendDisconnectRequest342:51.584 [Tel-3 ] Code conn:29 isdnLiSendDisconnectRequest()342:51.584 [teldrv-3 ] Code L4->N_DISC_RQ342:51.584 [Tel-3 ] Code isdnGccReportCallFuncAsyncCmplt: 12 0(4634784)342:51.584 [Tel ] Code (4634784) Connection has new timeout -1342:51.584 [Tel-3 ] Code (4634784) eSTATE_RELEASE_PENDING_IDLE from eSTATE_INBOUND_ALERTING342:51.584 [teldrv-3 ] Prot [1332] NLS->DISC: 08 02 93 32 45 08 02 80 92 342:51.584 [Tel-3 ] Code _isdnGccCallRelease: (4634784)342:51.584 [Tel-3 ] Code ISDN Task(2) eISDN_MSG_REQUEST_CALL_RELEASE342:51.584 [Tel-3 ] Code (4634784) eISDN_MSG_REQUEST_CALL_RELEASE handled before FSM342:51.616 [teldrv-3 ] Prot [1332] NLS<-REL: 08 02 13 32 4D 342:51.616 [teldrv-3 ] Prot [1332] NLS->REL_COM: 08 02 93 32 5A 342:51.616 [Tel-3 ] Event l4_appl N_DISC_CF connid:29 cause[00:00] datalen:0342:51.616 [Tel-3 ] Code isdnLiAppOnDisconnectConfirm(29)342:51.616 [Tel-3 ] Code _isdnLiFreeTdmChannel(7)342:51.616 [Tel-3 ] Code ISDN Task(2) eISDN_MSG_IND_DISCONNECT_CONFIRM342:51.616 [Tel-3 ] Code (4634784) eISDN_MSG_IND_DISCONNECT_CONFIRM in eSTATE_RELEASE_PENDING_IDLE342:51.616 [Tel-3 ] Code _actSetCallIdle342:51.616 [Tel-3 ] Code isdnGccSetCallIdle: 4634784342:51.616 [Tel-3 ] Code isdnGccChangeCallState: 4634784 IDLE342:51.616 [Tel ] Code (4634784) Connection has new timeout -1342:51.616 [Tel-3 ] Code _entryIdleState342:51.616 [Tel-3 ] Code (4634784) eSTATE_IDLE from eSTATE_RELEASE_PENDING_IDLE342:51.616 [Tel-3 ] Code _isdnFsmToneInterfaceCallback conn:65535 tdm:7 5344f04342:52.096 [Tel ] Code isdnGccFreeConnection: 4634784
The IP endpoint in this case is sending the DMG a "480 Temporarily Unavailable" which in turn the DMG sends a disconnect to the ISDN side. I recommend looking into the IP endpoint as to why this call is being returned.
Hope this helps
342:51.584 [VoIP ] Prot ---->SIP/2.0 480 Temporarily Unavailable
342:51.584 [teldrv-3 ] Prot [1332] NLS->DISC: 08 02 93 32 45 08 02 80 92
