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 [EMAIL PROTECTED]: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 '[EMAIL PROTECTED]' Request 102: Found
Aug 31 22:51:53 DEBUG[3916]: Acked pending invite 102
Aug 31 22:51:53 DEBUG[3916]: Stopping retransmission on '[EMAIL PROTECTED]' of Request 102: Found
Aug 31 22:51:53 DEBUG[3916]: build_route: Contact hop: <sip:[EMAIL PROTECTED]>
Aug 31 22:51:53 VERBOSE[21799]: -- SIP Seeding '079999' at [EMAIL PROTECTED]: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
Aug 31 22:51:53 DEBUG[21799]: Oooh, format changed to 2
Aug 31 22:52:59 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]:22034 for 160
Aug 31 22:52:59 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]: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 [EMAIL PROTECTED]:22034 for 160
Aug 31 22:53:14 DEBUG[3916]: Auto destroying call '[EMAIL PROTECTED]'
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 appended to acl for peer
Aug 31 22:55:01 DEBUG[21806]: 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 with 0.0.0.0
Aug 31 22:55:01 DEBUG[21806]: ##### Testing 127.0.0.1 with 127.0.0.0
Aug 31 22:55:01 VERBOSE[21806]: == Manager 'admin' logged on from 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
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 appended to acl for peer
Aug 31 22:55:01 DEBUG[21823]: 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 with 0.0.0.0
Aug 31 22:55:01 DEBUG[21823]: ##### Testing 127.0.0.1 with 127.0.0.0
Aug 31 22:55:01 VERBOSE[21823]: == Manager 'admin' logged on from 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
Aug 31 22:55:24 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]:22034 for 160
Aug 31 22:55:24 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]: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 [EMAIL PROTECTED]:22034 for 160
Aug 31 22:55:39 DEBUG[3916]: Auto destroying call '[EMAIL PROTECTED]'
Aug 31 22:57:49 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]:22034 for 160
Aug 31 22:57:49 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]: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 [EMAIL PROTECTED]: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 [EMAIL PROTECTED]: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 '[EMAIL PROTECTED]' of Request 103: Found
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 [EMAIL PROTECTED]: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 '[EMAIL PROTECTED]' Request 102: Found
Aug 31 22:51:53 DEBUG[3916]: Acked pending invite 102
Aug 31 22:51:53 DEBUG[3916]: Stopping retransmission on '[EMAIL PROTECTED]' of Request 102: Found
Aug 31 22:51:53 DEBUG[3916]: build_route: Contact hop: <sip:[EMAIL PROTECTED]>
Aug 31 22:51:53 VERBOSE[21799]: -- SIP Seeding '079999' at [EMAIL PROTECTED]: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
Aug 31 22:51:53 DEBUG[21799]: Oooh, format changed to 2
Aug 31 22:52:59 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]:22034 for 160
Aug 31 22:52:59 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]: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 [EMAIL PROTECTED]:22034 for 160
Aug 31 22:53:14 DEBUG[3916]: Auto destroying call '[EMAIL PROTECTED]'
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 appended to acl for peer
Aug 31 22:55:01 DEBUG[21806]: 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 with 0.0.0.0
Aug 31 22:55:01 DEBUG[21806]: ##### Testing 127.0.0.1 with 127.0.0.0
Aug 31 22:55:01 VERBOSE[21806]: == Manager 'admin' logged on from 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
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 appended to acl for peer
Aug 31 22:55:01 DEBUG[21823]: 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 with 0.0.0.0
Aug 31 22:55:01 DEBUG[21823]: ##### Testing 127.0.0.1 with 127.0.0.0
Aug 31 22:55:01 VERBOSE[21823]: == Manager 'admin' logged on from 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
Aug 31 22:55:24 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]:22034 for 160
Aug 31 22:55:24 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]: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 [EMAIL PROTECTED]:22034 for 160
Aug 31 22:55:39 DEBUG[3916]: Auto destroying call '[EMAIL PROTECTED]'
Aug 31 22:57:49 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]:22034 for 160
Aug 31 22:57:49 VERBOSE[3916]: -- SIP Seeding '079999' at [EMAIL PROTECTED]: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 [EMAIL PROTECTED]: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 [EMAIL PROTECTED]: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 '[EMAIL PROTECTED]' 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?
_______________________________________________ --Bandwidth and Colocation sponsored by Easynews.com --
Asterisk-Users mailing list [email protected] http://lists.digium.com/mailman/listinfo/asterisk-users To UNSUBSCRIBE or update options visit: http://lists.digium.com/mailman/listinfo/asterisk-users
