Hello all,
My asterisk locks up in two diffent ways. Firstly, it presentes the exactly same behaviour as described in
forums.whirlpool.net.au/archive/1710819. That is to say, it starts to queing messages and does not respond to incoming or outcoming calls. I can still log on the server and run CLI. I solve this problem by running a monitoring script that
netstats the port. If it see a lot of messages, it kills (the “asterisk restart” cmd becomes useless when the problem
happens) the asterisk PID as starts asterisk again. Messages and debug information varies a lot.
The 2nd sort of lock is more challenging. When that happens, we don’t see messages queued then my monitoring script does not work.
Below, i show messages and debug information for two incoming calls I’ve made while the system was locked.
Any help will be very appreciated
Best
Leo
########### Addioinall Info:
I’m quite new on asterisk, but the one who installed and setup the application for me is an expert. However, he cannot figure
hout what’s happening. Here is my configuration
a) Asterisk: 1.6.2.20
b) Linux 2.6.38-8-server #42-Ubuntu SMP Mon Apr 11 03:49:04 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux
c) Digium card 1AEX808EF (8 port modular analog PCI-Express x1 card with 8 Trunk)
d) [general]
static=yes
writeprotect=no
;autofallthrough=no
clearglobalvars=no
############### [1st call]
messages
[Oct 11 08:53:01] WARNING[29885]: channel.c:785 __ast_channel_alloc_ap: Channel allocation failed: Refusing due to active shutdown
[Oct 11 08:53:01] WARNING[29885]: chan_sip.c:6941 sip_new: Unable to allocate AST channel structure for SIP channel
[Oct 11 08:53:01] NOTICE[29885]: chan_sip.c:21116 handle_request_invite: Unable to create/find SIP channel for this INVITE
[Oct 11 08:53:01] WARNING[29885]: channel.c:785 __ast_channel_alloc_ap: Channel allocation failed: Refusing due to active shutdown
[Oct 11 08:53:01] WARNING[29885]: chan_sip.c:6941 sip_new: Unable to allocate AST channel structure for SIP channel
[Oct 11 08:53:01] NOTICE[29885]: chan_sip.c:21116 handle_request_invite: Unable to create/find SIP channel for this INVITE
[Oct 11 08:53:15] NOTICE[29885]: chan_sip.c:22170 handle_request_subscribe: Received SIP subscribe fo
debug
[Oct 11 08:52:55] DEBUG[29885] chan_sip.c: Destroying SIP dialog 68f6cba17e4e4f8d0c10de3d4f617b83@192.168.0.5
[Oct 11 08:53:01] DEBUG[29885] acl.c: Found IP address for this socket
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Target address 63.209.144.201 is not local, substituting externip
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 201.77.180.150:5060
[Oct 11 08:53:01] VERBOSE[29885] netsock.c: == Using SIP RTP CoS mark 5
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Setting NAT on RTP to On
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Allocating new SIP dialog for CXC-116-6228f9b0-ca90d13f-13c4-4e942e1d-f19aba7d-40d6cbda - INVITE (With RTP)
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Setting NAT on RTP to On
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing session-level SDP o=551997727725 1318333981 1318333981 IN IP4 63.209.144.201… UNSUPPORTED.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing session-level SDP s=Skype call… UNSUPPORTED.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing session-level SDP c=IN IP4 63.209.144.201… OK.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000… OK.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000… OK.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000… OK.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000… OK.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no… UNSUPPORTED.
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: We’re settling with these formats: 0xc (ulaw|alaw)
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Checking SIP call limits for device 99051000141077
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Updating call counter for incoming call
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: build_route: Contact hop: sip:551997727725@63.209.144.201:5060;transport=udp
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Trying to put ‘SIP/2.0 503’ onto UDP socket destined for 63.209.144.201:5060
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Stopping retransmission on ‘CXC-116-6228f9b0-ca90d13f-13c4-4e942e1d-f19aba7d-40d6cbda’ of Response 1: Match Found
[Oct 11 08:53:01] DEBUG[29885] acl.c: Found IP address for this socket
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Target address 63.209.144.201 is not local, substituting externip
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 201.77.180.150:5060
[Oct 11 08:53:01] VERBOSE[29885] netsock.c: == Using SIP RTP CoS mark 5
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Setting NAT on RTP to On
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Allocating new SIP dialog for CXC-968-6228fd30-ca90d13f-13c4-4e942e1d-f19abbb7-14296fc4 - INVITE (With RTP)
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Setting NAT on RTP to On
[Oct 11 08:53:01] DEBUG[29885] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED.
############ [2nd call]
messages
[Oct 11 08:58:10] WARNING[29890]: channel.c:785 __ast_channel_alloc_ap: Channel allocation failed: Refusing due to active shutdown
[Oct 11 08:58:10] WARNING[29890]: chan_dahdi.c:9845 handle_init_event: Cannot allocate new structure on channel 3
[Oct 11 08:58:15] WARNING[29890]: channel.c:785 __ast_channel_alloc_ap: Channel allocation failed: Refusing due to active shutdown
[Oct 11 08:58:15] WARNING[29890]: chan_dahdi.c:9845 handle_init_event: Cannot allocate new structure on channel 3
debug
[Oct 11 08:58:10] VERBOSE[29874] asterisk.c: – Remote UNIX connection
[Oct 11 08:58:10] DEBUG[29890] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 3
[Oct 11 08:58:14] DEBUG[29890] chan_dahdi.c: Monitor doohicky got event Ring Begin on channel 3
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Allocating new SIP dialog for 22140693041fc0e430e61f65687cf723@127.0.0.1 - OPTIONS (No RTP)
[Oct 11 08:58:15] DEBUG[29885] acl.c: Found IP address for this socket
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.0.5:5060
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Initializing initreq for method OPTIONS - callid 57946794365cec8161278cd023a843a0@192.168.0.5
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.0.104:13748
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Stopping retransmission on ‘57946794365cec8161278cd023a843a0@192.168.0.5’ of Request 102: Match Found
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Destroying SIP dialog 57946794365cec8161278cd023a843a0@192.168.0.5
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Allocating new SIP dialog for 6984256a206373996dd29d65013125d8@127.0.0.1 - OPTIONS (No RTP)[Oct 11 08:58:15] DEBUG[29885] acl.c: Found IP address for this socket
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.0.5:5060
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Initializing initreq for method OPTIONS - callid 224ef373540325dd17bb5a214bef33e0@ 192.168.0.5
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.0.114:12112
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Stopping retransmission on ‘224ef373540325dd17bb5a214bef33e0@192.168.0.5’ of Reque st 102: Match Found
[Oct 11 08:58:15] DEBUG[29885] chan_sip.c: Destroying SIP dialog 224ef373540325dd17bb5a214bef33e0@192.168.0.5
[Oct 11 08:58:15] DEBUG[29890] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 3
[Oct 11 08:58:18] DEBUG[29885] chan_sip.c: Allocating new SIP dialog for 0661413b08403dfc2b51d6c67e487344@127.0.0.1 - OPTIONS (No RTP)
[Oct 11 08:58:18] DEBUG[29885] acl.c: Found IP address for this socket
[Oct 11 08:58:18] DEBUG[29885] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.0.5:5060
[Oct 11 08:58:18] DEBUG[29885] chan_sip.c: Initializing initreq for method OPTIONS - callid 0c72302960f09ecc292be476582875d1@ 192.168.0.5
[Oct 11 08:58:18] DEBUG[29885] chan_sip.c: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.0.127:60590
[Oct 11 08:58:18] DEBUG[29885] chan_sip.c: Stopping retransmission on ‘0c72302960f09ecc292be476582875d1@192.168.0.5’ of Reque st 102: Match Found
[Oct 11 08:58:18] DEBUG[29885] chan_sip.c: Destroying SIP dialog 0c72302960f09ecc292be476582875d1@192.168.0.5
[Oct 11 08:58:35] DEBUG[3834] config.c: Parsing /etc/asterisk/asterisk.conf
[Oct 11 08:58:35] DEBUG[3834] xmldoc.c: gl_pathc 9