Bug 1722722 Comment 17 Edit History

Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.

I believe I am experiencing this same issue, or something very similar. Playing videos doesn't appear to trigger the issue for me, so let me know if I should file a separate bug instead. I haven't quite worked out the reproduction steps yet, so I'll just describe what I've found so far.

I have a large default profile, with ~500 tabs and ~30 windows. I am testing with Firefox Nightly 2021-08-23.

## Just after startup

After initially starting Firefox and letting everything settle in, we reach a baseline of about 20% CPU use by Firefox and 20% CPU use by WindowServer. A profile from this time looks like https://share.firefox.dev/3Dkl1xp. 1% of parent process time is spent in `CA::Transaction::commit`. Overall, for driving so many windows, it seems pretty good. Ideally there would be no work to do at all, but that might be hard to achieve.

With the extra logging variables, Console shows logs like the following during this period:

```
default	21:13:31.678719+0100	firefox	CoreAnimation buffers: currently 1.51MB; maximum 1.78MB
default	21:13:31.920274+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.920401+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:31.938102+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.938201+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:31.954158+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.954245+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:31.971332+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.971421+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:31.988420+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.988609+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.004873+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.004964+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.021219+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.021332+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.037694+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.037796+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.421138+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.421240+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.437308+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.437403+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.454508+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.454613+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.469820+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.469940+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.488042+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.488110+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.503458+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.503514+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.521563+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.521625+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.536833+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.536885+0100	firefox	Transaction (0x12f981000) property contents changed
```

There appear to be 60 CA transactions / sec, so perhaps that's tied to the monitor refresh rate...?

## Later in the day

Then, "after a while" of use (one day later, same session, no restarts, no clear trigger), the steady state has risen to more like 50% CPU use by Firefox and 50% CPU use by WindowServer. A profile from this time looks like https://share.firefox.dev/2WmdMnw. `CA::Transaction::commit` has grown from 1% parent process time in the previous profile to 8% in this one. 

The Console logs seem basically the same as before:

```
default	15:15:42.819247+0100	firefox	CoreAnimation buffers: currently 2.73MB; maximum 66.2MB
default	15:15:42.906346+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.906419+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.922127+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.922187+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.941709+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.941776+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.960844+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.960903+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.977971+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.978038+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.995711+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.995779+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:43.011955+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:43.012042+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:43.029365+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:43.029427+0100	firefox	Transaction (0x12f981000) property contents changed
```

The internal CA buffer size is a bit larger than before, but also doesn't seem to be leaking or anything like that.
I believe I am experiencing this same issue, or something very similar. Playing videos doesn't appear to trigger the issue for me, so let me know if I should file a separate bug instead. I haven't quite worked out the reproduction steps yet, so I'll just describe what I've found so far.

I have a large default profile, with ~500 tabs and ~30 windows. I am testing with Firefox Nightly 2021-08-23.

## Just after startup

After initially starting Firefox and letting everything settle in, we reach a baseline of about 20% CPU use by Firefox and 20% CPU use by WindowServer. A profile from this time looks like https://share.firefox.dev/3Dkl1xp. 1% of parent process time is spent in `CA::Transaction::commit`. Overall, for driving so many windows, it seems pretty good. Ideally there would be no work to do at all, but that might be hard to achieve.

With the extra logging variables, Console shows logs like the following during this period:

```
default	21:13:31.678719+0100	firefox	CoreAnimation buffers: currently 1.51MB; maximum 1.78MB
default	21:13:31.920274+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.920401+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:31.938102+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.938201+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:31.954158+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.954245+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:31.971332+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.971421+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:31.988420+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:31.988609+0100	firefox	Transaction (0x12f981000) property contents changed
default	21:13:32.004873+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	21:13:32.004964+0100	firefox	Transaction (0x12f981000) property contents changed
```

There appear to be 60 CA transactions / sec, so perhaps that's tied to the monitor refresh rate...?

## Later in the day

Then, "after a while" of use (one day later, same session, no restarts, no clear trigger), the steady state has risen to more like 50% CPU use by Firefox and 50% CPU use by WindowServer. A profile from this time looks like https://share.firefox.dev/2WmdMnw. `CA::Transaction::commit` has grown from 1% parent process time in the previous profile to 8% in this one. 

The Console logs seem basically the same as before:

```
default	15:15:42.819247+0100	firefox	CoreAnimation buffers: currently 2.73MB; maximum 66.2MB
default	15:15:42.906346+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.906419+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.922127+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.922187+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.941709+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.941776+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.960844+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.960903+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.977971+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.978038+0100	firefox	Transaction (0x12f981000) property contents changed
default	15:15:42.995711+0100	firefox	Began transaction (0x12f981000) change on layer 0x7fa8f1a278b0 for contents, 0x0
default	15:15:42.995779+0100	firefox	Transaction (0x12f981000) property contents changed
```

The internal CA buffer size is a bit larger than before, but also doesn't seem to be leaking or anything like that.

Back to Bug 1722722 Comment 17