awe247

[awe247]

Diagnosing performance issues in Chromium browsers

Recently we had complaints from a customer that our forms were taking an unusually long time to load and in many cases caused Chrome to report that the page was "unresponsive". Initially reproducing the problem in our environment was tricky which hindered out efforts to diagnose it. The customer's environment was also heavily restricted. The first port of call is always to open "Developer tools" (F12) and examine the network traffic or console logs but in this case there was nothing obviously wrong. The first idea was to ask the customer to clear out their "Local storage" (Dev Tools > Application > Local Storage) in case, somehow, a bad form structure had been cached and was now causing our scripts in to a tight loop. However, the issue remained and we had to dig deeper.

Chrome Performance Tab

How to Analyze Runtime Performance: Google DevTools

Since we were still having trouble reproducing the issue we asked the customer to access the Peformance tab in Developer tools and attempt to reproduce the issue as they profiled it (Ctrl+Shift+E to reload and record). They could then export the result by right-clicking the results and selecting "Save profile...". We received enough traces from the customer to see that there was an obvious problem, manifesting as a large gap where it seems like there was no obvious activity occurring at all. Normally if our product has initiated the problem, it would be visible as high script activity, or large amounts of CSS animation or even an open network request. Even though we were witnessing a fair amount of "Layout Shift" and also some warnings about long tasks, it was the big gap of seemingly no activity which was more concerning. The trace includes screen shots and it's clear to see that where the user was witnessing the browser lock up was at the beginning of this gap. Even when we asked for more details from the trace in the Chrome settings (i.e. Advanced paint instrumentation and (under Experiments) Timeline: show all events, Timeline: event initiators and Timeline: V8 Runtime Call Stats on Timeline this area remained unpopulated.

Chrome Tracing

Chrome Tracing for Fun and Profit

We were still not seeing something so we moved deeper. Enter chrome://tracing/. This is another way to run a performance trace in Chrome but it offers more detail, customisation and purpose built out-of-the-box traces. (Chrome has a lot of tools available in this manner. You can see a listing of them if you browse to chrome://chrome-urls/). We asked the customer for more traces and (for good measure) done with varying profiles that are presented when beginning the trace. We were particular interested in seeing the "Chrome developer (overall)" and "Rending" output. Again, the customer obliged but it was actually the "Web developer" trace that seemed to best show where time was being spent.

This kind of long running task, inside the main rendering loop, suggested Chromium was getting caught up either on constructing or handling inter-process communication to do with the accessibility tree. Clicking on the little magnifying class will also take you to the relevant piece of code in the Chromium source, so I could find that function and see that it looked like it indeed had to do with event processing.

https://source.chromium.org/chromium/chromium/src/+/main:content/renderer/accessibility/render_accessibility_impl.cc;l=663

The high CPU was also something we could use to highlight where this hang was taking place. With SysInternals Suite's Process Explorer (Chrome has a built-in Task Manager (Ctrl+Esc) but, again, it's pretty high level), once we were able to reproduce the issue locally, we could see that there was a particular instance of chrome.exe that was going to high CPU during the hang. Inspecting this process gave us information that it was launched with the following arguments....

"C:\Program Files (x86)\Google\Chrome\Application\chrome.exe" --type=renderer --field-trial-handle=1680,15553868430398110585,11130752057137292634,131072 --lang=en-GB --origin-trial-disabled-features=SecurePaymentConfirmation --device-scale-factor=1 --num-raster-threads=4 --enable-main-frame-before-activation --renderer-client-id=17137 --no-v8-untrusted-c

