Call Dropping - didn't get a frame

Asterisk Asterisk Support
1

I have an intermittent problem with calls dropping. I’ve set busydetect and callprogress to no. From the looks of the log, it might actually be a sip problem but I am unsure. I have a 4 port FXO digium card and all calls go through the PSTN. The relevant entry is about halfway down:

Nov 8 07:13:24 DEBUG[3138] acl.c: ##### Testing 10.10.10.223 with 10.10.10.0
Nov 8 07:13:24 DEBUG[3138] chan_sip.c: Stopping retransmission on ‘33d54511206523577ca8321b2acf3ed9@10.10.10.240’ of Request 102: Match Found
Nov 8 07:13:28 DEBUG[3138] channel.c: Scheduling timer at 0 sample intervals
Nov 8 07:13:28 DEBUG[3138] chan_sip.c: Stopping retransmission on ‘127934477a67545574a7c9c308890260@10.10.10.240’ of Response 1317948817: Match Found
Nov 8 07:13:33 DEBUG[3138] chan_sip.c: Auto destroying call '34728b0ec47e4aefe0f0046ddf529593@10.10.10.223’
Nov 8 07:13:44 DEBUG[15982] channel.c: Didn’t get a frame from channel: SIP/203-0986b638
Nov 8 07:13:44 DEBUG[15982] channel.c: Bridge stops bridging channels Zap/1-1 and SIP/203-0986b638
Nov 8 07:13:44 DEBUG[15982] chan_sip.c: update_call_counter(203) - decrement call limit counter
Nov 8 07:13:44 DEBUG[15982] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Nov 8 07:13:44 DEBUG[15982] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.

Please help!

2

Can anyone venture a guess as to what the log entries mean? It seems as though I’m losing contact with the phone…

3

If you find out let me know… I am having the exact same problem!!!

Thanks,
Dan
Dan.Creed@thecreeds.net

4

I can join you for that… I’m using Aastra 480i phones, and my log does look the same,
channel.c: Didn’t get a frame from channel: SIP/

and then just after
channel.c: Bridge stops bridging channels Zap/1-1 and SIP/

what kind of sip phones are you using ???

5

Hey,
It would be great if you post the entry you have in sip.conf about this phone.
And also talk about your network setup, Ex: Does your sip phone is behind nat?

6

NO NAT… I’ve got my asterisk box configured with a public IP address… my client to my asterisk box is of course NAT’ed 192.168.10.X…

I use broad voice… here is my sip_additional.conf (using freepbx)

register=2627350025@sip.broadvoice.com:9639wx29q9:2627350025@sip.broadvoice.com

[210]
username=210
type=friend
secret=1234
record_out=Always
record_in=Always
qualify=yes
port=5060
nat=yes
mailbox=210@device
host=dynamic
dtmfmode=rfc2833
context=from-internal
canreinvite=yes
callerid=House Phone <210>

[broadvoice-in]
username=2627350025
user=2627350025
type=user
secret=9639wx29q9
nat=no
insecure=very
host=sip.broadvoice.com
fromdomain=sip.broadvoice.com
dtmfmode=inband
dtmf=inband
context=from-pstn

[broadvoice-out]
username=2627350025
user=phone
type=peer
secret=9639wx29q9
nat=no
insecure=very
host=sip.broadvoice.com
fromuser=2627350025
fromdomain=sip.broadvoice.com
dtmfmode=inband
dtmf=inband
context=from-pstn
canreinvite=no
authname=2627350025

Here is the log from a call

