962140 - [Meta] crash in mozilla::widget::NativeKey::RemoveFollowingCharMessage() or mozilla::widget::NativeKey::GetFollowingCharMessage(tagMSG&)

Status: RESOLVED FIXED

(Core Graveyard :: Widget: WinRT, defect, P1)

Description

[Jim Mathies [:jimm]]

This bubbled up into our top five recently. It's a forced crash due to a missing character message.

http://hg.mozilla.org/mozilla-central/annotate/171857e7e334/widget/windows/KeyboardLayout.cpp#l1288

This bug was filed from the Socorro interface and is 
report bp-8b71b401-771d-491a-9ad9-2a3a52140120.
=============================================================

0 	xul.dll 	mozilla::widget::NativeKey::RemoveFollowingCharMessage() 	widget/windows/KeyboardLayout.cpp
1 	xul.dll 	mozilla::widget::NativeKey::DispatchKeyPressEventForFollowingCharMessage() 	widget/windows/KeyboardLayout.cpp
2 	xul.dll 	mozilla::widget::NativeKey::HandleKeyDownMessage(bool *) 	widget/windows/KeyboardLayout.cpp
3 	xul.dll 	MetroWidget::WindowProcedure(HWND__ *,unsigned int,unsigned int,long)

Comment 1

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Hmm, it's very odd.

DispatchKeyPressEventForFollowingCharMessage() is called only when IsFollowedByCharMessage() returns true.

I have no idea of the difference between IsFollowedByCharMessage() and RemoveFollowingCharMessage()'s check...

Comment 2

[Jim Mathies [:jimm]]

Does this have to be a MOZ_CRASH or can we just warn?

Comment 3

[Matt Brubeck (:mbrubeck)]

I'm seeing this a *lot* in Nightly and Aurora.  I think it should block Metro Firefox 28.  It's now the #2 metro topcrash in Aurora 28.

Comment 4

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Hmm, it's a regression of 28? Did we change something message handling code only on Metro?

Comment 5

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

(In reply to Jim Mathies [:jimm] from comment #2)
> Does this have to be a MOZ_CRASH or can we just warn?

It's possible, but it should be the last resort. We should research what's the cause (and STR).

Comment 6

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #4)
> Hmm, it's a regression of 28? Did we change something message handling code
> only on Metro?

According to the breakdown this happens on all Windows versions and in all products, including Firefox and MetroFirefox.

Firefox reports with a lot of comments:

https://crash-stats.mozilla.com/report/list?signature=mozilla%3A%3Awidget%3A%3ANativeKey%3A%3ARemoveFollowingCharMessage%28%29&product=Firefox&query_type=contains&range_unit=weeks&process_type=any&hang_type=any&date=2014-01-31+11%3A00%3A00&range_value=1#tab-sigsummary

"This is the 3rd time in the last hour that Firefox has crashed on me. Each time I was trying to forward an email and it crashed while I was adding/writing a message to the recipient."

"I am working in Turbotax and twice the connection has crashed. I believe I lost the first data I entered"

"ONE THING THAT MAY BE CAUSING THE PROBLEMS is that I am using Dragon natural speaking, it seemed to have more problems since installing that. But, due to problems with my hands typing in need to use it."

"hit m key and it crashed"

"The whole application suddenly closed. I was using Dragon speak, version 11.5, to reply to e-mails that I had received."

"I was using DragonDictate when the machine crashed this is not the first time this has happened in fact it happens way too often."

"This is very annoying. Was in the middle of a purchase."

Comment 7

[Jim Mathies [:jimm]]

On desktop this happens on simple key downs:

0 	xul.dll 	mozilla::widget::NativeKey::RemoveFollowingCharMessage() 	widget/windows/KeyboardLayout.cpp
1 	xul.dll 	mozilla::widget::NativeKey::DispatchKeyPressEventForFollowingCharMessage() 	widget/windows/KeyboardLayout.cpp
2 	xul.dll 	mozilla::widget::NativeKey::HandleKeyDownMessage(bool *) 	widget/windows/KeyboardLayout.cpp
3 	xul.dll 	nsWindow::ProcessKeyDownMessage(tagMSG const &,bool *) 	widget/windows/nsWindow.cpp
4 	xul.dll 	nsWindow::ProcessMessage(unsigned int,unsigned int &,long &,long *) 	widget/windows/nsWindow.cpp
5 	xul.dll 	nsWindow::WindowProcInternal(HWND__ *,unsigned int,unsigned int,long) 	widget/windows/nsWindow.cpp
6 	xul.dll 	CallWindowProcCrashProtected 	xpcom/base/nsCrashOnException.cpp
7 	xul.dll 	nsWindow::WindowProc(HWND__ *,unsigned int,unsigned int,long) 	widget/windows/nsWindow.cpp
8 	user32.dll 	InternalCallWinProc 	
9 	user32.dll 	UserCallWinProcCheckWow 	
10 	user32.dll 	DispatchMessageWorker 	
11 	user32.dll 	DispatchMessageW 	
12 	xul.dll 	nsAppShell::ProcessNextNativeEvent(bool)

Comment 8

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

In HandleKeyDownMessage(), DispatchKeyPressEventForFollowingCharMessage() is called only this code:

> 1088   if (IsFollowedByCharMessage()) {
> 1089     return DispatchKeyPressEventForFollowingCharMessage();
> 1090   }

IsFollowedByCharMessage() checks with PeekMessage():

> 751     if (!WinUtils::PeekMessage(&nextMsg, mMsg.hwnd, WM_KEYFIRST, WM_KEYLAST,
> 752                                PM_NOREMOVE | PM_NOYIELD)) {
> 753       return false;
> 754     }
> 755   }
> 756   return (nextMsg.message == WM_CHAR ||
> 757           nextMsg.message == WM_SYSCHAR ||
> 758           nextMsg.message == WM_DEADCHAR);

And RemoveFollowingCharMessage() does:

> 1284   MSG msg;
> 1285   if (!WinUtils::GetMessage(&msg, mMsg.hwnd, WM_KEYFIRST, WM_KEYLAST) ||
> 1286       !(msg.message == WM_CHAR || msg.message == WM_SYSCHAR ||
> 1287         msg.message == WM_DEADCHAR)) {
> 1288     MOZ_CRASH("We lost the following char message");
> 1289   }
> 1290 
> 1291   return msg;

It seems that PeekMessage() finds a WM_*CHAR message, but GetMessage() doesn't find the same message. Is it possible?

Comment 9

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Oh, GetMessage()'s result is BOOL but if there is no message, it returns -1. It's really different point of them. But I have no idea how it causes this because we expect return TRUE in this case.

Another difference of them is, GetMessage() always prefers WM_QUIT. But I don't think we can reach here when the queue has WM_QUIT...

Comment 10

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #9)
> Oh, GetMessage()'s result is BOOL but if there is no message, it returns -1.
> It's really different point of them. But I have no idea how it causes this
> because we expect return TRUE in this case.
> 
> Another difference of them is, GetMessage() always prefers WM_QUIT. But I
> don't think we can reach here when the queue has WM_QUIT...

Yeah I don't see that happening either.

Comment 11

[Jim Mathies [:jimm]]

