So heres the scenario, I made sip trunk between IP office 500 and Asterisk Freepbx, SIP trunk is UP on both sides, Asterisk has a 3rd Party VOIP trunk , I need Avaya Phones to call international call using the VOIP provider which is configured in Asterisk. For Asterisk phones, I can route the calls through the VOIP provider without any issue but when it comes to the Avaya phones, its not going through… I badly need your help guys.
We badly need solid information like CLI and SIP traces!
do you want the IP office Sip trace? Here it is…
******** Warning: Logging to Screen Started **********
1087027mS PRN: 711: Digit Pressed 3
1087028mS CMCallEvt: 0.1067.0 -1 BaseEP: NEW CMEndpoint f54dc534 TOTAL NOW=1 CALL_LIST=0
1087028mS CMCallEvt: 0.1067.0 -1 Clark.-1: NEW CMExtnEndpoint f54dc534, Name=Clark, Extn=711, Phys Extn=711
1087028mS CMCallEvt: CREATE CALL:15 (f540eaa0)
1087028mS CMCallEvt: 0.1068.0 -1 BaseEP: NEW CMEndpoint f54e2088 TOTAL NOW=2 CALL_LIST=0
1087030mS CMExtnEvt: Clark: CMExtnHandler::SetCurrent( id: 0->1067 )
1087030mS CMExtnRx: v=711, p1=0
CMSetup
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[711] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Clark
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Clark
1087030mS CMCallEvt: 0.1067.0 15 Clark.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
1087030mS CMExtnEvt: v=2 State, new=Dialling old=Idle,0,0,Clark
1087031mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=711 dir=out complete=0 ses=0
1087031mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
1087032mS CMCallEvt: 0.1067.0 15 Clark.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
1087032mS CMExtnTx: v=711, p1=0
CMSetupAck
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
BChan: slot=0 chan=5
Timed: 26/03/12 17:39
1087033mS CMExtnRx: v=711, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[3] Type=Default (100) Reason=CMDRdirect
1087033mS CMTARGET: 0.1067.0 15 Clark.0: CancelTimer CMTCDialToneTimeout
1087033mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=3 sub= calling=711 dir=out complete=0 ses=0
1087033mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number=3 type=100 depth=1 nobar=1 setorig=1 ses=0
1087034mS CD: CALL: 0.1067.0 BState=Idle Cut=0 Music=0.0 Aend=“Clark(711)” (0.5) Bend="" [] (0.0) CalledNum=3 () CallingNum=711 (Clark) Internal=1 Time=6 AState=Dialling
1087281mS RES: Mon 26/3/2012 17:39:56 FreeMem=69304144(1) CMMsg=5 (6) Buff=5200 953 870 7447 5 Links=6634
1087281mS RES2: IP 500 V2 6.1(22) Tasks=40 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=56 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
1087439mS PRN: 711: Digit Pressed 4
1087439mS CMExtnRx: v=711, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[4] Type=Default (100) Reason=CMDRdirect
1087439mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=34 sub= calling=711 dir=out complete=0 ses=0
1087440mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number=34 type=100 depth=1 nobar=1 setorig=1 ses=0
1089239mS PRN: 711: Digit Pressed 0
1089239mS CMExtnRx: v=711, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
1089239mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=340 sub= calling=711 dir=out complete=0 ses=0
1089240mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number=340 type=100 depth=1 nobar=1 setorig=1 ses=0
1089414mS PRN: 711: Digit Pressed 0
1089414mS CMExtnRx: v=711, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
1089415mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=3400 sub= calling=711 dir=out complete=0 ses=0
1089415mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number=3400 type=100 depth=1 nobar=1 setorig=1 ses=0
1091101mS PRN: 711: Digit Pressed 4
1091101mS CMExtnRx: v=711, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[4] Type=Default (100) Reason=CMDRdirect
1091102mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=34004 sub= calling=711 dir=out complete=0 ses=0
1091102mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number=34004 type=100 depth=1 nobar=1 setorig=1 ses=0
1091289mS PRN: 711: Digit Pressed 4
1091289mS CMExtnRx: v=711, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[4] Type=Default (100) Reason=CMDRdirect
1091290mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=340044 sub= calling=711 dir=out complete=0 ses=0
1091290mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number=340044 type=100 depth=1 nobar=1 setorig=1 ses=0
1091576mS PRN: 711: Digit Pressed 0
1091576mS CMExtnRx: v=711, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[0] Type=Default (100) Reason=CMDRdirect
1091577mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=3400440 sub= calling=711 dir=out complete=0 ses=0
1091577mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number=3400440 type=100 depth=1 nobar=1 setorig=1 ses=0
1091851mS PRN: 711: Digit Pressed #
1091851mS CMExtnRx: v=711, p1=0
CMInformation
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[#] Type=Default (100) Reason=CMDRdirect
1091852mS CMTARGET: 0.1067.0 15 Clark.0: LOOKUP CALL ROUTE: type=100 called_party=3400440# sub= calling=711 dir=out complete=0 ses=0
1091852mS CMTARGET: 0.1067.0 15 Clark.0: ADD TARGET (N): number=3400440# type=100 depth=1 nobar=1 setorig=1 ses=0
1091852mS CMTARGET: 0.1067.0 15 Clark.0: SYS SC: 3400440# 4 00440 sc=type=Dial code=34N;, num=N callinfop->sending_complete=0 secondary_dialtone=
1091853mS CMARS: FindActiveARSByGroupID GroupID=20 - Not Found
1091853mS CMLRQ: FindActiveLRQByGroupID GroupID=20 - Not Found
1091853mS CMTARGET: Problem with Line Id: 19 - check_DNS 1 OperationalTest: 0, IP address: 192.168.2.100
1091853mS CMMap: a=0.18 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 1, total 20
1091854mS CMCallEvt: 0.1069.0 -1 BaseEP: NEW CMEndpoint f556f400 TOTAL NOW=3 CALL_LIST=1
1091855mS CMTARGET: DIAL LINE: 15 GROUP = 20 SUCCESS = f556f400
1091856mS CMTARGET: 0.1067.0 15 Clark.0: CancelTimer CMTCDialToneTimeout
1091856mS CMTARGET: 0.1067.0 15 Clark.0: INITIAL TARGETING SUCCEEDED
1091856mS CMTARGET: 0.1067.0 15 Clark.0: GetNoAnswerTimer:18
1091856mS CMCallEvt: 0.1068.0 15 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
1091857mS CMCallEvt: 20.1069.0 15 SIPTrunk Endpoint: StateChange: END=T CMCSIdle->CMCSOffering
1091859mS CMLineTx: v=0
CMSetup
Line: type=SIPLine 20 Call: lid=20 id=1069 in=0
Called[00440] Type=Default (100) Reason=CMDRdirect Calling[711] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=5
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Clark
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Clark
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=711
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceStdPhone type=26 number=2 channel=0 rx_gain=32 tx_gain=32 ep_callid=1067 ipaddr=192.168.2.201 apps=0
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Clark
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Clark
IE CMIEMohSourceId (247) MOH Source = 255
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageISO8859-1
invokeId 14629
user ‘Clark’ presentation Allowed
IE CMIEFastStartInfoData (6)
Display [Clark>00440]
Timed: 26/03/12 17:40
Locale: ara
1091861mS SIP Tx: UDP 192.168.2.201:5060 -> 192.168.2.25:5060
INVITE sip:00440@192.168.2.25 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.201:5060;rport;branch=z9hG4bK96f27bb4326d1618fef403fa91357821
From: “Clark” sip:711@192.168.2.25;tag=c56bae427efe00a6
To: sip:00440@192.168.2.25
Call-ID: 8dac023a768431fe9556557ee08bced6@192.168.2.201
CSeq: 978219281 INVITE
Contact: “Clark” sip:711@192.168.2.201:5060;transport=udp
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Content-Type: application/sdp
Supported: timer
Content-Length: 300
v=0
o=UserA 336682660 4150378944 IN IP4 192.168.2.201
s=Session SDP
c=IN IP4 192.168.2.201
t=0 0
m=audio 49152 RTP/AVP 0 8 18 4 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
1091862mS CD: CALL: 0.1067.0 BState=Idle Cut=0 Music=0.0 Aend=“Clark(711)” (0.5) Bend=“Line 20” [Line 20] (0.0) CalledNum=3400440# () CallingNum=711 (Clark) Internal=0 Time=4834 AState=Dialling
1091864mS SIP Rx: UDP 192.168.2.25:5060 -> 192.168.2.201:5060
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.2.201:5060;branch=z9hG4bK96f27bb4326d1618fef403fa91357821;received=192.168.2.201;rport=5060
From: “Clark” sip:711@192.168.2.25;tag=c56bae427efe00a6
To: sip:00440@192.168.2.25
Call-ID: 8dac023a768431fe9556557ee08bced6@192.168.2.201
CSeq: 978219281 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: sip:00440@192.168.2.25
Content-Length: 0
1091866mS CMLineRx: v=0
CMProceeding
Line: type=SIPLine 20 Call: lid=20 id=1069 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=3400440#
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceSIPTrunk type=0 number=20 channel=0 rx_gain=32 tx_gain=32 ep_callid=1069 ipaddr=192.168.2.201 apps=0
1091867mS CMCallEvt: 0.1068.0 15 TargetingEP: RequestEnd 20.1069.0 15 SIPTrunk Endpoint
1091867mS CMTARGET: 0.1067.0 15 Clark.0: CancelTimer CMTCNoAnswerTimeout
1091867mS CMCallEvt: 0.1068.0 -1 BaseEP: DELETE CMEndpoint f54e2088 TOTAL NOW=2 CALL_LIST=1
1091867mS CMCallEvt: 20.1069.0 15 SIPTrunk Endpoint: StateChange: END=B CMCSOffering->CMCSAccept
1091868mS CMCallEvt: 0.1067.0 15 Clark.0: StateChange: END=A CMCSDialling->CMCSDialled
1091868mS CMExtnEvt: v=2 State, new=Proceeding old=Dialling,0,0,Clark
1091869mS CMExtnTx: v=711, p1=0
CMProceeding
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=3400440#
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceSIPTrunk type=0 number=20 channel=0 rx_gain=32 tx_gain=32 ep_callid=1069 ipaddr=192.168.2.201 apps=0
Timed: 26/03/12 17:40
1091870mS SIP Rx: UDP 192.168.2.25:5060 -> 192.168.2.201:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.201:5060;branch=z9hG4bK96f27bb4326d1618fef403fa91357821;received=192.168.2.201;rport=5060
From: “Clark” sip:711@192.168.2.25;tag=c56bae427efe00a6
To: sip:00440@192.168.2.25;tag=as2564b7a1
Call-ID: 8dac023a768431fe9556557ee08bced6@192.168.2.201
CSeq: 978219281 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: sip:00440@192.168.2.25
Content-Type: application/sdp
Content-Length: 235
v=0
o=root 2648 2648 IN IP4 192.168.2.25
s=session
c=IN IP4 192.168.2.25
t=0 0
m=audio 15786 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
1091874mS SIP Tx: UDP 192.168.2.201:5060 -> 192.168.2.25:5060
ACK sip:00440@192.168.2.25 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.201:5060;rport;branch=z9hG4bKca853dcea952379e25004c95ad6cda6f
From: “Clark” sip:711@192.168.2.25;tag=c56bae427efe00a6
To: sip:00440@192.168.2.25;tag=as2564b7a1
Call-ID: 8dac023a768431fe9556557ee08bced6@192.168.2.201
CSeq: 978219281 ACK
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO, UPDATE
Content-Length: 0
1091876mS CMLineRx: v=0
CMConnect
Line: type=SIPLine 20 Call: lid=20 id=1069 in=0
Called[Clark] Type=Default (100) Reason=CMDRdirect
IE CMIEFastStartInfoData (6)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=3400440#
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceSIPTrunk type=0 number=20 channel=0 rx_gain=32 tx_gain=32 ep_callid=1069 ipaddr=192.168.2.201 apps=0
1091876mS CMCallEvt: 20.1069.0 15 SIPTrunk Endpoint: StateChange: END=B CMCSAccept->CMCSConnReq
1091876mS CMCallEvt: 0.1067.0 15 Clark.0: StateChange: END=A CMCSDialled->CMCSOGConnReq
1091876mS CMExtnEvt: v=2 State, new=Connected old=Proceeding,0,0,Clark
1091878mS CMExtnTx: v=711, p1=0
CMConnect
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
Called[Clark] Type=Default (100) Reason=CMDRdirect
IE CMIEFastStartInfoData (6)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=3400440#
IE CMIEDeviceDetail (231) LOCALE=ara HW=15 VER=6 class=CMDeviceSIPTrunk type=0 number=20 channel=0 rx_gain=32 tx_gain=32 ep_callid=1069 ipaddr=192.168.2.201 apps=0
Timed: 26/03/12 17:40
1091879mS CMExtnRx: v=711, p1=0
CMConnectAck
Line: type=DigitalExtn 2 Call: lid=0 id=1067 in=0
1091879mS CMCallEvt: 0.1067.0 15 Clark.0: StateChange: END=A CMCSOGConnReq->CMCSConnected
1091879mS CMTARGET: 0.1067.0 15 Clark.0: ~CMTargetHandler f54e38f8 ep f54dc534
1091880mS CMCallEvt: 20.1069.0 15 SIPTrunk Endpoint: StateChange: END=B CMCSConnReq->CMCSConnected
1091881mS CMLineTx: v=0
CMConnectAck
Line: type=SIPLine 20 Call: lid=20 id=1069 in=0
BChan: slot=0 chan=5
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Clark
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Clark
in this trace, from the Avaya phone, I am dialing 00440#, 00 is the dial plan for asterisk to use the SIP provider trunk , 440 is to check the balance of the card, # is for avaya to send the digits to asterisk, however I am getting, the number you dial is invalid, I assume that it is looking for an Asterisk extension…
-
I expected the traces to be from Asterisk.
-
The trace you provided shows a successful call.
-
Asterisk will not output such a message unless there is explicit dialplan code to do so. It would normally leave the call unanswered and give a 404 status response, if the number was bad. GUIs may do different.
how can I get the traces from asterisk? yes the call is being accepted by asterisk but its not passing the route to the voip provider
Start the CLI (asterisk -r). Then use wiki.asterisk.org/wiki/display/ … nformation for guidance, although this may produced rather too much detail.
Please try and locate the problem area before you post any of it here, as trawling through detailed logging is time consuming.