1411549 - Empty notification received after re-connecting the account on desktop

Status: VERIFIED FIXED

(Firefox for iOS :: General, defect, P1)

Description

[Catalin Suciu [:csuciu]]

v10.0 (7233)
iPad Air 2 (10.3.3)

1. Connect account A on desktop.
2. Connect account A on iOS.
3. Sync both clients.
4. Disconnect/re-connect a few times on desktop.
            => See the push notifications being received correctly on iOS.
5. Disconnect on desktop.
5. Re-connect on desktop after ~ 30 minutes


Result: An empty notification is received on iOS.  

I was able to reproduce this issue in 2/4 tries.

Comment 1

[Catalin Suciu [:csuciu]]

Attachment: Screen Shot 2017-10-25 at 16.01.17.png

I've just reproduced this issue by doing a few consecutive disconnects/re-connects on desktop.

Comment 2

[Justin D'Arcangelo [:justindarc]]

Attachment: Finally a log showing NotificationService getting terminated.txt

Most relevant bits:

default	14:52:03.072346 -0400	SpringBoard	[org.mozilla.ios.Fennec.NotificationService] Beginning extension session...


and ~1sec later:

error	14:52:04.071630 -0400	SpringBoard	[org.mozilla.ios.Fennec.NotificationService] Extension will be killed due to sluggish startup
error	14:52:04.560174 -0400	SpringBoard	Hub connection error Error Domain=NSCocoaErrorDomain Code=4097 "connection to service named org.mozilla.ios.Fennec.NotificationService" UserInfo={NSDebugDescription=connection to service named org.mozilla.ios.Fennec.NotificationService}

Comment 3

[Justin D'Arcangelo [:justindarc]]

Attachment: GitHub Pull Request

Comment 4

[Stefan Arentz | :st3fan | ⏰ EST | he/him]

Comment on attachment 8922480 [details] [review]
GitHub Pull Request

Looks good - just added some small questions to the PR.

Comment 5

[Justin D'Arcangelo [:justindarc]]

Landed on master:

https://github.com/mozilla-mobile/firefox-ios/commit/9966bf5c25c2b426497af875568c5e50308803a4

Landed on v10.x:

https://github.com/mozilla-mobile/firefox-ios/commit/5a782f55fd0767d5caf16fa3482c49b228e5b4c7

Comment 6

[Justin D'Arcangelo [:justindarc]]

Catalin, please re-test with latest builds with my patch applied. Thanks!

Comment 7

[Stefan Arentz | :st3fan | ⏰ EST | he/him]

Extension error whilst trying to modify push notification A68B-356E: Error Domain=NSCocoaErrorDomain Code=4099 "The connection from pid 1448 was invalidated from this process." UserInfo={NSDebugDescription=The connection from pid 1448 was invalidated from this process.}

Comment 8

[Justin D'Arcangelo [:justindarc]]

Re-opening this since we're still actively investigating.

Comment 9

[Justin D'Arcangelo [:justindarc]]

Attachment: Let's try this again - GitHub Pull Request

It's unclear at this point if this will resolve our issue, but in local builds, this PR reduces the size of NotificationService.appex from 1.2MB down to 970KB. Cold launches (i.e. first notification received after installing) seems to consistently take ~300ms on my iPhone 6S running iOS 11.0.3 with this patch and subsequent launches take roughly ~50ms. This doesn't seem to be *that* much of an improvement over master, but it is a bit more consistent. I have not seen any blank notifications with this patch applied which means that all launches of NotificationService come in at under the 1000ms cut-off.

The methodology I used to measure these times is as follows:

1. Install local Fennec build with patch applied
2. Connect device to Mac and open Console.app
3. Filter on "NotificationService"
4. When a notification is first received by the OS, a message will be logged by SpringBoard that looks like:

`default    15:45:20.508870 -0400    SpringBoard    [org.mozilla.ios.Fennec.NotificationService] Beginning extension session...`

5. As soon as the NotificationService process has finished launching, another message will be logged by SpringBoard that looks like:

`default    15:45:20.547867 -0400    SpringBoard    [org.mozilla.ios.Fennec.NotificationService] Extension session created successfully for UUID FE14999B-0B2A-4570-95B0-89A55E719EA9`

6. Subtract the timestamps between the two messages to get an approximation of startup time for NotificationService

Note, if NotificationService takes longer than 1000ms to launch, you won't see the "Extension session created successfully" message. Instead, you'll see a message logged by SpringBoard that looks like:

`error    14:52:04.071630 -0400    SpringBoard    [org.mozilla.ios.Fennec.NotificationService] Extension will be killed due to sluggish startup`

Anytime I've observed the "killed due to sluggish startup" message, the difference between its timestamp and that of the "Beginning extension session" message is just shy of 1000ms. However, I have not yet seen this happen with this patch applied so hopefully this will resolve it (*fingers crossed*).

Comment 10

[James Hugman [:jhugman] [@jhugman]]

Comment on attachment 8924010 [details] [review]
Let's try this again - GitHub Pull Request

LGTM. 

I'd add a herebedragons comment at the top of Profile. (see PR)

Comment 11

[Justin D'Arcangelo [:justindarc]]

Landed on master:

https://github.com/mozilla-mobile/firefox-ios/commit/1f0f709c959f68043c91477106af47b4875d5f0d

Landed on v10.x:

https://github.com/mozilla-mobile/firefox-ios/commit/fe8b9f251ff0955d2da13362b783ab32059603a2

Comment 12

[Justin D'Arcangelo [:justindarc]]

Attachment: Yet another GitHub Pull Request

Carrying over R+ from :st3fan on Slack.

Comment 13

[Justin D'Arcangelo [:justindarc]]

Landed attachment #8924701 [details] [review] on master:

https://github.com/mozilla-mobile/firefox-ios/commit/aeb80d641282df23cd19a24e23abee08a61aa1ad

Landed attachment #8924701 [details] [review] on v10.x:

https://github.com/mozilla-mobile/firefox-ios/commit/bda2844b3688a9a8cfdf122a2b8a612b5cbe8c41

Comment 14

[Catalin Suciu [:csuciu]]

Following the STRs from the description and comment #1, I'm no longer able to reproduce the bug.