Closed Bug 684028 Opened 13 years ago Closed 11 years ago

JM+TI: long, noticeable GC pauses with Color GameBoy

Categories

(Core :: JavaScript Engine, defect)

x86_64
Windows 7
defect
Not set
normal

Tracking

()

RESOLVED INCOMPLETE
Tracking Status
firefox9 - affected
firefox10 - affected
firefox11 - ---
firefox12 - ---
firefox13 - ---

People

(Reporter: dmandelin, Unassigned)

References

(Blocks 1 open bug)

Details

Attachments

(1 file)

Grant's comment to my blog:

>Is it TI that's causing some bigger GC pauses now? I noticed the GC all-stops 
>the JavaScript GameBoy Color emulator (http://www.grantgalitz.org/gamecenter/) 
>now for a half a second a times now in the nightly. Much better performance 
>though, and not every game experiences the GC pauses as much as some (I wonder 
>if its Firefox acting up on the x-coord caching for optimizing GB-classic mode 
>sprite priority rendering (TL;DR - A sort algorithm that rebuilds a 
>multidimensional array for a performance trick not even desktop GBC emulators 
>do (But necessary otherwise firefox would run some games 1/3 speed.).)).

Grant, do you happen to know in what games it's particularly easy to see this? Or do you have a JS-only test case? I saw it in Tetris and Centipede, I think, but I had to play for a while.
There are actually two pauses to worry about it seems. One being the GC pause and the other being the HTML5 localstorage access pause (Because the SRAM from the games actually save to local storage for saving capabilities). The HTML5 localstorage pause is known to get very very long if you go nuts and try to save too much, and it also kicks in a few seconds after it has started.

As for the GC pause, I've seen this slightly more in the black & white classic games (Made for gameboy and not gameboy), but it's hard to tell though. I'm thinking the reason for GB classic games GC'ing a little more was due to more array creation/manipulation for that performance trick described in the blog comment.

Other than the sprite x-coord caching for GB-classic games, the only other thing that reasonably could cause GC'ing would be the VRAM tile caching, and would be the same for all the games (And some games would thrash it more than others, giving a variable GC need I'm guessing.).

This thing can be turned into a test very easily, as it could just try to update a dummy canvas. In what way would you like a test script though? ROMs could even be converted to a JS-array to make it even easier (Did this with the boot ROM.).
To help with test making, the sound can be turned off completely from a setting. There is also a speed multiplier function that can be called to increase out the speed of the entire emulator for benchmarking purposes.
comment update/correction: *As for the GC pause, I've seen this slightly more in the black & white classic games (As in made for Gameboy and not Gameboy Color (Tetris, Super Mario Land, MegaMan 1-4).).
Also, ignore that pause that occurs just after the boot ROM hands control over to the main ROM. That's from the emulator rebuilding its entire memory handling as another optimization trick (So the emulated CPU only needs to call one function inside an array to get to the desired mem read/write handler). Also creates / nulls some memory arrays depending on the main ROM type.
It does seem like whenever sprite DMA (in GB-classic ROMs) happens often, that Firefox does seem to experience a slight increase in random pauses that affect the sound output. 

The function on line 8295 gets called: https://github.com/grantgalitz/GameBoy-Online/blob/master/js/GameBoyCore.js#L8295 which generates a new blank multi-dimensional array from scratch (Since sorting through an outdated copy would require more iterations upon resort). It then goes on to add the 40 sprite lookups to their corresponding x-coord address that's used as an indice. format is like this - cache[x-coord][sprite priority rendering based on memory address location (from 0 to a max of ten (This array is variable length, depending on the number of sprites on said x-coord))]
The 3D "FX" Demo rom recently added to that list really experiences this problem. There is a lot of LD opcode loop unrolling in that ROM, causing the cached VRAM tiles to be invalidated upon rendering quite often.
Not too bad with this one.
Still heard audible clicks, which means the GC had to delay setInterval long enough to cause the audio buffer to be depleted before the next refill.
Gonna need to go deeper with a firefox debug build outputting useful info I guess.
Noticed Firefox GC'd 20 megabytes of RAM at a pause (Giant memory release proof that GC caused it) that caused gaps in the audio. I see this happen way way more often in the nightlies than firefox stable.
Hi Grant. I tried the game out using the 3D "FX" Demo. All the GC pauses were ~15ms, which seems pretty reasonable to me. I also didn't notice any audio or video glitches.