...which, again, pointed the finger squarely at the renderer. Suspending the process in Process Explorer we were able to do a full dump of the process at that time and examine it with WinDbg* (actually, inspecting with Process Explorer would have given the same information in a more friendly manner, but I didn't know that at the time) and looking closer at what threads are active showed that one in particular had a call stack...

# Child-SP          RetAddr           Call Site 00 0000004b`1f9ff2a8 00007fff`9e40bba3 ntdll!NtRemoveIoCompletion+0x14 01 0000004b`1f9ff2b0 00007fff`45371476 KERNELBASE!GetQueuedCompletionStatus+0x53 02 0000004b`1f9ff310 00007fff`45371392 chrome!GetHandleVerifier+0x1199196 03 0000004b`1f9ff450 00007fff`4537129f chrome!GetHandleVerifier+0x11990b2 04 0000004b`1f9ff4b0 00007fff`425aa151 chrome!GetHandleVerifier+0x1198fbf 05 0000004b`1f9ff540 00007fff`42fde87c chrome!Ordinal0+0x4a151 06 0000004b`1f9ff590 00007fff`431eec48 chrome!ChromeMain+0x6376c 07 0000004b`1f9ff5f0 00007fff`431ee9d4 chrome!ChromeMain+0x273b38 08 0000004b`1f9ff740 00007fff`431ee808 chrome!ChromeMain+0x2738c4 09 0000004b`1f9ff7a0 00007fff`42d44c9f chrome!ChromeMain+0x2736f8 0a 0000004b`1f9ff830 00007fff`a1db7974 chrome!IsSandboxedProcess+0x34447f 0b 0000004b`1f9ff8b0 00007fff`a1f1a2f1 kernel32!BaseThreadInitThunk+0x14 0c 0000004b`1f9ff8e0 00000000`00000000 ntdll!RtlUserThreadStart+0x21

...which suggested it was waiting for some sort of event processing to complete. It could have been possible to build a debug version of Chrome to either break into what the process was doing or to add more logging, however, we were satisfied that it was a Chromium renderer issue at this point and investigate further was probably not a good investment of our time.

WinDbg* WinDbg is available in the Windows 10 SDK. If Visual Studio 2019 is present, it can also be installed through that.

https://docs.microsoft.com/en-us/windows-hardware/drivers/debugger/debugger-download-tools

https://docs.microsoft.com/en-us/windows-hardware/drivers/debugger/opening-a-crash-dump-file-using-windbg

https://docs.microsoft.com/en-us/windows-hardware/drivers/debugger/calls-window

Conclusion

While we had been able to reproduce we tested the form via a process of elimination (yes, brute force), removing and moving controls around to see if it had any effect. We were able to determine that the problem was most evident if there were initial tabs visible on first load that contained one or more form controls (i.e. non-empty and non-grid). It didn't seem to be any type of control in particular that caused the problem. Any series of basic form controls would do it. With this in mind, we could think in terms of mitigation and providing the customer with a workaround while this Chrome issue was in play, by delaying the visibility of tab contents until after the greater browser window had completed it's layout activity. The hope was that by staggering the presentation of parts of the window, that the renderer would have a simpler time of it and we would reduce the amount of IPC generated.

Other Things

These are some other things we tried which didn't lead anywhere, but maybe useful when pursuing future issues:

The customer had complained that the issue also occurred on Edge (which initially discouraged thoughts that it could be a Chrome problem, until someone here mentioned that Edge is now built on Chromium🙄)

When we started to suspect that processing around accessibility was at fault, we wanted to see if running without it made any difference for the customer. This is possible to do from chrome://accessibility/ and/or running Chrome with the command line flag, --disable-renderer-accessibility. I believed this required all chrome processes to be restarted and also wasn't going to be a solution for the customer. It was simply done in hopes of isolating where Chrome was having the problem.

We tried Chrome's Incognito Mode to reproduce the problem. This would have given us an idea that perhaps the customer had a plugin or extension that was behind the problem

The customer sent through network activity logs initially (simply because they are used to these sorts of problems occurring) and HAR (http archive) files can be viewed easily at http://www.softwareishard.com/har/viewer/

We tried running Chrome with verbose logging enable. The customer was able to output the logs to a file, but it was easier to visualise them with Sawbuck in real-time as the problem was occurring (it showed that no logs were being output during the hang).

[awe247]

So, trivia at The Carrington for a change. I had to venture deeper into Surry Hills then I ever have had to before. It’s closer to the Brett Whiteley Studio but despite living in Surry Hills once upon a time, I had never been.

The pub seems fine. Trivia takes place at the back in the dining area where they also allow people to bring their dogs. Apropos of nothing, there was an odd moment where I recognised the lady walking into the bar ahead of me as Tony Abbott’s sister. The menu looks good but is pricey af and I’m a bit light on funds right now so didn’t partake. It worked out though because I happened to pass a Little Caesars.

Host was Hannah Conda (yes, to your question) who was also fine. Kept the game moving well although padded it with anecdotes and such. There was a paper plane contest in the middle of round 2 which I swear I would have won... had I not hit the disco ball hanging in the middle of the room.

We came equal third/second in the end and lost out in a tense game of Rock, Paper, Scissors.

[awe247]

Filed under: “reasons I will be mostly broke this year”

[awe247]

australian gothic

- we all refer to the prime minister by their first name. we know them well, and they know us. all of us.

- there’s a man on the street corner who never leaves. “just waiting for a mate,” he says. you realise he is on every corner, of every street.

- you are swooped by a magpie in the same place, at the same time, every single day. “it’s swooping season!” says your neighbour. it has always been swooping season.

- sometimes you hear a woman whispering late at night - or early in the morning. “rage” she hisses. “rage”.

- the prime minister never seems to last long and often disappears through no discernible democratic process. one of them eats a raw onion in an attempt to assimilate. he is gone by morning, replaced by another.

[awe247]

I arrived first at our reserved table for tonight's trivia and let the team know, on WhatsApp, that we were sitting up the back again near the screens that are permanently tuned to the races at the Strawb. Neil jokingly (or so I had thought) asked me to put a fiver on number 4 in the next race. Turns out that Regal Bill went on to win that race at Albion Park which would have netted Neil a nifty $34 had I actually placed the bet. Because of course that would happen.

There weren't many teams present on this occasion. Even the staff were letting us know we were in with a chance. We certainly seemed to be nailing a good share of the correct answers and were equal first at the half way point. As a team of four old blokes in the end we were only bested by the team of four even older blokes, which may just have been our future selves time-travelling back for a trivia night. I didn't want to approach them lest the same matter occupy the same space and collapse existence. In any case, The Devil Hates Kung-Fu got $30 for a second place and we added a drinks voucher to that when I clued in to a "Who Am I?" simply because I knew Chris Hemsworth had been on Home & Away and also married a Spanish chick.

They cook the rump steaks nicely here and I was happy with my upgrade to sweet potato chips, but I let myself down by picking the red wine jus for the sauce. We weren't wanting for topics of conversation either. But I guess that's bound to happen when trivia night's run 3 months apart and Trump is in office.

[awe247]

I had cause to be in the city late for work and so thought it might be possible to rally The Devil Hates Kung-Fu to salvage my day. Bruce and Neil were able to answer the call and with a multitude of venues to choose from for Trivia on a Tuesday night we elected to try The Wild Rover. A self-proclaimed "Irish folk barn crossed with New York chic" and a touch of Sydney urban wankery thrown in for good measure. Their menu wasn't particularly exciting but this is probably because they put more focus on their whisky selection. However, they get major cool points for hiding themselves away in an old shirt shop in Surry Hills with no external branding other then a door lit with a green light. The place was pretty packed so it was definitely a good idea to book a table.

The host noticed me sitting by myself and made it known that Trivia at The Wild Rover isn't taken too seriously. Also adding that at the end of the night teams are able to wager any or all of their accrued points on the final question which is an interesting twist but put me in the mind of those shows like Good News Week or Have You Been Paying Attention? where nothing really matters. Later on Neil would repeatedly echo this sentiment throughout the night seemingly mired in nihilism (or Neil-ism as Bruce pronounced it).

We didn't perform badly as such. We only really dropped a few questions here and there and a perfect score was had on the Famous Faces sheet. In fact we were never out of reach of first place but it's just one of those places where the standard appears to be pretty high. Even after going all in with our total of 50 points on the final question and coming up with the correct answer of Pangaea, it still wasn't enough to pull a win out of the hat. Not a bad night in the end but we might stick with Wednesdays in future.

Here we are last night reppin for the DHKF.

[awe247]

Not the greatest outing The Devil Hates Kung-Fu has ever had. So close to most of the answers but seeming to settle on the wrong choice in the end.

The Strawb was fully booked for tables so Pete got there early and grabbed a free one by the betting screens. It was a little far away from the host (who got pretty surly if you wanted to ask him for any clarification) and we only had one chap come up to yell at his horse on the monitor, but it suited us fine. If anything we were having too good a time and had to be hushed by the table of fourteen next to us. We were second at the break behind that team but managed to falter to fourth in the final leg.

As always we came undone at the music and sports questions but the multi-point questions hit particularly hard this week. We agonized and strained to recall George Ezra's last name and it turned out the song was sung by Hozier. That about sums up our game.

I'm kind of over the menu here. It's standard pub fair, not too exe and it tastes fine but there's not much to get excited about.

Maybe it's time to try another venue and another night again? Next time.

[awe247]

YES!!! God, even just as a cubby house for the kids. So much yes.

[awe247]

i shirt myself

[awe247]

Another fine trivia start to a new year, kicking it off in January at the Strawb, with a full compliment of Fu-ers and a convincing win on 59 points.

There seemed to be a lot of geography questions this time. One exception and a point of contention was the two highest selling mononymous, male singers of all time. Prince was one without a doubt but it came down to a vote between Sting and Eminem for the second. Democracy let us down, as it has all of us in recent memory, with Pete casting the deciding vote for Sting.

We were also two years shy of the jackpot, electing 1950 as the year that the schooner was introduced as the standard unit of measure for drinks in New South Wales.

Maybe we can get out a few more times this year? Our name doesn't seem to ring out as loud or as often. In fact, the host proclaimed victory for The Devil Hats Kung-Fu! I was sure I wrote it down correctly.

[awe247]

Six-months since the last outing and The Devil Hates Kung-Fu has returned to the Strawberry Hills Hotel with Trivia fire. Crushed it. Completely owned the night with 67 points all up. As usual there were a couple of multi-point questions in the mix but this time the full 7 or 8 points came our way for each of them. Quite a bit of time was spent mulling over one-word countries that contain a 'y' in the middle of their names (not at the start or end though).

I even made a contribution to the music questions which are normally best left to others, picking out My Chemical Romance's hit and recognizing Sia's voice if not the song itself. Then we made a few educated guesses like that the Dalai Lama made an appearance on Masterchef this year (and not Australia's Next Top Model like I had hoped). We even ended up only being one year out from the jackpot year, which would have netted us a nifty $50 pot, deciding on 1972 for when the PRC was added to the UN.

I had the Angus Beef Burger which was fine, but I do miss the cheapy meals.

[awe247]

Patient Gamer Entry #2

Well, I now consider Borderlands (the original) to be moved to the “Complete” column. In fact, I think every drop of enjoyment was completely extracted out of the main story missions and DLC. Last night, Crawmerax was dealt with and I consider that to have been the ultimate challenge from this game. The cliff glitch was made use of, but because karma happened, Crawmerax dropped most of his loot over said cliff when he died. 

Here’s how Brick ended up...

Having played semi-regularly with three other people every Tuesday night since late 2014 to get this done, I’m feeling like there’s going to be a great big hole in my week. Lucky I’m patient enough for Borderlands 2.

[awe247]

The world breaks everyone and afterward many are strong in the broken places. But those that will not break it kills. It kills the very good and the very gentle and the very brave impartially. If you are none of these you can be sure it will kill you too but there will be no special hurry.

Ernest Hemingway, A Farewell to Arms, 1929

[awe247]

Grow Park

Got it on the second try! Well, it was bound to happen one day.

[awe247]

First time for trivia at the Norfolk Hotel in Surry Hills. I was pretty excited by the promised $12 Southern Fried Steaks and this joint is right next door to an eatery called the House of Crabs which I will be returning to try at some point.

We didn’t have the best lead-in, failing to come up with a team name that was “less convincing than Johnny Depp and Amber Heard’s video apology to Australia” and ended up sticking with the tried and true. Much to the hosts chagrin.

The trivia itself is pretty fun and is peppered with a few oddball questions and bonus rounds. Guessing the song that was being beat-boxed is the one that sticks in my mind. I almost had the celebrity behind the nachos but could only recall that he was Jon Snow. I always seem to forget the actors names from Game of Thrones. In any case, it opens many things up when you have screens around the bar to do these kinds of questions on. It was pretty refreshing and the host was like-able as well as keeping the pace up so we were wrapped up by 9:30 pretty much.

Kudos to Pete for getting Gone With The Wind in the Cinema Dyslexia question in the end. I had got as far as Thee Night Window. Its my wife who is gifted with solving anagrams.

[awe247]

I don't fear the man who knows something, I fear the man who knows something that's wrong.

Not Abraham Lincoln (via The Philip DeFranco Show)

[awe247]

Trivia accounts opened for yet another year. Where else but the Strawb. This place got pricey with their food but damn if that wasn't a delicious lamb burger. 

Bruce got the Who-Am-I question with Sinead O'Connor. Good thing too because our rounds were mediocre at best. My contribution of Piers Morgan as an answer to top 50 earners with initials PM was rejected. Good thing too because it was Dr. Phil McGraw.