{"id":2601,"date":"2012-06-25T16:48:24","date_gmt":"2012-06-25T14:48:24","guid":{"rendered":"http:\/\/glandium.org\/blog\/?p=2601"},"modified":"2019-09-03T15:30:35","modified_gmt":"2019-09-03T06:30:35","slug":"the-tale-of-a-weird-crash-and-a-2-5-year-old-bug","status":"publish","type":"post","link":"https:\/\/glandium.org\/blog\/?p=2601","title":{"rendered":"The tale of a weird crash, and a 2.5 year-old bug"},"content":{"rendered":"

10 days ago, I landed bug 616262<\/a>, and Windows Mochitest-Other immediately turned perma-orange on an a11y test<\/a>, in the form of a crash. It hadn't happened when I was testing the patch queue on Try, nor did it happen on PGO and debug builds on mozilla-central.<\/p>\n

That looked like a good candidate for a compiler bug.<\/p>\n

The first thing I tried to do is to find what particular change had made it orange, since it was green on my earlier attempts on Try. After some bisecting through Try pushes over the week-end, it turned out the changeset immediately after the one I had based my attempts on Try on was turning the test crashy. Unfortunately, it was a merge changeset, so I had to check the merged branch. After some more bisecting, it turned out that only four<\/em> consecutive changesets were making the test non<\/em>-crashy, and the one I had been using was the last one of them. Moreover, none<\/a> of them<\/a> was a11y<\/a>-related<\/a>.<\/p>\n

That looked like a good candidate for a compiler bug.<\/p>\n

Since I was at a dead-end trying to find some changeset that triggered the crash, and since using Try was already a slow process, I went ahead trying to reproduce locally... which didn't happen. I never upgraded MSVC on my Windows install, so I was still using 2005, while our build slaves now use 2010. So I upgraded MSVC to 2010, and finally was able to reproduce locally.<\/p>\n

That looked like a good candidate for a MSVC 2010 bug.<\/p>\n

The stack trace that MSVC was giving me when the crash was occurring was not very useful. The crash was supposedly happening in nsTSubstring_CharT::SetCapacity<\/code><\/a>, called from Accessible::GetARIAName<\/code><\/a>. Sometimes it would happen in arena_malloc<\/code><\/a>, called from the same Accessible::GetARIAName<\/code><\/a>. Unfortunately, the stack trace wasn't going higher, which suggested stack corruption.<\/p>\n

Because an unoptimized build would not crash and because optimizations were making things hard to poke from within the debugger, I added some printf<\/code>s in Accessible::GetARIAName<\/code><\/a>. It didn't crash anymore.<\/p>\n

That really looked like a good candidate for a MSVC 2010 bug.<\/p>\n

Since the function was called a whole lot before actually crashing, I needed to determine what code in Accessible::GetARIAName<\/code><\/a> was being reached before the crash. One of the things I tested was this patch:<\/p>\n

\n
--- a\/accessible\/src\/generic\/Accessible.cpp\r\n+++ b\/accessible\/src\/generic\/Accessible.cpp\r\n@@ -2429,6 +2429,8 @@ Accessible::GetARIAName(nsAString& aName\r\n   if (NS_SUCCEEDED(rv)) {\r\n     label.CompressWhitespace();\r\n     aName = label;\r\n+  } else {\r\n+    MOZ_CRASH();\r\n   }\r\n \r\n   if (label.IsEmpty() &&\r\n<\/pre>\n<\/blockquote>\n
For those not familiar with Mozilla codebase, MOZ_CRASH<\/code>, as its name suggests, triggers a crash. So if the else<\/code> part is ever reached, the build would crash. It turns out it did... not. At all.<\/p>\n
Comparing at assembly level, the functions with and without the patch above were strictly identical, except that one specific jump would go to the crashing code instead of going to the rest of the function. The crashing code wasn't even added within the function, but at the end.<\/p>\n
At this point, I was pretty certain that the problem was, in fact, not<\/em> in the function where the crash was occurring. The base observation was that adding code may un-trigger the crash, suggesting something weird happening depending on where some function appearing after Accessible::GetARIAName<\/code><\/a> is located in the binary. Sure enough, reordering the source files in accessible\/src\/generic<\/code> made the crash disappear with an unmodified Accessible::GetARIAName<\/code><\/a>.<\/p>\n
So, after validating that adding a small function after an unmodified Accessible::GetARIAName<\/code><\/a> was not triggering the crash, I went on to find the last place where adding the function would not stop triggering the crash. Which I found to be that spot<\/a>. With a dummy function before DocAccessible::ContentRemoved<\/code>, the crash wouldn't occur, and with the same dummy function after, it would. But DocAccessible::ContentRemoved<\/code> is empty, how can adding a function before or after make a difference?!?<\/p>\n
Since these DocAccessible<\/code> functions are good candidates for Identical Code Folding<\/a>, I tried disabling it, and it surely did make things worse: the addition of the dummy function stopped \"fixing\" the crash.<\/p>\n
That really looked like a good candidate for something that was going to be near impossible to debug.<\/p>\n
At this point, I really wished I had a more reliable stack trace, and with fingers crossed (since so many factors were, in fact, \"fixing\" the crash), I tried again with frame pointers enabled. And fortunately, the crash was still happening. After some self-punishment for not having tried that earlier, I finally got a more meaningful stack trace showing the Accessible::GetARIAName<\/code><\/a> (indirectly) coming from nsTextEquivUtils::AppendFromAccessible<\/code><\/a>, itself being called from nsTextEquivUtils::AppendFromAccessibleChildren<\/code><\/a>, itself called from nsTextEquivUtils::AppendFromAccessible<\/code><\/a>.<\/p>\n
Fortunately, the place indirectly calling Accessible::GetARIAName<\/code><\/a> was reached much less often than Accessible::GetARIAName<\/code><\/a>, so it was possible to use a breakpoint there<\/a>, continue until the n<\/em>th time, and then step until Accessible::GetARIAName<\/code><\/a>. Finally I knew where and why the crash was happening: really in Accessible::GetARIAName<\/code><\/a>, because mContent<\/code> was NULL.<\/p>\n
Obviously, when the crash doesn't happen, mContent<\/code> is never NULL. After some fiddling with both builds with the crash and builds without, I found that nsTextEquivUtils::AppendFromAccessible<\/code><\/a> was never called for an Accessible with a NULL mContent<\/code> when the crash doesn't occur. Which makes sense, but makes the problem upper in the stack.<\/p>\n
After more fiddling, and finding out that both crashing and non-crashing builds were initializing a nsHTMLWin32ObjectAccessible<\/a> with a NULL mContent<\/code>, I had to find why either the Accessible's mContent<\/code> value changed in one case and not the other, or why nsTextEquivUtils::AppendFromAccessible<\/code><\/a> was called for that nsHTMLWin32ObjectAccessible<\/code> in one case and not the other.<\/p>\n
And in the end, it turned out the difference was that the gRoleToNameRulesMap<\/code><\/a> value for nsHTMLWin32ObjectAccessible<\/code>'s Role was wrong in one case and not the other, making nsTextEquivUtils::AppendFromAccessible<\/code> being called<\/a> or not.<\/p>\n
So the root cause of all this nightmarish chase was that nsHTMLWin32ObjectAccessible<\/code>'s Role is ROLE_EMBEDDED_OBJECT<\/a>, and that the gRoleToNameRulesMap<\/code><\/a> array stopped at ROLE_GRID_CELL<\/a> (which happens to be ROLE_EMBEDDED_OBJECT - 1<\/a>).<\/p>\n
The changeset that added ROLE_EMBEDDED_OBJECT<\/a> but forgot to add the corresponding gRoleToNameRulesMap<\/code><\/a> entry is 2.5 years old<\/a>, and other additional roles have been added since then.<\/p>\n
Conclusion, the problem was not the compiler doing something broken, but it was the linker laying things out differently in some cases, leading to different values returned when reading past gRoleToNameRulesMap<\/code><\/a>, depending on what the linker put there.<\/p>\n
It looks like we've been pretty (un?)lucky not to have been hit by this earlier. It's now fixed on all branches, and bug 616262 landed again, with a pretty green Windows Mochitest-Other.<\/p>\n
As of writing, I still don't know why the stack trace was truncated in the first place, since the stack was, in fact, not corrupted. I think I don't care anymore.<\/p>\n","protected":false},"excerpt":{"rendered":"
10 days ago, I landed bug 616262, and Windows Mochitest-Other immediately turned perma-orange on an a11y test, in the form of a crash. It hadn’t happened when I was testing the patch queue on Try, nor did it happen on PGO and debug builds on mozilla-central. That looked like a good candidate for a compiler […]<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"closed","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[25],"tags":[23],"class_list":["post-2601","post","type-post","status-publish","format-standard","hentry","category-planet-mozilla","tag-en"],"_links":{"self":[{"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=\/wp\/v2\/posts\/2601","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=2601"}],"version-history":[{"count":34,"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=\/wp\/v2\/posts\/2601\/revisions"}],"predecessor-version":[{"id":2636,"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=\/wp\/v2\/posts\/2601\/revisions\/2636"}],"wp:attachment":[{"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=2601"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=2601"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/glandium.org\/blog\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=2601"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}