1638616 - JavaScript error: resource://gre/modules/IMIncomingServer.jsm, line 165: TypeError: can't access property "setBool", this.imAccount is null

Status: NEW

(Thunderbird :: Testing Infrastructure, defect, P3)

Description

[ISHIKAWA, Chiaki]

Attachment: Excerpt from local mochitest log where the error occured.

During mochitest execution with FULL DEBUG version of TB under Debian
GNU/Linux 64-bit, I saw the following error.

JavaScript error: resource://gre/modules/IMIncomingServer.jsm, line 165: TypeError: can't access property "setBool", this.imAccount is null

I think the error is architecture neutral and so I set it to ALL.

The source code in question is as follows.

IMIncomingServer.jsm
https://searchfox.org/comm-central/source/mail/components/im/IMIncomingServer.jsm#165

  setBoolValue(aPrefName, aValue) {
    this.imAccount.setBool(aPrefName, aValue); <===
  },

The error seems to happen before an individual test occurs.
It seems that the error occurs on the dummy server side of the test,
but I am not certain.
The following shows the location of the error from the viewpoint of
mochitest sequence.

egrep "(TEST_START|TEST_END|Entering test|Leaving test|this.imAccount is null)" /FF-NEW/log1223-mochitest.txt

...

109:16.48 TEST_START: comm/mail/test/browser/folder-widget/browser_messageFilters.js
109:16.64 INFO Entering test bound setupModule
109:16.74 INFO Leaving test bound setupModule
109:16.74 INFO Entering test bound test_message_filter_shows_newsgroup_server
109:17.96 INFO Leaving test bound test_message_filter_shows_newsgroup_server
109:17.96 INFO Entering test bound test_customize_toolbar_doesnt_double_get_mail_menu
109:24.01 INFO Leaving test bound test_customize_toolbar_doesnt_double_get_mail_menu
109:24.01 INFO Entering test bound test_address_books_appear_in_message_filter_dropdown
109:25.54 INFO Leaving test bound test_address_books_appear_in_message_filter_dropdown
109:25.54 INFO Entering test bound test_can_cancel_quit_on_filter_changes
109:27.04 INFO Leaving test bound test_can_cancel_quit_on_filter_changes
109:27.04 INFO Entering test bound test_can_quit_on_filter_changes
109:27.19 INFO Leaving test bound test_can_quit_on_filter_changes
109:27.21 TEST_END: Test OK. Subtests passed 12/12. Unexpected 0
110:07.04 GECKO(953119) JavaScript error: resource://gre/modules/IMIncomingServer.jsm, line 165: TypeError: can't access property "setBool", this.imAccount is null
110:10.89 TEST_START: comm/mail/test/browser/im/browser_chatTabRestore.js
110:11.07 INFO Entering test bound test_chat_tab_restore
110:11.29 INFO Leaving test bound test_chat_tab_restore
110:11.38 TEST_END: Test OK. Subtests passed 3/3. Unexpected 0
110:11.38 TEST_START: comm/mail/test/browser/im/browser_toolbarButtons.js
...

I am attaching an excerpt from my local mochitest execution with FULL
DEBUG version of TB.
The log is more verbose than normal execution because I have added
local debug dump.

As I mention, it seems that the error message appears BETWEEN individual test.

Possibly related: Bug 1230500
TypeError: this.imAccount is null when opening tab under Account Settings

Comment 1

[ISHIKAWA, Chiaki]

The error is visible on tryserver as well.
For example,
https://firefoxci.taskcluster-artifacts.net/PsAVG86SRpGAD6j6V1le6A/0/public/logs/live_backing.log

Comment 2

[Khushil Mistry [:khushil324]]

Attachment: Bug-1638616_setBool-imAccount-error-0.patch

This is error is coming from https://searchfox.org/comm-central/source/mail/components/im/content/imAccountWizard.js#396-400. (When you try to create the chat account)

We can simply add the if condition here. Setting up the imAccount object details while creating the incoming server is of no use. So when we assign it here: https://searchfox.org/comm-central/source/mail/components/im/content/imAccountWizard.js#401, the right the imAccount object is assigned to an incoming server.

Comment 3

[Patrick Cloke [:clokep]]

This doesn't seem like the right fix -- wouldn't we need to apply it to each of the types of option setters then? Shouldn't we be assuring that the imAccount is setup before trying to initialize the incoming server?

I'm not really sure of the interaction between incoming server and imAccount though.

Comment 4

[Khushil Mistry [:khushil324]]

