1589779 - C-C TB Strange *LOCAL* linux |make xpcshell-test| errors. All related to indexedDB tests?

Status: RESOLVED WORKSFORME

(Testing :: XPCShell Harness, defect, P3)

Description

[ISHIKAWA, Chiaki]

Attachment: log1083-xpcshell.txt: *LOCAL* linux |mach xpcshell-test| log with many indexedDB errors.

I could successfully run |mach xpcshell-test| LOCALLY on August 25th.
The summary lines from the test are shown below.

666:27.62 INFO INFO | Result summary:
666:27.62 INFO INFO | Passed: 3189
666:27.62 INFO INFO | Failed: 8
666:27.62 INFO INFO | Todo: 4
666:27.62 INFO INFO | Retried: 14
666:27.62 SUITE_END

Betwenn August 25 and a few days ago, something has changed and now I get the following errors during my LOCAL run of xpcshell-test.
(Ouch forgot to insert this initially. Sorry.)
225:05.14 INFO INFO | Result summary:
225:05.14 INFO INFO | Passed: 3121
225:05.14 INFO INFO | Failed: 127
225:05.14 INFO INFO | Todo: 4
225:05.14 INFO INFO | Retried: 131
225:05.14 SUITE_END

However, the remote tryserver DOES NOT such errors. See, for example,
https://treeherder.mozilla.org/#/jobs?repo=try-comm-central&revision=66ef3c2b0a7daf6d91aba1af924ca769f8cd282e

I am stumped to see where to look.
Running xpcshell-test successfully is very important to check the sanity of my local patches before submission.
Also, sometimes I have to run debugger and other tools to figure out what is wrong with my patch that fails the tests. This I cannot do with tryserver run.

My environment is the latest Debian GNU/Linux that runs inside virtualbox hosted on Windows 10 Pro.
uname -a
Linux ip030 5.2.0-2-amd64 #1 SMP Debian 5.2.9-2 (2019-08-21) x86_64 GNU/Linux

I am mentioning the Debian name because I suspect it could be related to some security setting that may hinder some local daemon to operate correctly?

From the attached log, I see error such as

• timed out tests,
• SQL syntax errors which seem to be lacking an indentifier somehow,
• " ERROR Unexpected exception Error: IndexedDB clear() The operation failed for reasons unrelated to the database itself and not covered by any other error code. at resource://services-common/kinto-offline-client.js:603"
• etc.

OR, is |mach xpcshell-test| no longer intenteded to execute locally?

