[cisco-voip] Remote site, phones unable to answer local POTS calls...

Ryan Ratliff rratliff at cisco.com
Mon Apr 26 16:04:02 EDT 2010


An IP phone console log is not at all where you need to be looking for the root of this.  Skinny phones are dumb, they just do what the CUCM (or CME) tell them to do.  You should be looking at CCM traces to see where the disconnect is originated and why.  I'd pay particular attention to the MGCP messages coming in.

-Ryan

On Apr 26, 2010, at 3:46 PM, Jonathan Charles wrote:

> I have a customer with remote sites over VPN and MGCP.
> 
> They have two FXO ports that are PLAR'd to a number on the two phones at the site.
> 
> When they try to answer, the call just drops.
> 
> If you put that DN (the PLAR DN) on a phone at HQ or another site, you can answer it fine...
> 
> Here is the phone trace:
> 
> |=== Syslogd === Fri Apr 23 05:08:24 2010
> ====================================================
> NOT 11:20:16.339662 DSP: STREAM- CloseEgressChan- ChanType 1, stream (48955692, 48955692) --> Chan 0
> NOT 11:20:16.343646 DSP: Added back for CODEC[0] G.711 direction:0 cost:14 old budget:71
> NOT 11:20:16.345560 DSP:  ETHSTAT-  (unicast, broadcast, multicast) rx  = 155437, 1194, 10135; tx = 432638, 234
> NOT 11:20:16.345997 DSP:  MIB2-  ipInDelivers= 155250, udpInDG= 122598, udpOutDG= 379907, udpNoPort= 29, udpInErr= 0, icmpInDestUnreach = 20, icmpOutDestUnreach = 1
> NOT 11:20:16.356629 DSP: STREAM- CloseIngressChan- ChanType 1, stream (48955692, 48955692) --> Chan 0
> NOT 11:20:16.361401 DSP: Added back for CODEC[0] G.711 direction:1 cost:15 old budget:85
> NOT 11:20:16.474339 DSP: ***MediaTerminationStopTone ignored, nonmatched call reference- new 48955733, current tone 48955692
> NOT 11:20:16.541935 DSP: ***MediaTerminationStopTone ignored, nonmatched call reference- new 48955733, current tone 48955692
> NOT 11:20:16.612986 DSP: ====== A phone call starts ....
> NOT 11:20:16.613866 DSP:  ETHSTAT-  (unicast, broadcast, multicast) rx  = 155438, 1194, 10135; tx = 432639, 234
> NOT 11:20:16.614811 DSP:  MIB2-  ipInDelivers= 155251, udpInDG= 122598, udpOutDG= 379907, udpNoPort= 29, udpInErr= 0, icmpInDestUnreach = 20, icmpOutDestUnreach = 1
> NOT 11:20:16.615743 DSP: STREAM- OpenEgressChan- ChanType 1, local (multicast host 0, port 0), MedType 12, Period 20, stream (48955733, 48955733) mix (1, 3)
> NOT 11:20:16.616839 DSP: STREAM- OpenEgressChan --> local port x0, reserved port x0, --> Chan 0
> NOT 11:20:16.619170 DSP: Subtracted for CODEC[2] G.729 or G.729B direction:0 cost:18 old budget:100
> NOT 11:20:16.643762 DSP: STREAM- OpenIngressChan- ChanType 1, Remote (host ac14a53e, port 4520), medType 12, Period 20, VAD 0, TOS b8, stream (48955733, 48955733) --> chan 0
> NOT 11:20:16.644799 DSP: STREAM- OpenIngressChan- mix (1, 3), dtmfpayloadtype 0
> NOT 11:20:16.646042 DSP: Subtracted for CODEC[2] G.729 or G.729B direction:1 cost:23 old budget:82
> NOT 11:20:16.813344 DSP: STREAM- CloseEgressChan- ChanType 1, stream (48955733, 48955733) --> Chan 0
> ERR 11:20:16.814306 DSP: MT:***RTP- zero (0) RTP packets receveid in 0 + seconds
> NOT 11:20:16.815515 DSP:  ETHSTAT-  (unicast, broadcast, multicast) rx  = 155444, 1194, 10135; tx = 432650, 236
> NOT 11:20:16.816466 DSP:  MIB2-  ipInDelivers= 155255, udpInDG= 122598, udpOutDG= 379915, udpNoPort= 29, udpInErr= 0, icmpInDestUnreach = 20, icmpOutDestUnreach = 1
> NOT 11:20:16.817451 DSP: select - total select returned = 46957, last snapshot = 0 
> NOT 11:20:16.818409 DSP: IP 0, stm SSRC x0:0, age 0, stTime 0, MCst 0
> NOT 11:20:16.819207 DSP: Packets discarded- Sequece number smaller than FIRST's 0, Clock Reset 0, Negative-Jitter packets 0, Dup Seq 0
> NOT 11:20:16.822768 DSP: Added back for CODEC[2] G.729 or G.729B direction:0 cost:18 old budget:59
> NOT 11:20:16.824965 DSP:  ETHSTAT-  (unicast, broadcast, multicast) rx  = 155444, 1194, 10135; tx = 432651, 236
> NOT 11:20:16.825925 DSP:  MIB2-  ipInDelivers= 155255, udpInDG= 122598, udpOutDG= 379915, udpNoPort= 29, udpInErr= 0, icmpInDestUnreach = 20, icmpOutDestUnreach = 1
> NOT 11:20:16.836205 DSP: STREAM- CloseIngressChan- ChanType 1, stream (48955733, 48955733) --> Chan 0
> NOT 11:20:16.841773 DSP: Added back for CODEC[2] G.729 or G.729B direction:1 cost:23 old budget:77
> NOT 11:20:24.942959 DSP: ***MediaTerminationStopTone ignored, nonmatched call reference- new 48955733, current tone 48955692
> WRN 11:20:25.233331 JVM: Startup Module Loader|cip.mmgr.ds:? - [MediaMgrSM]: Unhandled Event, State = StateOnHook Event = EventEndcall
> NOT 11:20:27.493661 DSP: ====== A phone call starts ....
> NOT 11:20:27.494542 DSP:  ETHSTAT-  (unicast, broadcast, multicast) rx  = 155453, 1194, 10135; tx = 432658, 236
> NOT 11:20:27.495496 DSP:  MIB2-  ipInDelivers= 155264, udpInDG= 122598, udpOutDG= 379916, udpNoPort= 29, udpInErr= 0, icmpInDestUnreach = 20, icmpOutDestUnreach = 1
> NOT 11:20:27.496435 DSP: STREAM- OpenEgressChan- ChanType 1, local (multicast host 0, port 0), MedType 4, Period 20, stream (48955692, 48955692) mix (1, 3)
> NOT 11:20:27.497477 DSP: STREAM- OpenEgressChan --> local port x0, reserved port x0, --> Chan 0
> NOT 11:20:27.499789 DSP: Subtracted for CODEC[0] G.711 direction:0 cost:14 old budget:100
> NOT 11:20:27.527585 DSP: STREAM- OpenIngressChan- ChanType 1, Remote (host a010102, port 40cc), medType 4, Period 20, VAD 0, TOS b8, stream (48955692, 48955692) --> chan 0
> NOT 11:20:27.528630 DSP: STREAM- OpenIngressChan- mix (1, 3), dtmfpayloadtype 0
> NOT 11:20:27.530135 DSP: Subtracted for CODEC[0] G.711 direction:1 cost:15 old budget:86
> NOT 11:21:15.120452 DSP: STREAM- CloseEgressChan- ChanType 1, stream (48955692, 48955692) --> Chan 0
> NOT 11:21:15.123486 DSP: Added back for CODEC[0] G.711 direction:0 cost:14 old budget:71
> NOT 11:21:15.125809 DSP:  ETHSTAT-  (unicast, broadcast, multicast) rx  = 155755, 1194, 10136; tx = 435049, 236
> NOT 11:21:15.127066 DSP:  MIB2-  ipInDelivers= 155566, udpInDG= 122887, udpOutDG= 382295, udpNoPort= 29, udpInErr= 0, icmpInDestUnreach = 20, icmpOutDestUnreach = 1
> NOT 11:21:15.138795 DSP: STREAM- CloseIngressChan- ChanType 1, stream (48955692, 48955692) --> Chan 0
> NOT 11:21:15.144475 DSP: Added back for CODEC[0] G.711 direction:1 cost:15 old budget:85
> NOT 11:21:15.256226 DSP: ***MediaTerminationStopTone ignored, nonmatched call reference- new 48955753, current tone 48955692
> NOT 11:21:15.302430 DSP: ***MediaTerminationStopTone ignored, nonmatched call reference- new 48955753, current tone 48955692
> NOT 11:21:15.390804 DSP: ====== A phone call starts ....
> NOT 11:21:15.391765 DSP:  ETHSTAT-  (unicast, broadcast, multicast) rx  = 155757, 1194, 10136; tx = 435052, 236
> NOT 11:21:15.392705 DSP:  MIB2-  ipInDelivers= 155568, udpInDG= 122887, udpOutDG= 382296, udpNoPort= 29, udpInErr= 0, icmpInDestUnreach = 20, icmpOutDestUnreach = 1
> NOT 11:21:15.393704 DSP: STREAM- OpenEgressChan- ChanType 1, local (multicast host 0, port 0), MedType 4, Period 20, stream (48955753, 48955753) mix (1, 3)
> NOT 11:21:15.394678 DSP: STREAM- OpenEgressChan --> local port x0, reserved port x0, --> Chan 0
> NOT 11:21:15.397059 DSP: Subtracted for CODEC[0] G.711 direction:0 cost:14 old budget:100
> NOT 11:21:15.429430 DSP: STREAM- OpenIngressChan- ChanType 1, Remote (host a0103ed, port 4464), medType 4, Period 20, VAD 0, TOS b8, stream (48955753, 48955753) --> chan 0
> NOT 11:21:15.430508 DSP: STREAM- OpenIngressChan- mix (1, 3), dtmfpayloadtype 0
> NOT 11:21:15.431951 DSP: Subtracted for CODEC[0] G.711 direction:1 cost:15 old budget:86
> NOT 11:21:43.295157 DSP: STREAM- CloseEgressChan- ChanType 1, stream (48955753, 48955753) --> Chan 0
> NOT 11:21:43.298723 DSP: Added back for CODEC[0] G.711 direction:0 cost:14 old budget:71
> NOT 11:21:43.301529 DSP:  ETHSTAT-  (unicast, broadcast, multicast) rx  = 157154, 1194, 10136; tx = 436452, 236
> NOT 11:21:43.302652 DSP:  MIB2-  ipInDelivers= 156965, udpInDG= 124274, udpOutDG= 383689, udpNoPort= 29, udpInErr= 0, icmpInDestUnreach = 20, icmpOutDestUnreach = 1
> NOT 11:21:43.317507 DSP: STREAM- CloseIngressChan- ChanType 1, stream (48955753, 48955753) --> Chan 0
> NOT 11:21:43.323572 DSP: Added back for CODEC[0] G.711 direction:1 cost:15 old budget:85
> NOT 11:21:43.333385 DSP: ***MediaTerminationStopTone ignored, nonmatched call reference- new 48955753, current tone 48955692
> WRN 11:21:43.794704 JVM: Startup Module Loader|cip.mmgr.ds:? - [MediaMgrSM]: Unhandled Event, State = StateOnHook Event = EventSetSpeakerModeOff
> WRN 11:21:43.796739 JVM: Startup Module Loader|cip.mmgr.ds:? - [MediaMgrSM]: Unhandled Event, State = StateOnHook Event = EventEndcall
> WRN 11:21:49.145365 JVM: Startup Module Loader|cip.mmgr.ds:? - [MediaMgrSM]: Unhandled Event, State = StateSpeakerOffHook Event = EventSetSpeakerMode
> WRN 11:22:04.233414 JVM: Startup Module Loader|cip.mmgr.ds:? - [MediaMgrSM]: Unhandled Event, State = StateOnHook Event = EventSetSpeakerModeOff
> WRN 11:22:04.235423 JVM: Startup Module Loader|cip.mmgr.ds:? - [MediaMgrSM]: Unhandled Event, State = StateOnHook Event = EventEndcall
> ERR 11:22:48.252904 JVM: compactRecords dbDataStart:48
> ERR 11:22:48.254926 JVM: compactRecords dbDataEnd:61312
> 
> 
> 
> Nothing really weird, except for the RTP zero packets.... 
> 
> MGCP is bound to the voice subinterface.
> 
> This was working two weeks ago, then stopped.
> 
> Any help would be appreciated... thanks!
> 
> 
> 
> 
> Jonathan
> _______________________________________________
> cisco-voip mailing list
> cisco-voip at puck.nether.net
> https://puck.nether.net/mailman/listinfo/cisco-voip




More information about the cisco-voip mailing list