Dec 22 11:57:46 VERBOSE[3412] logger.c: – SIP/broadvoice-out-0a1b11f0 is making progress passing it to SIP/201-0a1b61d8
Dec 22 11:57:46 DEBUG[3412] channel.c: Building translator from ulaw to SLINEAR for spies on channel SIP/201-0a1b61d8
Dec 22 11:57:52 DEBUG[3316] chan_sip.c: Acked pending invite 103
Dec 22 11:57:52 DEBUG[3316] chan_sip.c: Stopping retransmission on '3d2a445b5df20cfb0a46aee13a67a663@sip.broadvoice.com’ of Request 103: Match Found
Dec 22 11:57:52 DEBUG[3316] chan_sip.c: build_route: Contact hop: sip:4142326957@147.135.12.128
Dec 22 11:57:52 VERBOSE[3412] logger.c: – SIP/broadvoice-out-0a1b11f0 answered SIP/201-0a1b61d8
Dec 22 11:57:52 DEBUG[3316] chan_sip.c: Stopping retransmission on ‘b4bc2c49-90302803@192.168.10.224’ of Response 102: Match Found
Dec 22 11:57:55 DEBUG[3316] chan_sip.c: Scheduled a registration timeout for sip.broadvoice.com id #134
Dec 22 11:57:56 DEBUG[3316] chan_sip.c: Stopping retransmission on ‘6fd23abf0bd9ca823cf2e6d64e9e9dcd@127.0.0.1’ of Request 115: Match Found
Dec 22 11:57:56 DEBUG[3316] chan_sip.c: Registration successful
Dec 22 11:57:56 DEBUG[3316] chan_sip.c: Cancelling timeout 134
Dec 22 11:58:03 DEBUG[3316] chan_sip.c: Auto destroying call '6fd23abf0bd9ca823cf2e6d64e9e9dcd@127.0.0.1’
Dec 22 11:58:07 DEBUG[3316] chan_sip.c: Stopping retransmission on ‘1bb890ea3462cad433ed406f3950b0ef@192.168.10.16’ of Request 102: Match Found
Dec 22 11:58:07 DEBUG[3316] chan_sip.c: Stopping retransmission on ‘2d712143695a5a3815a258f109c1161e@192.168.10.16’ of Request 102: Match Found
Dec 22 11:58:07 DEBUG[3316] chan_sip.c: Stopping retransmission on ‘2d6990ea1155e0cd6e73a99f0f35073e@192.168.10.16’ of Request 102: Match Found
Dec 22 11:58:07 DEBUG[3412] channel.c: Didn’t get a frame from channel: SIP/201-0a1b61d8
Dec 22 11:58:07 DEBUG[3412] channel.c: Bridge stops bridging channels SIP/201-0a1b61d8 and SIP/broadvoice-out-0a1b11f0
Dec 22 11:58:07 DEBUG[3412] chan_sip.c: update_call_counter(4142326957) - decrement call limit counter
Dec 22 11:58:07 DEBUG[3412] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Dec 22 11:58:07 VERBOSE[3412] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on ‘SIP/201-0a1b61d8’ in macro ‘dialout-trunk’
Dec 22 11:58:07 VERBOSE[3412] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on ‘SIP/201-0a1b61d8’
Dec 22 11:58:07 VERBOSE[3412] logger.c: – Executing Macro(“SIP/201-0a1b61d8”, “hangupcall”) in new stack
Dec 22 11:58:07 VERBOSE[3412] logger.c: – Executing ResetCDR(“SIP/201-0a1b61d8”, “w”) in new stack
Dec 22 11:58:07 DEBUG[3412] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 22 11:58:07 DEBUG[3412] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES (‘2006-12-22 11:57:43’,‘2627350025’,‘2627350025’,‘4142326957’,‘from-internal’, ‘SIP/201-0a1b61d8’,‘SIP/broadvoice-out-0a1b11f0’,‘ResetCDR’,‘w’,24,15,‘ANSWERED’,3,’’)
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '2627350025’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '2627350025’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '4142326957’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is 'from-internal’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is 'SIP/201-0a1b61d8’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is 'SIP/broadvoice-out-0a1b11f0’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is 'ResetCDR’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is 'w’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '2006-12-22 11:57:43’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '2006-12-22 11:57:52’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '2006-12-22 11:58:07’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '24’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '15’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is 'ANSWERED’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is 'DOCUMENTATION’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '(null)'
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '1166810263.6’
Dec 22 11:58:07 DEBUG[3412] pbx.c: Function result is '(null)'
Dec 22 11:58:07 VERBOSE[3412] logger.c: – Executing NoCDR(“SIP/201-0a1b61d8”, “”) in new stack
Dec 22 11:58:07 NOTICE[3412] cdr.c: CDR on channel ‘SIP/201-0a1b61d8’ not posted
Dec 22 11:58:07 NOTICE[3412] cdr.c: CDR on channel ‘SIP/201-0a1b61d8’ lacks end
Dec 22 11:58:07 DEBUG[3412] pbx.c: Expression result is '1’
Dec 22 11:58:07 VERBOSE[3412] logger.c: – Executing GotoIf(“SIP/201-0a1b61d8”, “1?theend”) in new stack
Dec 22 11:58:07 VERBOSE[3412] logger.c: – Goto (macro-hangupcall,s,6)
Dec 22 11:58:07 VERBOSE[3412] logger.c: – Executing Wait(“SIP/201-0a1b61d8”, “5”) in new stack
Dec 22 11:58:07 VERBOSE[3412] logger.c: == Spawn extension (macro-hangupcall, s, 6) exited non-zero on ‘SIP/201-0a1b61d8’ in macro 'hangupcall’
Dec 22 11:58:07 VERBOSE[3412] logger.c: == Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/201-0a1b61d8’
Dec 22 11:58:07 DEBUG[3412] channel.c: Spy MixMonitor removed from channel SIP/201-0a1b61d8
Dec 22 11:58:07 DEBUG[3412] chan_sip.c: update_call_counter(201) - decrement call limit counter

7

The client phone is a Sipura SPA2002… Can give you access to my system if you want to look through the logs and config’s yourself…

Thanks,
Dan

8

My setup : Phones and the asterisk server in the same network on an
Edgecore POE switch with 15 Aastra 480i (the switch is only used for voip).
Server :smiley:ell 2850 with 2 Gig ram. Digium TE210P with 1 Pri connected to telco.

Zaptel.conf:
loadzone = no
defaultzone = no

span=1,1,0,ccs,hdb3,crc4
span=2,0,0,ccs,hdb3,crc4

bchan=1-15
dchan=16
bchan=17-31

bchan=32-46
dchan=47
bchan=48-62

Zapata.conf:
[trunkgroups]

[channels]

language=nl
context=from-pstn
switchtype=euroisdn
signalling=pri_cpe
rxwink=300 ; Atlas seems to use long (250ms) winks
;
; Whether or not to do distinctive ring detection on FXO lines
;
;usedistinctiveringdetection=yes
priindication=outofband
usecallerid=yes
hidecallerid=no
callwaiting=yes
usecallingpres=yes
callwaitingcallerid=yes
threewaycalling=yes
transfer=yes
cancallforward=yes
callreturn=yes
echocancel=yes
echocancelwhenbridged=yes
echotraining=yes
echotraining=400
rxgain=1.0
txgain=-1.0
group=0
callgroup=1
pickupgroup=1
immediate=no
busydetect=no
callprogress=no
resetinterval=never
channel => 1-15,17-31

Sip.conf:
[2705]
username=2705
type=friend
secret=2705
record_out=Adhoc
record_in=Adhoc
qualify=no
port=5060
pickupgroup=1
nat=never
mailbox=2705@device
host=dynamic
dtmfmode=rfc2833
disallow=all
context=from-internal
canreinvite=no
callgroup=1
callerid=2705 <2705>
allow=alaw

The users have experienced beeing disconnected even in a meetme conference dialing local.