New issue
Advanced search Search tips

Issue 691188 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Apr 2017
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 2
Type: Bug



Sign in to add a comment

setValueAtTime() sometimes randomly fails for certain time inputs

Reported by linb...@gmail.com, Feb 11 2017

Issue description

UserAgent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/56.0.2924.87 Safari/537.36

Steps to reproduce the problem:
1. Open index.html, looping synthesized WebAudio sound should play.

2. Listen carefully to the bass section.
   The first two iterations will play only 3 notes, ignoring the 4th while still playing the 3rd.
   The third iteration successfully plays the 4th note, in-place of where the second half of the 3rd note was in the previous two iterations.
   There will be a seemingly random pattern of correct and incorrect playbacks for further iterations.

What is the expected behavior?
Every loop of the music sequence should be identical.

This application uses a Web Worker solution to pre-schedule oscillator changes to create a seamless loop of music. Each time the AudioContext.currentTime is 3 ticks behind the song's time, it allocates another buffer of scheduled changes to the oscillators.

Much testing has been done to ensure it runs smoothly, even looping at very short intervals. This edge-case bug came up in Chrome where it has no issue in Firefox or Edge.

What went wrong?
This effect appears to be related to the startTime parameter, especially when there are repeating decimals, e.g. 3.5999999999999996.

From my preliminary testing, it appears to be a rare occurrence, and possibly only affects the last scheduled oscillator event. It also appears to be somewhat related to repeating decimal digits such as 3.66666666667 and 12.19999999998! Values such as 1069.1999999999955, 1083.5999999999954, 1093.1999999999953 all trigger the issue.

I first noticed this issue occurring very rarely, seemingly random: only on iteration 13 and 30 in one case. This was before I switched to a BPM formula for tempo calculation. By luck my specified BPM of 100 was able to trigger this problem on the first iteration. Note that changing the BPM value from 100 to 99 or 101 makes the 4th note play successfully.

To illustrate this, these are the given time values (in seconds) for the first 3 iterations:

Iteration 1, Note 1: 0
Iteration 1, Note 2: 1.2
Iteration 1, Note 3: 2.4
Iteration 1, Note 4: 3.5999999999999996   <---- doesn't play!

Iteration 2, Note 1: 4.8
Iteration 2, Note 2: 6
Iteration 2, Note 3: 7.199999999999999
Iteration 2, Note 4: 8.399999999999999   <---- doesn't play

Iteration 3, Note 1: 9.6
Iteration 3, Note 2: 10.799999999999999
Iteration 3, Note 3: 12
Iteration 3, Note 4: 13.2     <---- now it does!

As you can see, it appears to affect the only the last-scheduled event in an oscillator.

If one modifies the musical note data and add a note further past the problematic note above, the problem ceases to exist. 

For example, the simple act of replacing a null value with a note past the ['e2'] value will cause it to work properly:

[
    ['a1'],null,null,null,
    null,null,null,null,
    ['c#2'],null,null,null,
    null,null,null,null,
    ['f#2'],null,null,null,
    null,null,null,null,
    ['e2'],null,['f2'],null,
    null,null,null,null,
],

I tried replacing all subsequent null values with a note, and all had no repeating decimals, highlighting this as a rarity.

However, if adding that note before the problematic ['e2'], the issue will still remain:

[
    ['a1'],null,null,null,
    null,null,null,null,
    ['c#2'],null,null,null,
    null,null,null,null,
    ['f#2'],null,null,null,
    null,null,['f2'],null,
    ['e2'],null,null,null,
    null,null,null,null,
]

I attempted to fix this using parseFloat(Number.toFixed(15)), and while it appeared to work at first, I quickly ran into a LONG sequence of problematic notes. However as you will see, it eventually rolled-over and began to work again:

OVERALL TIMER: 129.59999999999997
OVERALL TIMER: 130.79999999999995
OVERALL TIMER: 131.99999999999997
OVERALL TIMER: 133.19999999999996

OVERALL TIMER: 134.39999999999998
OVERALL TIMER: 135.59999999999997
OVERALL TIMER: 136.79999999999998
OVERALL TIMER: 137.99999999999997

OVERALL TIMER: 139.2
OVERALL TIMER: 140.39999999999998
OVERALL TIMER: 141.6
OVERALL TIMER: 142.79999999999998

...Starting to work now???

