Hi!
We have a SIP server with a TE410P card with asterisk version Asterisk
CVS-D2005.02.12.14.37.11-04/13/05-16:14:03. Sometime the calls get
disconnected with now reason and the users get a busy signal. The log file
show this for one of the calls that got disconnected:
Aug 31 22:51:53 VERBOSE[3911]: -- Accepting call from '46362302' to
'36917474' on channel 0/5, span 1
Aug 31 22:51:53 DEBUG[3911]: Enabled echo cancellation on channel 5
Aug 31 22:51:53 VERBOSE[21799]: -- Executing
ESC[1;36;40mMacroESC[0;37;40m("ESC[1;35;40mZap/5-1ESC[0;37;40m",
"ESC[1;35;40mstdexten|079999|SIP/079999ESC[0;37;40m")
Aug 31 22:51:53 VERBOSE[21799]: -- Executing
ESC[1;36;40mDBgetESC[0;37;40m("ESC[1;35;40mZap/5-1ESC[0;37;40m",
"ESC[1;35;40mtemp=CFIM/079999ESC[0;37;40m") in new stack
Aug 31 22:51:53 VERBOSE[21799]: -- DBget: varname=temp, family=CFIM,
key=079999
Aug 31 22:51:53 DEBUG[21799]: Unable to find key '079999' in family
'CFIM'
Aug 31 22:51:53 VERBOSE[21799]: -- DBget: Value not found in database.
Aug 31 22:51:53 VERBOSE[21799]: -- Executing
ESC[1;36;40mGotoESC[0;37;40m("ESC[1;35;40mZap/5-1ESC[0;37;40m",
"ESC[1;35;40ms|11ESC[0;37;40m") in new stack
Aug 31 22:51:53 VERBOSE[21799]: -- Goto (macro-stdexten,s,11)
Aug 31 22:51:53 VERBOSE[21799]: -- Executing
ESC[1;36;40mDialESC[0;37;40m("ESC[1;35;40mZap/5-1ESC[0;37;40m",
"ESC[1;35;40mSIP/079999|40ESC[0;37;40m") in new stack
Aug 31 22:51:53 VERBOSE[21799]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:51:53 DEBUG[21799]: Setting NAT on RTP to 524288
Aug 31 22:51:53 DEBUG[21799]: Outgoing Call for 36917474
Aug 31 22:51:53 DEBUG[21799]: 36917474 is not a local user
Aug 31 22:51:53 VERBOSE[21799]: -- Called 079999
Aug 31 22:51:53 DEBUG[3916]: (Provisional) Stopping retransmission (but
retaining packet) on
'07640a664ced6ffa7006f3916dac5cc2@194.255.106.3'Request 102: Found
Aug 31 22:51:53 DEBUG[3916]: Acked pending invite 102
Aug 31 22:51:53 DEBUG[3916]: Stopping retransmission on
'07640a664ced6ffa7006f3916dac5cc2@194.255.106.3' of Request 102: Found
Aug 31 22:51:53 DEBUG[3916]: build_route: Contact hop: <
sip:36917474@83.95.111.21>
Aug 31 22:51:53 VERBOSE[21799]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:51:53 VERBOSE[21799]: -- SIP/079999-8a0b answered Zap/5-1
Aug 31 22:51:53 DEBUG[21799]: RTP NAT: Using address
83.95.111.21:22138<http://83.95.111.21:22138>
Aug 31 22:51:53 DEBUG[21799]: Oooh, format changed to 2
Aug 31 22:52:59 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:52:59 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:52:59 VERBOSE[3916]: -- Saved useragent "Asterisk PBX" for
peer
079999
Aug 31 22:52:59 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:53:14 DEBUG[3916]: Auto destroying call
'46d329fd2fc9a5763c3ffb184ef755f1@127.0.0.1'
Aug 31 22:55:01 DEBUG[21806]: Manager received command 'Login'
Aug 31 22:55:01 VERBOSE[21806]: == Parsing '/etc/asterisk/manager.conf':
Aug
31 22:55:01 VERBOSE[21806]: == Parsing '/etc/asterisk/manager.conf':
Found
Aug 31 22:55:01 DEBUG[21806]:
0.0.0.0/0.0.0.0/0.0.0.0<http://0.0.0.0/0.0.0.0/0.0.0.0>appended to acl
for peer
Aug 31 22:55:01 DEBUG[21806]:
127.0.0.1/255.255.255.0/255.255.255.0<http://127.0.0.1/255.255.255.0/255.255.255.0>appended
to acl for peer
Aug 31 22:55:01 DEBUG[21806]: ##### Testing 127.0.0.1
<http://127.0.0.1>with
0.0.0.0 <http://0.0.0.0>
Aug 31 22:55:01 DEBUG[21806]: ##### Testing 127.0.0.1
<http://127.0.0.1>with
127.0.0.0 <http://127.0.0.0>
Aug 31 22:55:01 VERBOSE[21806]: == Manager 'admin' logged on from
127.0.0.1<http://127.0.0.1>
Aug 31 22:55:01 DEBUG[21806]: Manager received command 'Ping'
Aug 31 22:55:01 DEBUG[21806]: Manager received command 'Logoff'
Aug 31 22:55:01 VERBOSE[21806]: == Manager 'admin' logged off from
127.0.0.1<http://127.0.0.1>
Aug 31 22:55:01 DEBUG[21823]: Manager received command 'Login'
Aug 31 22:55:01 VERBOSE[21823]: == Parsing '/etc/asterisk/manager.conf':
Aug
31 22:55:01 VERBOSE[21823]: == Parsing '/etc/asterisk/manager.conf':
Found
Aug 31 22:55:01 DEBUG[21823]:
0.0.0.0/0.0.0.0/0.0.0.0<http://0.0.0.0/0.0.0.0/0.0.0.0>appended to acl
for peer
Aug 31 22:55:01 DEBUG[21823]:
127.0.0.1/255.255.255.0/255.255.255.0<http://127.0.0.1/255.255.255.0/255.255.255.0>appended
to acl for peer
Aug 31 22:55:01 DEBUG[21823]: ##### Testing 127.0.0.1
<http://127.0.0.1>with
0.0.0.0 <http://0.0.0.0>
Aug 31 22:55:01 DEBUG[21823]: ##### Testing 127.0.0.1
<http://127.0.0.1>with
127.0.0.0 <http://127.0.0.0>
Aug 31 22:55:01 VERBOSE[21823]: == Manager 'admin' logged on from
127.0.0.1<http://127.0.0.1>
Aug 31 22:55:01 DEBUG[21823]: Manager received command 'Status'
Aug 31 22:55:01 DEBUG[21823]: Manager received command 'Logoff'
Aug 31 22:55:01 VERBOSE[21823]: == Manager 'admin' logged off from
127.0.0.1<http://127.0.0.1>
Aug 31 22:55:24 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:55:24 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:55:24 VERBOSE[3916]: -- Saved useragent "Asterisk PBX" for
peer
079999
Aug 31 22:55:24 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:55:39 DEBUG[3916]: Auto destroying call
'46d329fd2fc9a5763c3ffb184ef755f1@127.0.0.1'
Aug 31 22:57:49 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:57:49 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:57:49 VERBOSE[3916]: -- Saved useragent "Asterisk PBX" for
peer
079999
Aug 31 22:57:49 VERBOSE[3916]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:57:49 DEBUG[3916]: Avoiding initial deadlock for
'SIP/079999-8a0b'
Aug 31 22:57:50 VERBOSE[3911]: -- Channel 0/5, span 1 got hangup
Aug 31 22:57:50 DEBUG[21799]: Bridge stops because we're zombie or need a
soft hangup: c0=Zap/5-1, c1=SIP/079999-8a0b, flags: No,Yes,No,No
Aug 31 22:57:50 DEBUG[21799]: Bridge stops bridging channels Zap/5-1 and
SIP/079999-8a0b
Aug 31 22:57:50 DEBUG[21799]: update_user_counter(36917474) - decrement
outUse counter
Aug 31 22:57:50 DEBUG[21799]: 36917474 is not a local user
Aug 31 22:57:50 VERBOSE[21799]: -- SIP Seeding '079999' at
36917474@83.95.111.21:22034 for 160
Aug 31 22:57:50 DEBUG[21799]: Exiting with DIALSTATUS=ANSWER.
Aug 31 22:57:50 VERBOSE[21799]: == Spawn extension (macro-stdexten, s, 11)
exited non-zero on 'Zap/5-1' in macro 'stdexten'
Aug 31 22:57:50 VERBOSE[21799]: == Spawn extension (isdn30_1, 36917474, 1)
exited non-zero on 'Zap/5-1'
Aug 31 22:57:50 DEBUG[21799]: Set option AUDIO MODE, value: ON(1) on Zap/5-1
Aug 31 22:57:50 DEBUG[21799]: Hangup: channel: 5 index = 0, normal = 26,
callwait = -1, thirdcall = -1
Aug 31 22:57:50 DEBUG[21799]: Not yet hungup... Calling hangup once with
icause, and clearing call
Aug 31 22:57:50 DEBUG[21799]: disabled echo cancellation on channel 5
Aug 31 22:57:50 DEBUG[21799]: Set option TDD MODE, value: OFF(0) on Zap/5-1
Aug 31 22:57:50 DEBUG[21799]: Updated conferencing on 5, with 0 conference
users
Aug 31 22:57:50 DEBUG[21799]: Set option AUDIO MODE, value: OFF(0) on
Zap/5-1
Aug 31 22:57:50 DEBUG[21799]: disabled echo cancellation on channel 5
Aug 31 22:57:50 VERBOSE[21799]: -- Hungup 'Zap/5-1'
Aug 31 22:57:50 DEBUG[3916]: Stopping retransmission on
'07640a664ced6ffa7006f3916dac5cc2@194.255.106.3' of Request 103: Found
Can someone explain what happend?
How can we fix this problem. Will it help to upgrade to asterisk 1.0.9? Or
upgrade the firmware on the TE410P card?
--
Morten Isaksen
http://www.misak.dk/blog/
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
http://lists.digium.com/pipermail/asterisk-users/attachments/20050831/029990ef/attachment.htm
