Hi Vyacheslav, Yeah, as I said I ran with trace-opt, trace-bailout and trace-deopt turned on. So 'disabled optimization for' doesn't mean the function is deoptimized? That's really surprising to me, because I see a performance hit for those functions, and I assume that optimization being turned off would mean that the functions would have to run using unoptimized JIT output. That's not the case then? Does that mean that this error message doesn't matter, and it's intended that these functions keep getting recompiled until they hit the limit?
It would be cool to know how to find out why the functions keep getting marked for recompilation, since the compiles seem to be taking time, but I guess that's less of an issue. Thanks, -kg On Tue, Nov 6, 2012 at 8:04 AM, Vyacheslav Egorov <[email protected]>wrote: > 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 > -- -kg -- v8-users mailing list [email protected] http://groups.google.com/group/v8-users
