Hi Kevin, Does it deoptimize?
I do not see any deoptimizations in the log you have attached, were you running with --trace-deopt? Vyacheslav Egorov On Tue, Nov 6, 2012 at 12:33 AM, Kevin Gadd <[email protected]> wrote: > Hi, > > I've been looking into some performance issues in Chrome Canary for a HTML5 > game I released a little while back. At present, Firefox Nightly runs this > game a lot faster than Canary does, which is surprising to me because Chrome > has a much better Canvas backend and used to do much better at running this > game. From doing some profiling and comparing profiles between the browsers, > I am pretty sure I am running into a V8 issue here - perhaps because > something is wrong with my JS. > > I ran the game with trace-opt, trace-bailout and trace-deopt turned on. I > see tons and tons of marking and optimization happening while the game is > running, and it never settles down, despite the fact that the game is not > particularly dynamic once it gets going - it reaches a steady state where it > is not generating tons of code on the fly, and types are not changing, so it > shouldn't be necessary to constantly recompile functions. > > Worse, though, I see a lot of these messages: > > [disabled optimization for Game_EnqueueTick, reason: optimized too many > times] > [disabled optimization for KinematicBody_get_SupportingBody, reason: > optimized too many times] > [disabled optimization for SpriteBatch_InternalDraw, reason: optimized too > many times] > [disabled optimization for DrawScaleF, reason: optimized too many times] > [disabled optimization for SpriteBatch_DeferBlit, reason: optimized too many > times] > > From looking at the code, this appears to be a deopt that is hit once a > function has been optimized 1000 times. I can't imagine why these functions > would be optimized 1000 times in the first place, and the deopt seems to be > hurting them because profiles in the Web Inspector show some of these > functions as bottlenecks - but in SpiderMonkey they barely contribute to CPU > time in comparison (and some of them are extremely simple). > > For example: > > function DrawScaleF (texture, position, sourceRectangle, color, > rotation, origin, scale, effects, layerDepth) { > var sourceX = 0, sourceY = 0, sourceWidth = 0, sourceHeight = 0; > if (sourceRectangle !== null) { > sourceX = sourceRectangle.X; > sourceY = sourceRectangle.Y; > sourceWidth = sourceRectangle.Width; > sourceHeight = sourceRectangle.Height; > } else { > sourceWidth = texture.Width; > sourceHeight = texture.Height; > } > > this.InternalDraw( > texture, position.X, position.Y, sourceWidth, sourceHeight, > sourceX, sourceY, sourceWidth, sourceHeight, > color, rotation, > origin.X, origin.Y, > scale, scale, > effects, layerDepth > ); > } > > This function is pretty simple, and the type information should basically > never change. sourceRectangle is always either null or an instance of one > specific class, texture is always an instance of one specific class, etc. > The function isn't doing any arithmetic or calling complex functions, it's > basically just a wrapper around InternalDraw. > > Normally I would expect this function to entirely get optimized out, or at > least get reduced down to some really simple code. That appears to be what > happens in SpiderMonkey. > > So, for stuff like this, what steps should I take to understand why a > function is being recompiled lots of times, and how can I work around this? > If I manage to get the hydrogen IR dumped, can I look for particular warning > signs in the IR for these functions? Are there some other debug flags I can > pass to the runtime to get diagnostic information here? > > If you want to test the game yourself with flags set, it's at > http://www.playescapegoat.com/. Just playing one or two stages should be > enough to generate lots of those messages. > > Possibly related: In the logs, sometimes I see it reoptimize the same > function like ten times back to back. Is this right? It seems like it > shouldn't happen. > > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 1.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [optimizing: DrawScaleF / 2c69a039 - took 0.000, 0.000, 0.000 ms] > [marking DrawScaleF 0x2c69a038 for recompilation, reason: small function, > ICs with typeinfo: 11/11 (100%)] > [disabled optimization for DrawScaleF, reason: optimized too many times] > > I've uploaded a log of one run with the trace options set here, if you want > to look at it: > http://pastebin.com/7aCyeZC2 > You can see some of the stuff I describe. > > Thanks, > -kg > > -- > v8-users mailing list > [email protected] > http://groups.google.com/group/v8-users -- v8-users mailing list [email protected] http://groups.google.com/group/v8-users
