1082178 - Wrong initialization of JS in workers

Status: VERIFIED FIXED

(Core :: DOM: Workers, defect)

Description

[Yury Delendik (:yury)]

Attachment: test/test_manifest.json

STR:
1. Clone and initialize pdf.js repository (requires git and node.js):
  a) git clone http://github.com/mozilla/pdf.js.git pdf.js
  b) cd pdf.js; npm install
  c) Save attached test_manifest.json over test/test_manifest.json
2. Run tests using firefox browser:
  a) cd pdf.js/test
  b) node test.js -b /path/to/firefox

Actial result:

In the testing window, the execution halts near 235 page.

Expected result:

Tests all pages almost the same speed.

Comment 1

[Yury Delendik (:yury)]

(Via bisecting on Ubuntu 14.04)

The first bad revision is:
changeset:   209343:8c00d59b1c00
user:        Andrea Marchesini <[e-mail]>
date:        Wed Oct 08 13:56:50 2014 +0100
summary:     Bug 1078163 - WorkerNavigator strings should honor general.*.override prefs in e10s mode, r=khuey


FWIW, navigator.userAgent is used once during worker script initialization and during painting of the content. (See https://github.com/mozilla/pdf.js/search?utf8=%E2%9C%93&q=navigator)

Andrea, do you have ideas what can cause execution of JavaScript to hang?

Comment 2

[Andrea Marchesini [:baku]]

Sorry, but I don't see any reason why this should be related. Do you have some log?
My patch changes how the runtimeService is initialized and that happens just once for dedicated workers.

Comment 3

[Yury Delendik (:yury)]

(In reply to Andrea Marchesini (:baku) from comment #2)
> Sorry, but I don't see any reason why this should be related. Do you have some log?

Not sure about which logs you are asking. It's just a web application that uses regular worker, but in this particular case it needs significant amount of memory in short period of time to parse binary data. Can it be a memory corruption?

I double checked and it looks like the patch above is at fault. Was you able to reproduce using the STR above?

Comment 4

[Andrea Marchesini [:baku]]

Actually debugging this issue I found bug 1082642. But it doesn't seem it is related.
And yes, with a non-debug build I can reproduce the issue.
Still debugging it.

Comment 5

[Kamil Jozwiak [:kjozwiak]]

m-c regression window:

- https://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-10-07-03-02-02-mozilla-central/
--> Runtime was 100.5 seconds [PASS]

- https://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-10-08-06-54-30-mozilla-central/
--> Runtime was 102.4 seconds [PASS]

- https://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-10-09-03-02-01-mozilla-central/
--> Runtime was 724.3 seconds [FAIL]

- https://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014-10-10-03-02-01-mozilla-central/
--> Runtime was 1335.6 seconds [FAIL]

https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=dd7637cc42d5&tochange=f0bb13ef0ee4

Comment 6

[Andrea Marchesini [:baku]]

So, I debugged it a bit more and the user-agent patch is not actually the cause of this issue because nothing of that code runs except at the beginning.
Are you sure about the bisecting?

Comment 7

[Yury Delendik (:yury)]

That's what it showing on my computer. But I'll be glad to see results from other computers to confirm it.

Comment 8

[Yury Delendik (:yury)]

Looks like it does not affect Windows or Linux 32bit.

I tried backing out the patch (see https://tbpl.mozilla.org/?tree=Try&rev=af0e436c63f4) -- this fixes the issue.

Comment 9

[Kamil Jozwiak [:kjozwiak]]

Yury,

I backed out the "209343" changeset from the "f0bb13ef0ee4" build and everything worked correctly. The tests finished in 93.9 seconds (Runtime was 93.9 seconds) compared to the original 724.3 seconds witch included the "209343" changeset.

I used the following steps:

- hg pull -u (on m-c)
- hg update -r f0bb13ef0ee4
- hg backout -r 209343
- ./mach build > out.txt 2>&1
- nodejs test.js -b ~/mozilla/mozilla-central/objdir-ff-debug/dist/bin/firefox

Comment 10

[Yury Delendik (:yury)]

[Tracking Requested - why for this release]:

PDF.js team is using Firefox Aurora to track regressions in PDF Viewer rendering. If Firefox Aurora cannot be used, the Firefox version will be fixed at the last working version, which is 33 (34 cannot be used as well since bug 1078163 was uplifted). The test harness uses the same code base as the integrated PDF Viewer, that means the viewer's stability will suffer as well on Firefox 34+.

Comment 11

[Andrea Marchesini [:baku]]

working on it. yury, I hope to have a working patch for today.

Comment 12

[Andrea Marchesini [:baku]]

Attachment: prefs.patch

Comment 13

[Yury Delendik (:yury)]

While we waiting for review, shall we backout the initial patch from the FF34?

Comment 14

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

Comment on attachment 8505461 [details] [diff] [review]
prefs.patch

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

::: dom/workers/RuntimeService.cpp
@@ +1838,5 @@
>    if (NS_FAILED(obs->AddObserver(this, NS_IOSERVICE_OFFLINE_STATUS_TOPIC, false))) {
>      NS_WARNING("Failed to register for offline notification event!");
>    }
>  
> +  NS_ASSERTION(!gRuntimeServiceDuringInit, "This should be false!");

MOZ_ASSERT

@@ +1898,5 @@
>                                                   nullptr))) {
>      NS_WARNING("Failed to register pref callbacks!");
>    }
>  
> +  NS_ASSERTION(gRuntimeServiceDuringInit, "Should be true!");

