[asterisk-dev] sched.c: Request to schedule in the past.

[Al Lougher]

Just revisiting this error again. Yesterday I was able to catch this happening with very little load on the server (5 calls). When the error occurs the outbound audio (custom playback module PlaybackAMD) pauses for the duration of the error. Example from the log below, note the delays before/after the error, this is where playback stops then continues.

Sep  8 16:07:53] VERBOSE[27186] logger.c:     -- PLAYBACKAMD: filename[customermessages/2790-20089816312],
initialSilence [50000] greeting [50000] afterGreetingSilence [50000]
totalAnalysisTime [5000] minimumWordLength [80] betweenWordsSilence
[30] maximumNumberOfWords [5] silenceThreshold [200]
[Sep  8 16:07:53] VERBOSE[27186]
 logger.c:     -- <SIP/65.248.16.32-0a24eab8> Playing 'customermessages/2790-20089816312' (language 'en')
[Sep  8 16:07:53] VERBOSE[27186] logger.c:     -- PLAYBACKAMD: Changed state to STATE_IN_SILENCE
[Sep  8 16:07:54] VERBOSE[27186] logger.c:     -- PLAYBACKAMD: Word detected. iWordsCount:1
[Sep  8 16:07:56] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:07:57] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:07:58] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:07:59] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:00] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:01] DEBUG[27186] sched.c: Request to schedule in the
 past?!?!
[Sep  8 16:08:02] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:03] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:04] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:05] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:06] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:06] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:06] VERBOSE[27186] logger.c:     -- PLAYBACKAMD: Changed state to STATE_IN_SILENCE
[Sep  8 16:08:07] DEBUG[27186] sched.c: Request to schedule in the past?!?!
[Sep  8 16:08:07] VERBOSE[27186] logger.c:     -- PLAYBACKAMD: Word detected. iWordsCount:2

Does anyone have an idea what can cause this error?

Thanks
Alan


--- On Fri, 5/16/08, Tilghman Lesher <tilghman at mail.jeffandtilghman.com> wrote:
From: Tilghman Lesher <tilghman at mail.jeffandtilghman.com>
Subject: Re: [asterisk-dev] sched.c: Request to schedule in the past.
To: "Asterisk Developers Mailing List" <asterisk-dev at lists.digium.com>
Date: Friday, May 16, 2008, 1:10 PM

On Friday 16 May 2008 14:48:54 Al Lougher wrote:
> I've a tweaked version
 of app_amd that instead of waiting for audio in
the
> receive direction, it begins streaming audio right away. The problem is
> it's occasionally throwing this error as well as stopping the stream
for a
> second or two then continuing. I think the error is being caused by either
> ast_sched_wait() or ast_sched_runq().

Generally you're going to see that error when a machine is heavily loaded
and
a scheduled task does not make it to the queue until after it was supposed to
have run.  A frequent cause nowadays is running Asterisk within a virtual
machine.  The load caused by other VMs on the same physical machine delays
the Asterisk process.  If this is the case, you might try moving your VM to
another physical machine that is not as heavily loaded or you might try a
dedicated machine.

I've also run into this error when running under valgrind with full
debugging
turned on, as that will
 also slow down the process threads markedly.

-- 
Tilghman

_______________________________________________
--Bandwidth and Colocation Provided by http://www.api-digital.com--

asterisk-dev mailing list
To UNSUBSCRIBE or update options visit:
   http://lists.digium.com/mailman/listinfo/asterisk-dev



      
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-dev/attachments/20080909/3369a824/attachment.htm