1038089 - Log the behavior of IMEStateManager for debug

Status: RESOLVED FIXED

(Core :: DOM: UI Events & Focus Handling, enhancement)

Description

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

I sometimes struggle with a strange bugs which could be a bug of IMEStateManager. However, most IMEStateManager methods are called at changing focus. Therefore, it's always troublesome.

I'd like to add NSPR logging code in IMEStateManager for debug.

Comment 1

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

Attachment: Patch

Comment 2

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

Comment on attachment 8456160 [details] [diff] [review]
Patch

This is not a part of release build.

This allows to log IMEStateManager behavior. The reason why I need this is, IMEStateManager is difficult to debug since it is worked with nsFocusManager.

The log style is same as widget/windows/nsTextStore.cpp. Using PR_LOG_ALWAYS, PR_LOG_ERROR and PR_LOG_DEBUG allows to log only what developer needs.

Comment 3

[Olli Pettay [:smaug][[e-mail]]]

Comment on attachment 8456160 [details] [diff] [review]
Patch

>+/**
>+ * When a method is called, log its arguments and/or related static variables
>+ * with PR_LOG_ALWAYS.  However, if it puts too many logs like
>+ * OnDestroyPresContext(), should log immediately before doing something
>+ * actually. In this case, the log should start with "ISM: <method name>".
I don't understand the comment "should log immediately ..."

> IMEStateManager::Shutdown()
> {
>+  PR_LOG(sISMLog, PR_LOG_ALWAYS,
>+    ("ISM: IMEStateManager::Shutdown(), "
>+     "sTextCompositions=0x%p, sTextCompositions->Length()=%u",
>+     sTextCompositions, sTextCompositions ? sTextCompositions->Length() : 0));
I'm surprised that PR_LOG doesn't put 0x with %p by default.
(since IIRC, 0x is there with printf at least on Linux and OSX, but not on Windows)

>     if (context.mIMEState.mEnabled == newState.mEnabled) {
>-      // the enabled state isn't changing.
>+      PR_LOG(sISMLog, PR_LOG_DEBUG,
>+        ("ISM:   IMEStateManager::OnChangeFocusInternal(), "
>+         "neither focuse nor IME state is not chaning"));
focuse ? chaning?
I guess
"neither focus nor IME state is changing"

>-IMEStateManager::DestroyTextStateManager()
>+IMEStateManager::DestroyIMEContentObserver()
Not really about this bug, but fine

>   nsCOMPtr<nsIWidget> widget = sPresContext->GetRootWidget();
>   if (!widget) {
>+    PR_LOG(sISMLog, PR_LOG_ERROR,
>+      ("ISM:   IMEStateManager::CreateIMEContentObserver(), FAILED due to "
>+       "there is root widget for the nsPresContext"));
is a root


>+  PR_LOG(sISMLog, PR_LOG_DEBUG,
>+    ("ISM:   IMEStateManager::CreateIMEContentObserver() is creating "
>+     "IMEContentObserver instance..."));
creating an ...




mostly rs+, since I rarely use prlog stuff

Comment 4

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

Thank you.

(In reply to Olli Pettay [:smaug] from comment #3)
> I'm surprised that PR_LOG doesn't put 0x with %p by default.
> (since IIRC, 0x is there with printf at least on Linux and OSX, but not on
> Windows)

Oh, really? I've never realized the difference. I'll check it on Linux and if 0x is appended automatically, I'll use macro for %p.

Comment 5

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

Ah, it's %p, not %x, then, just dropping %p isn't problem.

Comment 6

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

On both Ubuntu and Mac OS X, %p doesn't show with "0x". So, I'll keep it.

Comment 7

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

https://hg.mozilla.org/integration/mozilla-inbound/rev/1ecced1dc1c2

Comment 8

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/1ecced1dc1c2