DeanStaunton
Technical User
We have a school that since coming back from the holidays are unable to make SIP calls.
SIP calls go via Gradwell and are authenticated by IP address only.
Incoming calls are fine, but outgoing calls appear to establish a connection as far as ringing, but when the called person answers, the call is left with no speech in either direction.
What then appear to happen at the IPO is that the SIP call is dropped, although it does not drop for the called person, and a new call is made over PSTN trunks to the same number, via the ARS fallback route.
The end user says nothing changed on their router/firewall or network over the holiday, but I have my doubts being a school.
There is a trace of a failed call below, and this line is interesting:-
348253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
348253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
Which appears several time during an outbound call attempt.
I have seen posts similar to this on TT but none seem to match our scenario.
Could anyone point me in the right direction i.e. IPO or customers network?
Many thanks!
343884mS SIP Tx: UDP 10.0.54.240:5060 -> 212.11.94.246:5060
INVITE sip:01392440850@212.11.94.246 SIP/2.0
Via: SIP/2.0/UDP 217.179.12.239:5060;rport;branch=z9hG4bKe579e0cde6fc271645026acde6e48669
From: "01503262625" <sip:01503262625@217.179.12.239>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>
Call-ID: 553aa254150fd4ea5e633383604356a6@217.179.12.239
CSeq: 424544783 INVITE
Contact: "01503262625" <sip:01503262625@217.179.12.239:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO
Content-Type: application/sdp
Content-Length: 232
v=0
o=UserA 1291714132 2094996720 IN IP4 217.179.12.239
s=Session SDP
c=IN IP4 217.179.12.239
t=0 0
m=audio 49152 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
343899mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
343900mS PRN: MZ stubs sip_cbk_fetchTxn no element found
344256mS RES: Mon 25/4/2016 14:17:50 FreeMem=70089384(2) CMMsg=5 (6) Buff=200 946 999 7454 5 Links=22251
344256mS RES2: IP 500 5.0(26) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=58 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
344882mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Length: 0
344884mS PRN: MZ stubs sip_cbk_fetchTxn no element found
344885mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
344889mS PRN: MZ stubs sip_cbk_fetchTxn no element found
345884mS SIP Tx: UDP 10.0.54.240:5060 -> 212.11.94.246:5060
INVITE sip:01392440850@212.11.94.246 SIP/2.0
Via: SIP/2.0/UDP 217.179.12.239:5060;rport;branch=z9hG4bKe579e0cde6fc271645026acde6e48669
From: "01503262625" <sip:01503262625@217.179.12.239>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>
Call-ID: 553aa254150fd4ea5e633383604356a6@217.179.12.239
CSeq: 424544783 INVITE
Contact: "01503262625" <sip:01503262625@217.179.12.239:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO
Content-Type: application/sdp
Content-Length: 232
v=0
o=UserA 1291714132 2094996720 IN IP4 217.179.12.239
s=Session SDP
c=IN IP4 217.179.12.239
t=0 0
m=audio 49152 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
345914mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
345918mS PRN: MZ stubs sip_cbk_fetchTxn no element found
347751mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
347754mS PRN: MZ stubs sip_cbk_fetchTxn no element found
347754mS PRN: MZ stubs sip_cbk_fetchTxn no element found
348249mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
348253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
348253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
348885mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
348886mS CMCallEvt: 17.1028.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSOffering->CMCSCompleted
348886mS CMCallEvt: 17.1028.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSCompleted->CMCSDelete
348887mS CMARS: Target: Short_Code: N; - Line_Group_ID: 100 has been set to: CMARS_OUTOFSERVICE
348887mS CMCallEvt: 0.1027.0 8 ARS for iLine: StateChange: END=B CMCSOverlapRecv->CMCSAccept
348887mS CMCallEvt: 0.1025.0 8 SteveGreen.0: StateChange: END=A CMCSDialling->CMCSRingBack
348888mS CMExtnEvt: v=7 State, new=Alerting old=Dialling,0,0,SteveGreen
348888mS CMExtnTx: v=124, p1=0
CMProgress
Line: type=DigitalExtn 2 Call: lid=0 id=1025 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 25/04/16 14:17
348888mS Stun: ~STUNClient 10.0.54.240:49152
348889mS Stun: ~STUNClient 10.0.54.240:49153
348889mS CMCallEvt: 17.1028.0 -1 BaseEP: DELETE CMEndpoint f531db58 TOTAL NOW=2 CALL_LIST=1
348890mS CD: CALL: 0.1025.0 BState=Ringing Cut=3 Music=0.0 Aend="SteveGreen(124)" (20.7) Bend="" [] (0.0) CalledNum=01392440850 () CallingNum=124 (SteveGreen) Internal=1 Time=15642 AState=Ringing
348891mS CMMap: a=21.39 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 6, total 8
348891mS CMMap: a=21.39 b=1.255 T
348891mS CMMap: PCG::MapBChan pcp[101]b1r0 cp_b f5507a08 other_cp_b f593b628 type CGTypeDTMF
348891mS CMMap: a=21.39 b=20.7 M2
348891mS CMMap: DTMF:
layTones g T[22] ,EEEEE
348891mS CMMap: Started playing tones, cp[101]b1r0 (from g null)
348891mS CMMap: cp[101]b1r0 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
349249mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
349252mS PRN: MZ stubs sip_cbk_fetchTxn no element found
349253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
349256mS RES: Mon 25/4/2016 14:17:55 FreeMem=70108128(2) CMMsg=5 (6) Buff=200 945 999 7454 5 Links=22279
349257mS RES2: IP 500 5.0(26) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=58 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
349884mS SIP Tx: UDP 10.0.54.240:5060 -> 212.11.94.246:5060
INVITE sip:01392440850@212.11.94.246 SIP/2.0
Via: SIP/2.0/UDP 217.179.12.239:5060;rport;branch=z9hG4bKe579e0cde6fc271645026acde6e48669
From: "01503262625" <sip:01503262625@217.179.12.239>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>
Call-ID: 553aa254150fd4ea5e633383604356a6@217.179.12.239
CSeq: 424544783 INVITE
Contact: "01503262625" <sip:01503262625@217.179.12.239:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO
Content-Type: application/sdp
Content-Length: 232
v=0
o=UserA 1291714132 2094996720 IN IP4 217.179.12.239
s=Session SDP
c=IN IP4 217.179.12.239
t=0 0
m=audio 49152 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
349887mS CMARS: MOVE TO ALTERNATE FORM: Main
349887mS CMARS: FORM: Main - Received Number: 01392440850
349887mS CMARS: FOUND A SHORT CODE - short_code: ? - Tel: . - Called_Party: 01392440850 - Line Group Id: 0
349887mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found
349887mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found
349888mS CMCallEvt: 0.1029.0 -1 BaseEP: NEW CMEndpoint f532c8d0 TOTAL NOW=3 CALL_LIST=1
349890mS CMARS: FOUND LINE - Line Id: 2 - using line group id: 0 - Called Number: 01392440850 - Calling Number: 124
349890mS CMARS: SEND Setup TO LINE - ARSTimeout
349891mS CMCallEvt: 0.1029.0 8 Alog Trunk:2: StateChange: END=child CMCSIdle->CMCSOffering
349891mS CMLineTx: v=2
CMSetup
Line: type=AnalogueLine 2 Call: lid=0 id=1029 in=0
Called[01392440850] Type=Default (100) Reason=CMDRdirect SndComp Calling[124] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=SteveGreen
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Steve Green
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=SteveGreen
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Steve Green
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=124
IE CMIEDeviceDetail (231) 0a0036f000000401 LOCALE=eng HW=8 VER=5 class=CMDeviceStdPhone type=41 number=7 channel=0 features=0x20 rx_gain=32 tx_gain=32 ep_callid=1025 ipaddr=10.0.54.240 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIEMohSourceId (247) MOH Source = 255
Locale: eng
349892mS CD: CALL: 0.1025.0 BState=Ringing Cut=3 Music=0.0 Aend="SteveGreen(124)" (20.7) Bend="" [Line 2] (0.0) CalledNum=01392440850 () CallingNum=124 (SteveGreen) Internal=1 Time=16645 AState=Ringing
349900mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
349903mS PRN: MZ stubs sip_cbk_fetchTxn no element found
349903mS PRN: MZ stubs sip_cbk_fetchTxn no element found
349944mS CMLineRx: v=2
CMSetupAck
Line: type=AnalogueLine 2 Call: lid=0 id=1029 in=0
BChan: slot=1 chan=2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=01392440850
IE CMIEDeviceDetail (231) 0a0036f000000405 LOCALE=eng HW=8 VER=5 class=CMDeviceAlogTrunk type=0 number=2 channel=0 features=0x1 rx_gain=32 tx_gain=32 ep_callid=1029 ipaddr=10.0.54.240 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
349945mS CMARS: LINE ep Received: CMSetupAck - child->state = CMCSOffering - ARS Call State = CMCSAccept
349945mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
349945mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: 0.1027.0 8 ARS for Main - Call State: CMCSAccept
349945mS CMCallEvt: 0.1027.0 -1 ARS for Main: StateChange: END=X CMCSAccept->CMCSDelete
349946mS CMCallEvt: 0.1029.0 8 Alog Trunk:2: StateChange: END=B CMCSOffering->CMCSOverlapRecv
349946mS CMCallEvt: 0.1027.0 -1 BaseEP: DELETE CMEndpoint f531eec4 TOTAL NOW=2 CALL_LIST=1
349948mS CMLineRx: v=2
CMProceeding
Line: type=AnalogueLine 2 Call: lid=0 id=1029 in=0
BChan: slot=1 chan=2
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=01392440850
IE CMIEDeviceDetail (231) 0a0036f000000405 LOCALE=eng HW=8 VER=5 class=CMDeviceAlogTrunk type=0 number=2 channel=0 features=0x0 rx_gain=32 tx_gain=32 ep_callid=1029 ipaddr=10.0.54.240 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
349948mS CMCallEvt: 0.1029.0 8 Alog Trunk:2: StateChange: END=B CMCSOverlapRecv->CMCSAccept
349949mS CMExtnTx: v=124, p1=0
CMProceeding
Line: type=DigitalExtn 2 Call: lid=0 id=1025 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=01392440850
IE CMIEDeviceDetail (231) 0a0036f000000405 LOCALE=eng HW=8 VER=5 class=CMDeviceAlogTrunk type=0 number=2 channel=0 features=0x0 rx_gain=32 tx_gain=32 ep_callid=1029 ipaddr=10.0.54.240 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Timed: 25/04/16 14:17
349949mS CD: CALL: 0.1025.0 BState=Ringing Cut=3 Music=0.0 Aend="SteveGreen(124)" (20.7) Bend="Line 2" [Line 2] (1.2) CalledNum=01392440850 () CallingNum=124 (SteveGreen) Internal=0 Time=16702 AState=Ringing
349950mS CMMap: Playing in progress, cp[101]b1r0 g null
349950mS CMMap: cp[101]b1r0 SetOperGroup from g null to g G[23] not executed, playing tones in progress ,EEEEE
349950mS CMMap: PCG::MapBChan pcp[91]b1r0 cp_b f59219fc other_cp_b 0 type CGTypeSimple
350714mS CMMap: PCG::UnmapBChan pcp[101]b1r0 cp_b f5507a08 other_cp_b f593b628
350714mS CMMap: a=21.39 b=20.7 M0
350714mS CMMap: a=21.39 b=0.0 T0
350715mS CMMap: a=21.39 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 5, total 8
350715mS CMMap: PCG::MapBChan pcp[101]b1r0 cp_b f5507a08 other_cp_b f59219fc type CGTypeSimple
350715mS CMMap: a=1.2 b=20.7 M1
351249mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
351252mS PRN: MZ stubs sip_cbk_fetchTxn no element found
351253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
353891mS CD: CALL: 0.1025.0 BState=Ringing Cut=3 Music=0.0 Aend="SteveGreen(124)" (20.7) Bend="Line 2" [Line 2] (1.2) CalledNum=01392440850 () CallingNum=124 (SteveGreen) Internal=0 Time=20644 AState=Ringing
354724mS CMLineRx: v=2
CMProgress
Line: type=AnalogueLine 2 Call: lid=0 id=1029 in=0
BChan: slot=1 chan=2
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) numbe
SIP calls go via Gradwell and are authenticated by IP address only.
Incoming calls are fine, but outgoing calls appear to establish a connection as far as ringing, but when the called person answers, the call is left with no speech in either direction.
What then appear to happen at the IPO is that the SIP call is dropped, although it does not drop for the called person, and a new call is made over PSTN trunks to the same number, via the ARS fallback route.
The end user says nothing changed on their router/firewall or network over the holiday, but I have my doubts being a school.
There is a trace of a failed call below, and this line is interesting:-
348253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
348253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
Which appears several time during an outbound call attempt.
I have seen posts similar to this on TT but none seem to match our scenario.
Could anyone point me in the right direction i.e. IPO or customers network?
Many thanks!
343884mS SIP Tx: UDP 10.0.54.240:5060 -> 212.11.94.246:5060
INVITE sip:01392440850@212.11.94.246 SIP/2.0
Via: SIP/2.0/UDP 217.179.12.239:5060;rport;branch=z9hG4bKe579e0cde6fc271645026acde6e48669
From: "01503262625" <sip:01503262625@217.179.12.239>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>
Call-ID: 553aa254150fd4ea5e633383604356a6@217.179.12.239
CSeq: 424544783 INVITE
Contact: "01503262625" <sip:01503262625@217.179.12.239:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO
Content-Type: application/sdp
Content-Length: 232
v=0
o=UserA 1291714132 2094996720 IN IP4 217.179.12.239
s=Session SDP
c=IN IP4 217.179.12.239
t=0 0
m=audio 49152 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
343899mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
343900mS PRN: MZ stubs sip_cbk_fetchTxn no element found
344256mS RES: Mon 25/4/2016 14:17:50 FreeMem=70089384(2) CMMsg=5 (6) Buff=200 946 999 7454 5 Links=22251
344256mS RES2: IP 500 5.0(26) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=58 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
344882mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Length: 0
344884mS PRN: MZ stubs sip_cbk_fetchTxn no element found
344885mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
344889mS PRN: MZ stubs sip_cbk_fetchTxn no element found
345884mS SIP Tx: UDP 10.0.54.240:5060 -> 212.11.94.246:5060
INVITE sip:01392440850@212.11.94.246 SIP/2.0
Via: SIP/2.0/UDP 217.179.12.239:5060;rport;branch=z9hG4bKe579e0cde6fc271645026acde6e48669
From: "01503262625" <sip:01503262625@217.179.12.239>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>
Call-ID: 553aa254150fd4ea5e633383604356a6@217.179.12.239
CSeq: 424544783 INVITE
Contact: "01503262625" <sip:01503262625@217.179.12.239:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO
Content-Type: application/sdp
Content-Length: 232
v=0
o=UserA 1291714132 2094996720 IN IP4 217.179.12.239
s=Session SDP
c=IN IP4 217.179.12.239
t=0 0
m=audio 49152 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
345914mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
345918mS PRN: MZ stubs sip_cbk_fetchTxn no element found
347751mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
347754mS PRN: MZ stubs sip_cbk_fetchTxn no element found
347754mS PRN: MZ stubs sip_cbk_fetchTxn no element found
348249mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
348253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
348253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
348885mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
348886mS CMCallEvt: 17.1028.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSOffering->CMCSCompleted
348886mS CMCallEvt: 17.1028.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSCompleted->CMCSDelete
348887mS CMARS: Target: Short_Code: N; - Line_Group_ID: 100 has been set to: CMARS_OUTOFSERVICE
348887mS CMCallEvt: 0.1027.0 8 ARS for iLine: StateChange: END=B CMCSOverlapRecv->CMCSAccept
348887mS CMCallEvt: 0.1025.0 8 SteveGreen.0: StateChange: END=A CMCSDialling->CMCSRingBack
348888mS CMExtnEvt: v=7 State, new=Alerting old=Dialling,0,0,SteveGreen
348888mS CMExtnTx: v=124, p1=0
CMProgress
Line: type=DigitalExtn 2 Call: lid=0 id=1025 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 25/04/16 14:17
348888mS Stun: ~STUNClient 10.0.54.240:49152
348889mS Stun: ~STUNClient 10.0.54.240:49153
348889mS CMCallEvt: 17.1028.0 -1 BaseEP: DELETE CMEndpoint f531db58 TOTAL NOW=2 CALL_LIST=1
348890mS CD: CALL: 0.1025.0 BState=Ringing Cut=3 Music=0.0 Aend="SteveGreen(124)" (20.7) Bend="" [] (0.0) CalledNum=01392440850 () CallingNum=124 (SteveGreen) Internal=1 Time=15642 AState=Ringing
348891mS CMMap: a=21.39 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 6, total 8
348891mS CMMap: a=21.39 b=1.255 T
348891mS CMMap: PCG::MapBChan pcp[101]b1r0 cp_b f5507a08 other_cp_b f593b628 type CGTypeDTMF
348891mS CMMap: a=21.39 b=20.7 M2
348891mS CMMap: DTMF:
layTones g T[22] ,EEEEE348891mS CMMap: Started playing tones, cp[101]b1r0 (from g null)
348891mS CMMap: cp[101]b1r0 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
349249mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
349252mS PRN: MZ stubs sip_cbk_fetchTxn no element found
349253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
349256mS RES: Mon 25/4/2016 14:17:55 FreeMem=70108128(2) CMMsg=5 (6) Buff=200 945 999 7454 5 Links=22279
349257mS RES2: IP 500 5.0(26) Tasks=32 RTEngine=0 CMRTEngine=0 Timer=58 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1
349884mS SIP Tx: UDP 10.0.54.240:5060 -> 212.11.94.246:5060
INVITE sip:01392440850@212.11.94.246 SIP/2.0
Via: SIP/2.0/UDP 217.179.12.239:5060;rport;branch=z9hG4bKe579e0cde6fc271645026acde6e48669
From: "01503262625" <sip:01503262625@217.179.12.239>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>
Call-ID: 553aa254150fd4ea5e633383604356a6@217.179.12.239
CSeq: 424544783 INVITE
Contact: "01503262625" <sip:01503262625@217.179.12.239:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, INFO
Content-Type: application/sdp
Content-Length: 232
v=0
o=UserA 1291714132 2094996720 IN IP4 217.179.12.239
s=Session SDP
c=IN IP4 217.179.12.239
t=0 0
m=audio 49152 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
349887mS CMARS: MOVE TO ALTERNATE FORM: Main
349887mS CMARS: FORM: Main - Received Number: 01392440850
349887mS CMARS: FOUND A SHORT CODE - short_code: ? - Tel: . - Called_Party: 01392440850 - Line Group Id: 0
349887mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found
349887mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found
349888mS CMCallEvt: 0.1029.0 -1 BaseEP: NEW CMEndpoint f532c8d0 TOTAL NOW=3 CALL_LIST=1
349890mS CMARS: FOUND LINE - Line Id: 2 - using line group id: 0 - Called Number: 01392440850 - Calling Number: 124
349890mS CMARS: SEND Setup TO LINE - ARSTimeout
349891mS CMCallEvt: 0.1029.0 8 Alog Trunk:2: StateChange: END=child CMCSIdle->CMCSOffering
349891mS CMLineTx: v=2
CMSetup
Line: type=AnalogueLine 2 Call: lid=0 id=1029 in=0
Called[01392440850] Type=Default (100) Reason=CMDRdirect SndComp Calling[124] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=SteveGreen
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Steve Green
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=SteveGreen
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Steve Green
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=124
IE CMIEDeviceDetail (231) 0a0036f000000401 LOCALE=eng HW=8 VER=5 class=CMDeviceStdPhone type=41 number=7 channel=0 features=0x20 rx_gain=32 tx_gain=32 ep_callid=1025 ipaddr=10.0.54.240 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIEMohSourceId (247) MOH Source = 255
Locale: eng
349892mS CD: CALL: 0.1025.0 BState=Ringing Cut=3 Music=0.0 Aend="SteveGreen(124)" (20.7) Bend="" [Line 2] (0.0) CalledNum=01392440850 () CallingNum=124 (SteveGreen) Internal=1 Time=16645 AState=Ringing
349900mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
349903mS PRN: MZ stubs sip_cbk_fetchTxn no element found
349903mS PRN: MZ stubs sip_cbk_fetchTxn no element found
349944mS CMLineRx: v=2
CMSetupAck
Line: type=AnalogueLine 2 Call: lid=0 id=1029 in=0
BChan: slot=1 chan=2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=01392440850
IE CMIEDeviceDetail (231) 0a0036f000000405 LOCALE=eng HW=8 VER=5 class=CMDeviceAlogTrunk type=0 number=2 channel=0 features=0x1 rx_gain=32 tx_gain=32 ep_callid=1029 ipaddr=10.0.54.240 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
349945mS CMARS: LINE ep Received: CMSetupAck - child->state = CMCSOffering - ARS Call State = CMCSAccept
349945mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
349945mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: 0.1027.0 8 ARS for Main - Call State: CMCSAccept
349945mS CMCallEvt: 0.1027.0 -1 ARS for Main: StateChange: END=X CMCSAccept->CMCSDelete
349946mS CMCallEvt: 0.1029.0 8 Alog Trunk:2: StateChange: END=B CMCSOffering->CMCSOverlapRecv
349946mS CMCallEvt: 0.1027.0 -1 BaseEP: DELETE CMEndpoint f531eec4 TOTAL NOW=2 CALL_LIST=1
349948mS CMLineRx: v=2
CMProceeding
Line: type=AnalogueLine 2 Call: lid=0 id=1029 in=0
BChan: slot=1 chan=2
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=01392440850
IE CMIEDeviceDetail (231) 0a0036f000000405 LOCALE=eng HW=8 VER=5 class=CMDeviceAlogTrunk type=0 number=2 channel=0 features=0x0 rx_gain=32 tx_gain=32 ep_callid=1029 ipaddr=10.0.54.240 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
349948mS CMCallEvt: 0.1029.0 8 Alog Trunk:2: StateChange: END=B CMCSOverlapRecv->CMCSAccept
349949mS CMExtnTx: v=124, p1=0
CMProceeding
Line: type=DigitalExtn 2 Call: lid=0 id=1025 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=01392440850
IE CMIEDeviceDetail (231) 0a0036f000000405 LOCALE=eng HW=8 VER=5 class=CMDeviceAlogTrunk type=0 number=2 channel=0 features=0x0 rx_gain=32 tx_gain=32 ep_callid=1029 ipaddr=10.0.54.240 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Timed: 25/04/16 14:17
349949mS CD: CALL: 0.1025.0 BState=Ringing Cut=3 Music=0.0 Aend="SteveGreen(124)" (20.7) Bend="Line 2" [Line 2] (1.2) CalledNum=01392440850 () CallingNum=124 (SteveGreen) Internal=0 Time=16702 AState=Ringing
349950mS CMMap: Playing in progress, cp[101]b1r0 g null
349950mS CMMap: cp[101]b1r0 SetOperGroup from g null to g G[23] not executed, playing tones in progress ,EEEEE
349950mS CMMap: PCG::MapBChan pcp[91]b1r0 cp_b f59219fc other_cp_b 0 type CGTypeSimple
350714mS CMMap: PCG::UnmapBChan pcp[101]b1r0 cp_b f5507a08 other_cp_b f593b628
350714mS CMMap: a=21.39 b=20.7 M0
350714mS CMMap: a=21.39 b=0.0 T0
350715mS CMMap: a=21.39 b=0.0 DTMF::~DTMF freed CMRTTonegen resource busy 5, total 8
350715mS CMMap: PCG::MapBChan pcp[101]b1r0 cp_b f5507a08 other_cp_b f59219fc type CGTypeSimple
350715mS CMMap: a=1.2 b=20.7 M1
351249mS SIP Rx: UDP 212.11.94.246:5060 -> 10.0.54.240:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.54.240:5060;received=10.0.54.240;branch=z9hG4bKe579e0cde6fc271645026acde6e48669;rport=5060
From: "01503262625" <sip:01503262625@10.0.54.240>;tag=e513bf3c96b4a751
To: <sip:01392440850@212.11.94.246>;tag=as706983b5
Call-ID: 553aa254150fd4ea5e633383604356a6@10.0.54.240
CSeq: 424544783 INVITE
Server: Asterisk PBX 11.21.0-gw0.62.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:*7718509552%2301392440850@212.11.94.246:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 271
v=0
o=root 1869653031 1869653031 IN IP4 212.11.94.246
s=Asterisk PBX 11.21.0-gw0.62.0
c=IN IP4 212.11.94.246
t=0 0
m=audio 18480 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
351252mS PRN: MZ stubs sip_cbk_fetchTxn no element found
351253mS PRN: MZ stubs sip_cbk_fetchTxn no element found
353891mS CD: CALL: 0.1025.0 BState=Ringing Cut=3 Music=0.0 Aend="SteveGreen(124)" (20.7) Bend="Line 2" [Line 2] (1.2) CalledNum=01392440850 () CallingNum=124 (SteveGreen) Internal=0 Time=20644 AState=Ringing
354724mS CMLineRx: v=2
CMProgress
Line: type=AnalogueLine 2 Call: lid=0 id=1029 in=0
BChan: slot=1 chan=2
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDNotISDN (1)
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) numbe