[Home]

Summary:ASTERISK-17442: [patch] Canary failure
Reporter:Stanislaw Pitucha (viraptor)Labels:
Date Opened:2011-02-20 14:46:26.000-0600Date Closed:2011-03-05 04:30:29.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:1.8.2 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) canary_ppid.patch
Description:I get a canary failure message ~a minute after asterisk starts up and receives some messages. The server is handling IAX clients only.

What can I provide to help debugging this?
Comments:By: Stanislaw Pitucha (viraptor) 2011-02-20 14:48:59.000-0600

Console / verbose logs don't provide any additional information.

By: Stanislaw Pitucha (viraptor) 2011-02-20 14:58:41.000-0600

For completeness in case they do matter - last events before the failure:

[...]
[Feb 20 22:56:52] DEBUG[28734]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for IAX2 - 1000202
[Feb 20 22:56:52] DEBUG[28734]: chan_iax2.c:13889 iax2_devicestate: Checking device state for device 1000202
[Feb 20 22:56:52] DEBUG[28734]: chan_iax2.c:13897 iax2_devicestate: iax2_devicestate: Found peer. What's device state of 1000202? addr=1430796598, defaddr=0 maxms=2000, lastms=33
[Feb 20 22:56:52] DEBUG[28734]: devicestate.c:458 do_state_change: Changing state for IAX2/1000202 - state 0 (Unknown)
[Feb 20 22:56:52] DEBUG[28734]: devicestate.c:438 devstate_event: device 'IAX2/1000202' state '0'
[Feb 20 22:56:52] DEBUG[28752]: chan_iax2.c:2714 sched_delay_remove: schedule decrement of callno used for A.B.C.D in 60 seconds
[Feb 20 22:56:52] DEBUG[28741]: chan_iax2.c:2396 peercnt_remove: ip callno count decremented to 2 for A.B.C.D
[Feb 20 22:56:53] WARNING[28729]: asterisk.c:3108 canary_thread: The canary is no more.  He has ceased to be!  He's expired and gone to meet his maker!  He's a stiff!  Bereft of life, he rests in peace.  His metabolic processes are now history!  He's off the twig!  He's kicked the bucket.  He's shuffled off his mortal coil, run down the curtain, and joined the bleeding choir invisible!!  THIS is an EX-CANARY.  (Reducing priority)

By: Tilghman Lesher (tilghman) 2011-02-22 12:43:06.000-0600

Then the canary is working as designed.

By: Tilghman Lesher (tilghman) 2011-02-22 12:44:48.000-0600

BTW, if you've disabled astcanary in menuselect, then it will prevent you from running Asterisk with the -p flag.

By: Stanislaw Pitucha (viraptor) 2011-02-22 15:08:58.000-0600

Well - that's cool, but that doesn't help me at all. The information I'm missing from the funny warning are:
- why did this condition occur?
- what should I do to prevent it happening?
- where do I find more information about it?

This message is supposed to warn me about something apparently. What should I do about it? I did not disable astcanary during installation and I'd like to run with realtime priority threads.

By: Tilghman Lesher (tilghman) 2011-02-22 19:59:10.000-0600

1) The condition occurred because the astcanary did not update the file in time.  When that happens, it's considered 'dead'.  By design, Asterisk lowers its realtime priority to avoid starving other system resources.  Possible causes are either that the astcanary was not installed or that the canary actually detected resource starvation and Asterisk shut off realtime priority in response.

2) Figure out why the canary is not running on a regular interval.

3) You've found out everything there is to know, already.

and now my question for you:

Why do you find it necessary to run Asterisk with realtime priority?  If your system is loaded so heavily that you need to provide Asterisk with priority scheduling over other processes, it's a clear indication that you need to move those other processes off to other machines and either give Asterisk a dedicated machine or switch to a cluster of machines which aren't so heavily loaded.  Realtime priority has never really made sense for a complex process like Asterisk.

By: Stanislaw Pitucha (viraptor) 2011-03-04 11:09:45.000-0600

I'd simply like to provide it priority over maintenance tasks that are triggered by hand / from cron. For example, I wouldn't like a system update to take asterisk's cpu share.

My main issue here is that the box is almost completely idle - it shouldn't be busy with anything apart from asterisk. And since asterisk doesn't handle anything right now, it's idle too. The average load and cpu usage are ~0 throughout the test. The canary dies anyways.

Actually in this case it indicated a bug in asterisk. Patch attached.

By: Digium Subversion (svnbot) 2011-03-05 04:28:25.000-0600

Repository: asterisk
Revision: 309677

U   branches/1.6.2/main/asterisk.c

------------------------------------------------------------------------
r309677 | tilghman | 2011-03-05 04:28:25 -0600 (Sat, 05 Mar 2011) | 7 lines

Missed part of the conversion when we started passing ppid to astcanary.

(closes issue ASTERISK-17442)
Reported by: viraptor
Patches:
      canary_ppid.patch uploaded by viraptor (license 543)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=309677

By: Digium Subversion (svnbot) 2011-03-05 04:29:31.000-0600

Repository: asterisk
Revision: 309678

_U  branches/1.8/
U   branches/1.8/main/asterisk.c

------------------------------------------------------------------------
r309678 | tilghman | 2011-03-05 04:29:31 -0600 (Sat, 05 Mar 2011) | 14 lines

Merged revisions 309677 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.6.2

........
 r309677 | tilghman | 2011-03-05 04:28:24 -0600 (Sat, 05 Mar 2011) | 7 lines
 
 Missed part of the conversion when we started passing ppid to astcanary.
 
 (closes issue ASTERISK-17442)
  Reported by: viraptor
  Patches:
        canary_ppid.patch uploaded by viraptor (license 543)
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=309678

By: Digium Subversion (svnbot) 2011-03-05 04:30:29.000-0600

Repository: asterisk
Revision: 309679

_U  trunk/
U   trunk/main/asterisk.c

------------------------------------------------------------------------
r309679 | tilghman | 2011-03-05 04:30:29 -0600 (Sat, 05 Mar 2011) | 21 lines

Merged revisions 309678 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.8

................
 r309678 | tilghman | 2011-03-05 04:29:30 -0600 (Sat, 05 Mar 2011) | 14 lines
 
 Merged revisions 309677 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.6.2
 
 ........
   r309677 | tilghman | 2011-03-05 04:28:24 -0600 (Sat, 05 Mar 2011) | 7 lines
   
   Missed part of the conversion when we started passing ppid to astcanary.
   
   (closes issue ASTERISK-17442)
    Reported by: viraptor
    Patches:
          canary_ppid.patch uploaded by viraptor (license 543)
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=309679