OVERALL TIMER: 144
OVERALL TIMER: 145.2
OVERALL TIMER: 146.4 
OVERALL TIMER: 147.6 

OVERALL TIMER: 148.8 
OVERALL TIMER: 150 
OVERALL TIMER: 151.20000000000002
OVERALL TIMER: 152.4 

OVERALL TIMER: 153.60000000000002
OVERALL TIMER: 154.8
OVERALL TIMER: 156.00000000000003
OVERALL TIMER: 157.20000000000002

It still works even with the repeating zeroes.

However, it eventually stops working again:

OVERALL TIMER: 595.2 
OVERALL TIMER: 596.4000000000001
OVERALL TIMER: 597.6
OVERALL TIMER: 598.8000000000001

OVERALL TIMER: 600
OVERALL TIMER: 601.2 
OVERALL TIMER: 602.4
OVERALL TIMER: 603.6

OVERALL TIMER: 604.8
OVERALL TIMER: 606
OVERALL TIMER: 607.1999999999999
OVERALL TIMER: 608.4

And here is where it rolls over and fails to play the final note yet again.

OVERALL TIMER: 609.5999999999999
OVERALL TIMER: 610.8
OVERALL TIMER: 611.9999999999999
OVERALL TIMER: 613.1999999999999

OVERALL TIMER: 614.3999999999999
OVERALL TIMER: 615.5999999999999
OVERALL TIMER: 616.7999999999998
OVERALL TIMER: 617.9999999999999

Hopefully this explains it...

Did this work before? N/A 

Does this work in other browsers? Yes

Chrome version: 56.0.2924.87  Channel: stable
OS Version: 6.1 (Windows 7, Windows Server 2008 R2)
Flash Version: Shockwave Flash 24.0 r0

I am using stable channel of most browsers, I did not test on Canary, etc. (Is there a portable version that doesn't interfere with the main browser, and can be removed after testing?)

I hope this info is useful in finding/crushing the bug.

 

Comment 1 by linb...@gmail.com, Feb 11 2017

Thought I already attached the html file... or my session expired, but here it is again
index.html
4.6 KB View Download

Comment 2 Deleted

Comment 3 by linb...@gmail.com, Feb 12 2017

The previous index.html crashed in Firefox because of non-breaking spaces in the file, so here is a fixed one. Please use it instead. Also the console output is cleaner as it only logs the affected bass notes and their value.

I have some more information on this issue:

The specific criteria for the bug is as follows:

1) It only affects the _last scheduled change_ to an individual AudioParam.

2) It only occurs when the value of startTime resembles 2.79999999999995, characterized by repeating 9. 

    Repeating 0 or an infinite repeating pattern such as 2.1234123412341234 are not affected.
    Ex. 0.15 * 3 = 0.44999999999999996
    This value is affected. Real value is 0.45
    Ex. 0.1 + 0.2 = 0.30000000000000004
    This value is not affected. Real value is 0.3

The issue can be fixed by a couple workarounds:

1) Because this only affects the _last scheduled change_ to an individual AudioParam, schedule additional changes before currentTime is able to reach the final scheduled change. In context of a music sequencer, this is best done by an entire buffer of the song.

2) Properly round the number before processing it in setValueAtTime.
   
    function fixN(n) { return parseFloat(n.toPrecision(16)); }

Each Oscillator and Gain Node have separate AudioParam event lists.
This means scheduling an additional event for the detune of an Osc won't affect its frequency.

Spec is here: https://webaudio.github.io/web-audio-api/#widl-AudioParam-setValueAtTime-void-float-value-double-startTime
index.html
4.7 KB View Download

Comment 4 by linb...@gmail.com, Feb 12 2017

Here is a 'reduced test case' of the bug: http://jsbin.com/mabebu/edit

(function() {
    // Setup oscillator
    var ctx = new AudioContext();
    var amp = ctx.createGain();
    amp.gain.value = 0.15;
    amp.connect(ctx.destination);
    var osc = ctx.createOscillator();
    osc.connect(amp);
    osc.start();
    
    var time = 0.59999; // input time value here
    var o = osc.frequency.setValueAtTime(110, time);
   
    console.log("Initial value:", o.value);
    // Get AudioParam value at time
    console.log("time is:",time)
    setTimeout(function(){ console.log("Value at " + time, o.value)  }, time*1000 + 10);
    // Stop after 1250 ms
    setTimeout(function(){osc.stop();}, 2250);
})();

