BCM 50 r6 SIP trunking with Draytel

[ccarmock]

Hi

Has anyone got a BCM working with Draytel SIP trunks?

I have been trying and managed to get the BCM registered with draytel. I have setup a route and routing digit.
Using BCM Monitor I can see my call going out over the IP trunk correctly but then get an error display on the set - Temp failure. Any idea what that is?

I then tried to define a proxy since the BCM is behind a NAT firewall (STUN is running correctly so it knows it's public address) wen I do this I get an error resource unavailable.

Is there a SIP log I can check on the BCM to see what's happening?

Any help appreciated.

 

[ccarmock]

I found the FEPS log had SIP setup details, so have captured the temp failure message....

Can anyone help me interpret what is going wrong? The dialled number is 902 which is a Draytel test number:-

2013-12-23T20:31:37.004 I {CP } - 6522 1 v===============================================v
2013-12-23T20:31:37.005 I {CP } - 6523 1 DS30terminal 0x319007b8 allocated - count is now 1
2013-12-23T20:31:37.006 I {CP } - 6524 1 Call from [Null Incoming] to [Waiting Info].
2013-12-23T20:31:37.070 I {VDI } - 6525 1 <<--[Msg]DS30 Recv (Port) <1>: VLI_DIAL, digits=902 NPI_TON=82, len=24(0x18) [04 00 00 00 00 12 00 01 00 03 00 03 F2 09 FF FF FF FF FF FF 00 52 00 01]
2013-12-23T20:31:37.071 I {VDI } - 6526 1 <<--[Msg]DS30 Recv (Port) <1>: vdi_clid, digits=882221 NPI_TON=82 pres=0, len=52(0x34) [04 00 00 00 00 2E 00 01 00 46 00 06 00 00 22 88 FF 12 FF FF FF FF FF FF FF FF FD 4B FF A0 52 FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF]
2013-12-23T20:31:37.072 I {VDI } - 6527 1 <<--[Msg]DS30 Recv (Port) <1>: [MCDN] - isSip=0 crLen=2 epidLen=9, len=75(0x4B) [03 01 20 09 00 3C 08 02 02 44 2E 00 01 0E 13 00 81 90 00 00 A3 00 00 00 00 00 00 00 09 0A 0F 00 E9 00 83 00 01 00 81 00 05 0C 07 00 52 80 06 00 08 08 02 02 02 01 03 09 03 00 D2 00 03 00 09 0A 02 00 01 07 06 00 19 E1 EE 80 CC]
2013-12-23T20:31:37.073 I {CP } - 6528 1 <<--[Msg]DS30 Recv (Call) [MCDN](H.323)
2013-12-23T20:31:37.074 I {VDI } - 6529 1 <<--[Msg]DS30 Recv (Port) <1>: [MCDN] - isSip=1 crLen=2 epidLen=9, len=41(0x29) [03 01 60 09 00 1A 05 00 44 02 01 07 13 00 81 90 00 00 A3 00 09 09 0F 00 E9 00 83 00 01 00 81 00 01 07 06 00 19 E1 EE 80 CC]
2013-12-23T20:31:37.074 I {CP } - 6530 1 <<--[Msg]DS30 Recv (Call) [MCDN](SIP)
2013-12-23T20:31:37.075 I {VDI } - 6531 1 <<--[Msg]DS30 Recv (Port) <1>: VLI_SEIZE, len=32(0x20) [04 00 00 00 00 1A 00 01 00 00 FF FF FF FF FF FF 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 01]
2013-12-23T20:31:37.076 I {VDI } - 6532 1 <<--[Msg]DS30 Recv (Port) <1>: VDI_STCOMMIT (VLI_SEIZE), len=12(0x0C) [04 00 00 00 00 06 00 00 00 58 FF FF]
2013-12-23T20:31:37.089 I {CP } - 6533 1 Call from [Waiting Info] to [Call Present].
2013-12-23T20:31:37.090 I {CP } - 6534 1 <<--[Msg]DS30 Recv (Call) SETUP called DN=902
2013-12-23T20:31:37.090 I {SYS } - 6535 ----- GWS: [VoIP Gateway\H323\Trunks\General\CallSignalingMethod] = 0
2013-12-23T20:31:37.091 I {SYS } - 6536 ----- Endpoint location query found endpoint matching Alias="902": Protocol=SIP Endpoint="" GatewayType="BCM36" MCDNcaps=0 Domain="" ITSPaccountFound=true ITSPaccount="Draytel"
2013-12-23T20:31:37.092 I {SYS } - 6537 ----- GWS: [VoIP Gateway\SIP\Trunks\General\RouteCallsUsingProxy] = false (not found in PDR - used default value)
2013-12-23T20:31:37.093 I {SYS } - 6538 ----- GWS: [VoIP Gateway\SIP\Trunks\General\RouteCallsUsingProxy] = false (not found in PDR - used default value)
2013-12-23T20:31:37.093 I {SYS } - 6539 ----- GWS: [VoIP Gateway\SIP\Trunks\General\RouteCallsUsingProxy] = false (not found in PDR - used default value)
2013-12-23T20:31:37.094 I {SYS } - 6540 ----- *INFO* - Found match - returning protocol=SIP - Using proxy=false / Signaling method=SM_DIRECT
2013-12-23T20:31:37.094 I {CP } - 6541 1 offering call to SipAddressType, bTrunk=1
2013-12-23T20:31:37.095 I {SYS } - 6542 ----- GWS: [VoIP Gateway\SIP\Trunks\General\RvSipLogLevel] = 1
2013-12-23T20:31:37.110 I {SYS } - 6543 ----- GWS: [VoIP Gateway\SIP\Trunks\General\CallSignalingPort] = 5060
2013-12-23T20:31:37.111 I {SIP } - 6544 0 *INFO* - (<TBD>)cSipCall("<ITSP TBD>")::initMembers() - Private IPaddrort=192.168.1.100:5060 decimal (IPaddr=a976ef0 hex) [EV] [SIG]
2013-12-23T20:31:37.112 I {SYS } - 6545 ----- GWS: [VoIP Gateway\SIP\Trunks\MediaParams\VoiceJitterBufSize] = 0
2013-12-23T20:31:37.112 I {SIP } - 6546 0 *INFO* - (0x10a27150)cSipAddress::createCall() - m_nActiveTrunkCalls = 1 [EV] [SIG]
2013-12-23T20:31:37.113 I {SIPM} - 6547 1 <<< I/F cSipMediaCtl::SetDestination
2013-12-23T20:31:37.114 I {SIPM} - 6548 1 Change cMState from Null to Idle
2013-12-23T20:31:37.115 I {SIP } - 6549 1 SIP CALL STATE (0x10aa4028/CID=<TBD>) Fm [_RV_Idle] To [_O_W8_SDP_OUT_CoreMakeRcvd] [EV] [SIG]
2013-12-23T20:31:37.131 I {SIP } - 6550 1 *INFO* - (0x10aa4028/CID=<TBD>)cSipCall("Draytel")::configForItspAccountOutbound() - ITSP account="Draytel" [EV] [SIG]
2013-12-23T20:31:37.132 I {SIP } - 6551 1 *INFO* - (0x10aa4028/CID=<TBD>)cSipCall("Draytel")::configForItspAccountCommon() - called from cSipCall::configForItspAccountOutbound() - Public IPaddrort=<public IP>:5060 decimal (IPaddr=5eaeb15a hex) [EV] [SIG]
2013-12-23T20:31:37.133 I {SIPM} - 6552 1 <<< I/F cSipMediaCtl::SetEnableMediaRelay(bRelayEnabled=true)
2013-12-23T20:31:37.133 I {SIPM} - 6553 1 EPF>>> AckCapabilities(m_OurCaps=
2013-12-23T20:31:37.135 I {SIPM} - 6554 1 <<< I/F cSipMediaCtl::SetSipStandardCapsEnabled(bSipStandardCapsEnabled=false)
2013-12-23T20:31:37.136 I {SIP } - 6555 1 *INFO* - (0x10aa4028/CID=<TBD>)cSipCall("Draytel")::sessionTimerOamParamsSave() - Method=Disabled Min-SE=90 Session-Expires=1800 RefresherRemote=false [EV] [SIG]
2013-12-23T20:31:37.137 I {SIP } - 6556 1 *INFO* - (0x10aa4028/CID=<TBD>)cSipCall("Draytel")::configForItspAccountOutbound() - Overriding called domain with ITSP account ItspDomainOrIpAddr="draytel.org" [EV] [SIG]
2013-12-23T20:31:37.138 I {SIP } - 6557 1 *INFO* - (0x10aa4028/CID=<TBD>)cSipCall("Draytel")::configForItspAccountOutbound() - m_bSupport100rel=true [EV] [SIG]
2013-12-23T20:31:37.139 I {SIP } - 6558 0 *INFO* - (0x310c6b00)cItspAccountMgr::trunkAllocate() - Now, "Draytel" trunk <count/limit>=<1/unlimited> [EV] [SIG]
2013-12-23T20:31:37.139 I {SYS } - 6559 ----- GWS: [VoIP Gateway\SIP\Trunks\General\SCNFallback] = 2
2013-12-23T20:31:37.140 I {SYS } - 6560 ----- GWS: [VoIP Gateway\SIP\Trunks\General\SCNFallback] = 2
2013-12-23T20:31:37.164 I {SIP } - 6561 1 SDP STATE (0x10aa4028/CID=<TBD>) Fm [_Idle] To [_O_W8_AckReqMediaOffer] [EV] [SIG]
2013-12-23T20:31:37.164 I {SIPM} - 6562 1 <<< I/F cSipMediaCtl:oReqMediaOffer(W4Connect=true)
2013-12-23T20:31:37.165 I {SIPM} - 6563 1 Change cMState from Idle to W4AckReqCapsOffer
2013-12-23T20:31:37.166 I {SIPM} - 6564 1 Change cCState from Idle to W4ConnectToOffer
2013-12-23T20:31:37.181 I {SIPM} - 6565 1 <<<EPF GetCapabilities(void)
2013-12-23T20:31:37.181 I {SIPM} - 6566 1 EPF>>> AckCapabilities(m_OurCaps=
2013-12-23T20:31:37.200 I {SIPM} - 6567 1 <<<EPF Connect(dir=sendrecv, W4bothCaps )
2013-12-23T20:31:37.201 I {SIPM} - 6568 1 EPF>>> GetOtherEndCapabilities()
2013-12-23T20:31:37.202 I {SIPM} - 6569 1 No caps to offer yet, wait for Received Capabilities or Negotiated Parameters
2013-12-23T20:31:37.202 I {SIPM} - 6570 1 Change cIState from DisabledForbidden to EnabledForbidden
2013-12-23T20:31:37.203 I {SIPM} - 6571 1 <<<EPF EnableOutboundStream(status=W4bothCaps )
2013-12-23T20:31:37.204 I {SIPM} - 6572 1 cStreamsStatus::OBEnable = ENABLED
2013-12-23T20:31:37.204 I {SIPM} - 6573 1 Change cOState from Disabled to Enabled
2013-12-23T20:31:37.205 I {SIPM} - 6574 1 cSipMediaCtl::NewOffer()
2013-12-23T20:31:37.205 I {SIPM} - 6575 1 cSipMediaCtl::NewOffer()
2013-12-23T20:31:37.238 I {SIPM} - 6576 1 <<<EPF ReceivedCapabilities(status=W4thisCaps , g711u+120s(0/6)@192.168.1.100:30040, g711A+120s(0/6), g729+120s(0/50), g729B+120s(0/50), T38_V1+120s(144/144))
2013-12-23T20:31:37.241 I {SIPM} - 6577 1 cSipMediaCtl::setTheirTransport(192.168.1.100:30041), was 0.0.0.0:0
2013-12-23T20:31:37.242 I {SIPM} - 6578 1 Change cCState from W4ConnectToOffer to IdleConnected
2013-12-23T20:31:37.243 I {SIPM} - 6579 1 EPF>>> GetOtherEndCapabilities(g711u+120s(0/6)@192.168.1.100:30040, g711A+120s(0/6), g729+120s(0/50), g729B+120s(0/50), T38_V1+120s(144/144))
2013-12-23T20:31:37.243 I {SIPM} - 6580 1 cSipMediaCtl::NewOffer()
2013-12-23T20:31:37.244 I {SIPM} - 6581 1 AckReqCapsOffer(g711u+120s(0/6)@192.168.1.100:30040, g711A+120s(0/6), g729+120s(0/50), g729B+120s(0/50), T38_V1+120s(144/144), complete)
2013-12-23T20:31:37.254 I {SIPM} - 6582 1 Change cMState from W4AckReqCapsOffer to W4MediaAnswer
2013-12-23T20:31:37.255 I {SYS } - 6583 ----- GWS: [VoIP Gateway\SIP\Trunks\MediaParams\G711DesiredPayloadSize] = 2
2013-12-23T20:31:37.255 I {SYS } - 6584 ----- GWS: [VoIP Gateway\SIP\Trunks\MediaParams\G711DesiredPayloadSize] = 2
2013-12-23T20:31:37.256 I {SYS } - 6585 ----- GWS: [VoIP Gateway\SIP\Trunks\MediaParams\G711DesiredPayloadSize] = 2
2013-12-23T20:31:37.256 I {SYS } - 6586 ----- GWS: [VoIP Gateway\SIP\Trunks\MediaParams\G711DesiredPayloadSize] = 2
2013-12-23T20:31:37.258 I {SYS } - 6587 ----- GWS: [VoIP Gateway\SIP\Trunks\MediaParams\G711DesiredPayloadSize] = 2
2013-12-23T20:31:37.258 I {SYS } - 6588 ----- GWS: [VoIP Gateway\SIP\Trunks\MediaParams\G711DesiredPayloadSize] = 2
2013-12-23T20:31:37.259 I {SIPM} - 6589 1 I/F >>> AckReqMediaOffer(sendrecv, g711A+120s(2/6)@192.168.1.100:30040, g711u+120s(2/6))
2013-12-23T20:31:37.260 I {SYS } - 6590 ----- GWS: [VoIP Gateway\SIP\Trunks\General\CallSignalingPort] = 5060
2013-12-23T20:31:37.261 I {SYS } - 6591 ----- GWS: [VoIP Gateway\SIP\Trunks\General\T38FaxSupportEnabled] = true
2013-12-23T20:31:37.261 I {SIP } - 6592 1 SDP STATE (0x10aa4028/CID=<TBD>) Fm [_O_W8_AckReqMediaOffer] To [_W8_InMsgAnswer] [EV] [SIG]
2013-12-23T20:31:37.262 I {SIP } - 6593 1 SIP CALL STATE (0x10aa4028/CID=<TBD>) Fm [_O_W8_SDP_OUT_CoreMakeRcvd] To [_O_W8_EV_Inviting] [EV] [SIG]
2013-12-23T20:31:37.263 I {SYS } - 6594 ----- GWS: [VoIP Gateway\SIP\Trunks\General\DomainName] = ""
2013-12-23T20:31:37.264 I {SYS } - 6595 ----- GWS: [VoIP Gateway\H323\Trunks\General\LastFwdNumOliEnabled] = 1
2013-12-23T20:31:37.266 I {SIP } - 6596 1 *INFO* - (0x10aa4028/CID=<TBD>)cSipCall("Draytel")::setOutboundProxy() - Setting outbound details: IPaddr="217.14.138.127" HostName="NULL" Port=5060 Transport=RVSIP_TRANSPORT_UDP [EV] [SIG]
2013-12-23T20:31:37.279 I {SIP } - 6597 1 *INFO* - (0x10aa4028/CID=<TBD>)cSipCall("Draytel")::setContactHdr() - Overriding maddr in Contact with SIP user maddr=false [EV] [SIG]
2013-12-23T20:31:37.280 I {SYS } - 6598 ----- GWS: [VoIP Gateway\SIP\Trunks\General\NumReqRetransmissions] = 4 (not found in PDR - used default value)
2013-12-23T20:31:37.282 I {SYS } - 6599 ----- GWS: [VoIP Gateway\SIP\Trunks\General\SdpAddRtpMaps] = false
2013-12-23T20:31:37.286 I {SYS } - 6600 ----- GWS: [Inventory\ExeVersion] = "46.53.0.33"
2013-12-23T20:31:37.302 I {SIP } - 6601 1 -->>[Msg]SIP Send INVITE (CID=31074dc CSeq=1 INVITE)("Draytel") To:902@draytel.org:5060 <SDP: SessId=1387830697 V=1387830697 [<Public ip>:30040 sendrecv g711a g711u rfc2833=120 inforeq=111]> (Dest=217.14.138.127:5060) (0x10aa4028/CID=31074dc) [EV] [SIG]
2013-12-23T20:31:37.311 I {SIP } - 6602 1 RV CALL STATE (0x10aa4028/CID=31074dc) - Fm [IDLE] To [INVITING], reason=LOCAL_INVITING [EV] [SIG]
2013-12-23T20:31:37.312 I {SIP } - 6603 1 SIP CALL STATE (0x10aa4028/CID=31074dc) Fm [_O_W8_EV_Inviting] To [_O_RV_Inviting] [EV] [SIG]
2013-12-23T20:31:37.312 I {SYS } - 6604 ----- GWS: [VoIP Gateway\SIP\Trunks\General\EndptRspTimerMsec] = 10000 (not found in PDR - used default value)
2013-12-23T20:31:41.340 I {SIP } - 6605 1 RV CALL STATE (0x10aa4028/CID=31074dc) - Fm [INVITING] To [MSG_SEND_FAILURE], reason=LOCAL_TIME_OUT [EV] [SIG]
2013-12-23T20:31:41.340 I {SIP } - 6606 1 SIP CALL STATE (0x10aa4028/CID=31074dc) Fm [_O_RV_Inviting] To [MsgSendFailure] [EV] [SIG]
2013-12-23T20:31:41.341 I {SYS } - 6607 ----- GWS: [VoIP Gateway\SIP\Trunks\General\RegExpiryAdvanceSeconds] = 30 (not found in PDR - used default value)
2013-12-23T20:31:41.342 I {SIP } - 6608 0 Thread: 3897 RV: [SIG] [Msg]SIP ERROR - TRANSACTION - SipTransactionDNSContinue - transaction 0x0x31a52dc0 Continue dns failed - transmitter has no additional addresses
2013-12-23T20:31:41.343 I {SIP } - 6609 0 Thread: 3897 RV: [SIG] [Msg]SIP ERROR - CALL - continueDNSForInviteTransaction: call-leg 0x0x31074dc0 - Failed to continue DNS for transaction 0x0x31a52dc0. (status -13)
2013-12-23T20:31:41.343 I {SIP } - 6610 0 Thread: 3897 RV: [SIG] [Msg]SIP ERROR - CALL - ContinueDNSCallLegMsg: call-leg 0x0x31074dc0 - Failed to continue DNS for INVITE transaction
2013-12-23T20:31:41.344 W {SIP } - 6611 1 *WARN*![Msg]SIP - (0x10aa4028/CID=31074dc)cSipCall("Draytel")::evMsgSendFailure() - Failed to RvSipCallLegDNSContinue(), rc=RV_ERROR_NOT_FOUND [EV] [SIG]
2013-12-23T20:31:41.346 I {SIP } - 6612 1 (0x10aa4028/CID=31074dc)cSipCall("Draytel")::[Msg]SIP Teardown - NearEnd [To Core: Temporary failure] [To SIP: <RV->Disconnect()>] [SIG]
2013-12-23T20:31:41.350 I {SIP } - 6613 1 SIP CALL STATE (0x10aa4028/CID=31074dc) Fm [_O_RV_Inviting] To [_BC_TearingDown] [EV] [SIG]
2013-12-23T20:31:41.350 I {SIPM} - 6614 1 <<< I/F cSipMediaCtl:oReset(Near)
2013-12-23T20:31:41.354 I {SIPM} - 6615 1 EPF>>> NotifyDisconnect()
2013-12-23T20:31:41.355 I {SIPM} - 6616 1 Change cMState from W4MediaAnswer to W4StreamsStopped
2013-12-23T20:31:41.355 I {SIPM} - 6617 1 cS::SetStreams(_,_)
2013-12-23T20:31:41.356 I {SIPM} - 6618 1 Change cSState from Idle to Busy
2013-12-23T20:31:41.356 I {SIPM} - 6619 1 Change cSState from Busy to Idle
2013-12-23T20:31:41.357 I {SIPM} - 6620 1 cSipMediaCtl::AckSetStreams()
2013-12-23T20:31:41.358 W {SIP } - 6621 1 *WARN*![Msg]SIP - (0x10aa4028/CID=31074dc)cSipCall("Draytel")::teardown() - Overriding SIPaction=<RV->Disconnect()> with SIPaction=<RV->Terminate()> because RV CallState=MSG_SEND_FAILURE [EV] [SIG]
2013-12-23T20:31:41.360 I {SIP } - 6622 1 RV CALL STATE (0x10aa4028/CID=31074dc) - Fm [MSG_SEND_FAILURE] To [TERMINATED], reason=CALL_TERMINATED [EV] [SIG]
2013-12-23T20:31:41.361 I {SIP } - 6623 1 (0x10aa4028/CID=31074dc)SIP CALL STATE :: - [_BC_TearingDown] received evTerminated() [SIG]
2013-12-23T20:31:41.362 I {SIP } - 6624 1 SIP CALL STATE (0x10aa4028/CID=31074dc) Fm [_BC_TearingDown] To [_RV_Terminated_W8_AckReset] [EV] [SIG]
2013-12-23T20:31:41.365 I {SIPM} - 6625 1 <<<EPF Disconnect(void)
2013-12-23T20:31:41.365 I {SIPM} - 6626 1 Disconnect(11) will not trigger renegotiation
2013-12-23T20:31:41.366 I {SIPM} - 6627 1 Change cIState from EnabledForbidden to DisabledForbidden
2013-12-23T20:31:41.366 I {SIPM} - 6628 1 Change cSState from Idle to Busy
2013-12-23T20:31:41.370 I {SIPM} - 6629 1 <<<EPF DisableOutboundStream(cause=4)
2013-12-23T20:31:41.370 I {SIPM} - 6630 1 cStreamsStatus::OBEnable = DISABLEREQUESTED
2013-12-23T20:31:41.371 I {SIPM} - 6631 1 Change cOState from Enabled to Disabled
2013-12-23T20:31:41.371 I {SIPM} - 6632 1 cStreamsStatus::OBEnable = DISABLED

 

[ccarmock]

This is partly solved. I find I can now place outbound calls.

I simply had to add draytel.org as the local SIP domain as well as the remote on the BCM and it worked, even though this seems counter intuitive.

However I still cannot receive calls - the call doesn't get offered to the BCM at all - looking to BCM monitor I see nothing and the caller gets a busy tone