[Cybernavy]

Hi guys,

I've got a problem that I can't seem to fix, even after a few weeks of trial/errors trying all that was suggested to me on other forums.


Our setup (in Belgium via Belgacom):
Dell 2950 server with Digium ISDN 4 port B410P card and 8 Linksys SPA962 phones.
Our supplier installed asterisk + MISDN + freepbx on the server and configured the SPA962 phones.
All our external calls are done via ISDN and an VoIP provider is configured, but not used.


Our problem:
Some 10% of ALL calls have a very bad habit of connecting the phones, but transmitting no sound.

Most of the times no sound is heared both ways, but sometimes it is only one phone that doens't receive sound ... the other phone does hear the swearing

This problem persist on both external AND internal calls!
The phone's display always shows a "connected ..."

I've tempered with the MISDN-init.conf, SPA962 settings and Asterisk extension settings .. but I haven't got a real clue what the problem could be.
Most sound problems can be traced back to NAT problems, but I've tried most NAT combinations on asterisk/Linksys already ... and the problem is also happening on internal calls that don't use NAT (external calls don't use NAT either I suppose since we use ISDN lines?).

Anybody?


There are a few answers that might help:
- how is your MISDN-init.conf configured. What is used: cyrstalclock, rxclock, DTMF, ...
- what are the exact SIP, NAT, RTP and DTMF settings on asterisk and on the phones.
- what are the SIP phones settings needed in asterisk?


any help is greatly appreciated ... because I'm out of options and this problem is still present after our first install some 6 months ago


edit: will try these settings http://forum.voxilla.com/linksys-spa...ium-23714.html

[Cybernavy]

anybody? any suggestion or someone willing to share his misdn-init.conf and/or SIP/RTP/... settings?

[mudcow007]

when the call disconnects is there any shown on the cli (command line interface)?

on asterisk type this

core set verbose 10

this will give you alot more out of asterisk an might describe your problem more

Sip settings in asterisk are pretty basic

sip.conf and extensions.conf work hand in hand

here is my setting in sip.conf

[general]
disallow=all
allow=ulaw
allow=alway

[phones1](!)
type=friend ;inbound and outbound calls
secret=password
qualify=yes ;phone is less than 2000ms away
nat=no ;phones arnt natted
host=dynamic ;this devive registers with us
canreinvite=no ;asterisk by default tries to redirect
call-limit=99 ; for hints

[Cybernavy]

Hmm,

Found that logging is kept in the FreePBX, so I will post the log here as soon as my collegues warn me about the problem occuring.

How can I check if this is correct? Is the packet size some option that has to correspondent to an Asterisk setting?
RTP Parameters
RTP Port Min: 5000
RTP Port Max: 5100
RTP Packet Size: 0.020
Max RTP ICMP Err: 0
RTCP Tx Interval: 0
No UDP Checksum: no
Symmetric RTP: yes
Stats In BYE: no

[Cybernavy]

it didn't take long, is this enough detail ?

Jun 5 10:47:44 DEBUG[26840] manager.c: Manager received command 'Ping'
Jun 5 10:47:45 DEBUG[4473] chan_sip.c: Stopping retransmission on '07bbce1a56636d0c46074f7e5fd6e847@192.168.1.55' of Request 102: Match Found
Jun 5 10:47:45 DEBUG[4473] chan_sip.c: Stopping retransmission on '468b8a6d4e37c96818b202371401900f@192.168.1.55' of Request 102: Match Found
Jun 5 10:47:45 DEBUG[4473] chan_sip.c: Stopping retransmission on '2af8bfa9789d3ac97f5a40f357af0bff@192.168.1.55' of Request 102: Match Found
Jun 5 10:47:45 DEBUG[9504] manager.c: Manager received command 'login'
Jun 5 10:47:45 VERBOSE[9504] logger.c: == Parsing '/etc/asterisk/manager.conf': Jun 5 10:47:45 VERBOSE[9504] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Jun 5 10:47:45 VERBOSE[9504] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': Jun 5 10:47:45 VERBOSE[9504] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': Found
Jun 5 10:47:45 VERBOSE[9504] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Jun 5 10:47:45 VERBOSE[9504] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Jun 5 10:47:45 DEBUG[9504] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Jun 5 10:47:45 DEBUG[9504] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Jun 5 10:47:45 DEBUG[9504] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Jun 5 10:47:45 DEBUG[9504] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Jun 5 10:47:45 VERBOSE[9504] logger.c: == Manager 'admin' logged on from 127.0.0.1
Jun 5 10:47:45 VERBOSE[9504] logger.c: == Manager 'admin' logged off from 127.0.0.1
Jun 5 10:47:46 DEBUG[4473] chan_sip.c: Stopping retransmission on '6d9eea452e036b443a1970e24b2627c3@192.168.1.55' of Request 102: Match Found
Jun 5 10:47:47 DEBUG[9438] channel.c: Didn't get a frame from channel: SIP/23-08ac9fd0
Jun 5 10:47:47 DEBUG[9438] channel.c: Bridge stops bridging channels SIP/22-08dd3918 and SIP/23-08ac9fd0
Jun 5 10:47:47 DEBUG[9438] chan_sip.c: update_call_counter(23) - decrement call limit counter
Jun 5 10:47:47 DEBUG[9438] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Jun 5 10:47:47 VERBOSE[9438] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on 'SIP/22-08dd3918' in macro 'dial'
Jun 5 10:47:47 VERBOSE[9438] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on 'SIP/22-08dd3918' in macro 'exten-vm'
Jun 5 10:47:47 VERBOSE[9438] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on 'SIP/22-08dd3918'
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Executing Macro("SIP/22-08dd3918", "hangupcall") in new stack
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Executing ResetCDR("SIP/22-08dd3918", "w") in new stack
Jun 5 10:47:47 DEBUG[9438] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jun 5 10:47:47 DEBUG[9438] 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,ama flags,accountcode) VALUES ('2008-06-05 10:47:31','\"Ann\" <22>','22','23','from-internal', 'SIP/22-08dd3918','SIP/23-08ac9fd0','ResetCDR','w',16,13,'ANSWERED',3,'')
Jun 5 10:47:47 DEBUG[9438] app_macro.c: Executed application: ResetCDR
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Executing NoCDR("SIP/22-08dd3918", "") in new stack
Jun 5 10:47:47 NOTICE[9438] cdr.c: CDR on channel 'SIP/22-08dd3918' not posted
Jun 5 10:47:47 NOTICE[9438] cdr.c: CDR on channel 'SIP/22-08dd3918' lacks end
Jun 5 10:47:47 DEBUG[9438] app_macro.c: Executed application: NoCDR
Jun 5 10:47:47 DEBUG[9438] pbx.c: Expression result is '1'
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Executing GotoIf("SIP/22-08dd3918", "1?skiprg") in new stack
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Goto (macro-hangupcall,s,6)
Jun 5 10:47:47 DEBUG[9438] app_macro.c: Executed application: GotoIf
Jun 5 10:47:47 DEBUG[9438] pbx.c: Expression result is '1'
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Executing GotoIf("SIP/22-08dd3918", "1?skipblkvm") in new stack
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Goto (macro-hangupcall,s,9)
Jun 5 10:47:47 DEBUG[9438] app_macro.c: Executed application: GotoIf
Jun 5 10:47:47 DEBUG[9438] pbx.c: Expression result is '1'
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Executing GotoIf("SIP/22-08dd3918", "1?theend") in new stack
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Goto (macro-hangupcall,s,11)
Jun 5 10:47:47 DEBUG[9438] app_macro.c: Executed application: GotoIf
Jun 5 10:47:47 VERBOSE[9438] logger.c: -- Executing Hangup("SIP/22-08dd3918", "") in new stack
Jun 5 10:47:47 VERBOSE[9438] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/22-08dd3918' in macro 'hangupcall'
Jun 5 10:47:47 VERBOSE[9438] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/22-08dd3918'
Jun 5 10:47:47 DEBUG[9438] chan_sip.c: update_call_counter(22) - decrement call limit counter
Jun 5 10:47:47 DEBUG[4473] chan_sip.c: Stopping retransmission on 'effdb500-78604114@192.168.1.151' of Request 102: Match Found
Jun 5 10:47:49 DEBUG[9522] manager.c: Manager received command 'login'
Jun 5 10:47:49 VERBOSE[9522] logger.c: == Parsing '/etc/asterisk/manager.conf': Jun 5 10:47:49 VERBOSE[9522] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Jun 5 10:47:49 VERBOSE[9522] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': Jun 5 10:47:49 VERBOSE[9522] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': Found
Jun 5 10:47:49 VERBOSE[9522] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Jun 5 10:47:49 VERBOSE[9522] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Jun 5 10:47:49 DEBUG[9522] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Jun 5 10:47:49 DEBUG[9522] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Jun 5 10:47:49 DEBUG[9522] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Jun 5 10:47:49 DEBUG[9522] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Jun 5 10:47:49 VERBOSE[9522] logger.c: == Manager 'admin' logged on from 127.0.0.1
Jun 5 10:47:49 VERBOSE[9522] logger.c: == Manager 'admin' logged on from 127.0.0.1

