[Home]

Summary:ASTERISK-10366: WaitMusicOnHold() waits three times longer than it should.
Reporter:Nick Barnes (bcnit)Labels:
Date Opened:2007-09-21 13:21:35Date Closed:2007-10-03 12:17:40
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Applications/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:extensions.conf:

exten => 20,1,Answer
exten => 20,n,NoOp(${EPOCH})
exten => 20,n,Wait(10)
exten => 20,n,NoOp(${EPOCH})
exten => 20,n,WaitMusicOnHold(10)
exten => 20,n,NoOp(${EPOCH})
exten => 20,n,Hangup



Verbose output:

   -- Executing [20@vitell-in:1] Answer("SIP/vitell402-0a1203e8", "") in new stack
   -- Executing [20@vitell-in:2] NoOp("SIP/vitell402-0a1203e8", "1190399508") in new stack
   -- Executing [20@vitell-in:3] Wait("SIP/vitell402-0a1203e8", "10") in new stack
   -- Executing [20@vitell-in:4] NoOp("SIP/vitell402-0a1203e8", "1190399518") in new stack
   -- Executing [20@vitell-in:5] WaitMusicOnHold("SIP/vitell402-0a1203e8", "10") in new stack
   -- Started music on hold, class 'default', on SIP/vitell402-0a1203e8
   -- Stopped music on hold on SIP/vitell402-0a1203e8
   -- Executing [20@vitell-in:6] NoOp("SIP/vitell402-0a1203e8", "1190399547") in new stack
   -- Executing [20@vitell-in:7] Hangup("SIP/vitell402-0a1203e8", "") in new stack
 == Spawn extension (vitell-in, 20, 7) exited non-zero on 'SIP/vitell402-0a1203e8'



As you can see, Wait() works pefectly, WaitMusicOnHold() waits longer!! This is repeatable and it always waits three times longer than the delay parameter - WaitMusicOnHold(20) waits a minute.
Comments:By: Tilghman Lesher (tilghman) 2007-09-21 14:03:27

I have to wonder about your environment, because I just tried this, and it waits exactly 10 seconds, which is correct:

exten => 8103,1,Set(time1=${EPOCH})
exten => 8103,n,WaitMusicOnHold(10)
exten => 8103,n,Set(time2=${EPOCH})
exten => 8103,n,Set(diff=$[${time2}-${time1}])

   -- Executing [8103@digium:1] Set("SIP/103-08232310", "time1=1190402281") in new stack
   -- Executing [8103@digium:2] WaitMusicOnHold("SIP/103-08232310", "10") in new stack
   -- Started music on hold, class 'default', on SIP/103-08232310
   -- Stopped music on hold on SIP/103-08232310
   -- Executing [8103@digium:3] Set("SIP/103-08232310", "time2=1190402291") in new stack
   -- Executing [8103@digium:4] Set("SIP/103-08232310", "diff=10") in new stack
 == Auto fallthrough, channel 'SIP/103-08232310' status is 'UNKNOWN'

By: Nick Barnes (bcnit) 2007-09-21 16:25:04

Yup. Must be environmental - tested on two other 1.4.11 boxes with mirror image configuration and they're fine.

But on this one box, it definitely waits three times longer.

Any ideas where I should start looking?

By: Tilghman Lesher (tilghman) 2007-09-21 21:25:47

No idea, sorry.  I've never seen any such behavior before.

By: Nick Barnes (bcnit) 2007-09-22 03:12:29

Hmmm. It's running on CentOS 5 32 bit kernel on an AMD 64 CPU. That's about the only thing which stands out as different to the other boxes it works on - 32bit kernel on 32bit CPU works fine as does 64 on 64. Probably nothing to do with it, but it's the only thing I can think of.

By: Tilghman Lesher (tilghman) 2007-10-03 10:27:00

Closing as unable to reproduce.  If you can figure out a test case that consistently causes this issue, feel free to reopen.

By: Nick Barnes (bcnit) 2007-10-03 10:56:33

This bug occurred with the stock kernel/config. I downloaded the latest kernel and compiled that - the problem went away.

Strange.

By: Tilghman Lesher (tilghman) 2007-10-03 12:17:40

Okay, we'll chalk this up to a distribution bug.