(In reply to Patrick Cloke [:clokep] from comment #3)

This doesn't seem like the right fix -- wouldn't we need to apply it to each of the types of option setters then? Shouldn't we be assuring that the imAccount is setup before trying to initialize the incoming server?

imAccount is getting initialized earlier. We can not pass it before initializing the incoming server and while we initialize the incoming server, we are using setBool and setBool is accessing the imAccount object. But whatever the incoming server is trying to set through setBool, it is already set in the imAccount object. And then here: https://searchfox.org/comm-central/source/mail/components/im/content/imAccountWizard.js#401, just after the initializing the incoming server, we are setting the imAccount for it.

Comment 5

[Florian Quèze [:florian]]

Which code is triggering a setBoolValue call on an incoming server that isn't fully created? Is this a regression?

Comment 6

[ISHIKAWA, Chiaki]

(In reply to Florian Quèze [:florian] from comment #5)

Which code is triggering a setBoolValue call on an incoming server that isn't fully created? Is this a regression?

"Is this a regression?": Hard to say.
Mochitest for TB was enabled December 2019 and former |make mozmill| test is gone.
I have begun running mochitest ONLY since January this year.
The first local mochitest I managed to run to completion on Jan 23 already had this error.

The tests for IM and calendar seem to be richer in mochitest than in |make mozmill| days (I am not sure. Just an impression.)
It took me a while to figure out what are important errors and warnings in mochitest after checking various errors and modified a script to extract and summarize such errors/warnings.

That I cannot successfully run mochitest for TB under valgrind is my biggest gripe regarding the new test paradigm.
And it is slow, takes close to twice the time it took |make mozmill| to finish. (But then, as I mention, there may be more tests in mochitest. I don't know. But surely there are easily noticeable visible delays between tests.)

Anyway, I inserted console.trace() in IMIncomingServer.jsm to trigger when the error occurs.
I am running the local test again. Will report the result tomorrow morning.
So we will at least know a single caller case which is triggering the error.
(There may be other error scenarios that may pop up after an initial band aid is applied.)

Comment 7

[ISHIKAWA, Chiaki]

Attachment: console.trace() output in a mochitest run: comm/mail/test/browser/account/browser_accountTelemetry.js

I obviously forgot to upload the log from my local test.
Here it is.
The error is triggered by
chrome://mochitests/content/browser/comm/mail/test/browser/account/browser_accountTelemetry.js 40 test_account_types (???)

Comment 8

[ISHIKAWA, Chiaki]

Attachment: console.trace() output in a mochitest run: chatHandler.jsm

I now realize there are TWO places where the error is reported.
The other error is after mochitestserver is started and chatHandler.jsm is invoked.
Local log is attached. (I removed verbose debug dumps manually.)

Comment 9

[Patrick Cloke [:clokep]]

Comment on attachment 9155204 [details] [diff] [review]
Bug-1638616_setBool-imAccount-error-0.patch

Clearing the review flag here, Florian's question from comment 5 needs answering.

Comment 10

[ISHIKAWA, Chiaki]

(In reply to Patrick Cloke [:clokep] from comment #9)

Comment on attachment 9155204 [details] [diff] [review]
Bug-1638616_setBool-imAccount-error-0.patch

Clearing the review flag here, Florian's question from comment 5 needs
answering.

Please see comment 7. Is this enough?

The error is triggered by
chrome://mochitests/content/browser/comm/mail/test/browser/account/browser_accountTelemetry.js 40 test_account_types (???)

Comment 11

[Patrick Cloke [:clokep]]

(In reply to ISHIKAWA, Chiaki from comment #10)

Please see comment 7. Is this enough?

The error is triggered by
chrome://mochitests/content/browser/comm/mail/test/browser/account/browser_accountTelemetry.js 40 test_account_types (???)

Maybe? But if it explains what is happening then I'm not seeing it. It would be nice to have an explanation of why this change is the correct change to make.

Comment 12

[Magnus Melin [:mkmelin]]

Looks like it's caused by MailServices.accounts.createIncomingServer creating an im account ->
https://searchfox.org/comm-central/rev/ec64095d118d299477d3e5f9fd2dc11912d0b573/mailnews/base/src/nsMsgAccountManager.cpp#414

Worth doing some debugging and see if/when the account is set vs. when the c++ pref wants to get set. At https://searchfox.org/comm-central/rev/ec64095d118d299477d3e5f9fd2dc11912d0b573/mail/components/im/IMIncomingServer.jsm#19-29

Depending on if there's some object creation timing issue, the c++ could set the mail.server.<key>.canChangeStoreType pref directly instead.

Comment 13

[Magnus Melin [:mkmelin]]

Fairly annoying console error spew...