| Summary: | ASTERISK-17446: Asterisk hangs when generating SIP calls with sipp | ||
| Reporter: | Muhammad Naseer Bhatti (nbhatti) | Labels: | |
| Date Opened: | 2011-02-21 03:59:45.000-0600 | Date Closed: | 2011-02-22 11:08:06.000-0600 |
| Priority: | Major | Regression? | No |
| Status: | Closed/Complete | Components: | Core/General |
| Versions: | 1.8.2 | Frequency of Occurrence | |
| Related Issues: | |||
| Environment: | Attachments: | ( 0) show_locks.txt | |
| Description: | Asterisk 1.6.2.16.1 and also have tried with 1.8.2.3, both reported the same results. Asterisk hangs when I try to generate calls with sipp. I am using simple UAC testing with a max call limit of 20, sipp -sn uac -d 2000 -s 2005 192.168.1.100 -l 20. After a few seconds Asterisk simply hangs. (or if there is any better word to describe the situation). In this state, it won't accept any SIP calls, now core or sip command will work through CLI. Even, core restart now won't result in any action. The only solution would be a kill -9. I reproduced this many times same environment. My asterisk configuration is very simple and minimal. If someone would like to login at the time of crash if this is not reproducible on your machine, I am help with that as well. Let me know if any more information is required. ****** ADDITIONAL INFORMATION ****** Hello, I have the following specs: ============= Linux voip 2.6.32-4-pve #1 SMP Wed Dec 15 14:04:31 CET 2010 x86_64 GNU/Linux # cat /etc/debian_version 6.0 # ulimit -a core file size (blocks, -c) 0 data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 16382 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 19096 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 8192 cpu time (seconds, -t) unlimited max user processes (-u) unlimited virtual memory (kbytes, -v) unlimited file locks (-x) unlimited ============= Asterisk 1.6.2.16.1 and also have tried with 1.8.2.3, both reported the same results. Asterisk hangs when I try to generate calls with sipp. I am using simple UAC testing with a max call limit of 20, sipp -sn uac -d 2000 -s 2005 192.168.1.100 -l 20. After a few seconds Asterisk simply hangs. (or if there is any better word to describe the situation). In this state, it won't accept any SIP calls, now core or sip command will work through CLI. Even, core restart now won't result in any action. The only solution would be a kill -9. I reproduced this many times same environment. My asterisk configuration is very simple and minimal. ====================== cat sip_additional.conf [sipp] type=friend context=sipp host=dynamic port=6000 user=sipp canreinvite=no disallow=all allow=ulaw ====================== cat extensions.conf [sipp] exten => 2005,1,Answer exten => 2005,2,SetMusicOnHold(default) exten => 2005,3,WaitMusicOnHold(10) exten => 2005,4,Hangup ====================== cat sip.conf [general] context=from-sip-external callerid=Unknown notifyhold=yes tos_sip=cs3 tos_audio=ef tos_video=af41 alwaysauthreject=yes useragent=MyAgent(1.0) disallow=all allow=g723 allow=g729 callevents=no jbenable=no maxexpiry=3600 defaultexpiry=120 minexpiry=60 allowguest=yes srvlookup=no registerattempts=0 registertimeout=6 g726nonstandard=no t38pt_udptl=no videosupport=no maxcallbitrate=384 canreinvite=no rtptimeout=7 notifyhold=yes rtpkeepalive=0 notifyringing=yes checkmwi=10 rtpholdtimeout=50 nat=yes tcpenable=no preferred_codec_only=yes language=en =============== If someone would like to login at the time of crash if this is not reproducible on your machine, I am help with that as well. Let me know if any more information is required. | ||
| Comments: | By: Alec Davis (alecdavis) 2011-02-21 04:18:00.000-0600 You'll need to recompile with the Compiler Flags DON'T_OPTIMIZE and DEBUG_THREADS enabled from make menuselect. Then once locked up from the CLI you should be able enter 'core show locks' Please then submit the output as an attached text file. By: Muhammad Naseer Bhatti (nbhatti) 2011-02-21 04:56:07.000-0600 File attached. Also observed, while the * is locked, netstat -anu shows lots of UDP ports opened. lsof shows they are owned by asterisk. But they are never closed. By: Muhammad Naseer Bhatti (nbhatti) 2011-02-21 06:30:48.000-0600 I think there has something to do with the timer library for Debian. I removed the WaitMusicOnHold and things look good so far.. Here's my new extensions.conf [sipp] exten => 2005,1,Answer exten => 2005,2,Playback(tt-codezone_MIXDOWN) exten => 2005,3,Hangup A friend of mine worked on * code says there are some issues with timer libraries of asterisk and avoiding them (either use USB_UHCI) may help? By: Ronald Chan (loloski) 2011-02-21 06:48:28.000-0600 https://issues.asterisk.org/view.php?id=17255 Please try the attached patch for the issues above, and let us know how is it going. By: Ronald Chan (loloski) 2011-02-21 07:00:49.000-0600 nbhatti, Could you please confirm if loading res_timing_dahdi fix your issue? in lieu of res_timing_pthread or res_timing_timerfd ? By: Ronald Chan (loloski) 2011-02-21 07:20:11.000-0600 Confirmed on Ubuntu Lucid, 10.04 with slight modification on the dialplan of original reporter. [sipp] exten => 9999,1,Progress same => n,Ringing same => n,Answer same => n,SetMusicOnHold(default) same => n,WaitMusicOnHold(10) same => n,Hangup root@pbx:/usr/src/1.6.2# sipp -sn uac -d 20000 -s 9999 192.168.0.101 -l 10 -r 2 Resolving remote host '192.168.0.101'... Done. ------------------------------ Scenario Screen -------- [1-9]: Change Screen -- Call-rate(length) Port Total-time Total-calls Remote-host 2.0(20000 ms)/1.000s 5061 82.11 s 70 192.168.0.101:5060(UDP) 0 new calls during 0.000 s period 0 ms scheduler resolution 0 calls (limit 10) Peak was 10 calls, after 5 s 0 Running, 3 Paused, 0 Woken up 0 dead call msg (discarded) 0 out-of-call msg (discarded) 1 open sockets Messages Retrans Timeout Unexpected-Msg INVITE ----------> 70 0 0 100 <---------- 70 0 0 0 180 <---------- 70 0 0 0 183 <---------- 70 0 0 0 200 <---------- E-RTD1 70 0 0 0 ACK ----------> 70 0 Pause [ 20.0s] 70 70 BYE ----------> 0 0 0 200 <---------- 0 0 0 0 ------------------------------ Test Terminated -------------------------------- ----------------------------- Statistics Screen ------- [1-9]: Change Screen -- Start Time | 2011-02-21 21:14:17:271 1298294057.271347 Last Reset Time | 2011-02-21 21:15:39:421 1298294139.421655 Current Time | 2011-02-21 21:15:39:422 1298294139.422035 -------------------------+---------------------------+-------------------------- Counter Name | Periodic value | Cumulative value -------------------------+---------------------------+-------------------------- Elapsed Time | 00:00:00:000 | 00:01:22:150 Call Rate | 0.000 cps | 0.852 cps -------------------------+---------------------------+-------------------------- Incoming call created | 0 | 0 OutGoing call created | 0 | 70 Total Call created | | 70 Current Call | 0 | -------------------------+---------------------------+-------------------------- Successful call | 0 | 0 Failed call | 0 | 70 -------------------------+---------------------------+-------------------------- Response Time 1 | 00:00:00:000 | 00:00:00:012 Call Length | 00:00:00:000 | 00:00:11:021 ------------------------------ Test Terminated -------------------------------- 2011-02-21 21:15:39:419 1298294139.419697: Aborting call on an unexpected BYE for call: 70-15431@127.0.1.1. sipp: There were more errors, enable -trace_err to log them. By: Ronald Chan (loloski) 2011-02-21 07:37:00.000-0600 Slightly modified again the dialplan, with the same effect, this fixed the issue [sipp] exten => 9999,1,Progress same => n,Ringing same => n,Answer same => n,MusicOnHold(10) # SetMusicOnHold(default) is deprecated!!!! same => n,Hangup root@stealth:/usr/src/1.6.2# sipp -sn uac -d 20000 -s 9999 192.168.0.101 -l 10 -r 2 Resolving remote host '192.168.0.101'... Done. ------------------------------ Scenario Screen -------- [1-9]: Change Screen -- Call-rate(length) Port Total-time Total-calls Remote-host 2.0(20000 ms)/1.000s 5061 140.67 s 61 192.168.0.101:5060(UDP) 0 new calls during 0.000 s period 0 ms scheduler resolution 0 calls (limit 10) Peak was 10 calls, after 5 s 0 Running, 11 Paused, 0 Woken up 0 dead call msg (discarded) 0 out-of-call msg (discarded) 1 open sockets Messages Retrans Timeout Unexpected-Msg INVITE ----------> 61 0 0 100 <---------- 61 0 0 0 180 <---------- 61 0 0 0 183 <---------- 61 0 0 0 200 <---------- E-RTD1 61 0 0 0 ACK ----------> 61 0 Pause [ 20.0s] 61 0 BYE ----------> 61 0 0 200 <---------- 61 0 0 0 ------------------------------ Test Terminated -------------------------------- ----------------------------- Statistics Screen ------- [1-9]: Change Screen -- Start Time | 2011-02-21 21:31:24:875 1298295084.875448 Last Reset Time | 2011-02-21 21:33:45:576 1298295225.576463 Current Time | 2011-02-21 21:33:45:576 1298295225.576763 -------------------------+---------------------------+-------------------------- Counter Name | Periodic value | Cumulative value -------------------------+---------------------------+-------------------------- Elapsed Time | 00:00:00:000 | 00:02:20:701 Call Rate | 0.000 cps | 0.434 cps -------------------------+---------------------------+-------------------------- Incoming call created | 0 | 0 OutGoing call created | 0 | 61 Total Call created | | 61 Current Call | 0 | -------------------------+---------------------------+-------------------------- Successful call | 0 | 61 Failed call | 0 | 0 -------------------------+---------------------------+-------------------------- Response Time 1 | 00:00:00:000 | 00:00:00:019 Call Length | 00:00:00:000 | 00:00:20:024 ------------------------------ Test Terminated ------------------------- By: Ronald Chan (loloski) 2011-02-21 07:40:17.000-0600 [sipp] exten => 9999,1,Progress same => n,Ringing same => n,Answer same => n,MusicOnHold(default,10) same => n,Hangup Another interesting bit, if you include a class MusicOnHold(default,10) the problem can also been observed, but omitting the class the problem is gone. Regards By: Muhammad Naseer Bhatti (nbhatti) 2011-02-21 07:40:27.000-0600 loloski, the issue is with WaitMusicOnHold(10). Once you remove, even SetMusicOnHold works fine. I am able to reproduce such with both 1.6.x and 1.8.x. I am now compiling/testing with res_timing_* and will post the results shortly. By: Ronald Chan (loloski) 2011-02-21 07:47:45.000-0600 nbhatti, WaitMusicOnHold is deprecated in favor of MusicOnHold, stealth*CLI> core show application waitmusiconhold -= Info about application 'WaitMusicOnHold' =- [Synopsis] Wait, playing Music On Hold [Description] WaitMusicOnHold(delay): !!! DEPRECATED. Use MusicOnHold instead !!! Plays hold music specified number of seconds. Returns 0 when done, or -1 on hangup. If no hold music is available, the delay will still occur with no sound. !!! DEPRECATED. Use MusicOnHold instead !!! [Syntax] Not available [Arguments] Not available [See Also] Not available stealth*CLI> But MusicOnHold has it's own quirk, if you include a class let say default the problem can be observed, but removing the class will fixed the issue. Regards, By: Ronald Chan (loloski) 2011-02-21 07:59:43.000-0600 I think the summary of the bug should be replaced, though i might be wrong too.... By: Ronald Chan (loloski) 2011-02-21 08:52:49.000-0600 [sipp] exten => 9999,1,Progress same => n,Ringing same => n,Answer same => n,Set(CHANNEL(musicclass)=default) same => n,MusicOnHold(10) same => n,Hangup with this one everything works perfectly including setting the class. By: Leif Madsen (lmadsen) 2011-02-22 11:08:05.000-0600 Closing this issue, as deprecated applications can be used for backwards compatibility, but issues produced by them will not be resolved. | ||