Performance Audit 2017: Beacon: Review cookie access

[nicjansma]

Boomerang and its plugins are getting/setting the page's cookie several times during the onload beacon preparation.

In most browsers, getting and setting the cookie is a possibly-slow operation, since it often involves reading or writing state to the disk.

RT alone calls getCookie 6 times during the load beacon preparation:

We should investigate if all of these gets/sets are necessary and combine/eliminate any extraneous ones.

[nicjansma]

This has been fixed in the Akamai fork and will be backported soon.

[aaarichter]

This has been fixed in the Akamai fork and will be backported soon.

@nicjansma Do you know when this is back-ported into this repo?

[nicjansma]

There are two things we've optimized for cookies: the size, and how often we're getting/setting.

The size improvements are already available in 8eea1d7

We've also improved the number of reads/writes we do in Boomerang, and this will be backported here within a few weeks.

[mc-chaos]

There are two things we've optimized for cookies: the size, and how often we're getting/setting.

The size improvements are already available in 8eea1d7

We've also improved the number of reads/writes we do in Boomerang, and this will be backported here within a few weeks.

How this work is in going?

[nicjansma]

Should be included in the latest backport:

#285

5529ec2

[nicjansma]

Commit message:

As part of the 2017 Boomerang Performance Audit we found that Boomerang was reading/writing the Cookie multiple times during the page load, and the relevant functions were showing up frequently in CPU profiles:

These accesses don't take a ton of time, but on lower-class computers we see 2-5ms.

After adding some instrumentation, on a blank page for a new session, we count the following accesses:

Breakdown

• Cookie Gets: 21
• Cookie Sets: 8

Here's a breakdown per phase:

• BOOMR.init() (initial)
  • get 3x
    • RT.initFromCookie -> RT.getCookie -> getCookie
    • RT.initFromCookie -> updateCookie -> getCookie
    • RT.initFromCookie -> updateCookie -> setCookie -> getCookie
  • set 1x
    • RT.initFromCookie -> updateCookie -> setCookie: writes the initial cookie with dm si sl ss tt and z:

                dm: "boomerang-test.local"
                si: "7g4ui46ntd5"
                sl: "0"
                ss: "jq8fiv2c"
                tt: "0"
                z: 1

• BOOMR.init() (from config.json)
  • get 3x
    • RT.initFromCookie -> RT.getCookie -> getCookie
    • RT.initFromCookie -> updateCookie -> getCookie
    • RT.initFromCookie -> updateCookie -> setCookie -> getCookie
  • set 1x
    • RT.initFromCookie -> updateCookie -> setCookie: adds the bcn:

                bcn: "/beacon" (NEW)
                dm: "boomerang-test.local"
                si: "7g4ui46ntd5"
                sl: "0"
                ss: "jq8fiv2c"
                tt: "0"
                z: 1

• page_ready (load)
  • get 10x
    • RT.done -> setPageLoadTimers -> RT.initFromCookie -> RT.getCookie -> getCookie
    • RT.done -> setPageLoadTimers -> RT.initFromCookie -> updateCookie -> getCookie
    • RT.done -> setPageLoadTimers -> RT.initFromCookie -> updateCookie -> setCookie -> getCookie
    • RT.done -> refreshSession -> getCookie -> getCookie
    • RT.done -> maybeResetSession -> updateCookie -> getCookie
    • RT.done -> maybeResetSession -> updateCookie -> setCookie -> getCookie
    • RT.done -> from setting ld -> updateCookie -> getCookie
    • RT.done -> from setting ld -> updateCookie -> setCookie -> getCookie
    • RT.done -> from random updateCookie -> updateCookie -> getCookie
    • RT.done -> from random updateCookie -> updateCookie -> setCookie -> getCookie
  • set 4x
    • RT.done -> setPageLoadTimers -> initFromCookie: doesn't change anything
    • RT.done: Doesn't change anything
    • RT.done -> maybeResetSession: updates the ss Session Start to something slightly higher

                bcn: "/beacon
                dm: "boomerang-test.local"
                si: "7g4ui46ntd5"
                sl: "0"
                ss: jq8fiqrg (UPDATED)
                tt: "0"
                z: 1

    * `RT.done`: Updates `ld` time, `tt` and `sl`:

                bcn: "/beacon
                dm: "boomerang-test.local"
                si: "7g4ui46ntd5"
                sl: "1" (UPDATED)
                ss: jq8fiqrg
                tt: "4pgx" (UPDATED)
                z: 1
                ld: "aolp" (NEW)

• unload
  • get 5x
    • RT.done -> refreshSession -> getCookie -> getCookie
    • RT.done -> from random updateCookie -> updateCookie -> getCookie
    • RT.done -> from random updateCookie -> updateCookie -> setCookie -> getCookie
    • RT.done -> from setting ul -> updateCookie -> getCookie
    • RT.done -> from setting ul -> updateCookie -> setCookie -> getCookie
  • set 2x
    • RT.done: doesn't change anything
    • RT.page_unload: Sets ul or hd

                bcn: "/beacon
                dm: "boomerang-test.local"
                si: "7g4ui46ntd5"
                sl: "1"
                ss: jq8fiqrg
                tt: "4pgx"
                z: 1
                ld: "aolp"
                hd: "g9p1" (NEW)

There's a lot of inefficiencies from the above access patterns.

Changes

The following changes were made:

1. The Cookie Set from page_ready in RT.maybeResetSession() was because of a check for BOOMR.session.start > t_start.

BOOMR.session.start was initialized to "now" when Boomerang starts up, but t_start is the NavTiming navigationStart. We could easily change BOOMR.session.start to the same navigationStart time by default, if it exists, saving a Cookie Set just to update ss.

This change removes a Cookie Set and 2 Cookie Gets (because each Set also does 2x Gets). We're now at:

• Cookie Gets: 19
• Cookie Sets: 7

2. Instead of constantly re-reading document.cookie to re-read the same RT cookie repeatedly, we can cache the last known values of our cookies, and just return those values. We'll also update the value anytime we Set the cookie.

This reduces Gets dramatically:

• Cookie Gets: 8
• Cookie Sets: 7

We still have 8 Gets because setCookie forces a Get:

3. setCookie would also call getCookie immediately afterwards to ensure the cookie was set (and cookies weren't disabled).

I don't think we need to do this for every setCookie. If setting cookies succeeds once, we can probably expect it to always succeed. We also don't take any meaningful action if it fails.

This reduces Gets again:

• Cookie Gets: 2
• Cookie Sets: 7

4. Since the value of the cookie is now cached, we don't need to Set it if there's no change.

We're now left with the only 4 times we update the cookie:

• Cookie Gets: 2
• Cookie Sets: 4

Final

We've reduced the 21 Gets to 2, and 8 Sets to 4:

Gets

1. Initial read of the cookie
2. The first time we call setCookie we double-check it was set

Sets

1. init: Writing initial cookie values dm si sl ss tt and z
2. config: Adding bcn
3. page_ready: Adding sl tt ld
4. unload: Adding hd