Yet another PRI with dropped calls

Hi, I’m having some issues with some dropped calls.
while having a conversation the call gets dropped, this is not all the time, but about 3-4 times a day out of 200-250 calls a day.

I’m running Asterisk 1.2.14 with zaptel-1.2.12 and libpri-1.2.4 with an Te210p on an Dell 850 with 1Gb ram.
Phones : Aastra 480i with firmware 1.4.1

Can anyone see if it’s the telco or the asterisk or the phones that is disconnecting the call ??

I have searched the forums for a couple of days, but did not find anything pointing me in the right direction.

Any help would be greatly appreciated. Thanks! :smiley:

Here is what comes out of the log with pri intense debug span 1 turned on:

Dec 19 14:04:49 VERBOSE[4502] logger.c: T203 counter expired, sending RR and scheduling T203 again
Dec 19 14:04:49 VERBOSE[4502] logger.c: Sending Receiver Ready (51)
Dec 19 14:04:49 VERBOSE[4502] logger.c:

[ 00 01 01 67 ]
Dec 19 14:04:49 VERBOSE[4502] logger.c:
Supervisory frame:
Dec 19 14:04:49 VERBOSE[4502] logger.c: > SAPI: 00 C/R: 0 EA: 0
TEI: 000 EA: 1
Dec 19 14:04:49 VERBOSE[4502] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
N®: 051 P/F: 1
0 bytes of data
Dec 19 14:04:49 VERBOSE[4502] logger.c: – Restarting T203 counter
Dec 19 14:04:49 VERBOSE[4502] logger.c:
< [ 00 01 01 81 ]
Dec 19 14:04:49 VERBOSE[4502] logger.c:
< Supervisory frame:
Dec 19 14:04:49 VERBOSE[4502] logger.c: < SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
Dec 19 14:04:49 VERBOSE[4502] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N®: 064 P/F: 1
< 0 bytes of data
Dec 19 14:04:49 VERBOSE[4502] logger.c: – ACKing all packets from 63 to (but not including) 64
Dec 19 14:04:49 VERBOSE[4502] logger.c: – Since there was nothing left, stopping T200 counter
Dec 19 14:04:49 VERBOSE[4502] logger.c: – Stopping T203 counter since we got an ACK
Dec 19 14:04:49 VERBOSE[4502] logger.c: – Nothing left, starting T203 counter
Dec 19 14:04:49 VERBOSE[4502] logger.c: – Got RR response to our frame
Dec 19 14:04:49 VERBOSE[4502] logger.c: – Restarting T203 counter
Dec 19 14:04:50 DEBUG[8426] channel.c: Didn’t get a frame from channel: SIP/2726-0901db38
Dec 19 14:04:50 DEBUG[8426] channel.c: Bridge stops bridging channels SIP/2726-0901db38 and Zap/3-1
Dec 19 14:04:50 DEBUG[8426] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/3-1
Dec 19 14:04:50 DEBUG[8426] chan_zap.c: Hangup: channel: 3 index = 0, normal = 20, callwait = -1, thirdcall = -1
Dec 19 14:04:50 DEBUG[8426] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
Dec 19 14:04:50 VERBOSE[8426] logger.c:
[ 00 01 80 66 08 02 00 4a 45 08 02 81 90 ]
Dec 19 14:04:50 VERBOSE[8426] logger.c:
Informational frame:
Dec 19 14:04:50 VERBOSE[8426] logger.c: > SAPI: 00 C/R: 0 EA: 0
TEI: 000 EA: 1
Dec 19 14:04:50 VERBOSE[8426] logger.c: > N(S): 064 0: 0
N®: 051 P: 0
9 bytes of data
Dec 19 14:04:50 VERBOSE[8426] logger.c: – Restarting T203 counter
Dec 19 14:04:50 VERBOSE[8426] logger.c: Stopping T_203 timer
Dec 19 14:04:50 VERBOSE[8426] logger.c: Starting T_200 timer
Dec 19 14:04:50 VERBOSE[8426] logger.c: > Protocol Discriminator: Q.931 (Cool len=9
Dec 19 14:04:50 VERBOSE[8426] logger.c: > Call Ref: len= 2 (reference 74/0x4A) (Originator)
Dec 19 14:04:50 VERBOSE[8426] logger.c: > Message type: DISCONNECT (69)
Dec 19 14:04:50 VERBOSE[8426] logger.c: > [08 02 81 90]
Dec 19 14:04:50 VERBOSE[8426] logger.c: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1)
Dec 19 14:04:50 VERBOSE[8426] logger.c: > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ]
Dec 19 14:04:50 DEBUG[8426] chan_zap.c: disabled echo cancellation on channel 3
Dec 19 14:04:50 DEBUG[8426] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/3-1
Dec 19 14:04:50 DEBUG[8426] chan_zap.c: Updated conferencing on 3, with 0 conference users
Dec 19 14:04:50 DEBUG[8426] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/3-1
Dec 19 14:04:50 DEBUG[8426] chan_zap.c: disabled echo cancellation on channel 3
Dec 19 14:04:50 VERBOSE[8426] logger.c: – Hungup ‘Zap/3-1’
Dec 19 14:04:50 DEBUG[8426] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Dec 19 14:04:50 VERBOSE[8426] logger.c: == Spawn extension (macro-dialout-trunk, s, 16) exited non-zero on ‘SIP/2726-0901db38’ in macro ‘dialout-trunk’
Dec 19 14:04:50 VERBOSE[8426] logger.c: == Spawn extension (macro-dialout-trunk, s, 16) exited non-zero on ‘SIP/2726-0901db38’
Dec 19 14:04:50 DEBUG[8426] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 19 14:04:50 DEBUG[8426] 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,uniqueid) VALUES (‘2006-12-19 13:59:20’,‘xxxxxxxx’,‘xxxxxxxx’,‘0049xxxxxxxxxx’,‘from-internal’, ‘SIP/2726-0901db38’,‘Zap/3-1’,‘Dial’,‘ZAP/g0/0049xxxxxxxxxx|120|r’,330,321,‘ANSWERED’,3,’’,’.376’)
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'xxxxxxxx’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'xxxxxxxx’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '0049xxxxxxxxxx’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'from-internal’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'SIP/2726-0901db38’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'Zap/3-1’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'Dial’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'ZAP/g0/0049xxxxxxxxxx|120|r’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '2006-12-19 13:59:20’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '2006-12-19 13:59:29’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '2006-12-19 14:04:50’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '330’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '321’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'ANSWERED’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is 'DOCUMENTATION’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '(null)'
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '.376’
Dec 19 14:04:50 DEBUG[8426] pbx.c: Function result is '(null)'
Dec 19 14:04:50 DEBUG[8426] chan_sip.c: update_call_counter(2726) - decrement call limit counter
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2718
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2710
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2708
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2723
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2713
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2705
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2715
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2707
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2717
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2711
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2725
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2709
Dec 19 14:04:50 VERBOSE[4490] logger.c: Extension Changed 2726 new state Idle for Notify User 2706
Dec 19 14:04:50 VERBOSE[4502] logger.c:

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
channel => 1-15,17-31

group=1
context=from-pstn
switchtype=euroisdn
signalling=pri_net
priindication=outofband
echocancel=yes
echocancelwhenbridged=yes
echotraining=yes
echotraining=400
callgroup=1
pickupgroup=1
immediate=no
busydetect=no
callprogress=no
channel => 32-46,48-62

Asterisk hungup the call. It was a normal hangup and not an error on the PRI side atleast. Probably need to look into the sip debug now.

Thanks for the answer.
It must be my Aastra phones dropping the call then, I will have to look into the Sip debug then.

I wen’t from Asterisk 1.2.7 to 1.2.14 and it kept on dropping calls. I might ask the Aastra people in the Trixbox forum if they have heard of it before.
(I will post back when I get it solved, if it can help others with the same issue)

M<<