I'm wondering if during the processing of non-queued events during the PeekMessage call in IsFollowedByCharMessage, we somehow end up processing the pending WM_CHAR message before the call to GetMessage to remove it.

Comment 12

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Oh, WM_QUIT case is possible:
http://mxr.mozilla.org/mozilla-central/source/widget/windows/nsAppShell.cpp#202

We're using PeekMessage() in the message loop now. But I don't think it causes this bug because it's odd user to type text at quitting.

Comment 13

[Jim Mathies [:jimm]]

unwrapped:


MSG nextMsg;
if (mFakeCharMsgs) {
  nextMsg = mFakeCharMsgs->ElementAt(0).GetCharMsg(mMsg.hwnd);
} else {
  if (!WinUtils::PeekMessage(&nextMsg, mMsg.hwnd, WM_KEYFIRST, WM_KEYLAST,
                              PM_NOREMOVE | PM_NOYIELD)) {
    return false;
  }
}

if (nextMsg.message == WM_CHAR ||
    nextMsg.message == WM_SYSCHAR ||
    nextMsg.message == WM_DEADCHAR) {
  if (mFakeCharMsgs) {
    mFakeCharMsgs->ElementAt(0).mConsumed = true;
    return mFakeCharMsgs->ElementAt(0).GetCharMsg(mMsg.hwnd);
  }

  MSG msg;
  if (!WinUtils::GetMessage(&msg, mMsg.hwnd, WM_KEYFIRST, WM_KEYLAST) ||
      !(msg.message == WM_CHAR || msg.message == WM_SYSCHAR ||
        msg.message == WM_DEADCHAR)) {
    MOZ_CRASH("We lost the following char message");
  }
}

One possibility is  that WinUtils::GetMessage returns 0, and we call MOZ_CRASH? Maybe we should handle those cases separately?

Comment 14

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

It's possible only when GetMessage() retrieves WM_QUIT...

Comment 15

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Attachment: Use PeekMessage() with RM_REMOVE instead of GetMessage() (landed on m-c, aurora and beta)

I hope that this patch fixes this bug...

Comment 16

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://tbpl.mozilla.org/?tree=Try&usebuildbot=1&rev=21d0b8da31dc

Comment 17

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

I'll be back 2 hours later, sorry.

Comment 18

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8368509 [details] [diff] [review]
Use PeekMessage() with RM_REMOVE instead of GetMessage() (landed on m-c, aurora and beta)

Let's try this.

We should fix at least two things after this.

1. The result type of WinUtils::GetMessage() should be BOOL, not bool. bool cannot represent -1.

2. Use GetMessage() in the message loop in nsAppShell.cpp. WM_QUIT should be preferred than the other messages.

Comment 19

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #18)
> Comment on attachment 8368509 [details] [diff] [review]
> Use PeekMessage() with RM_REMOVE instead of GetMessage()
> 
> Let's try this.
> 
> We should fix at least two things after this.
> 
> 1. The result type of WinUtils::GetMessage() should be BOOL, not bool. bool
> cannot represent -1.


Did you miss a WinUtils change in your patch? I don't see this part.

Comment 20

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

(In reply to Jim Mathies [:jimm] from comment #19)
> (In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #18)
> > Comment on attachment 8368509 [details] [diff] [review]
> > Use PeekMessage() with RM_REMOVE instead of GetMessage()
> > 
> > Let's try this.
> > 
> > We should fix at least two things after this.
> > 
> > 1. The result type of WinUtils::GetMessage() should be BOOL, not bool. bool
> > cannot represent -1.
> 
> 
> Did you miss a WinUtils change in your patch? I don't see this part.

The 2 things should be landed *after* this bug. They're pretty risky for now.

Comment 21

[Jim Mathies [:jimm]]

Comment on attachment 8368509 [details] [diff] [review]
Use PeekMessage() with RM_REMOVE instead of GetMessage() (landed on m-c, aurora and beta)

Ok sounds good. This will be an interesting experiment.

Comment 22

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/8ded1c0760cc

Thanks! I can go to bed!!

Let's watch the result for a couple of days.

Comment 23

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/8ded1c0760cc

Comment 24

[Jim Mathies [:jimm]]

Hmm, still showing up in 02-01 nightly - 

https://crash-stats.mozilla.com/report/list?product=MetroFirefox&range_value=7&range_unit=days&date=2014-02-03&signature=mozilla%3A%3Awidget%3A%3ANativeKey%3A%3ARemoveFollowingCharMessage%28%29&version=MetroFirefox%3A29.0a1#tab-reports

Comment 25

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Attachment: Append unexpected message log to crash report

https://tbpl.mozilla.org/?tree=Try&usebuildbot=1&rev=d8399c123969

I hope that this would give us more hints.

I'm thinking the possibilities of this bug are:

Another thread/process post or send message to our main thread. Then, input message gives lower priority than it. If the found char message comes from device and somebody post/send a key message between IsFollowingCharMessage() and RemoveFollowingCharMessage(), this may cause this bug.

This sounds like not realistic scenario for me. However, if application such as a11y tools post multiple key messages to us sequentially, our thread may peek WM_(SYS)KEYDOWN message during the sequence. I guess that this might be possible. (I assume that WM_(SYS)(DEAD)CHAR messages are always queued as input message from a device.)

Anyway, I want to see more detail of what happens as far as possible.

Comment 26

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

According to the change by the previous landing, I believe that PeekMessage() doesn't fail but it retrieves KEYDOWN or KEYUP message.

Comment 27

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8369457 [details] [diff] [review]
Append unexpected message log to crash report

Let's land this.

After checking the crash report, I'll create next patch.

Comment 28

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8369457 [details] [diff] [review]
Append unexpected message log to crash report

Oops, the logging message is odd. I'll post new patch.

Comment 29

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Attachment: Append unexpected message log to crash report (landed on m-c, aurora and beta)

Comment 30

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/d8b63edf935b

Comment 31

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/d8b63edf935b

Comment 32

[Jim Mathies [:jimm]]

I think the first patch may have helped reduce these. We have two crashes in the nightly build of 02-01 which included the fix. But we haven't seen any since then.

This landed 
Fri Jan 31 15:51:32 2014
Next nightly:
Sat Feb 1 08:07:34 2014
http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014/02/2014-02-01-07-49-23-mozilla-central/firefox-29.0a1.en-US.win32.txt

https://crash-stats.mozilla.com/report/list?product=MetroFirefox&range_value=7&range_unit=days&date=2014-02-06&signature=mozilla%3A%3Awidget%3A%3ANativeKey%3A%3ARemoveFollowingCharMessage%28%29&version=MetroFirefox%3A29.0a1#tab-reports

Comment 33

[Jim Mathies [:jimm]]

Comment on attachment 8368509 [details] [diff] [review]
Use PeekMessage() with RM_REMOVE instead of GetMessage() (landed on m-c, aurora and beta)

[Approval Request Comment]
Bug caused by (feature/regressing bug #): long standing bug
User impact if declined: crashy browser when entering form input data
Testing completed (on m-c, etc.): on mc and aurora, crash count reduced.
Risk to taking this patch (and alternatives if risky): low
String or IDL/UUID changes made by this patch: none

Comment 34

[Jim Mathies [:jimm]]

sorry, wrong crash bug.

Comment 35

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://crash-stats.mozilla.com/report/index/a67fe373-0036-4d9f-83d4-db3ab2140206
Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000020, lParam: 0x00390001, InSendMessageEx()=ISMEX_NOSEND,
Next key message: Unknown (0x00000000), wParam: 0x00000000, lParam: 0x00000000

https://crash-stats.mozilla.com/report/index/734ad868-1822-4a73-b284-b8ad42140206
Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000020, lParam: 0x00390001, InSendMessageEx()=ISMEX_NOSEND,
Next key message: Unknown (0x00000000), wParam: 0x00000000, lParam: 0x00000000 

https://crash-stats.mozilla.com/report/index/1118149d-3df8-4101-a5b7-02e372140206
Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000020, lParam: 0x00390001, InSendMessageEx()=ISMEX_NOSEND, Next key message: Unknown (0x00000000), wParam: 0x00000000, lParam: 0x00000000 

These logs are odd. PeekMessage() succeeded but the got message is WM_NULL!

Comment 36

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Odd... I cannot emulate the situation...

https://tbpl.mozilla.org/?tree=Try&usebuildbot=1&rev=31bbff97c227

Comment 37

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Came from desktop:

https://crash-stats.mozilla.com/report/index/00db1124-68ff-49b3-8205-ca9b42140206
Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000033, lParam: 0x40040001, InSendMessageEx()=ISMEX_NOSEND,
Next key message: WM_KEYDOWN (0x00000100), wParam: 0x00000033, lParam: 0x40040001

https://crash-stats.mozilla.com/report/index/0953c2a9-c93e-45e8-a730-c14862140206
Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000034, lParam: 0x00050001, InSendMessageEx()=ISMEX_NOSEND,
Next key message: WM_KEYUP (0x00000101), wParam: 0x00000034, lParam: 0xC0050001 

https://crash-stats.mozilla.com/report/index/8fd97970-6cec-40c4-8495-fbcaa2140206
Handling message: WM_KEYDOWN (0x00000100), wParam: 0x0000001B, lParam: 0x00010001, InSendMessageEx()=ISMEX_NOSEND,
Next key message: WM_SYSKEYDOWN (0x00000104), wParam: 0x00000012, lParam: 0x20380001

These logs are not so odd to me because these are possible as I said in comment 25.

I'll create a patch for this, first. I'm still thinking the reason why PeekMessage() returns WM_NULL on Metrofox.

Comment 38

[Jim Mathies [:jimm]]

> I'll create a patch for this, first. I'm still thinking the reason why
> PeekMessage() returns WM_NULL on Metrofox.

winrt is really aggressive about checking app event loops for hangs. WM_NULL is what it uses to do this. Is it possible these null events are getting injected at a point our keyboard handling doesn't expect?

Comment 39

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

(In reply to Jim Mathies [:jimm] from comment #38)
> > I'll create a patch for this, first. I'm still thinking the reason why
> > PeekMessage() returns WM_NULL on Metrofox.
> 
> winrt is really aggressive about checking app event loops for hangs. WM_NULL
> is what it uses to do this. Is it possible these null events are getting
> injected at a point our keyboard handling doesn't expect?

I guessed so. But I cannot reproduce the bug with this patch, see comment 36.
https://hg.mozilla.org/try/rev/cd4740da9560

I don't understand why the PeekMessage() returns WM_NULL since we pass WM_KEYFIRST and WM_KEYLAST to it.

Comment 40

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #39)
> (In reply to Jim Mathies [:jimm] from comment #38)
> > > I'll create a patch for this, first. I'm still thinking the reason why
> > > PeekMessage() returns WM_NULL on Metrofox.
> > 
> > winrt is really aggressive about checking app event loops for hangs. WM_NULL
> > is what it uses to do this. Is it possible these null events are getting
> > injected at a point our keyboard handling doesn't expect?
> 
> I guessed so. But I cannot reproduce the bug with this patch, see comment 36.
> https://hg.mozilla.org/try/rev/cd4740da9560
> 
> I don't understand why the PeekMessage() returns WM_NULL since we pass
> WM_KEYFIRST and WM_KEYLAST to it.

Well PostMessage is a little different from SendMessage/SendMessageTimeout. Sent messages get priority in the event queue.

Comment 41

[Jim Mathies [:jimm]]

I agree though, it's really odd that WM_NULL would be peeked as a keyboard event.

Comment 42

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Posted message has higher priority than input message from device. So, if PeekMessage() can return WM_NULL in that case, the test build should crash, but I cannot reproduce it.

We should confirm one more thing. That is, when PeekMessage() returns WM_NULL, whether the WM_*CHAR message is still in the queue or not. I guess that it's not removed. WM_NULL is inserted before WM_*CHAR. If so, PeekMessage() should retry until it returns WM_*CHAR.

Comment 43

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Attachment: Remove following char message of keydown message with found message (landed on m-c, aurora and beta)

This patch tries to remove found char message and pass it to handling method.

Comment 44

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

I don't understand well about the issue of WM_NULL. But I guess that Metrofox shouldn't use WM_NULL. It might better to use user or app defined message or registered message instead.

Comment 45

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #44)
> I don't understand well about the issue of WM_NULL. But I guess that
> Metrofox shouldn't use WM_NULL. It might better to use user or app defined
> message or registered message instead.

Windows uses WM_NULL and SendMessageTimeout to check if our event loop is processing messages in a timely fashion. If it isn't, explorer kills the browser.

Comment 46

[Jim Mathies [:jimm]]

(In reply to Jim Mathies [:jimm] from comment #45)
> (In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #44)
> > I don't understand well about the issue of WM_NULL. But I guess that
> > Metrofox shouldn't use WM_NULL. It might better to use user or app defined
> > message or registered message instead.
> 
> Windows uses WM_NULL and SendMessageTimeout to check if our event loop is
> processing messages in a timely fashion. If it isn't, explorer kills the
> browser.

On Vista and up, this would result in a non-responding ghost window. I don't think this is specific to Metro.

Comment 47

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/ada4aec5053f

Comment 48

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/ada4aec5053f

Comment 49

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/16a356b13057

Not sure if this means 28 is fixed for good or not, but setting the status to fixed gets it off my radar for now. Please set it back to affected if something else needs to land here at some point.

Comment 50

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g28_v1_3/rev/16a356b13057

Comment 51

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

New query:
https://crash-stats.mozilla.com/report/list?signature=mozilla%3A%3Awidget%3A%3ANativeKey%3A%3AGetFollowingCharMessage%28tagMSG%26%29&product=Firefox&product=MetroFirefox&query_type=contains&range_unit=weeks&process_type=any&platform=win&hang_type=any&date=2014-02-13+00%3A00%3A00&range_value=1#tab-reports

There is one report:
https://crash-stats.mozilla.com/report/index/a6fd640f-8028-474e-8cf6-7380f2140212

Comment 52

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Looks like the third patch succeeded to reduce most cases of the crash!

However, there is still strange report:

Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000020, lParam: 0x00390001, InSendMessageEx()=ISMEX_NOSEND, 
Found message: WM_CHAR (0x00000102), wParam: 0x00000020, lParam: 0x00390001

This means that PeekMessage() with PM_REMOVE failed to retrieve WM_CHAR which was found immediately before. This means that the WM_CHAR message has been really lost before we handle it.

What should we do???

Comment 53

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

jimm:

I have a question. On Metrofox, the main message loop which retrieves all messages and NativeKey run in same thread?

Comment 54

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #53)
> jimm:
> 
> I have a question. On Metrofox, the main message loop which retrieves all
> messages and NativeKey run in same thread?

Yes, same thread. We do send events async though by bouncing them off runnables to keep the dispatcher off the stack. But all of that is handled after the keyboard code receives the events. We bounce the events in DispatchKeyboardEvent.

http://mxr.mozilla.org/mozilla-central/source/widget/windows/winrt/MetroWidget.cpp#828
http://mxr.mozilla.org/mozilla-central/source/widget/windows/winrt/MetroWidget.cpp#691

Comment 55

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Thanks. But it's really odd. Then, I have no idea who removed the message from the queue.

If we completely lose the change to receive the message, we just return the found message at that time. However, otherwise, i.e., if we will receive the lost char message later, we shouldn't dispatch keypress event here, or, we should dispatch it with found message and ignore next message...

Comment 56

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Oh, super search is better:
https://crash-stats.mozilla.com/search/?signature=~mozilla%3A%3Awidget%3A%3ANativeKey%3A%3AGetFollowingCharMessage&_facets=signature&_columns=date&_columns=signature&_columns=product&_columns=version&_columns=build_id&_columns=platform

https://crash-stats.mozilla.com/report/index/0237012b-5ab0-4e64-84a2-53ee62140213
https://crash-stats.mozilla.com/report/index/3a22ca0b-9db0-4f7d-a843-783672140213
https://crash-stats.mozilla.com/report/index/83d50e95-4aa5-4b28-9823-806c22140213
https://crash-stats.mozilla.com/report/index/f6a15c55-61e0-4ba9-ae00-8dda92140213

All of them crashes handling same key, VK_SPACE (0x20).

Repeat count is 1, scan code is 0x39. So, looks like it's caused by holding press space key if it's not generated by another application.

Comment 57

[Jim Mathies [:jimm]]

Why do we assume that WM_CHAR for printable keys will be in the event queue when we receive the WM_KEYDOWN event?

Comment 58

[Jim Mathies [:jimm]]

If I understand this correctly, we're crashing here - 

http://hg.mozilla.org/mozilla-central/annotate/802d87c77e76/widget/windows/KeyboardLayout.cpp#l1341

for this forced crash:

https://crash-stats.mozilla.com/report/index/3a22ca0b-9db0-4f7d-a843-783672140213

steps:

1) we've received a WM_KEYDOWN for virtual key code VK_SPACE (0x00000020)

2) we call peek message (PM_NOREMOVE) for window mMsg.hwnd looking for a WM_CHAR message that matches the WM_KEYDOWN, which we find in the event queue.

Found message: WM_CHAR (0x00000102), wParam: 0x00000020, lParam: 0x00390001

3) we try to remove the WM_CHAR message with peek message for window nextKeyMsg.hwnd, which fails.

4) we crash

am I following this right?

Comment 59

[Jim Mathies [:jimm]]

Can we upload the last two patches to aurora and see if it helps there?

mc, last 7 days:
https://crash-stats.mozilla.com/search/?signature=~mozilla%3A%3Awidget%3A%3ANativeKey%3A%3ARemoveFollowingCharMessage%28%29&version=30.0a1&_facets=signature&_columns=date&_columns=signature&_columns=product&_columns=version&_columns=build_id&_columns=platform

aurora, last 7 days:
https://crash-stats.mozilla.com/search/?signature=~mozilla%3A%3Awidget%3A%3ANativeKey%3A%3ARemoveFollowingCharMessage%28%29&version=29.0a2&_facets=signature&_columns=date&_columns=signature&_columns=product&_columns=version&_columns=build_id&_columns=platform

Comment 60

[Jim Mathies [:jimm]]

Note, on mc, the problem still seems to be present, but mostly on desktop. Not sure why that is.

Comment 61

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

(In reply to Jim Mathies [:jimm] from comment #57)
> Why do we assume that WM_CHAR for printable keys will be in the event queue
> when we receive the WM_KEYDOWN event?

Because if the key is a printable key, ::TranslateMessage() must generate one or more WM_*CHAR messages.

(In reply to Jim Mathies [:jimm] from comment #58)
> If I understand this correctly, we're crashing here - 
> 
> http://hg.mozilla.org/mozilla-central/annotate/802d87c77e76/widget/windows/
> KeyboardLayout.cpp#l1341
> 
> for this forced crash:
> 
> https://crash-stats.mozilla.com/report/index/3a22ca0b-9db0-4f7d-a843-
> 783672140213
> 
> steps:
> 
> 1) we've received a WM_KEYDOWN for virtual key code VK_SPACE (0x00000020)
> 
> 2) we call peek message (PM_NOREMOVE) for window mMsg.hwnd looking for a
> WM_CHAR message that matches the WM_KEYDOWN, which we find in the event
> queue.
> 
> Found message: WM_CHAR (0x00000102), wParam: 0x00000020, lParam: 0x00390001
> 
> 3) we try to remove the WM_CHAR message with peek message for window
> nextKeyMsg.hwnd, which fails.
> 
> 4) we crash
> 
> am I following this right?

Yes, but the actual crash line is here:
http://hg.mozilla.org/mozilla-central/annotate/802d87c77e76/widget/windows/KeyboardLayout.cpp#l1362
(according to the difference of the appending note)

(In reply to Jim Mathies [:jimm] from comment #59)
> Can we upload the last two patches to aurora and see if it helps there?

Yeah, perhaps, the last patch reduces a lot of crashes.

(In reply to Jim Mathies [:jimm] from comment #60)
> Note, on mc, the problem still seems to be present, but mostly on desktop.
> Not sure why that is.

Please note that the signature is changed by the last patch. RemoveFollowingCharMessage() is now GetFollowingCharMessage(tagMSG&) on m-c.

Comment 62

[Jim Mathies [:jimm]]

> (In reply to Jim Mathies [:jimm] from comment #60)
> > Note, on mc, the problem still seems to be present, but mostly on desktop.
> > Not sure why that is.
> 
> Please note that the signature is changed by the last patch.
> RemoveFollowingCharMessage() is now GetFollowingCharMessage(tagMSG&) on m-c.

ah, bummer. There are a bunch of these in the 2-13 build. :/

Comment 63

[Jim Mathies [:jimm]]

(In reply to Jim Mathies [:jimm] from comment #62)
> > (In reply to Jim Mathies [:jimm] from comment #60)
> > > Note, on mc, the problem still seems to be present, but mostly on desktop.
> > > Not sure why that is.
> > 
> > Please note that the signature is changed by the last patch.
> > RemoveFollowingCharMessage() is now GetFollowingCharMessage(tagMSG&) on m-c.
> 
> ah, bummer. There are a bunch of these in the 2-13 build. :/

or rather, 2-12 build. 2-13 isn't out yet.

Comment 64

[Jim Mathies [:jimm]]

metro and desktop seem to be crashing in two different places, which is interesting.

MetroFirefox:

Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000020 (space), lParam: 0x00390001,
Found message: WM_CHAR (0x00000102), wParam: 0x00000020, lParam: 0x00390001

Firefox:

Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000080 (VK_F17), lParam: 0x00000001,
Found message: WM_CHAR (0x00000102), wParam: 0x00000938 ???, lParam: 0x00000001, 
Removed message: WM_CHAR (0x00000102), wParam: 0x00000938 ???, lParam: 0x00800001

^ kinda weird, isn't wParam for WM_CHAR supposed to be the character code?

http://msdn.microsoft.com/en-us/library/windows/desktop/ms646276(v=vs.85).aspx

Comment 65

[Jim Mathies [:jimm]]

Generally, the assumption here that a call to PeekMessage with PM_NOREMOVE guarantees a subsequent call to PeekMessage with PM_REMOVE for the same message will return it, seems flawed.

Comment 66

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

U+0938: स

The lParam change is odd, it changes the scancode. However, the important thing is the wParam value. We should omit the lParam check for the latter. At least for now, only when wParam is changed, it means we may lost a WM_CHAR.

Comment 67

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #66)
> U+0938: स

Ah thanks.  

Can we go ahead flag these patches for uplift? That WM_NULL check really seems to have helped. We don't see many of these crashes on beta but there are a lot on aurora.

Comment 68

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8369857 [details] [diff] [review]
Append unexpected message log to crash report (landed on m-c, aurora and beta)

[Approval Request Comment]
User impact if declined: This is necessary for applying following patch.
Testing completed (on m-c, etc.): landed.
Risk to taking this patch (and alternatives if risky): Nothing, this just adds the detail at crash to the log.
String or IDL/UUID changes made by this patch: Nothing.

Comment 69

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8372896 [details] [diff] [review]
Remove following char message of keydown message with found message (landed on m-c, aurora and beta)

[Approval Request Comment]
User impact if declined: Some users meet this crash a lot. Actually, this patch reduces some crash patterns on m-c according to the crash report of Nightly builds.
Testing completed (on m-c, etc.): landed, and we're collecting crash reports.
Risk to taking this patch (and alternatives if risky): Low risk. There are still crash scenarios even we land this, but this actually reduces the number of crash reports on Nightly.
String or IDL/UUID changes made by this patch: Nothing.

Comment 70

[Sylvestre Ledru [:Sylvestre]]

Masayuki, can you confirm that it has landed in m-c ?
(I would like to see it in m-c before uplifting it aurora)
thanks

Comment 71

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

(In reply to Sylvestre Ledru [:sylvestre] from comment #70)
> Masayuki, can you confirm that it has landed in m-c ?
> (I would like to see it in m-c before uplifting it aurora)
> thanks

Yes, I did it. The last patch changes the crash signature since it changes the method name.

Comment 72

[u279076]

This has dropped 16 positions in the last week in Firefox 28 and now sits at #91 accounting for 0.11% of our browser crashes on Windows. So while this crash isn't 100% solved it does seem to be occurring at much lower volume.

Comment 73

[u279076]

Marking this verified for Firefox 28 based on comment 72. Please revert this change if you think this is still an issue.

Comment 74

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/687a3cf84d32
https://hg.mozilla.org/releases/mozilla-aurora/rev/fe56f56eafbc

Comment 75

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Logs of remaining crashes are:

> Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000080, lParam: 0x00000001, InSendMessageEx()=ISMEX_NOSEND,
> Found message: WM_CHAR (0x00000102), wParam: 0x0000092F, lParam: 0x00000001,
> Removed message: WM_CHAR (0x00000102), wParam: 0x0000092F, lParam: 0x00800001 

and

> Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000080, lParam: 0x00000001, InSendMessageEx()=ISMEX_NOSEND,
> Found message: WM_CHAR (0x00000102), wParam: 0x000000A0, lParam: 0x00000001,
> Removed message: WM_CHAR (0x00000102), wParam: 0x000000A0, lParam: 0x002A0001 

http://download.microsoft.com/download/1/6/1/161ba512-40e2-4cc9-843a-923143f3456c/scancode.doc
According to "Keyboard Scan Code Specification", scan code 0x80 means releasing undefined key. 0x2A is pressing left shift key. It might occur when new keydown or keyup message is inserted to the queue. Although, I have no idea to confirm it.

Comment 76

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Attachment: NativeKey should not check scan code at comparing found char message and removed char message (landed on m-c and aurora)

Let's ignore the scan code value at comparing found char message with removed char message.

That's all for the crash reasons which we know.

Comment 77

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Thank you, let's close this bug after watching crash reports for a week.
https://hg.mozilla.org/integration/mozilla-inbound/rev/efd7039a2ff2

Comment 78

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #74)
> https://hg.mozilla.org/releases/mozilla-aurora/rev/687a3cf84d32
> https://hg.mozilla.org/releases/mozilla-aurora/rev/fe56f56eafbc

These crashes are showing up on beta now in higher numbers. Would you feel comfortable uplifting these?

https://crash-stats.mozilla.com/topcrasher/products/MetroFirefox/versions/28.0b

Comment 79

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Sure, but I should confirm that the patches can be applied to beta tomorrow.

Comment 80

[Robert Kaiser]

(In reply to Anthony Hughes, QA Mentor (:ashughes) from comment #72)
> This has dropped 16 positions in the last week in Firefox 28 and now sits at
> #91 accounting for 0.11% of our browser crashes on Windows. So while this
> crash isn't 100% solved it does seem to be occurring at much lower volume.

Just as a note, for seeing a clear picture for a specific beta on things like this, please looks at the topcrash pages for the specific betas - there's a reason why we have specific "28.0b3" etc. in the Socorro version dropdown next to the generic "28.0b". ;-)

Comment 81

[Jim Mathies [:jimm]]

(In reply to Robert Kaiser (:[e-mail]) from comment #80)
> Just as a note, for seeing a clear picture for a specific beta on things
> like this, please looks at the topcrash pages for the specific betas -
> there's a reason why we have specific "28.0b3" etc. in the Socorro version
> dropdown next to the generic "28.0b". ;-)

Hmm, none of these display any crash reports for both Firefox and MetroFirefox.

Comment 82

[u279076]

More specific breakdown by Beta version...

28.0b3 - 4 crashes per 2 installs
https://crash-stats.mozilla.com/report/list?product=MetroFirefox&range_value=7&range_unit=days&date=2014-02-18&signature=mozilla%3A%3Awidget%3A%3ANativeKey%3A%3ARemoveFollowingCharMessage%28%29&version=MetroFirefox%3A28.0b3

28.0b2 - 8 crashes per 7 installs
https://crash-stats.mozilla.com/report/list?product=MetroFirefox&range_value=7&range_unit=days&date=2014-02-18&signature=mozilla%3A%3Awidget%3A%3ANativeKey%3A%3ARemoveFollowingCharMessage%28%29&version=MetroFirefox%3A28.0b2

Comment 83

[Robert Kaiser]

(In reply to Jim Mathies [:jimm] from comment #81)
> (In reply to Robert Kaiser (:[e-mail]) from comment #80)
> > Just as a note, for seeing a clear picture for a specific beta on things
> > like this, please looks at the topcrash pages for the specific betas -
> > there's a reason why we have specific "28.0b3" etc. in the Socorro version
> > dropdown next to the generic "28.0b". ;-)
> 
> Hmm, none of these display any crash reports for both Firefox and
> MetroFirefox.

For me, https://crash-stats.mozilla.com/topcrasher/products/MetroFirefox/versions/28.0b has this crash at #2 right now and https://crash-stats.mozilla.com/topcrasher/products/MetroFirefox/versions/28.0b3 has it at #1.

Comment 84

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/efd7039a2ff2

Comment 85

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8369857 [details] [diff] [review]
Append unexpected message log to crash report (landed on m-c, aurora and beta)

This will be overwritten by next patch. This is necessary only for applying next patch.

Comment 86

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8372896 [details] [diff] [review]
Remove following char message of keydown message with found message (landed on m-c, aurora and beta)

[Approval Request Comment]
User impact if declined: Some users using something a11y tools for text input meet the crash.
Testing completed (on m-c, etc.): on m-c and on aurora.
Risk to taking this patch (and alternatives if risky): Low risk. This patch just reduces the cases calling MOZ_CRASH() since some causes of the unexpected cases are researched.
String or IDL/UUID changes made by this patch: Nothing.

Comment 87

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

FYI: applied to beta: https://tbpl.mozilla.org/?tree=Try&usebuildbot=1&rev=1a3798a951b0

Comment 88

[Lukas Blakk [:lsblakk] use ?needinfo]

Masayuki, it looks like this has landed properly on Nightly & Aurora so can you update the status flags for 29 & 30 when you come back to put in your beta landing links?

Comment 89

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

The reason why I've not changed the flags yet is that we still watching if this bug is completely fixed by the last patch. So, it's not enough only the approved patches to fix this bug completely. Although, they actually reduce the number of crash reports.

But yes, I'll change the flags when I believe this bug completely fixed on each branch.

Comment 90

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

The latest build which reported this crash is 2/17's build. LGTM. Let's keep watching the stats for a couple of days.

https://crash-stats.mozilla.com/report/list?signature=mozilla%3A%3Awidget%3A%3ANativeKey%3A%3AGetFollowingCharMessage%28tagMSG%26%29&#tab-reports

Comment 91

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/releases/mozilla-beta/rev/e0abf66b4e04
https://hg.mozilla.org/releases/mozilla-beta/rev/0fe827107658

I think that we should uplift the last patch too.

Comment 92

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g28_v1_3/rev/e0abf66b4e04
https://hg.mozilla.org/releases/mozilla-b2g28_v1_3/rev/0fe827107658

Comment 93

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8377472 [details] [diff] [review]
NativeKey should not check scan code at comparing found char message and removed char message (landed on m-c and aurora)

[Approval Request Comment]
User impact if declined: This avoids the remaining known case of this crash.
Testing completed (on m-c, etc.): Landed only on m-c. After the landing, we've not see this crash. (20140217030202 is the latest build of 30.0a1, this is landed on 2/18)
https://crash-stats.mozilla.com/report/list?signature=mozilla%3A%3Awidget%3A%3ANativeKey%3A%3AGetFollowingCharMessage%28tagMSG%26%29&#tab-reports
Risk to taking this patch (and alternatives if risky): Very low risk. The scan code difference has no problem.
String or IDL/UUID changes made by this patch: Nothing.

Comment 94

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8377472 [details] [diff] [review]
NativeKey should not check scan code at comparing found char message and removed char message (landed on m-c and aurora)

https://hg.mozilla.org/releases/mozilla-aurora/rev/744c8107734f

Comment 95

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

On Nightly, the 17th day's build is the last crashable build. So, this bug must be fixed completely with the last patch.

Comment 96

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Oh...

https://crash-stats.mozilla.com/report/index/6df449ed-302f-49e6-bd0e-f86a12140224
https://crash-stats.mozilla.com/report/index/4b6872b7-f710-4a55-8361-dce462140224
https://crash-stats.mozilla.com/report/index/90952072-757c-4213-8149-2d79a2140224

These are reported only from Metrofox.

> Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000020, lParam: 0x00390001, InSendMessageEx()=ISMEX_NOSEND, 
> Found message: WM_CHAR (0x00000102), wParam: 0x00000020, lParam: 0x00390001

This might indicate we need to work more for this bug...
# This log indicates PeekMessage(RM_REMOVE) failed due to no message.

Comment 97

[Marco Mucci [:MarcoM]]

Hey Kamil, would you tag this as [qa+] or [qa-]?

Comment 98

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/39ff71c70bf8

Comment 99

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g28_v1_3/rev/39ff71c70bf8

Comment 100

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Hmm, as I said in comment 96, we need more research and work.

Comment 101

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Attachment: Log more details in the queue when PeekMessage() fails to remove found char message

I guess that failure of PeekMessage(PM_REMOVE) is caused by focus move or exiting apps. I want to see state of the queue. Let's land this on both m-c and Aurora. This is reported only from Metrofox of Aurora. I guess that the remaining crash occurs in really rare environment.

Comment 102

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

I don't know if we should take the found char message or just ignore the phantom　char message because it might come later. This is reason why I want to see the message queue.

Comment 103

[u279076]

Flagging for verification via crashstats after the next Beta is on the wire for a few days.

Comment 104

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/8335da20a00e

Comment 105

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/8335da20a00e

Comment 106

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8381319 [details] [diff] [review]
Log more details in the queue when PeekMessage() fails to remove found char message

[Approval Request Comment]
User impact if declined: There is a case of remaining rare crash case. However, we don't know why that occurs. This patch logs more information of the Windows message queue at that time. We see the remaining crash's report only on Metrofox of Aurora. Therefore, we need to uplift this to Aurora for researching the cause.
Testing completed (on m-c, etc.): Landed on m-c.
Risk to taking this patch (and alternatives if risky): Not risky. This patch just adds additional information to the crash reporter before the call of MOZ_CRASH().
String or IDL/UUID changes made by this patch: Nothing.

Comment 107

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Wow, new case comes:

https://crash-stats.mozilla.com/report/index/cce66a0e-f415-4c95-aa7b-0e3342140226

> Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00001300, lParam: 0x00000000, InSendMessageEx()=ISMEX_NOSEND, 
> Found message: WM_DEADCHAR (0x00000103), wParam: 0x00001300, lParam: 0x00240001, 
> Removed message: WM_DEADCHAR (0x00000103), wParam: 0x00000000, lParam: 0x00000000

Looks like the dead key state is cleared by somebody. I guess WM_KEYDOWN or something is inserted before the WM_DEADCHAR...

Comment 108

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/b921918ab99b

Comment 109

[Jim Mathies [:jimm]]

Here's a new one on beta6, 2-24 release - 

https://crash-stats.mozilla.com/report/index/d820391e-5a90-4a88-bd83-cfe282140226

Handling message: WM_KEYDOWN (0x00000100), wParam: 0x0000000D, lParam: 0x001C0001, InSendMessageEx()=ISMEX_NOSEND, 
Found message: WM_CHAR (0x00000102), wParam: 0x0000000D, lParam: 0x001C0001

Comment 110

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://crash-stats.mozilla.com/report/index/7aff1c12-ef74-4e4b-afc0-d63642140227

> Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000030, lParam: 0x000B0001, InSendMessageEx()=ISMEX_NOSEND, 
> Found message: WM_CHAR (0x00000102), wParam: 0x00000030, lParam: 0x000B0001, 
> Removed message: WM_CHAR (0x00000102), wParam: 0x00000065, lParam: 0x00120001

This report seems that another case of the crash of comment 107.

While 0 keydown is handling, WM_CHAR for 0 is found. However, the removed message is WM_CHAR for e generated by e key...

I have no idea in which case this occurs...

Comment 111

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

(In reply to Jim Mathies [:jimm] from comment #109)
> Here's a new one on beta6, 2-24 release - 
> 
> https://crash-stats.mozilla.com/report/index/d820391e-5a90-4a88-bd83-
> cfe282140226
> 
> Handling message: WM_KEYDOWN (0x00000100), wParam: 0x0000000D, lParam:
> 0x001C0001, InSendMessageEx()=ISMEX_NOSEND, 
> Found message: WM_CHAR (0x00000102), wParam: 0x0000000D, lParam: 0x001C0001

We need 26 or later build's crash report on Nightly or Aurora... Unluckily, 25th build is the last report :-(

Comment 112

[Jim Mathies [:jimm]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #111)
> (In reply to Jim Mathies [:jimm] from comment #109)
> > Here's a new one on beta6, 2-24 release - 
> > 
> > https://crash-stats.mozilla.com/report/index/d820391e-5a90-4a88-bd83-
> > cfe282140226
> > 
> > Handling message: WM_KEYDOWN (0x00000100), wParam: 0x0000000D, lParam:
> > 0x001C0001, InSendMessageEx()=ISMEX_NOSEND, 
> > Found message: WM_CHAR (0x00000102), wParam: 0x0000000D, lParam: 0x001C0001
> 
> We need 26 or later build's crash report on Nightly or Aurora... Unluckily,
> 25th build is the last report :-(

This could have something to do with our funky async input handling, or it might have something to do with the soft keyboard. I'll try to find some time to do some investigating.

Comment 113

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Hmm...

https://crash-stats.mozilla.com/report/index/cad86ed7-093b-4e10-8d2b-16df12140228
https://crash-stats.mozilla.com/report/index/4108dcdb-aa41-4f2c-8958-5856d2140301
https://crash-stats.mozilla.com/report/index/6bc3ed50-5e98-4fb3-99a0-effd92140228
https://crash-stats.mozilla.com/report/index/e9519835-bb57-493c-9198-c4ff82140228
https://crash-stats.mozilla.com/report/index/29382059-998e-4bb5-a328-88bfe2140228
https://crash-stats.mozilla.com/report/index/ba22e1e1-756a-44ca-a85f-b0f2d2140302
https://crash-stats.mozilla.com/report/index/62bcadb9-5485-4586-be72-02c9b2140302

> Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000020, lParam: 0x00390001, hwnd=0x191258, InSendMessageEx()=ISMEX_NOSEND, 
> Found message: WM_CHAR (0x00000102), wParam: 0x00000020, lParam: 0x00390001, 
> WM_NULL has been removed: 1, 
> There is no key message in any window, 
> Next message in all windows: Unknown (0x0000C2ED), wParam: 0x00000000, lParam: 0x066F8970, hwnd=0x12124c, time=166724656

In these cases, found char message has gone after we found WM_NULL in the queue.

I think that we should just ignore the fact of found the message because it might be redirected to different thread or process or cancelled.

Only this report indicates such behavior:
https://crash-stats.mozilla.com/report/index/9b0156a9-cb0a-4324-80b0-ad6c02140302

> Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000008, lParam: 0x000E0001, hwnd=0x30360, InSendMessageEx()=ISMEX_NOSEND, 
> Found message: WM_DEADCHAR (0x00000103), wParam: 0x00000020, lParam: 0x000E0001, 
> WM_NULL has been removed: 0, 
> Next key message in all windows: WM_DEADCHAR (0x00000103), wParam: 0x00000020, lParam: 0x000E0001, hwnd=0x30360, time=10729640, 
> Next message in all windows: WM_DEADCHAR (0x00000103), wParam: 0x00000020, lParam: 0x000E0001, hwnd=0x30360, time=10729640

Comment 114

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #113)
> Only this report indicates such behavior:
> https://crash-stats.mozilla.com/report/index/9b0156a9-cb0a-4324-80b0-
> ad6c02140302
> 
> > Handling message: WM_KEYDOWN (0x00000100), wParam: 0x00000008, lParam: 0x000E0001, hwnd=0x30360, InSendMessageEx()=ISMEX_NOSEND, 
> > Found message: WM_DEADCHAR (0x00000103), wParam: 0x00000020, lParam: 0x000E0001, 
> > WM_NULL has been removed: 0, 
> > Next key message in all windows: WM_DEADCHAR (0x00000103), wParam: 0x00000020, lParam: 0x000E0001, hwnd=0x30360, time=10729640, 
> > Next message in all windows: WM_DEADCHAR (0x00000103), wParam: 0x00000020, lParam: 0x000E0001, hwnd=0x30360, time=10729640

Oops, I misread this log. This is really odd. There is the message which we want to remove from the queue. But PeekMessage() failed it.

Comment 115

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Attachment: When PeekMessage() fails to remove found char message, just ignore it (not to dispatch keyprese event)

I think that if PeekMessage(PM_REMOVE) fails due to losing message, we shouldn't dispatch keypress event because system/user expect that the key event shouldn't cause text input.

Even with this patch, there will be still remaining minor cases. However, I guess that it's enough for next release.

I believe that we need to redesign WM_CHAR message handling in other bug.

Comment 116

[Jim Mathies [:jimm]]

Comment on attachment 8384548 [details] [diff] [review]
When PeekMessage() fails to remove found char message, just ignore it (not to dispatch keyprese event)

Review of attachment 8384548 [details] [diff] [review]:
-----------------------------------------------------------------

::: widget/windows/KeyboardLayout.cpp
@@ +1358,5 @@
>                                 nextKeyMsg.message, nextKeyMsg.message,
>                                 PM_REMOVE | PM_NOYIELD)) {
> +      MSG nextKeyMsgInAllWindows;
> +      // The char message is redirected to different thread's window by focus
> +      // move or someting or just calcelled by external application.

nit - comment needs cleanup: 'someting', 'calcelled'

Comment 117

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/cb3551d93d56

Comment 118

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/cb3551d93d56

Comment 119

[Sylvestre Ledru [:Sylvestre]]

I am updating the status-firefox28 & status-firefox29 since it was reopened.

Comment 120

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8384548 [details] [diff] [review]
When PeekMessage() fails to remove found char message, just ignore it (not to dispatch keyprese event)

[Approval Request Comment]
User impact if declined: Some users still meet this crash due to strange behavior of something like a11y tools. This patch avoids the most crash cases of renaming cases.
Testing completed (on m-c, etc.): Landed on m-c.
Risk to taking this patch (and alternatives if risky): The risk is low. However, instead of that users will meet this crash, they may see different bug that they try to input some text but some characters may be not inputted actually. Anyway, we are not sure why we loses found char message... If such bug won't be filed, we have no change to fix such bug if there is.
String or IDL/UUID changes made by this patch: Nothing.

Comment 121

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/0ff3e973d66c

Comment 122

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8381319 [details] [diff] [review]
Log more details in the queue when PeekMessage() fails to remove found char message

[Approval Request Comment]
User impact if declined: This patch just appending additional information to the crash report. This is necessary for applying next patch.
Testing completed (on m-c, etc.): Landed on m-c and Aurora.
Risk to taking this patch (and alternatives if risky): Nothing.
String or IDL/UUID changes made by this patch: Noting.

Comment 123

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8384548 [details] [diff] [review]
When PeekMessage() fails to remove found char message, just ignore it (not to dispatch keyprese event)

[Approval Request Comment]
User impact if declined: This patch avoids to crash with a cause which is the most frequent of remaining causes.
Testing completed (on m-c, etc.): Landed on m-c and Aurora. Although, the landing dates are in a couple of days. However, I recommend to uplift them as far as possible for QA.
Risk to taking this patch (and alternatives if risky): Low risk. But instead of avoiding the crash, users might see that text input sometimes fails in the case.
String or IDL/UUID changes made by this patch: Nothing.

Comment 124

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Attachment: Collect more details of the queue status when we removed unexpected char message from the queue

Although, we cannot land next fix in this cycle, we should try the last issue which has already known.

This patch collects the message queue information when we remove unexpected char message. We need to lift this up to beta because some beta users sometimes meet this case.

Comment 125

[Jim Mathies [:jimm]]

Comment on attachment 8386593 [details] [diff] [review]
Collect more details of the queue status when we removed unexpected char message from the queue

In the case of metrofx, we only have one window. Not sure if the "other window" dumps will hit on anything. Be interesting to see the output.

Comment 126

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/6261d982a867
https://hg.mozilla.org/releases/mozilla-beta/rev/1f65632180df

Comment 127

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g28_v1_3/rev/6261d982a867
https://hg.mozilla.org/releases/mozilla-b2g28_v1_3/rev/1f65632180df

Comment 128

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/22f582a3a583

Comment 129

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Comment on attachment 8386593 [details] [diff] [review]
Collect more details of the queue status when we removed unexpected char message from the queue

[Approval Request Comment]
User impact if declined: This patch collects more information when we remove unexpected char message which case is the last known reason of this crash.
Testing completed (on m-c, etc.): Landed on m-c.
Risk to taking this patch (and alternatives if risky): Nothing, this appends additional information to the crash report's note before a call of MOZ_CRASH().
String or IDL/UUID changes made by this patch: Nothing.

Comment 130

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/b4d0524265ec

Comment 131

[u279076]

Can this be marked fixed now? We'll need to have this flagged as fixed before it can be verified.

Comment 132

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

(In reply to Anthony Hughes, QA Mentor (:ashughes) from comment #131)
> Can this be marked fixed now? We'll need to have this flagged as fixed
> before it can be verified.

I believe that we succeeded to _reduce_ the number of crashes, however, we've not this bug completely yet...

This bug is not too long and fixed a lot of crash cases. So, this bug isn't good as a bug in bugzilla. I'll separate this bug as each issue, then, you can verify fix of each cases with crash reports.

Comment 133

[u279076]

Sounds good, thanks Masayuki. Marking this bug as such so we can verify the effect this bug has had on "fixed" branches.

Comment 134

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

I think that this should be open as a meta bug of the signatures.

Comment 135

[Robert Kaiser]

A meta bug with checked-in patches is an absolute no-no usually but you made it into that. :(

I prefer closing the bug with the patches, try to verify there that they helped and exclusively only open followup bug for any remaining issues or things that didn't work correctly.

This here is a total mess now. :(

Comment 136

[Robert Kaiser]

Also, if this bug stays open, please remove any tracking flags as a meta bug doesn't qualify for tracking per definition.

Comment 137

[mmmhamd511]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #134)
> I think that this should be open as a meta bug of the signatures.

Comment 138

[mmmhamd511]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #134)
> I think that this should be open as a meta bug of the signatures.

Comment 139

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Some stack traces are odd:

https://crash-stats.mozilla.com/report/index/23e5dc1c-b4c1-4258-91ca-9bc1b2170127
https://crash-stats.mozilla.com/report/index/1f493b94-32a1-4d65-b588-2c26c2170127
https://crash-stats.mozilla.com/report/index/451785c0-f555-403f-a1ac-c943a2170128
https://crash-stats.mozilla.com/report/index/af28555b-b7f8-42b2-aac1-b72c32170128
https://crash-stats.mozilla.com/report/index/6a670f6d-2b48-44dd-b102-f251d2170128

nsWindow::ProcessKeyDownMessage(tagMSG const&, bool*) is suddenly called from unexpected methods.

Makoto-san, do you know if this kind of stack traces are just broken result of Breakpad? Or they indicate crashes caused by already broken memory?

Comment 140

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Oops, Kato-san, I forgot to ni? to you at writing previous comment, please check it.

Comment 141

[Makoto Kato [:m_kato]]

(In reply to Masayuki Nakano [:masayuki] from comment #139)
> Some stack traces are odd:
> 
> https://crash-stats.mozilla.com/report/index/23e5dc1c-b4c1-4258-91ca-
> 9bc1b2170127
> https://crash-stats.mozilla.com/report/index/1f493b94-32a1-4d65-b588-
> 2c26c2170127
> https://crash-stats.mozilla.com/report/index/451785c0-f555-403f-a1ac-
> c943a2170128
> https://crash-stats.mozilla.com/report/index/af28555b-b7f8-42b2-aac1-
> b72c32170128
> https://crash-stats.mozilla.com/report/index/6a670f6d-2b48-44dd-b102-
> f251d2170128
> 
> nsWindow::ProcessKeyDownMessage(tagMSG const&, bool*) is suddenly called
> from unexpected methods.
> 
> Makoto-san, do you know if this kind of stack traces are just broken result
> of Breakpad? Or they indicate crashes caused by already broken memory?

Until Firefox 51, we use omit-frame-poitner option to build Firefox.  So on x86 build, we cannot get correct stack trace well.  But from Firefox 52, we won't use it (but it might cause performance issue) by bug 1322735.

Also, since crash report server doesn't install Windows symbols of all version automatically now, some stack (into user32.dll etc) cannot be resolved.

Comment 142

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Thank you for the information. But the reports are from 52 Beta, so, I still don't understand what occurs...

Comment 144

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

According to the result of bug 1335306, the keyboard layout of all crash reports with 53.0b3 is, "US". This means that the users are using hacky key input utilities which *should* be created as keyboard layout or IME. Instead of using Windows's multiple keyboard layouts feature, the hacky keyboard layouts _override_ US keyboard layout behavior at runtime.

One is C-DAC's product but still not sure which product is exactly the cause, though. The company releases at least a software keyboard:
https://cdac.in/index.aspx?id=mc_ilf_Keyboard
This supports to input Bengali, Assamese and Manipuri. So, around India users the most victims of this crash.

On the other hand, there are some crash reports which include Chinese character, '㕲'. This is bug 1336322 and bug 1336331. Oddly, these odd cases also caused by US keyboard layout, but there are no unknown DLL file in their reports. So, I have no idea what's the cause of these bugs, sigh.

Comment 145

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

Except some edge cases, we have no report with latest versions. So, we should mark this bug as FIXED for now. If you still hit this crash, please file a new bug and let us know what keyboard layout are you using and what result is expected at the crash. Because we cannot decide which information coming from your keyboard layout is respected due to the keyboard layout's bug.