How fast is your computer? Also, are you certain that the GC is responsible? 20MB is a very small amount of memory to GC, so it shouldn't take very long. The best way to check is to enable javascript.options.mem.log in about:config and watch the error console. If you notice any long GCs (> 30ms) when you see a glitch, then we know it's the GC. Otherwise it isn't.
Well, I did hear audio glitching (popping noise due to the waveform going from -1 to 0 to -1 very fast (Waveform goes in one direction here, so the neutral point is -1 and not 0!)) on my macbook pro (mid-2010 / core 2 duo / Snow Leopard) right when the GC happened. 15 milliseconds is long for me, since I time the emulator with a 16 millisecond setInterval timer with low audio latency (25 thousand sample frame buffering target at 256khz stereo.).
Anyhow, this needs to made into a proper shell test of some sort.
I'm pretty ignorant about how games work, but your numbers seem off to me. If you're using 256Khz stereo audio (which, btw, seems way higher than you need), then it sounds like you need to fill your buffer 20 times per second (256,000 / 25,000 * 2 (for stereo)). So why do you need the setInterval callback to run every 16 ms = 62 times per second?

Also, you said "when the GC happened" in comment 11. Was that based on the memory log in the error console?
The emulator itself runs once every 16 milliseconds. The audio is replenished with the corresponding amount of samples during this time. Firefox and pretty much every browser in existence doesn't actually do 16 millisecond iterations exactly (Due to system delays/ IRQ timer accuracy). As a result, I actually check how many samples are left to play in firefox, and I make sure there are at least 25k sample frames left in the buffer. I implement audio in that I don't run blind, so I maintain the buffering, unlike what JSNES does (Which over-produces samples and runs blind causing giant overflows).
Actually, I had the activity monitor for osx opened at that time and as a coincidence I noticed the memory usage fell 20 megs at the same time of the gap in the audio output. Went from ~190 megs to 170 megs, I wish I had actual logs to detail this.
Also, this should not be tested on Windows XP, because Firefox still has edge-case audio bugs pertaining to how many samples are actually buffered (Some WinXP bug that I've tried to work around).
Note: It could be **way worse** like Google Chrome - http://www.youtube.com/watch?v=RjX1xXKWXtI (Bug now only seems to still occur in Windows (Worse is the fact that they knew about this bug, and yet they still landed web audio to stable.)) D:
I took a video of the Looney Tunes game running once in Firefox 6, and another in the nightlies.

Here's the Firefox 6 video - http://www.youtube.com/watch?v=Y2Gqoo6Tzn0

Here's the Firefox nightly video - http://www.youtube.com/watch?v=qQlnPNpw6JA

I did notice the audio drop-outs in the nightly video, but just barely (You have to pay attention to hear them). They happen very quickly, but they do happen (You hear no audio for a few milliseconds when there clearly should be audio).

Also to note is that Firefox glitches out with the graphics in the last 10 seconds of the nightly video. That should probably be reported if not already. D:
This basically looks like a very subtle perf issue at this point, which is not necessarily related to TI, so taking off the tracking list for 9.
Can we at least post a diagnosis? Why do we think this is a subtle perf issue?
(In reply to Andreas Gal :gal from comment #20)
> Can we at least post a diagnosis? Why do we think this is a subtle perf
> issue?

Expanding: right now, it doesn't look like this is a TI regression, it looks like audio getting cut out by GC pauses. I don't think we can reasonably fix this for 9 at this point through a profile-and-tune approach, and it doesn't look like a show-stopper. It does look like IGC will help a lot, and it's coming soon, so I'm not prioritizing effort on this bug specifically at this time. Marking tracking10+ to remind us to recheck when we get IGC.
Could this be at all related to the investigation in bug 711900? Since bug 641025 didn't land for 10, what's the next step here?
This showed up in 9, so it can't be 711900 per se.  Could be something else I guess.

One thing that could be done is to run a recent-ish Nightly and look at the GC output in the error console, as Bill added some more detailed time breakdowns in Firefox 11 I think.  Odds are, it will just show that the time is being spent in marking, which isn't useful, but it might point to some other phase blowing up.
There are only 3 betas left, with a code freeze on 1/20. Although not the same cause as bug 711900, this tracked bug should still get some attention to ensure that it doesn't exacerbate pauses.
(In reply to Alex Keybl [:akeybl] from comment #24)
> There are only 3 betas left, with a code freeze on 1/20. Although not the
> same cause as bug 711900, this tracked bug should still get some attention
> to ensure that it doesn't exacerbate pauses.

I think IGC is the most promising avenue right now for fixing this.
Anyhow, this only became an issue starting with Firefox 9, which I still find strange, because Firefox 4 through 8 GC worked perfectly with this case.

Sigh, at least Firefox *runs* this, as the latest stable of Opera cannot run it due to Opera implementing typed arrays wrong, causing the emulated CPU to crash. Also Safari 5.1.2 on snow leopard reloads the page as soon as the emulator runs, do it enough and you get this mysterious gray screen of death. Interestingly the Safari issue is a regression, as it used to work in earlier Safari 5 versions (And it works in webkit nightly). *SIGH*
There might be pauses because of TI analysis and recompilation, which happens in very large functions in particular. Grant, does your code contain any large functions? If so, it might be interesting to break them up into smaller ones to see if that helps (at least until bug 706914 lands). In Emscripten we purposefully disable inlining in LLVM and limit inlining in closure, to work around this issue.
Alon: There are a lot of big functions that also contain unrolled loops (Performance win in V8). Specifically BGGBCLayerRender and the DMAWrite functions are pretty big, as well as the updateCore function which updates all the counters and the entire emulated state. Eh, can't split it out without having perf loss in V8 and even Firefox (Manually inlined stuff for performance after looking at load stats.). I am always looking at ways to simplify it though.
TI does do a nice job of optimization though, as the load is usually 20% less in Firefox 9 than in Firefox 8.
V8 wins on the opcode interpretation (inline-caching of common results), while TI wins on the gfx routines (loop-inception).
Blocks: WebJSPerf
URL has changed to www.grantgalitz.org/GBCOnline/
I noticed V8 in Google Chrome optimizes the graphics JIT *heavily* that was recently landed. Basically it only renders the "queued" scanlines when VRAM or I/O changes cause the gfx JIT to spill. IonMonkey should be able to inspect the render loops too I guess, as V8 is able to do so (When V8 does, it causes funcs taking 25% of the CPU load to drop to 1%-ish, that big).
[Triage Comment]
Does this still need to be tracked for 11?  It's unclear if any advances are being made on resolving this.  Next step?
(In reply to Lukas Blakk [:lsblakk] from comment #33)
> [Triage Comment]
> Does this still need to be tracked for 11?  It's unclear if any advances are
> being made on resolving this.  Next step?

Nah. It's good to keep it on the radar for the future, though. Current work on JITs and GCs will hopefully fix this bug along the way.
[Triage Comment]
Nothing moving here yet enough to track this for Beta 13, untracking.  Please update tracking flags when this has a target milestone.
The domain now shows a godaddy placeholder. Grant, do you have this online somewhere else?
Flags: needinfo?(grantgalitz)
Nope, took it offline, run it on localhost to test it. It's open source on github. I'm working on a GBA emulator now https://github.com/grantgalitz/IodineGBA and Firefox has some gnarly GC pauses in it. I test it with nightly though - http://imgur.com/a/LTQkg
Flags: needinfo?(grantgalitz)
Thanks, resolving incomplete then. We have plenty of examples for things that suffers from GC pauses so I don't think we need to track this one, given that it's kinda hard to test.

Please do file bugs for your new emulator if and when you think we or you can gain through it. :)
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: