Summary:	ASTERISK-07983: Asterisk can't dial or register sip devices after a while
Reporter:	Francesco Romano (francesco_r)	Labels:
Date Opened:	2006-10-23 08:19:30	Date Closed:	2011-06-07 14:03:03
Priority:	Major	Regression?	No
Status:	Closed/Complete	Components:	Core/General
Versions:		Frequency of Occurrence
Related Issues:
Environment:		Attachments:	( 0) extensions_sip.tar.gz ( 1) full_log ( 2) full_log.tgz ( 3) sip_debug.txt
Description:	In two identical machines and similar configurations, asterisk stop to work with sip devices one or two times a day. The core application and the zap side seems continue to work well instead. I must stop and restart asterisk to redial or to reregister sip devices. Asterisk 1.2.13 is installed in Slackware 10.2 with customised SMP Kernel 2.6.13 and with FreePBX as frontend. All version i tried from 1.2.9 did the same problem. The hardware is Dual Xeon 3GHZ on Intel SE7520AF2 MB with dual PRI Sangoma A102 card. For example this is few moment before the problem, from the full log: Oct 23 12:34:40 VERBOSE[4268] logger.c:     -- AGI Script dialparties.agi completed, returning 0 Oct 23 12:34:40 VERBOSE[4268] logger.c:     -- Executing Dial("Local/273@from-internal-67b1,2", "SIP/273||tT") in new stack Oct 23 12:34:40 DEBUG[4268] chan_sip.c: Setting NAT on RTP to 0 Oct 23 12:34:40 DEBUG[4268] chan_sip.c: Outgoing Call for 273 Oct 23 12:34:40 VERBOSE[4268] logger.c:     -- Called 273 Oct 23 12:34:40 VERBOSE[4268] logger.c:     -- SIP/273-083bfff8 is ringing Oct 23 12:34:44 VERBOSE[4268] logger.c:     -- SIP/273-083bfff8 answered Local/273@from-internal-67b1,2 Oct 23 12:34:52 DEBUG[4268] channel.c: Didn't get a frame from channel: Local/273@from-internal-67b1,2 Oct 23 12:34:52 DEBUG[4268] channel.c: Bridge stops bridging channels Local/273@from-internal-67b1,2 and SIP/273-083bfff8 Oct 23 12:34:52 DEBUG[4268] chan_sip.c: update_call_counter(273) - decrement call limit counter Oct 23 12:34:52 DEBUG[4268] app_dial.c: Exiting with DIALSTATUS=ANSWER. And this is the problem: Oct 23 12:37:33 VERBOSE[5136] logger.c:     -- AGI Script dialparties.agi completed, returning 0 Oct 23 12:37:33 VERBOSE[5136] logger.c:     -- Executing Dial("Local/220@from-internal-590d,2", "SIP/220||tT") in new stack Oct 23 12:37:33 DEBUG[5136] chan_sip.c: Setting NAT on RTP to 0 Oct 23 12:37:33 DEBUG[5136] chan_sip.c: Outgoing Call for 220 Oct 23 12:37:33 VERBOSE[5136] logger.c:     -- Called 220 Oct 23 12:37:48 DEBUG[5136] chan_sip.c: update_call_counter(220) - decrement call limit counter Oct 23 12:37:48 DEBUG[5136] chan_sip.c: Acked pending invite 102 Oct 23 12:37:48 DEBUG[5136] chan_sip.c: Stopping retransmission on '792ae8b736858b1c2b70227e439189cd@192.168.36.15' of Request  102: Match Found Oct 23 12:37:48 DEBUG[5136] app_dial.c: Exiting with DIALSTATUS=CANCEL. I have recompile both asterisks with dont-optimize and "DEBUG_THREADS = -DDEBUG_THREADS -DDO_CRASH" options in Makefile but i don't have core dumps or deadlock. I have other asterisk server installed with Slackware, Freepbx and the same kernel version and works well, but these two are the busiest, sometimes all 60 pri channels are occupied. I have attached also a piece of the full log, the last successfully call is at 12:34:44 (you can see "build_route: Contact hop: <sip:273@192.168.36.47:5060>") Thank you
Comments:	By: Joshua C. Colp (jcolp) 2006-10-24 10:02:50 We need to see a sip debug, the device you're talking about isn't sending back any indication that it is ringing - so the person assumes something is wrong and hangs up. By: Olle Johansson (oej) 2006-10-25 14:56:49 Please read the bug guide lines. If you file a SIP issue, you need to enable SIP debug and make sure SIp signalling is included in the debug output. By: Francesco Romano (francesco_r) 2006-10-26 04:06:35 I have attached a sip debug from the asterisk console, a the end of the file also the output from the program iptraf. Tonight i'll try to upgrade the kernel. By: Francesco Romano (francesco_r) 2006-10-26 04:37:51 I will repost also another sip debug with verbose 4 and history/dumphistory enable By: Francesco Romano (francesco_r) 2006-10-27 11:06:48 I have uploaded the full log with sip history enabled, the last successfully sip answered call is around 17:00:39. By: fugitivo (fugitivo) 2006-11-02 11:45:30.000-0600 Same problem here, please check ASTERISK-8208260 for a complete debug. By: fugitivo (fugitivo) 2006-11-02 11:48:44.000-0600 Downgrading to 1.2.8 fixes the problem. I've been working for 2 days with this version and I don't have the same problem. By: Francesco Romano (francesco_r) 2006-11-04 11:51:56.000-0600 I have also downgraded to 1.2.8 in many machines, it worked well for 2 days but this afternoon in one server the problem reappeared. So also with 1.2.8 the bug is present but less then with the latest versions. By: fugitivo (fugitivo) 2006-11-04 20:08:53.000-0600 Just to check if we're not using the same phones, what are you using? I'm using SJPHONE in my case. 1.2.8 is working fine for me, but I could see one time doing 'show channels' that I had a lot of Agentmonitoroutgoing() channels. That put all the phones in status "waiting for register". But this time is different, i can do a sip reload and it works, but doesn't solve the problem, I have to restart asterisk. I don't think this is the same bug. By: Francesco Romano (francesco_r) 2006-11-05 08:01:10.000-0600 Also for me the softphones are SJPhone, hardware phones are Grandstream GXP2000. In another call center with Asterisk 1.2.13 that before blocked many times a day, we have converted nearly 30 of 100 clients from SJPhone to Idefisk IAX sofphone and we have now 4 days uptime. By: fugitivo (fugitivo) 2006-11-05 09:00:45.000-0600 We could assume that SJPHONE is the problem? By: Olle Johansson (oej) 2006-11-06 09:03:24.000-0600 Well, regardless, a phone should not be able to lock the server... By: fugitivo (fugitivo) 2006-11-06 09:04:48.000-0600 I agree that a phone shouldn't be able to lock the server, but we have a point in common here. By: Francesco Romano (francesco_r) 2006-11-13 13:01:27.000-0600 Important update: we have finished to convert all the call center clients to iax and today asterisk blocked in the same manner, can't dial or register iax clients... zap side instead have continued to work well instead. So it's not a sip module issue, is perhaps chan_local the problem? By: Serge Vecher (serge-v) 2006-11-17 09:57:24.000-0600 can we see some excerpts of a dialplan please. By: Francesco Romano (francesco_r) 2006-11-22 09:49:34.000-0600 I have uploaded the extensions.conf and sip.conf of one server. By: fugitivo (fugitivo) 2006-11-22 10:08:14.000-0600 Migrating all softphones to Eyebeam fixed the problem for me... By: tecnica (tecnica) 2006-12-04 13:15:54.000-0600 I'm having the same problem. Are you using the call-limit statement in sip.conf ? Migration to EyeBeam was not solve the problem for me. By: fugitivo (fugitivo) 2006-12-04 13:34:47.000-0600 Not using call-limit here. I must confirm that eyebeam fixed my problem, Asterisk is running without any problem for several days. By: Serge Vecher (serge-v) 2006-12-05 10:45:30.000-0600 francesco_r: if I'm reading your notes in 8086 correctly, does the patch there fix your issues here in 8204? By: Francesco Romano (francesco_r) 2006-12-05 10:48:16.000-0600 I have patched asterisk in one of the affected server for the bug ASTERISK-7868, changed in extensions.conf all deadagi to agi, and now i have 5 days uptime. I'll wait some more days to see if is finally resolved. By: fugitivo (fugitivo) 2006-12-05 10:52:28.000-0600 I must add that I wasn't using deadagi nor agi when I had this problem with sjphone. By: Serge Vecher (serge-v) 2006-12-05 11:02:05.000-0600 fugitivo, technica: if you are both not using agi and the patch in 8086 does not fix your problems, then you are likely facing a different issues, albeit with similar symptoms. If above is true, then I'd encourage you to open a new issue with respective debugging information. By: fugitivo (fugitivo) 2006-12-05 11:04:29.000-0600 serge-v, my problem was solved migrating all sjphones to eyebeam, I opened a bug report but someone related it to this bug. By: Francesco Romano (francesco_r) 2006-12-05 12:34:36.000-0600 Serge-v , i forgotten to say an important thing in the previous note: i have upgraded asterisk to SVN 48157. By: tecnica (tecnica) 2006-12-05 14:31:58.000-0600 Dears, I'm using AGI as IVC front-end to a queue. I'm verifing if ASTERISK-7868 applies to my system, cause AGI is asterisk-java implemented, not a script one. By: Derrick Bradbury (snapple42) 2007-01-31 14:44:14.000-0600 I am having the same issue.. It's actually happened to me twice so far. In both cases a person tried to park a call by transferring to ext 70. It was the same extension. We changed the phone to try and rule out a hardware issue. We are using Aastra 480i's in all cases. In both cases, all of the sip phones could not make outbound calls, or pick up any inbound calls... but the IAX softclient did work perfectly. I have FULL debugging turned on, and am just waiting for it to happen again. By: fugitivo (fugitivo) 2007-01-31 16:37:44.000-0600 Just wondering. Question for all people having this problem: Are you recording conversations? Is the hard drive where you store recordings almost full? I was experiencing some weird behaviaur with a full disk causing delay in audio when answering a call (no sound for the first 10 seconds of conversation). After freeing space, the problem dissapeared. Also sip freezes are gone. By: Francesco Romano (francesco_r) 2007-01-31 17:11:18.000-0600 I have 10-15% of used space in these machines... so for me this is not the problem. And only in one these calls are monitored. Just the other day asterisk blocked 3 times after 2 weeks of uptime. By: tecnica (tecnica) 2007-01-31 18:06:37.000-0600 Yes, we are recording the calls. But have lots of disk space. Our Asterisk blocks 2-3 sip channels per day. By: Serge Vecher (serge-v) 2007-02-05 10:35:33.000-0600 ok, is everybody seeing this on 1.2.14? By: fugitivo (fugitivo) 2007-02-05 10:40:28.000-0600 It seems that my comment regarding recordings and free space is not the problem as  I had a block last week twice a day. Using version 1.2.14 serge-v. By: Derrick Bradbury (snapple42) 2007-02-05 11:07:55.000-0600 Happened to me again today... I have full sip debug, and verbose/debugging at 5... I'll narrow it down and upload logs as soon as I can... By: Derrick Bradbury (snapple42) 2007-02-08 11:11:07.000-0600 Happened yet again... I have 4 crash logs, and each time the calls stopped after this: Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 DEBUG[25157] channel.c: Avoiding deadlock for 'SIP/408-08a09bf0' Feb  8 11:17:02 WARNING[25157] channel.c: Avoided deadlock for '0x89d64c0', 10 retries! Feb  8 11:17:02 VERBOSE[25157] logger.c:     -- Remote UNIX connection disconnected This sequence has happened before (in the logs) and no problems, but each time the SIP calls stopped working this was after the last successful answer. I am running 1.2.13 on that server, and am upgrading to 1.2.14 with the patches from 8086 that are already in that trunk. If people are interested, I can post a link to the logs (over 1MB compressed each) By: Serge Vecher (serge-v) 2007-02-08 12:56:17.000-0600 snapple42, yes, please get 1.2.14 going or 1.2 from svn, no patches, produce those logs and post the link. By: fugitivo (fugitivo) 2007-02-13 12:25:59.000-0600 I want to add a note. In my case the problem seems to be related to the database. Right now i'm reindexing table cdr and sip is freezed. I'm using postgresql 8.x as database. By: Luiz Henrique (lhgomes) 2007-02-13 13:42:43.000-0600 In my case the problem NOT seems to be related to the database. Right now i stopped database cdr and sip is NOT freezed. I'm using MySQL as database. By: fugitivo (fugitivo) 2007-02-13 13:58:17.000-0600 If I stop my database, sip freezes, i need to unload cdr_pgsql.so, why's that? By: Luiz Henrique (lhgomes) 2007-02-14 15:11:56.000-0600 I killed all AGI integration (recordingcheck and fixlocalprefix) and freezes are gone. Past 2 days without problems. Maybe AGI Bug? By: fugitivo (fugitivo) 2007-02-14 15:15:16.000-0600 I'm not using AGI at all, but manager commands. By: Luiz Henrique (lhgomes) 2007-02-14 15:23:35.000-0600 Fugitivo, your problem seems this http://bugs.digium.com/view.php?id=4953 therefore it is related with the database. By: fugitivo (fugitivo) 2007-02-14 15:35:39.000-0600 I'm using PostgreSQL. The bug seems to be related to MySQL By: Derrick Bradbury (snapple42) 2007-02-14 19:16:00.000-0600 We upgraded to 1.2.14 about a week ago, this included the patches from bug 8086... so far (knock on solid wood) things seem to be working. I'll post in a little bit if things are still clear. By: Luiz Henrique (lhgomes) 2007-02-15 11:27:03.000-0600 When the problem happened, we already use version 1.2.14 with patch. After we removed all AGI commands, the problem stopped. By: Serge Vecher (serge-v) 2007-02-19 08:47:30.000-0600 alright, since snapple42 has reported positive results, what is the status with 1.2.15? If the problem persists, somebody needs to upload sip debugging information as per bug guidelines or this bug will be closed. By: Serge Vecher (serge-v) 2007-03-06 09:51:58.000-0600 no response for over two weeks; if still an issue please ask a bug marshall on #asterisk-bugs to reopen the issue with debugging info provided.