Values that work:
0.3333
0.6666
0.9999
0.12366
0.5151980123789

Values that do not work:
0.33333
0.66666
0.99999
0.13333
0.53333
0.93333
0.06666
0.26666
0.46666
0.86666
0.19999
0.39999
0.59999
0.79999
0.11199
0.11198
0.12266
0.15733
0.35733
0.55733
0.151980123789

It appears that only the first 5 or 6 digits after the decimal have an effect, and the bug occurs usually when all digits are either even or odd. Only specific patterns of numbers trigger the bug; 0.53339 and 0.37555 are fine while 0.266663 triggers the bug and 0.266667 doesn't.

Also, using fixN() as a workaround doesn't actually fix the issue, and actually includes the integer part of the number as part of the calculation... so not the best.
The best workaround appears to be rounding to 4 decimals with `Math.round((num) * 10000) / 10000`. This should give a resolution of about 100 microseconds (don't know if that is less or more than WebAudio's time resolution, but it should be fine).


Comment 5 by ajha@chromium.org, Feb 13 2017

Labels: Needs-Triage-M56

Comment 6 by rtoy@chromium.org, Feb 13 2017

Labels: Needs-Feedback
Thanks so much for the repro case.  However, I'm unable to reproduce this using Chrome 57. Using http://jsbin.com/mabebu/edit, I hear a tone and the console logs show the correct frequency at the start and at the selected time.

