Closed Bug 892606 Opened 12 years ago Closed 12 years ago

Intermittent test_keycodes.xul | Exited with code -1073741819 during test run | application crashed [@ mozilla::widget::VirtualKey::GetNativeUniChars(unsigned char)]

Categories

(Core :: Widget, defect)

Product:
Core
Component:
Widget
Platform:
x86
Windows 8
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla26
Tracking Flags:
Tracking Status
firefox24 --- unaffected
firefox25 + fixed
firefox26 + fixed

People

(Reporter: RyanVM, Assigned: masayuki)

Details

(Keywords: crash, intermittent-failure, regression)

Attachments

(4 files)

part.1 Add debug logs to KeyboardLayout.cpp
3.99 KB, patch
jimm
: review+
Details | Diff | Splinter Review
part.2 Fix scancode value in lParam generated by KeyboardLayout::SynthesizeNativeKeyEvent()
2.90 KB, patch
jimm
: review+
Details | Diff | Splinter Review
part.3 FakeCharMsg should be marked as consumed and only non-consumed char message should be synthesized
14.02 KB, patch
jimm
: review+
Details | Diff | Splinter Review
part.4 Don't handle non-keydown message as a part of dead key handling after keydown causes resetting dead key state
3.63 KB, patch
jimm
: review+
Details | Diff | Splinter Review
Masayuki, I can't help but notice that this happened on the push for bug 875674. Is it possible that this was caused by that? https://tbpl.mozilla.org/php/getParsedLog.php?id=25162872&tree=Mozilla-Inbound WINNT 6.2 mozilla-inbound debug test mochitest-other on 2013-07-11 02:17:04 PDT for push 86a041d63d65 slave: t-w864-ix-054 02:38:36 INFO - 50909 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_keycodes.xul | French keyCode=221 (0xDD) chars='', wrong keycode 02:38:36 INFO - 50910 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_keycodes.xul | French keyCode=221 (0xDD) chars='', wrong location 02:38:36 INFO - 50911 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_keycodes.xul | keycode is undefined 02:38:36 INFO - [Parent 2960] WARNING: Unknown key code comes, please check latest MSDN document, there may be some new keycodes we have not known.: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/widget/windows/KeyboardLayout.cpp, line 2057 02:38:37 INFO - WARNING: shutting down early because of crash!: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/dom/plugins/ipc/PluginModuleChild.cpp, line 703 02:38:37 INFO - WARNING: plugin process _exit()ing: file e:/builds/moz2_slave/m-in-w32-d-0000000000000000000/build/dom/plugins/ipc/PluginModuleChild.cpp, line 668 02:38:37 INFO - NPP_Destroy 02:38:37 INFO - NPP_Destroy 02:38:37 INFO - nsStringStats 02:38:37 INFO - => mAllocCount: 98 02:38:37 INFO - => mReallocCount: 1 02:38:37 INFO - => mFreeCount: 17 -- LEAKED 81 !!! 02:38:37 INFO - => mShareCount: 153 02:38:37 INFO - => mAdoptCount: 0 02:38:37 INFO - => mAdoptFreeCount: 0 02:38:37 WARNING - TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/widget/tests/test_keycodes.xul | Exited with code -1073741819 during test run 02:38:37 INFO - INFO | automation.py | Application ran for: 0:18:30.535000 02:38:37 INFO - INFO | zombiecheck | Reading PID log: c:\users\cltbld~1.t-w\appdata\local\temp\tmpddp1papidlog 02:38:37 INFO - ==> process 2960 launched child process 1784 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.1308d540.1038908931 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:37 INFO - ==> process 2960 launched child process 2312 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.15f10bf0.1437780737 -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" tab) 02:38:37 INFO - ==> process 2960 launched child process 2296 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.15ffd240.1498367386 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:37 INFO - ==> process 2960 launched child process 3940 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.15ffc4d0.1927607691 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:37 INFO - ==> process 2960 launched child process 3748 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.15fffa90.1215232263 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:37 INFO - ==> process 2960 launched child process 3104 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.160002a0.1461066567 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:37 INFO - ==> process 2960 launched child process 2988 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.15ffaf50.1932189351 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:37 INFO - ==> process 2960 launched child process 2224 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.16001d80.1564711947 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:37 INFO - ==> process 2960 launched child process 1320 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.16001ed8.2137159064 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:37 INFO - ==> process 2960 launched child process 836 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=2960.2098c160.900661566 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 2960 "\\.\pipe\gecko-crash-server-pipe.2960" plugin) 02:38:43 WARNING - PROCESS-CRASH | chrome://mochitests/content/chrome/widget/tests/test_keycodes.xul | application crashed [@ mozilla::widget::VirtualKey::GetNativeUniChars(unsigned char)] 02:38:43 INFO - Crash dump filename: c:\users\cltbld~1.t-w\appdata\local\temp\tmpoc2j1m\minidumps\601afb09-1273-42e2-9e0d-b17667a0b0a8.dmp 02:38:43 INFO - Operating system: Windows NT 02:38:43 INFO - 6.2.9200 02:38:43 INFO - CPU: x86 02:38:43 INFO - GenuineIntel family 6 model 30 stepping 5 02:38:43 INFO - 8 CPUs 02:38:43 INFO - Crash reason: EXCEPTION_ACCESS_VIOLATION_READ 02:38:43 INFO - Crash address: 0x59f6fa8 02:38:43 INFO - Thread 0 (crashed) 02:38:43 INFO - 0 xul.dll!mozilla::widget::VirtualKey::GetNativeUniChars(unsigned char) [KeyboardLayout.cpp:86a041d63d65 : 341 + 0x0] 02:38:43 INFO - eip = 0x734b50ff esp = 0x00a8c870 ebp = 0x00a8c87c ebx = 0x00000000 02:38:43 INFO - esi = 0x059f6fa8 edi = 0x00a8c8fc eax = 0x0000040c ecx = 0x00000000 02:38:43 INFO - edx = 0x00000001 efl = 0x00210246 02:38:43 INFO - Found by: given as instruction pointer in context 02:38:43 INFO - 1 xul.dll!mozilla::widget::VirtualKey::GetUniChars(unsigned char) [KeyboardLayout.cpp:86a041d63d65 : 316 + 0x7] 02:38:43 INFO - eip = 0x734b5db4 esp = 0x00a8c884 ebp = 0x00a8c8d4 02:38:43 INFO - Found by: call frame info 02:38:43 INFO - 2 xul.dll!mozilla::widget::KeyboardLayout::InitNativeKey(mozilla::widget::NativeKey &,mozilla::widget::ModifierKeyState const &) [KeyboardLayout.cpp:86a041d63d65 : 1491 + 0x28] 02:38:43 INFO - eip = 0x734b699d esp = 0x00a8c8dc ebp = 0x00a8c978 02:38:43 INFO - Found by: call frame info 02:38:43 INFO - 3 xul.dll!mozilla::widget::NativeKey::NativeKey(nsWindowBase *,tagMSG const &,mozilla::widget::ModifierKeyState const &,mozilla::widget::NativeKey::FakeCharMsg const *) [KeyboardLayout.cpp:86a041d63d65 : 564 + 0xf] 02:38:43 INFO - eip = 0x734b7178 esp = 0x00a8c980 ebp = 0x00a8c9ac 02:38:43 INFO - Found by: call frame info 02:38:43 INFO - 4 xul.dll!mozilla::widget::KeyboardLayout::SynthesizeNativeKeyEvent(nsWindowBase *,int,int,unsigned int,nsAString_internal const &,nsAString_internal const &) [KeyboardLayout.cpp:86a041d63d65 : 2313 + 0x1c] 02:38:43 INFO - eip = 0x734b88bf esp = 0x00a8c9b4 ebp = 0x00a8ced0 02:38:43 INFO - Found by: call frame info 02:38:43 INFO - 5 xul.dll!nsWindow::SynthesizeNativeKeyEvent(int,int,unsigned int,nsAString_internal const &,nsAString_internal const &) [nsWindow.cpp:86a041d63d65 : 5655 + 0x16] 02:38:43 INFO - eip = 0x734e18d9 esp = 0x00a8ced8 ebp = 0x00a8cef4 02:38:43 INFO - Found by: call frame info 02:38:43 INFO - 6 xul.dll!nsDOMWindowUtils::SendNativeKeyEvent(int,int,int,nsAString_internal const &,nsAString_internal const &) [nsDOMWindowUtils.cpp:86a041d63d65 : 1031 + 0x20] 02:38:43 INFO - eip = 0x72dee71f esp = 0x00a8cefc ebp = 0x00a8cf18 02:38:43 INFO - Found by: call frame info 02:38:43 INFO - 7 xul.dll!NS_InvokeByIndex [xptcinvoke.cpp:86a041d63d65 : 70 + 0x2] 02:38:43 INFO - eip = 0x7262f12f esp = 0x00a8cf20 ebp = 0x00a8cf4c 02:38:43 INFO - Found by: call frame info
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #0) > Masayuki, I can't help but notice that this happened on the push for bug > 875674. Is it possible that this was caused by that? I don't think so. The bug changes Mac's code and few XP code. However, the changed XP code isn't used on Windows in default settings. > chrome://mochitests/content/chrome/widget/tests/test_keycodes.xul | French > keyCode=221 (0xDD) chars='', wrong location > 02:38:36 INFO - 50911 INFO TEST-PASS | > chrome://mochitests/content/chrome/widget/tests/test_keycodes.xul | keycode > is undefined > 02:38:36 INFO - [Parent 2960] WARNING: Unknown key code comes, please > check latest MSDN document, there may be some new keycodes we have not > known. This warning is very strange. It's crashed at this test: http://mxr.mozilla.org/mozilla-central/source/widget/tests/test_keycodes.xul#1954 So, the sending virtual keycode is same as its previous test but the previous test passed without this warning. Additionally, this warning happens only when the virtual keycode value is not defined. And even if the value is broken, http://mxr.mozilla.org/mozilla-central/source/widget/windows/KeyboardLayout.cpp#1459 The virtualKeyIndex must be -1. Then, this crash must not happen. However, it happens. Therefore, it might be the memory was already broken...
We're still hitting this pretty regularly. Any ideas?
Flags: needinfo?(masayuki)
No, I don't. There are some crash reports: https://crash-stats.mozilla.com/report/list?product=Firefox&query_search=signature&query_type=contains&reason_type=contains&date=2013-08-06&range_value=28&range_unit=days&hang_type=any&process_type=any&signature=mozilla%3A%3Awidget%3A%3AVirtualKey%3A%3AGetNativeUniChars%28unsigned+char%29 I'll take a look as far as possible. However, I'll be offline next week. So, if I cannot touch this bug this week, I'll do it 8/19 or later. And the reported stacks are very odd... That's impossible...
Flags: needinfo?(masayuki)
Perhaps, I found the cause.
Assignee: nobody → masayuki
Status: NEW → ASSIGNED
First, logging better information for debug. Then, we know what happens at crash. Immediately before the crash, we can see following log twice: activeDeadKeyIndex: -1 mActiveDeadKey: 0xFFFFFFFF (-1) virtualKey: 0xDD That means we access mVirtualKeys[-1] at WM_CHAR for second character (The second character of "^^") and WM_KEYUP because mActiveDeadKey was already cleared as -1 at handling WM_KEYDOWN.
Attachment #788186 - Flags: review?(jmathies)
This patch doesn't fix this bug directly. However, this causes synthesizing wrong WM_CHAR message. Then, NativeKey fails to compute correct virtual keycode value and DOM keyCode value. 1. Use current synthesizing key in the for loop (the first chunk and second chunk). 2. The scancode should be stored at 23-16 bit of lParam (the last chunk).
Attachment #788188 - Flags: review?(jmathies)
Next, let's improve the SynthesizeNativeKey(). Currently, it assumes that second or later WM_CHAR messages are not consumed. Therefore, 2nd or later characters are sent with HandleCharMessage(). However, HandleKeyDownMessage() may consume two or more WM_CHAR messages. So, let's send all following WM_CHAR messages to HandleKeyDownMessage(). And then, if it's consumed, mark it as so. Finally, only non-consumed char messages should be sent to HandleCharMessage().
Attachment #788191 - Flags: review?(jmathies)
This is the fixing patch of this crash bug. First, the NeedsToHandleWithoutFollowingCharMsg() checks mIsDeadKey for not firing keypress events case. However, this is wrong. mIsDeadKey is true when the dead key causes text input such as 2nd same key press. So, it should check whether the inputting text is empty or not. Next, at second key press of same dead key, WM_KEYDOWN causes resetting the dead key state (the bottom of the patch, a call of DeactivateDeadKeyState()). So, when following WM_CHAR (for second character) and WM_KEYUP handler creates NativeKey instance, the dead key handling is already finished (at the WM_KEYDOWN). Therefore, if mActiveDeadKey is already cleared, let's set only the last character which is inputted by the last pressed key. Then, we can avoid to reach here: > UniCharsAndModifiers prevDeadChars = > mVirtualKeys[activeDeadKeyIndex].GetUniChars(mDeadKeyShiftState); In the future, the keyup event's KeyboardEvent.key will have only the last character by this change. However, I believe that this is right behavior. Because WM_KEYUP may not be received immediately after the second dead key press. E.g., if user keeps pressing the key, auto repeat causes next WM_KEYDOWN. Or user might press another dead key before releasing the pressed dead key. So, it's impossible to compute the actual inputted text for WM_KEYUP event in such complex path. This patch only changes the normal path (i.e., not only for the test path).
Attachment #788193 - Flags: review?(jmathies)
I think that this is NOT a regression of 25 due to the code is older than it. However, according to the crash reports, this crash starts 25. So, I think that this should be back ported to only 25. https://crash-stats.mozilla.com/report/list?product=Firefox&query_search=signature&query_type=contains&reason_type=contains&date=2013-08-06&range_value=28&range_unit=days&hang_type=any&process_type=any&signature=mozilla%3A%3Awidget%3A%3AVirtualKey%3A%3AGetNativeUniChars%28unsigned+char%29 The STR of this bug is: 1. Type a dead key 2. Type a dead key again Then, the second key press handle may cause crash due to accessing out of range of an array.
status-firefox25: --- → affected
status-firefox26: --- → affected
tracking-firefox25: --- → ?
tracking-firefox26: --- → ?
s/the second key press handle/the second key press handler
Attachment #788186 - Flags: review?(jmathies) → review+
Comment on attachment 788188 [details] [diff] [review] part.2 Fix scancode value in lParam generated by KeyboardLayout::SynthesizeNativeKeyEvent() Review of attachment 788188 [details] [diff] [review]: ----------------------------------------------------------------- ::: widget/windows/KeyboardLayout.h @@ +303,5 @@ > MSG msg; > msg.hwnd = aWnd; > msg.message = mIsDeadKey ? WM_DEADCHAR : WM_CHAR; > msg.wParam = static_cast<WPARAM>(mCharCode); > + msg.lParam = static_cast<LPARAM>(mScanCode << 16); Where are we getting mScanCode from, WinUtils::GetScanCode?
Attachment #788188 - Flags: review?(jmathies) → review+
Comment on attachment 788191 [details] [diff] [review] part.3 FakeCharMsg should be marked as consumed and only non-consumed char message should be synthesized Review of attachment 788191 [details] [diff] [review]: ----------------------------------------------------------------- ::: widget/windows/KeyboardLayout.cpp @@ +2314,5 @@ > NativeKey nativeKey(aWidget, keyDownMsg, modKeyState); > nativeKey.HandleKeyDownMessage(); > } else { > + nsAutoTArray<NativeKey::FakeCharMsg, 10> fakeCharMsgs; > + for (uint32_t j = 0; j < chars.Length(); j++) { nit - not a huge fan of index variables in small loops like this named 'i' or 'j', I'd prefer something like 'idx'.
Attachment #788191 - Flags: review?(jmathies) → review+
Attachment #788193 - Flags: review?(jmathies) → review+
(In reply to Jim Mathies [:jimm] from comment #26) > Comment on attachment 788188 [details] [diff] [review] > part.2 Fix scancode value in lParam generated by > KeyboardLayout::SynthesizeNativeKeyEvent() > > Review of attachment 788188 [details] [diff] [review]: > ----------------------------------------------------------------- > > ::: widget/windows/KeyboardLayout.h > @@ +303,5 @@ > > MSG msg; > > msg.hwnd = aWnd; > > msg.message = mIsDeadKey ? WM_DEADCHAR : WM_CHAR; > > msg.wParam = static_cast<WPARAM>(mCharCode); > > + msg.lParam = static_cast<LPARAM>(mScanCode << 16); > > Where are we getting mScanCode from, WinUtils::GetScanCode? Exactly.
(In reply to Jim Mathies [:jimm] from comment #27) > Comment on attachment 788191 [details] [diff] [review] > part.3 FakeCharMsg should be marked as consumed and only non-consumed char > message should be synthesized > > Review of attachment 788191 [details] [diff] [review]: > ----------------------------------------------------------------- > > ::: widget/windows/KeyboardLayout.cpp > @@ +2314,5 @@ > > NativeKey nativeKey(aWidget, keyDownMsg, modKeyState); > > nativeKey.HandleKeyDownMessage(); > > } else { > > + nsAutoTArray<NativeKey::FakeCharMsg, 10> fakeCharMsgs; > > + for (uint32_t j = 0; j < chars.Length(); j++) { > > nit - not a huge fan of index variables in small loops like this named 'i' > or 'j', I'd prefer something like 'idx'. Hmm, I don't like it... The loop is in a for loop which uses "i". So, "j" is better at least here...
I'd like to know jimm still thinks I should change the variable name even in this case (see comment 29).
Flags: needinfo?(jmathies)
(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) (offline: 8/13-8/18 JST) from comment #30) > I'd like to know jimm still thinks I should change the variable name even in > this case (see comment 29). I usually try to avoid i's and j's in general, but it's not that big a deal. Your code, you can use the variables you like.
Flags: needinfo?(jmathies)
Can we uplift this to Aurora too please?
status-firefox26: affected → fixed
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #34) > Can we uplift this to Aurora too please? Of course, but I think that we should wait next week for tested by Nightly users.
+1 to comment 35, but a=akeybl when ready to uplift.
tracking-firefox25: ? → +
tracking-firefox26: ? → +
Keywords: regression
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: