1267526 - [non-e10s][TSF] First character of IME input is committed immediately in Google contacts

Status: RESOLVED FIXED

(Core :: DOM: Events, defect)

Description

[Brian Birtles (:birtles, Feb 26~ parental leave)]

Attachment: screenshot.png

STR:
1. Go to https://contacts.google.com/u/0/preview/all
(You will need a regular Google account, not a corporate one. If you get redirected to https://www.google.com/contacts/u/0/?cplus=0#contacts the bug won't reproduce.)
2. Click the red '+' button in the bottom right to create a new contact.
3. Type 'Test' or something for the name
4. Click 'Create'
5. Click on the 'Add an address' line
6. Activate a Japanese IME (I can reproduce with MS-IME and Google IME)
7. Type yuubin

Expected results:
ゆうびん is displayed with appropriate candidates (郵便 etc.)

Actual results:
'y' is committed immediately and ううびん becomes the uncommitted string

This can also be reproduced by taking an existing contact, clearing the address and trying to enter a new address.

I can reproduce on Nightly and Aurora on different (Windows 10) computers.

Comment 1

[Andrew Overholt [:overholt]]

This seems pretty bad. Do you know someone who can fix this, Brian?

Comment 2

[Brian Birtles (:birtles, Feb 26~ parental leave)]

According to Makoto, Masayuki knows this code best. He's away this week, however, so I'll follow up with him early next week.

Comment 3

[Makoto Kato [:m_kato]]

When not using e10s, this issue occurs.

But when using e10s, another problem occur w/ TSF.
1. Input 'ああ'

Result
Show uncommitted 'ああ' + committed 'あ’


Maybe, Google apps updates composition or text on input event or another event.  So composition state will be broken.

Comment 4

[Brian Birtles (:birtles, Feb 26~ parental leave)]

Hi Mike, we're trying to debug Google Contacts to work out what the Javascript is doing here in response to the 'input' (and possibly 'keypress') events but the minified source is a real pain to work out. The "Auto Prettify Minified Sources" function also doesn't seem to work for me. What tools do you normally use to dig into complex and minified sites like this in your web compat work?

Comment 5

[Brian Birtles (:birtles, Feb 26~ parental leave)]

Confirmed that this same issue occurs in Firefox 45 and 46 so if it is a regression, it is not a recent one.

Comment 6

[Mike Taylor [:miketaylr]]

Hey Brian,

Yeah, Fx DevTools struggles with minified sources (I can never get breakpoints to stick after "beautify"-ing them). Depending on the issue, I end up using a combination of Chrome DevTools debugger and Charles proxy's "Map Local"[1] to serve a locally beautified script. 

http://www.jsnice.org/ is also helpful to get more context on minified code, but it's online only.

That said, Hallvord has done some work debugging IME on Google properties, he might be able to lend a hand here.

[1] https://www.charlesproxy.com/documentation/tools/map-local/

Comment 7

[Brian Birtles (:birtles, Feb 26~ parental leave)]

That's great, thanks Mike!

Comment 8

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

log in non-e10s mode:

> 5912[156dd31d800]: TSF: 0x156f7ff5c00   Unlocked (TS_LF_READWRITE) <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::FlushPendingActions() flushing COMPOSITION_START={ mSelectionStart=0, mSelectionLength=0 }
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::FlushPendingActions() dispatching compositionstart event...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::OnUpdateCompositionInternal(), mDeferNotifyingTSF=false
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::MaybeFlushPendingNotifications(), putting off flushing pending notifications due to being the document locked...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::FlushPendingActions() flushing COMPOSITION_UPDATE={ mData="お", mRanges=0x156870cbc40, mRanges->Length()=2 }
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::FlushPendingActions() dispatching compositionchange event...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::OnUpdateCompositionInternal(), mDeferNotifyingTSF=false
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::MaybeFlushPendingNotifications(), putting off flushing pending notifications due to being the document locked...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::OnTextChangeInternal(aIMENotification={ mMessage=0x00000004, mTextChangeData={ mStartOffset=0, mRemovedEndOffset=0, mAddedEndOffset=1, mCausedOnlyByComposition=true, mIncludingChangesDuringComposition=false, mIncludingChangesWithoutComposition=false }), mSink=0x156f1146f08, mSinkMask=TS_AS_TEXT_CHANGE | TS_AS_SEL_CHANGE | TS_AS_LAYOUT_CHANGE | TS_AS_ATTR_CHANGE | TS_AS_STATUS_CHANGE, mComposition.IsComposing()=true
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::OnSelectionChangeInternal(aIMENotification={ mSelectionChangeData={ mOffset=1, Length()=0, mReversed=false, mWritingMode=Horizontal, mCausedByComposition=false, mCausedBySelectionEvent=false, mOccurredDuringComposition=true } }), mSink=0x156f1146f08, mSinkMask=TS_AS_TEXT_CHANGE | TS_AS_SEL_CHANGE | TS_AS_LAYOUT_CHANGE | TS_AS_ATTR_CHANGE | TS_AS_STATUS_CHANGE, mIsRecordingActionsWithoutLock=false, mComposition.IsComposing()=true
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::MaybeFlushPendingNotifications(), putting off flushing pending notifications due to being the document locked...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::MaybeFlushPendingNotifications(), mLockedContent is cleared
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::MaybeFlushPendingNotifications(), calling TSFTextStore::NotifyTSFOfLayoutChange()...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::NotifyTSFOfLayoutChange(), calling ITextStoreACPSink::OnLayoutChange()...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00 TSFTextStore::RequestLock(dwLockFlags=TS_LF_READ, phrSession=0x42803fe9e0), mLock=not-specified, mDestroyed=false
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   Locking (TS_LF_READ) >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

<snip>

> 5912[156dd31d800]: TSF: 0x156f7ff5c00   Unlocked (TS_LF_READWRITE) <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::MaybeFlushPendingNotifications(), calling TSFTextStore::NotifyTSFOfSelectionChange()...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::NotifyTSFOfSelectionChange(), committing the composition for avoiding making TIP confused...
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::CommitCompositionInternal(aDiscard=false), mSink=0x156f1146f08, mContext=0x156f10cb8e0, mComposition.mView=0x156f126e1a0, mComposition.mString="お"
> 5912[156dd31d800]: TSF: 0x156f7ff5c00   TSFTextStore::CommitCompositionInternal(), requesting TerminateComposition() for the context 0x156f10cb8e0...

So, looks like web contents reset selection even there is composition string.

Comment 9

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=a922502d9170

Comment 10

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

It seems that the e10s mode's bug will be fixed by bug 1224994.

Committing composition forcibly occurs unnecessary selection change notification from IMEContentObserver (I'm still not sure the reason, though). But we can avoid this bug with checking if the selection is actually changed in TSFTextStore.

I wonder, this might be reproduced on Linux too.

Comment 11

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Attachment: MozReview Request: Bug 1267526 part.0 IMMHandler and TSFTextStore should use LazyLogModule instead of PR_NewLogModule for consistency with related logs in dom/events r?m_kato

Review commit: https://reviewboard.mozilla.org/r/52105/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/52105/

Comment 12

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Attachment: MozReview Request: Bug 1267526 part.1 TSFTextStore shouldn't notify TSF of selectin change when the selection isn't actually changed r?m_kato

Review commit: https://reviewboard.mozilla.org/r/52107/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/52107/

Comment 13

[Makoto Kato [:m_kato]]

Comment on attachment 8751568 [details]
MozReview Request: Bug 1267526 part.0 IMMHandler and TSFTextStore should use LazyLogModule instead of PR_NewLogModule for consistency with related logs in dom/events r?m_kato

https://reviewboard.mozilla.org/r/52105/#review49051

Comment 14

[Makoto Kato [:m_kato]]

Comment on attachment 8751569 [details]
MozReview Request: Bug 1267526 part.1 TSFTextStore shouldn't notify TSF of selectin change when the selection isn't actually changed r?m_kato

https://reviewboard.mozilla.org/r/52107/#review49061

Comment 15

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/f062b5921a2e
https://hg.mozilla.org/integration/mozilla-inbound/rev/63073a4784cf

Comment 16

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/f062b5921a2e
https://hg.mozilla.org/mozilla-central/rev/63073a4784cf

Comment 17

[Hallvord R. M. Steen [:hallvors]]

I did start investigating this, but Masayuki-san was too fast :D

Comment 18

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

(In reply to Hallvord R. M. Steen [:hallvors] from comment #17)
> I did start investigating this, but Masayuki-san was too fast :D

I guessed the cause from IME module's log but I'm still not sure what causes this bug. If you can investigate what Google does, it's very helpful to us for writing tests. If you have much time to investigate this, could you do that?

Comment 19

[Hallvord R. M. Steen [:hallvors]]

Sure, will do.

Comment 20

[Hallvord R. M. Steen [:hallvors]]

I've figured out that if you stop listening to input events, this doesn't happen.

Comment 21

[Hallvord R. M. Steen [:hallvors]]

(I still need to find the exact code that somehow modifies the selection in an oninput handler..)