here too

Comment 15

[Andrea Marchesini [:baku]]

(In reply to Yury Delendik (:yury) from comment #13)
> While we waiting for review, shall we backout the initial patch from the
> FF34?

I'm landing this patch in the next 10 minutes. We should uplift this patch to aurora and beta.

Comment 16

[Andrea Marchesini [:baku]]

Comment on attachment 8505461 [details] [diff] [review]
prefs.patch

Approval Request Comment
[Feature/regressing bug #]: bug 1078163
[User impact if declined]: JS in workers in snot correct initialized using the values from the preferences.
[Describe test coverage new/current, TBPL]: none
[Risks and why]: The patch is small and simple. So I don't see big risks.
[String/UUID change made/needed]: none

https://hg.mozilla.org/integration/mozilla-inbound/rev/14c6cf6337cc

Comment 17

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/14c6cf6337cc

Comment 18

[Kamil Jozwiak [:kjozwiak]]

I ran through the test case(s) using the steps provided in comment #0 and comment #9 using changeset c0ddb1b098ec (the latest m-c) and didn't run into the original problem. I ran through the tests five different times, results:

Run #1: Runtime was 89.5 seconds [Passed]
Run #2: Runtime was 88.1 seconds [Passed]
Run #3: Runtime was 85.8 seconds [Passed]
Run #4: Runtime was 88.6 seconds [Passed]
Run #5: Runtime was 88.5 seconds [Passed]

Originally, the tests would take anywhere between 700s - 1500s with the issue.

Comment 19

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/002b6085c793
https://hg.mozilla.org/releases/mozilla-beta/rev/301822ecb5fa

Comment 20

[Kamil Jozwiak [:kjozwiak]]

Using the STR provided in comment #0 and comment #9, I went through the following builds:

fx 35 aurora using changeset caaf56e6e947:

Run #1: Runtime was 93.1 seconds
Run #2: Runtime was 92.8 seconds
Run #3: Runtime was 91.1 seconds
Run #4: Runtime was 91.3 seconds
Run #5: Runtime was 94.3 seconds

fx 34 beta using changeset cadb1112c8fb:

Run #1: Runtime was 88.1 seconds
Run #2: Runtime was 84.5 seconds
Run #3: Runtime was 86.5 seconds
Run #4: Runtime was 88.9 seconds
Run #5: Runtime was 90.3 seconds