[Cybernavy]

any luck finding some strangeness in the log?

[mudcow007]

did you check your codecs?

did the log happen when a call was dropped?

it looks like the call is dropping into a macro called "macro-hangupcall" follow your dialplan through an see what happens to calls

[Cybernavy]

yes, this was taken just after a dropped call was done.

FreePBX
I changed the SIP config allow/disallow in FreePBX to (before today these options were empty .. to allow anything I guess):

This device uses sip technology.s
secret: xxx
dtmfmode: rfc2833
canreinvite: yes
context: from-internal
host: dynamic
type: friend
nat: yes
port: 5060
qualify: yes
callgroup: 1
pickupgroup: 1
disallow:
allow:
dial: SIP/22
accountcode:
mailbox: 22@device

On the asterisk
changed the config misdn-init.conf yesterday, because leaving out the last option created a higher percentage of lost calls.
card=1,0x4,dtmf
te_ptp=1,2
te_ptmp=3
bridging=no
poll=128
#dsp_poll=128
#dsp_options=0
#dtmfthreshold=100
debug=0

but is dtmf the way to go?
Doesn't that need to be changed according to the ISDN card we have? I've also commented the dsp_poll, dsp_options and dtmfthreshold ... but that didn't change anything.


[from-internal]
include => from-internal-xfer
include => bad-number
... and that's it.


[from-internal-xfer]
include => parkedcalls
include => from-internal-custom -----> doens't exist anywhere in the dialplan but here.
include => ext-fax
include => ext-local-confirm
include => findmefollow-ringallv2
include => from-internal-additional
exten => s,1,Macro(hangupcall)
exten => h,1,Macro(hangupcall)


Linksys SPA962
RTP Packet Size: 0.020 ... was set by our supplier, but this was originaly 0.030. Does this values have to correspondent with some Asterisk value?
pref codec: G711A
sec codec: G711U
third codec: G729A

[Cybernavy]

any ideas?