Determining cause of deoptimisation

Question

First, the question:

How can I determine the cause of deoptimisation of my function?

For example, here is a deoptimisation entry for one of my functions:

[deoptimizing (DEOPT eager): begin 0x3ca09e9f4d1 mergeObjects (opt #50) @12, FP to SP delta: 96]
            ;;; jump table entry 8: deoptimization bailout 12.
  translating mergeObjects => node=43, height=64
    0x7fff5fbfecd0: [top + 128] <- 0xcd290004121 ; [sp + 144] 0xcd290004121 <undefined>
    0x7fff5fbfecc8: [top + 120] <- 0x3ca09e9ca19 ; [sp + 136] 0x3ca09e9ca19 <an Object with map 0x4c8d818621>
    0x7fff5fbfecc0: [top + 112] <- 0x2c9b8b1b95a9 ; [sp + 128] 0x2c9b8b1b95a9 <an Object with map 0x7e33a207821>
    0x7fff5fbfecb8: [top + 104] <- 0x2c9b8b1b9229 ; rax 0x2c9b8b1b9229 <JS Array[0]>
    0x7fff5fbfecb0: [top + 96] <- 0xcd290004181 ; [sp + 112] 0xcd290004181 <false>
    0x7fff5fbfeca8: [top + 88] <- 0x2481f54fb4b6 ; caller's pc
    0x7fff5fbfeca0: [top + 80] <- 0x7fff5fbfed40 ; caller's fp
    0x7fff5fbfec98: [top + 72] <- 0x3ca09e8eae1; context
    0x7fff5fbfec90: [top + 64] <- 0x3ca09e9f4d1; function
    0x7fff5fbfec88: [top + 56] <- 0x70a69429aa1 ; [sp + 32] 0x70a69429aa1 <String[3]: key>
    0x7fff5fbfec80: [top + 48] <- 0xcd290004121 <undefined> ; literal
    0x7fff5fbfec78: [top + 40] <- 0xcd290004121 <undefined> ; literal
    0x7fff5fbfec70: [top + 32] <- 0x3ca09e9ca19 ; [sp + 136] 0x3ca09e9ca19 <an Object with map 0x4c8d818621>
    0x7fff5fbfec68: [top + 24] <- 0x4c8d818621 ; [sp + 64] 0x4c8d818621 <Map(elements=3)>
    0x7fff5fbfec60: [top + 16] <- 0x2c9b8b014341 ; [sp + 56] 0x2c9b8b014341 <FixedArray[3]>
    0x7fff5fbfec58: [top + 8] <- 0x300000000 ; [sp + 48] 3
    0x7fff5fbfec50: [top + 0] <- 0 ; [sp + 40] (smi)
[deoptimizing (eager): end 0x3ca09e9f4d1 mergeObjects @12 => node=43, pc=0x2481f54ecd00, state=NO_REGISTERS, alignment=no padding, took 0.060 ms]
[removing optimized code for: mergeObjects]

I suspect that the reason, albeit not very telling, is this:

jump table entry 8: deoptimization bailout 12.

Where can I find more information about this and other reasons for deoptimisation? And more importantly, how can I determine what part of my JS code caused this deoptimisation?

Here are some other deoptimisation reasons I see for other functions:

• deoptimize: Insufficient type feedback for generic named access
• deoptimize: Insufficient type feedback for RHS of binary operation
• jump table entry X: deoptimization bailout Y. - lots of these with different numbers

In layman's terms, I would like to be able to look at this log and say "Okay, my function got deoptimised because v8 predicted I will only use strings as its function parameter and here I called it with an integer" (or something similar).

I would also love to learn more about the other information I can see in these logs - for example, what do the various deoptimisations mean (eager, soft etc.)? What do the numbers in the first line mean? What else should be of interest to me in this log while improving performance?

If it is in any way relevant, the code being deoptimised in the log above is here and to generate the logs (by running the library's benchmark), execute in the project's root:

node --trace_deopt --code_comments bench

Answer 1

Petka Antonov (creator of bluebird) describes some optimization killers here. I don't know how to interpret your V8 output, but your code does contain a for-in loop, which can cause de-optimization under some conditions. For example, if the object being iterated is in hashtable mode. From the writeup:

An object will go into hash table mode for example when you add too many properties dynamically (outside constructor), delete properties, use properties that cannot be valid identifiers and so on. In other words, when you use an object as if it was a hash table, it will be turned into a hash table. Passing such an object to for-in is a no no. You can tell if an object is in hash table mode by calling console.log(%HasFastProperties(obj)) when the flag --allow-natives-syntax is enabled in Node.JS.

This level of V8 optimization definitely does seem like some sort of dark art :) Hope that helps!