[Home]

Summary:ASTERISK-09617: * is looping and CPU goes at 100%
Reporter:Clod Patry (junky)Labels:
Date Opened:2007-06-07 14:10:59Date Closed:2011-06-07 14:08:22
Priority:MinorRegression?No
Status:Closed/CompleteComponents:. I did not set the category correctly.
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 9912.patch.txt
Description:I've noticed taht after a certain time of * running, * is looping and the CPU goes at 100%

this is after
System uptime: 1 day, 22 hours, 51 minutes, 18 seconds

****** ADDITIONAL INFORMATION ******

It's looping regarding channel.c
Even if ive turn internal_timing = no in my asterisk.conf, that loop starting over and over after like 30-35 hours of uptime

If I restart now, everything will be fixed, but the problem occurs over & over.
I could restart now each night, but thats a tweak and this system is so busy, it never goes at 0 active calls (always, min. 10 channels).

this is the loop:

[Jun  7 15:04:12] DEBUG[1217]: channel.c:2475 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=85)
[Jun  7 15:04:12] DEBUG[1217]: app_meetme.c:2124 conf_run: Got unrecognized frame on channel SIP/64.15.69.138-0dacdb50, f->frametype=5,f->subclass=0
[Jun  7 15:04:12] DEBUG[1217]: channel.c:2475 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=85)
[Jun  7 15:04:12] DEBUG[1217]: app_meetme.c:2124 conf_run: Got unrecognized frame on channel SIP/64.15.69.138-0dacdb50, f->frametype=5,f->subclass=0
[Jun  7 15:04:12] DEBUG[1217]: channel.c:2475 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=85)
[Jun  7 15:04:12] DEBUG[1217]: app_meetme.c:2124 conf_run: Got unrecognized frame on channel SIP/64.15.69.138-0dacdb50, f->frametype=5,f->subclass=0
[Jun  7 15:04:12] DEBUG[1217]: channel.c:2475 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=85)
[Jun  7 15:04:12] DEBUG[1217]: app_meetme.c:2124 conf_run: Got unrecognized frame on channel SIP/64.15.69.138-0dacdb50, f->frametype=5,f->subclass=0
[Jun  7 15:04:12] DEBUG[1217]: channel.c:2475 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=85)
[Jun  7 15:04:12] DEBUG[1217]: app_meetme.c:2124 conf_run: Got unrecognized frame on channel SIP/64.15.69.138-0dacdb50, f->frametype=5,f->subclass=0
[Jun  7 15:04:12] DEBUG[1217]: channel.c:2475 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=85)
[Jun  7 15:04:12] DEBUG[1217]: app_meetme.c:2124 conf_run: Got unrecognized frame on channel SIP/64.15.69.138-0dacdb50, f->frametype=5,f->subclass=0
[Jun  7 15:04:12] DEBUG[1217]: channel.c:2475 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=85)
[Jun  7 15:04:12] DEBUG[1217]: app_meetme.c:2124 conf_run: Got unrecognized frame on channel SIP/64.15.69.138-0dacdb50, f->frametype=5,f->subclass=0
Comments:By: Russell Bryant (russell) 2007-06-07 14:48:31

Please try the attached patch and see if it fixes the issue
By: Joshua C. Colp (jcolp) 2007-06-13 14:10:07

I can confirm this fixes the issue for me so I've put it into 1.4 as of revision 69144 and trunk as of revision 69147.
By: Clod Patry (junky) 2007-06-15 21:54:27

I just installed 1.4.5 and im still getting the same behavior (CPU goes at 100% again).



By: Joshua C. Colp (jcolp) 2007-07-08 20:58:06

Okay, is it the same message on screen? Can you get a backtrace of everything running to see if anything is abnormal?
By: Clod Patry (junky) 2007-07-08 22:30:36

there's no message (like the previous i was getting) so far.
nothing special is running on that machine.
I noticed this happen only on machine running ubuntu-server 7.04 on x86-64.
If I remind correctly this happen since 1.4.1

Im open to help with debugging,troubleshoot even to give access to server.

this is an output of top:

top - 23:48:43 up 47 min,  1 user,  load average: 1.01, 0.92, 0.52
Tasks:  64 total,   2 running,  62 sleeping,   0 stopped,   0 zombie
Cpu(s): 50.1%us,  0.0%sy,  0.0%ni, 49.9%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   1027012k total,   403228k used,   623784k free,    10628k buffers
Swap:  3004112k total,        0k used,  3004112k free,   313384k cached

 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                        
4089 root      15   0  370m  12m 7384 S  100  1.2  11:48.91 asterisk                                                                                        
   1 root      18   0  5064 1956  564 S    0  0.2   0:01.79 init                                                                                            
   2 root      RT   0     0    0    0 S    0  0.0   0:00.00 migration/0                                                                                    
   3 root      34  19     0    0    0 S    0  0.0   0:00.00 ksoftirqd/0  
[...]

and the last time, this is when i was getting a 100% cpu.
deer*CLI> core show uptime
System uptime: 47 minutes, 51 seconds
(with * 1.4.6)
By: Joshua C. Colp (jcolp) 2007-07-08 22:41:28

The ast_grab_core script in utils/scripts will grab a core dump from a running Asterisk. Open the core dump in gdb and grab a backtrace, this should allow us to see what is causing the CPU usage.
By: Clod Patry (junky) 2007-07-25 05:00:44

after few days of activity:
im still getting a lot of:
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)
[Jul 25 06:14:00] DEBUG[32054]: channel.c:2522 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=136)

will see with ast_grab_core.
By: Tilghman Lesher (tilghman) 2007-08-29 14:16:38

Housekeeping:  any updates?
By: Clod Patry (junky) 2007-08-30 14:50:09

I've been unable to use the ast_grab_core utils.
The load is going after only like 2 days of full load.
By: Tilghman Lesher (tilghman) 2007-11-01 17:37:10

Is this still an issue with the current 1.4?  Have you been able to grab a core with the noted script yet?
By: Tilghman Lesher (tilghman) 2007-12-06 18:41:09.000-0600

No response from reporter