Didn't get a frame from channel: Which Channel?

Asterisk Asterisk Support
1

This an issue that comes up regularly. The call gets dropped randomly.

I want your opinion on whether this is the * server not receiving a frame from an internal sip phone, which would indicate a network issue, or could it be from the zap side of the equation?

I have a TE110P T1 and sip phones on the network side, with the latest * and zaptel (1.2.12.1*).

/etc/asterisk/zapata.conf employs callprogress and busydetect, busycount and busypattern. (USA)

Here is the log:

Sep 26 11:26:07 DEBUG[8118] chan_zap.c: Dialing 'xxx1215’
Sep 26 11:26:07 DEBUG[8118] chan_zap.c: Deferring dialing…
Sep 26 11:26:08 DEBUG[8118] chan_zap.c: Exception on 30, channel 20
Sep 26 11:26:08 DEBUG[8118] chan_zap.c: Got event Wink/Flash(3) on channel 20 (index 0)
Sep 26 11:26:08 DEBUG[8118] chan_zap.c: Ignoring wink on channel 20
Sep 26 11:26:08 DEBUG[8118] chan_zap.c: Exception on 30, channel 20
Sep 26 11:26:08 DEBUG[8118] chan_zap.c: Got event Hook Transition Complete(12) on channel 20 (index 0)
Sep 26 11:26:09 DEBUG[8118] chan_zap.c: Exception on 30, channel 20
Sep 26 11:26:09 DEBUG[8118] chan_zap.c: Got event Dial Complete(9) on channel 20 (index 0)
Sep 26 11:26:09 DEBUG[8118] chan_zap.c: Enabled echo cancellation on channel 20
Sep 26 11:26:09 DEBUG[8118] chan_zap.c: Engaged echo training on channel 20
Sep 26 11:26:11 DEBUG[8118] chan_zap.c: Exception on 30, channel 20
Sep 26 11:26:11 DEBUG[8118] chan_zap.c: Got event Dial Complete(9) on channel 20 (index 0)
Sep 26 11:26:11 DEBUG[8118] chan_zap.c: Echo cancellation already on
Sep 26 11:26:11 DEBUG[8118] chan_zap.c: Done dialing, but waiting for progress detection before doing more…
Sep 26 11:26:21 DEBUG[8118] chan_zap.c: Exception on 30, channel 20
Sep 26 11:26:21 DEBUG[8118] chan_zap.c: Got event Ring/Answered(2) on channel 20 (index 0)
Sep 26 11:26:21 DEBUG[8118] chan_zap.c: Line answered
Sep 26 11:26:21 DEBUG[8118] chan_sip.c: sip_answer(SIP/214-082ac870)
Sep 26 11:26:21 DEBUG[8118] rtp.c: Ooh, format changed from unknown to ulaw
Sep 26 11:26:21 DEBUG[8118] channel.c: Dropping duplicate answer!
Sep 26 11:26:22 DEBUG[8118] rtp.c: Got RTCP report of 92 bytes
Sep 26 11:26:32 DEBUG[8118] rtp.c: Got RTCP report of 92 bytes
Sep 26 11:26:33 DEBUG[8118] channel.c: Didn’t get a frame from channel: SIP/214-082ac870
Sep 26 11:26:33 DEBUG[8118] channel.c: Bridge stops bridging channels SIP/214-082ac870 and Zap/20-1
Sep 26 11:26:33 DEBUG[8118] channel.c: Hanging up channel 'Zap/20-1’
Sep 26 11:26:33 DEBUG[8118] chan_zap.c: zt_hangup(Zap/20-1)
Sep 26 11:26:33 DEBUG[8118] chan_zap.c: Hangup: channel: 20 index = 0, normal = 30, callwait = -1, thirdcall = -1
Sep 26 11:26:33 DEBUG[8118] chan_zap.c: disabled echo cancellation on channel 20
Sep 26 11:26:33 DEBUG[8118] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/20-1
Sep 26 11:26:33 DEBUG[8118] chan_zap.c: Updated conferencing on 20, with 0 conference users
Sep 26 11:26:33 DEBUG[8118] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Sep 26 11:26:33 DEBUG[8118] app_macro.c: Spawn extension (macro-dialout-trunk,s,16) exited non-zero on ‘SIP/214-082ac870’ in macro 'dialout-trunk’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Spawn extension (macro-dialout-trunk,s,16) exited non-zero on 'SIP/214-082ac870’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '“xxxxxxxx” '
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'xxxxxx9000’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'xxx1215’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'from-internal’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'SIP/214-082ac870’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'Zap/20-1’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'Dial’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'ZAP/G0/xxx1215|120|r’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '2006-09-26 11:26:07’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '2006-09-26 11:26:21’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '2006-09-26 11:26:33’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '26’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '12’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'ANSWERED’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is 'DOCUMENTATION’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '(null)'
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '1159284367.2748’
Sep 26 11:26:33 DEBUG[8118] pbx.c: Function result is '(null)'
Sep 26 11:26:33 DEBUG[8118] channel.c: Hanging up channel 'SIP/214-082ac870’
Sep 26 11:26:33 DEBUG[8118] chan_sip.c: Hangup call SIP/214-082ac870, SIP callid 895a5d63-d870c3a5-7aa6f6d6@10.0.1.186)
Sep 26 11:26:33 DEBUG[8118] chan_sip.c: update_call_counter(214) - decrement call limit counter
Sep 26 11:26:33 DEBUG[8118] chan_sip.c: Updating call counter for incoming call
Sep 26 11:26:33 DEBUG[8118] chan_sip.c: Call from user ‘214’ removed from call limit 2

Thanks for your input.

Jonathan Galpin

2

Sep 26 11:26:33 DEBUG[8118] channel.c: Didn’t get a frame from channel: SIP/214-082ac870

this indicates that the SIP endpoint stopped sending data. that would indicate to me that the internal network or endpoint is the issue.

best bet would be to try and get a wireshark (formerly ethereal) capture of the data stream and try to debug from that.

we are experiencing occasional issues of a similar nature - i have yet to get a good capture as our agents have not been very helpful or cooperative in terms of getting this resolved.

if you find anything, please post - i’d be interested in your results.