I mean some tests in |make mozmill| seem to assume certain daemons running on certain ports which may collide with my local daemons.
(and as a matter of fact, |make mozmill| seemed to use example.{org,com} domain names thinking that they won't collide with tester's domain: unfortunately, I used the said domain names within my firewall on this computer and thus some test inevitably failed until I changed my local domain within my firewall to |example.localdomain|. Hmm...

So there can be various issues related to system setting that may have changed on my end without my knowning due to package upgrade of Debian GNU/Linux.
I also recall something about new javascript-based DB being substituted for mork database, and that may explain I see many errors related to kinto-offline-client.js.

Any tips to look into this issue are appreciated.

Comment 1

[ISHIKAWA, Chiaki]

OR, is |mach xpcshell-test| no longer intenteded to execute locally?

I mean some tests in |make mozmill| seem to assume certain daemons running on certain ports which may collide with my local daemons.
(and as a matter of fact, |make mozmill| seemed to use example.{org,com} domain names thinking that they won't collide with tester's domain: unfortunately, I used the said domain names within my firewall on this computer and thus some test inevitably failed until I changed my local domain within my firewall to |example.localdomain|. Hmm...

I meant to say that maybe |mach xpcshell-test| may have introduced such hard-coded domain names and such(?)

TIA

Comment 2

[Geoff Brown [:gbrown]]

I ran 'mach xpcshell-test' locally against mozilla-central (different from the report, but convenient for me) on ubuntu 18.04 and tests generally passed:

Ran 3896 checks (195 subtests, 3701 tests)
Expected results: 3593
Skipped: 296 tests
Unexpected results: 7
  test: 4 (4 fail)
  subtest: 3 (3 fail)

Comment 3

[ISHIKAWA, Chiaki]

(In reply to Geoff Brown [:gbrown] from comment #2)

I ran 'mach xpcshell-test' locally against mozilla-central (different from the report, but convenient for me) on ubuntu 18.04 and tests generally passed:

Ran 3896 checks (195 subtests, 3701 tests)
Expected results: 3593
Skipped: 296 tests
Unexpected results: 7
  test: 4 (4 fail)
  subtest: 3 (3 fail)

Thank you for the pointer.

I see. Then either

1. C-C has changed something that does not work right for local tester, or
2. my Debian GNU/Linux environment has introduced something that break the tests.

OTOH, your run skipped 296 tests. Maybe those failing tests under C-C are supposed to be skipped.
(But then again, on tryserver, they seem to pass.)

Well, let me take a bit more time to figure this out.
I am right now tidying up a set of patches that have been updated to match the re-formatted C-C tree (using clang-format) and
am chasing a bug that crept into it when the copy&paste&edit work was done to accommodate the bitrot caused by clang-formatter.
In doing so, I wanted to make sure that everyting is A-OK but these strange local errors have made it rather difficult to
verify the patches. But for now, I am trusting tryserver to check the sanity of patches: it is just that, it is a bit awkward to submit the job and wait for the run.

Thank you again. Maybe I should run M-C xpcshell-test to see if they are all right locally.

Comment 4

[ISHIKAWA, Chiaki]

I run Debian GNU/Linux.
uname -a
Linux ip030 5.2.0-3-amd64 #1 SMP Debian 5.2.17-1 (2019-09-26) x86_64 GNU/Linux

I dug up a few things.

This could be LINUX-specific xpcshell-tests errors.

General Observation:

It seems that more tests are run than before, say, in Augst.
(Maybe some tests that cannot be executed locally might have been
enabled accidentally?. Some tests need to run a remote SQLserver which may not be
available locally???) [1]

Timing:

The error seems to have started on local xpcshell-tests some time between late August and
Oct 14 (at the latest).

Strange errors:
I also noticed a strange increase of the number of following
warnings. Not sure the warning is related to indexedDB errors I observe.

..., Main Thread] WARNING: 'result.isErr()', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/startupcache/StartupCache.cpp, line 173

(This could mean that the newly-executed FAILING tests are producing these warnings, since the stderr/stdout are only listed when a test fails,
OR the source code has been changed.The warning is printed below.
https://dxr.mozilla.org/mozilla-central/source/startupcache/StartupCache.cpp?q=StartupCache.cpp&redirect_type=direct#173

  // If we shutdown quickly timer wont have fired. Instead of writing
  // it on the main thread and block the shutdown we simply wont update
  // the startup cache. Always do this if the file doesn't exist since
  // we use it part of the package step.
  if (!mCacheData.initialized() || ShouldCompactCache()) {
    mDirty = true;
    auto result = WriteToDisk();
    Unused << NS_WARN_IF(result.isErr());     <== This.
  }

Aha, the code has been changed very recently.
https://bugzilla.mozilla.org/show_bug.cgi?id=1550108

But I am not sure if the change is related to the local xpcshell-test test failures, but just in case I will ping the bugzilla.

I base my observation on the following data.

Here are some info printed by the following commands.

export LANG=C; for f in /FF-NEW/log10xpc.txt; do echo $f; ls -l $f; echo "# of result.isErr" $(grep -c result.isErr $f); grep -2 Skipped: $f; done

Namely, I printed out the time stamp of the local log file and the number of "result.isErr()" warning lines. And the final summary of xpcshell-tests.
Well, I wish I run xpcshell-tests weekly or something, but as an occasional patch contributor, it is difficult to do that.

Here is an excerpt where the jump of # of errors happened. (I inserted a newline just before the file name is printed for readability.

In August, things were OK, but in October, something went wrong.
--- begin quote ---
/FF-NEW/log1048-xpcshell.txt
-rw-r--r-- 1 ishikawa ishikawa 849683 Aug 1 08:24 /FF-NEW/log1048-xpcshell.txt

of result.isErr 0 <=== no result.isErr() lines.

Ran 3786 checks (19 subtests, 3767 tests)
Expected results: 3204
Skipped: 572 tests
Unexpected results: 10 <=== some tests are known to fail.
test: 6 (6 fail)

/FF-NEW/log1057-xpc-test.txt
-rw-r--r-- 1 ishikawa ishikawa 559817 Aug 25 23:11 /FF-NEW/log1057-xpc-test.txt

of result.isErr 0 <=== no result.isErr() lines.

Ran 3814 checks (26 subtests, 3788 tests)
Expected results: 3226
Skipped: 574 tests
Unexpected results: 14 <=== some tests are known to fail.
test: 8 (7 fail, 1 timeout)

/FF-NEW/log1081-xpcshell.txt
-rw-r--r-- 1 ishikawa ishikawa 6507841 Oct 14 06:01 /FF-NEW/log1081-xpcshell.txt

of result.isErr 5620 <=== 5620 result.isErr() Warnings (!?)

                             This is about twice the errors of
                             single run since this log contains
                             TWO xpcshell-tests results.

Ran 5292 checks (1335 subtests, 3957 tests)
Expected results: 4527 <==== Suddenly more tests
Skipped: 570 tests, 1 subtests
Unexpected results: 194 <===== Large # of errors.
test: 133 (90 fail, 43 timeout)

Another run in the same log file.
Ran 5238 checks (1286 subtests, 3952 tests)
Expected results: 4485
Skipped: 570 tests, 1 subtests
Unexpected results: 182 <==== large # of errors
test: 127 (89 fail, 38 timeout)

/FF-NEW/log1082-xpcshell.txt
-rw-r--r-- 1 ishikawa ishikawa 3309568 Oct 18 17:15 /FF-NEW/log1082-xpcshell.txt

of result.isErr 2757 <=== large # of result.isErr() warnings.

Ran 5238 checks (1284 subtests, 3954 tests)
Expected results: 4485
Skipped: 570 tests, 1 subtests
Unexpected results: 182 <=== large # of errors.
test: 127 (89 fail, 38 timeout)

/FF-NEW/log1083-xpcshell.txt
-rw-r--r-- 1 ishikawa ishikawa 2973867 Oct 19 04:22 /FF-NEW/log1083-xpcshell.txt

of result.isErr 2757 <=== large # of result.isErr() warnings.

Ran 5238 checks (1286 subtests, 3952 tests)
Expected results: 4485
Skipped: 570 tests, 1 subtests
Unexpected results: 182 <=== large # of errors.
test: 127 (89 fail, 38 timeout)
--- end quote ---

Thus, the number of tests have been increased lately (at the latest in October) under linux.
Those added tests may be the cause of the observed failures.
The number of "result.isErr()" warnings jumped as well.

[1] SQLserver ?
I am attaching an excerpt from a local test. There is a mention of example.org. It shows the symptom an indexedDB error rather nicely.

Comment 5

[ISHIKAWA, Chiaki]

Attachment: an example of indexedDB related error with a reference to example.org

The attached file was produced by picking up lines with particular PID, 29914 from a
local log.: e.g.,
grep 29914 log1097-xpcshell.txt

I see flurry of result.isErr() warnings.
I think the SQL statement
on the |77:57.82 pid:29914 [29914, IndexedDB #1] WARNING:| warning line
could not be compiled because it is missing an ID or filename(?)
in after FROM in
|object_data.file_ids, object_data.data FROM AS index_table JOIN object_data ON|

I see such SQL syntax errors in many places.
I don't know why. Maybe a bug in Debian's SQL library?

Comment 6

[ISHIKAWA, Chiaki]

Attachment: time series of result.isErr() warnings.

I no longer see the result.isErr() warning in my local test.
The attachment suggests something changed at the end of January/beginning of Feb time frame.

Of course, this can mean a few things.:

• C-C/M-C fixes, or
• my local linux (Debian GNU/Linux) fixed SQL library bug(?)
• etc.

But I cannot reproduce it for now.

Comment 7

[ISHIKAWA, Chiaki]

Since I cannot reproduce, I am closing this for now.