I also ran your test in index.html, and all notes are always played at least for the 30 sec I let it run. (I'm not sure what to look for because the console logs I have are different from what you show.)

Could you test with Chrome 57 (beta) and/or Chrome 58 (dev)?

Comment 7 by rtoy@chromium.org, Feb 13 2017

Probably the same as  issue 645776 .

Comment 8 by linb...@gmail.com, Feb 13 2017

Just tested beta. Chrome 57.0.2987.37 beta (64-bit) is unaffected by the bug, so it must've been fixed somewhere. It is affecting 56.0.2924.87 stable (64-bit).

--------

About  issue 645776 : Yes related. I wasn't sure at first, but in an additional test case in the comments (comment #2), it is noted that this code yields more errors for some unknown reason:

    var startTime = audioContext.currentTime + 128 / audioContext.sampleRate
    osc.frequency.setValueAtTime(val, startTime);


The value here (128 / audioContext.sampleRate) is typically (128 / 48000) = 0.0026666666666666666

I modified that test case to log the currentTime parameter on each failure, and 99% of the time, the logged values fail my own test case here in c#4.

Log of values is here: http://pastebin.com/raw/R7S3F93z
I only took the first 5 digits of the fractional part as that is the only part that causes the bug.
Real output looks like this:

21.53333333333333
22.37333333333333
22.53333333333333
23.37333333333333
23.53333333333333
256.06399999999996
256.14399999999995
256.26399999999995
256.38399999999996
256.50399999999996

Notice the jump from 23 seconds to 256 seconds, that is not random. There is something specific about the the number being fed into setValueAtTime that causes it to be ignored. 

--------

Is  issue 622082  more accurate to what is happening? Are these events ignored because internally, they appear to be in the past? Perhaps some incorrect rounding issue?

Comment 9 by linb...@gmail.com, Feb 13 2017

Actually in my test case in comment 4, specifying a time value as far ahead as 10+ seconds into the future will still fail, so I doubt it is a rounding issue. I would like to know what fixed it though.

On stable Chrome 56, using #c4 test case with time input 7.11199 (only .11199 matters): 

"Initial value:"
440
"Time set was:"
7.11199
"Value at time=7.11199"
440
"ERROR: Bug has occured"

Comment 10 by rtoy@chromium.org, Feb 13 2017

I'm getting a bit confused on what is producing what.  In c#8, you have a new bit of code and some saved values.  What test are you applying this too? Is it index.html or the reduced test case in the jsbin example?

I am encouraged that Chrome 57 seems to have this fixed.  There have been quite a few issues with AudioParams that have been fixed over the last couple of versions.

Comment 11 by linb...@gmail.com, Feb 14 2017

I was referring to a reproducible test done in comment #2 from  issue 645776 :

"Comment 2 by yotamm...@gmail.com, Sep 11
Here's an interesting discovery. If I schedule the event exactly 128 sample (one block) in the future, this error happens much more often:

https://jsfiddle.net/yotammann/8jrudcs8/10/"


I forked that fiddle test (here: https://jsfiddle.net/6xmh64un/) to log the startTime of setValueAtTime() whenever the error occurs, and found that most of those affected values also cause the bug over here using my own test from earlier: http://jsbin.com/mabebu/edit.

That tells me that they are related issues.

The JSFiddle produced a log like:

23.53333333333333
256.06399999999996

I just extracted the first 5 decimal places 0.xxxxx of 200+ values, removed duplicates and put it in that paste: http://pastebin.com/raw/R7S3F93z. All of those values cause the bug in my own test case (the JSBin above).

Hope that clears up any confusion.

Basically, this bug causes events scheduled to certain fractions of a second, such as 23.53333333333333, to not take effect; to be ignored or cancelled.

Comment 12 by rtoy@chromium.org, Feb 14 2017

Thanks for the update.  I ran https://jsfiddle.net/6xmh64un/ with Chrome 57 and everything seems to be working.  You also mentioned c#8 that Chrome 57 does not have this problem. So is this issue really fixed for you?  Can't really do anything about Chrome 56.

Comment 13 by linb...@gmail.com, Feb 14 2017

Do we know what was the cause and what was the fix that solved this bug?

Until that update from beta is rolled out, I have to use a workaround of rounding to 4 decimal places to avoid the bug in Chrome 56. 

Comment 14 by rtoy@chromium.org, Feb 14 2017

No, I don't actually know what fixed it.  How important is that to you?  And does it really matter?

Sorry about the bug in Chrome 56.

Not sure what you mean by "update from beta", but Chrome 57 is available and apparently fixes the issue.
Project Member

Comment 15 by sheriffbot@chromium.org, Feb 22 2017

Labels: -Needs-Feedback Needs-Review
Owner: rtoy@chromium.org
Thank you for providing more feedback. Adding requester "rtoy@chromium.org" for another review and adding "Needs-Review" label for tracking.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

Comment 16 by linb...@gmail.com, Feb 22 2017

> No, I don't actually know what fixed it.  How important is that to you?  And does it really matter?
>
> Sorry about the bug in Chrome 56.
>
> Not sure what you mean by "update from beta", but Chrome 57 is available and apparently fixes the issue.

No problem, it's just that most people use stable, which is still affected by this bug. It's important to me, because it's not an obscure bug, It does occur in production and I need a workaround to ensure my code works reliably. The best solution thus far is to round startTime to 4 decimal digits (e.g. 23.5333333333333333 becomes 23.5333) which is not ideal. And not everyone will always be up to date with the latest version, etc. For me, knowing what caused this bug gives me better info on what I was doing wrong, or help devise a better workaround.

I had hoped I provided enough info to track down the bug, which appears to have been fixed if only by consequence of another issue. It is a shame you don't think it is worth looking into. 

It's possible that this patch (linked in  issue 645776 ) is what fixed it, but I cannot see why.

https://codereview.chromium.org/2567183002

In my description of this issue, I mentioned that it only affects the last scheduled event.
Interestingly this patch specifically mentions the last event:

    "The optimization for the case when the last event is in the past does
    not work for k-rate AudioParams because the final value returned is
    the last value requested."

But it supposedly only affects when the last event is in the past.

My issue is when events are scheduled with time values such as 23.53333333333333.
They fail my test case just as much as 0.5333333333333333 or 5.5333333333333333, and they aren't in the past.

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

In any case, it would be best to not overlook bugs that end up fixed by mistake. Especially in software as widely used as Chrome/Chromium. Just because one patch fixes multiple issues, doesn't mean that the main causes were addressed. It's always possible that changes which shouldn't affect a fixed issue could make an unknown bug appear again.

Comment 17 by rtoy@chromium.org, Feb 22 2017

If you're really interested to know what fixed the issue, a binary bisect can be done to find the CL that fixed it.

Even if we knew exactly which CL fixes this, it's fairly unlikely that Chrome 56 would accept the change at this stage.

Again, sorry for breaking this.
Cleaning up "Needs-Review" label as we are not using this label for triage. Ref  bug 684919 
Labels: -Needs-Review

Comment 20 by rtoy@chromium.org, Apr 5 2017

Status: Fixed (was: Unconfirmed)
Closing as fixed.

If this issue still occurs, please reopen with updated information or create a new bug.

Sign in to add a comment