1410887 - push notifications not being delivered to fennec nightly 58

Status: RESOLVED WORKSFORME

(Cloud Services Graveyard :: Server: WebPush, defect)

Description

[Ben Kelly [:bkelly, not reviewing]]

STR:

1. Open fennec nightly 58.
2. Open a tab with https://gauntface.github.io/simple-push-demo/
3. Select "Enable push notifications"
4. Accept the permission dialog.
5. Click "Send a Push via XHR"

Expected:

A push notification should appear.

Actual:

Nothing happens.

These steps fail on fennec 58, but succeed on fennec 57.  They also succeed on desktop for all versions.

I assume this is some kind of GCM integration issue, but not sure.  Sorry if its the wrong category.

JR, any ideas?

Comment 1

[JR Conlin [:jrconlin,:jconlin]]

we don't do anything on the server that differentiates between gecko versions, so I'm not exactly sure what may have changed. I know that android generally pushed folks to use FCM rather than the older GCM. For what it's worth, the server already supports FCM (use "fcm" instead of "gcm" in the endpoint. You will probably need to use a different registration ID since it's a different service.)

I'm able to verify on my own device that Beta is able to receive notifications on 57.0b9, but not on 58.

I'll try looking into what I can, but it'd be helpful to know what version of Play services you're using for 58 and if it's different than the version you've used for 57.

Comment 2

[Ben Kelly [:bkelly, not reviewing]]

My 57 and 58 are on the same device.  How do I check my play services version?

Comment 3

[JR Conlin [:jrconlin,:jconlin]]

I'm not one of the gecko developers, so unfortunately, I can't answer that if you don't know. 

We did discover that endpoint that google uses for downstream messages appears to have changed and a library we depend on has not updated to use it. I'll continue to investigate that, but I have no expectation that it will resolve this issue.

I've reached out to the mobile-firefox group separately to see if I can get assistance.

Comment 4

[Ben Kelly [:bkelly, not reviewing]]

Kit, do you have any thoughts here?  I know you are not working on push any more, but not sure where to look or who to ask.

Thanks.

Comment 5

[Nick Alexander :nalexander [he/him]]

(In reply to Ben Kelly [:bkelly] from comment #2)
> My 57 and 58 are on the same device.  How do I check my play services
> version?

bkelly: can you give me buildid's for your 57 and 58 versions?  We updated _many_ dependencies in preparation for building with Gradle, and it's possible one of those upset the GCM registration.

Comment 6

[Ben Kelly [:bkelly, not reviewing]]

My beta 57 says rev 4b93f26c855 and buildid 20171016210922.

Night 58 says rev 69e24c678 and buildid 20171022100051.


Note, this only seemed to break in the last few days.  I know I got a nightly 58 push message last Thursday or so because I was trying to test bug 1409761.

Comment 7

[Lina Butler (ex-Mozilla)]

Grisha, did we change anything in push for 58? I know you're on holiday this week, flagging you just in case you're around...

Comment 8

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Nick Alexander :nalexander from comment #5)
> bkelly: can you give me buildid's for your 57 and 58 versions?  We updated
> _many_ dependencies in preparation for building with Gradle, and it's
> possible one of those upset the GCM registration.

By the way, if the problem is due to these dependency changes, what kind of testing do we need to catch this in the future?  If automated testing is not practical, can we get a smoke test added to the softvision QA test plan?

Comment 9

[Ben Kelly [:bkelly, not reviewing]]

I guess they wouldn't have run the manual smoke tests yet since this is still just nightly, though.

Comment 10

[JR Conlin [:jrconlin,:jconlin]]

:bkelley, if it's any help, I built https://jrconlin.github.io/Webpush_QA/ to help our QA test our service. It should work on android as well. If there are any improvements or adjustments you need, let me know.

Comment 11

[Nick Alexander :nalexander [he/him]]

With a new Firefox 58, installed from the Google Play store, I have no issues receiving GCM messages:

$ adb shell setprop log.tag.GeckoPushGCM DEBUG
$ adb shell setprop log.tag.GeckoPushService DEBUG
$ adb logcat -c 
$ adb logcat | grep 'Gecko'
I/GeckoTabs( 4523): zerdatime 352747 - page load stop
D/GeckoToolbar( 4523): onTabChanged: STOP
I/GeckoConsole( 4523): VAPID Keys defined.
D/GeckoBrowserApp( 4523): BrowserApp.onTabChanged: 0: STOP
V/InputMethodManager( 4523): START INPUT: org.mozilla.gecko.GeckoView{11ae3500 VFE..... .F...... 0,0-1080,1701 #7f090108 app:id/layer_view} ic=null tba=android.view.inputmethod.EditorInfo@1f170c20 controlFlags=#0
I/GeckoPushService( 4523): Handling event: PushServiceAndroidGCM:UnsubscribeChannel
I/GeckoPushManager( 4523): Unsubscribing from channel with chid: 90134ddae5784622beed9217845eef5d
I/GeckoConsole( 4523): Preflight is Ok
I/GeckoPushManager( 4523): Unsubscribed from channel with chid: 90134ddae5784622beed9217845eef5d
I/GeckoPushService( 4523): Handling event: PushServiceAndroidGCM:SubscribeChannel
I/GeckoPushManager( 4523): Subscribing to channel for service: webpush; for profile named: default
I/GeckoPushGCM( 4523): Cached GCM token exists.
D/GeckoPushManager( 4523): Existing uaid is fresh; no need to request from autopush endpoint.
I/GeckoPushManager( 4523): Got chid and endpoint.
I/GeckoConsole( 4523): receiverKey BAzB5IiDPXh4ELFFQjaAfq9TT2lU8EAWqq5iN-JyzI5DWDt0YZiLHgyIzhQTyBfg7T5hyhHARu2AAdNtOUdqMVI
I/GeckoConsole( 4523): Auth key:  MvQqFGU5DAul4E7QbNZmqQ
I/GeckoConsole( 4523): data: Amidst the mists and coldest frosts, I thrust my fists against the posts, and still demand to see the ghosts.
I/GeckoConsole( 4523): subscription [object Object]
I/GeckoConsole( 4523): Sender Key [object Object]
I/GeckoConsole( 4523): calling wp_encrypt( [object Object] [object Object] 51,216,138,99,153,204,36,206,234,124,2,62,88,78,60,140 65,109,105,100,115,116,32,116,104,101,32,109,105,115,116,115,32,97,110,100,32,99,111,108,100,101,115,116,32,102,114,111,115,116,115,44,32,73,32,116,104,114,117,115,116,32,109,121,32,102,105,115,116,115,32,97,103,97,105,110,115,116,32,116,104,101,32,112,111,115,116,115,44,32,97,110,100,32,115,116,105,108,108,32,100,101,109,97,110,100,32,116,111,32,115,101,101,32,116,104,101,32,103,104,111,115,116,115,46 )
I/GeckoConsole( 4523): receiverKey: 4,12,193,228,136,131,61,120,120,16,177,69,66,54,128,126,175,83,79,105,84,240,64,22,170,174,98,55,226,114,204,142,67,88,59,116,97,152,139,30,12,136,206,20,19,200,23,224,237,62,97,202,17,192,70,237,128,1,211,109,57,71,106,49,82
I/GeckoConsole( 4523): Private Key: [object Object]
I/GeckoConsole( 4523): client p256dh key: [object CryptoKey]
I/GeckoConsole( 4523): deriving new key:  [object Object] [object Object] 256
I/GeckoConsole( 4523): Auth Secret: 50,244,42,20,101,57,12,11,165,224,78,208,108,214,102,169
I/GeckoConsole( 4523): ikm:      154,219,195,81,150,158,144,229,167,244,211,188,39,127,80,201,60,83,84,74,131,22,0,60,119,164,2,146,106,50,119,2
I/GeckoConsole( 4523): salt:  51,216,138,99,153,204,36,206,234,124,2,62,88,78,60,140
I/GeckoConsole( 4523): ikm2:  155,229,68,79,218,232,69,54,145,3,2,248,84,31,98,233,95,181,149,204,206,250,37,137,154,252,231,227,129,142,90,144
I/GeckoConsole( 4523): receiverKey:  4,12,193,228,136,131,61,120,120,16,177,69,66,54,128,126,175,83,79,105,84,240,64,22,170,174,98,55,226,114,204,142,67,88,59,116,97,152,139,30,12,136,206,20,19,200,23,224,237,62,97,202,17,192,70,237,128,1,211,109,57,71,106,49,82
I/GeckoConsole( 4523): senderKey:    4,188,204,68,180,102,7,188,47,232,8,31,106,24,72,148,235,254,247,216,89,65,252,165,116,33,113,36,161,177,173,104,84,106,119,67,35,91,155,215,21,198,194,90,141,247,4,87,111,51,178,145,156,77,112,117,254,244,146,83,153,203,191,2,180
I/GeckoConsole( 4523): makeInfo head: Content-Encoding: aesgcm
I/GeckoConsole( 4523): makeInfo base: 0,80,45,50,53,54,0,0,65,4,12,193,228,136,131,61,120,120,16,177,69,66,54,128,126,175,83,79,105,84,240,64,22,170,174,98,55,226,114,204,142,67,88,59,116,97,152,139,30,12,136,206,20,19,200,23,224,237,62,97,202,17,192,70,237,128,1,211,109,57,71,106,49,82,0,65,4,188,204,68,180,102,7,188,47,232,8,31,106,24,72,148,235,254,247,216,89,65,252,165,116,33,113,36,161,177,173,104,84,106,119,67,35,91,155,215,21,198,194,90,141,247,4,87,111,51,178,145,156,77,112,117,254,244,146,83,153,203,191,2,180
I/GeckoConsole( 4523): cEKinfo:  Content-Encoding: aesgcm
I/GeckoConsole( 4523): cEKinfo:  67,111,110,116,101,110,116,45,69,110,99,111,100,105,110,103,58,32,97,101,115,103,99,109,0,80,45,50,53,54,0,0,65,4,12,193,228,136,131,61,120,120,16,177,69,66,54,128,126,175,83,79,105,84,240,64,22,170,174,98,55,226,114,204,142,67,88,59,116,97,152,139,30,12,136,206,20,19,200,23,224,237,62,97,202,17,192,70,237,128,1,211,109,57,71,106,49,82,0,65,4,188,204,68,180,102,7,188,47,232,8,31,106,24,72,148,235,254,247,216,89,65,252,165,116,33,113,36,161,177,173,104,84,106,119,67,35,91,155,215,21,198,194,90,141,247,4,87,111,51,178,145,156,77,112,117,254,244,146,83,153,203,191,2,180
I/GeckoConsole( 4523): makeInfo head: Content-Encoding: nonce
I/GeckoConsole( 4523): makeInfo base: 0,80,45,50,53,54,0,0,65,4,12,193,228,136,131,61,120,120,16,177,69,66,54,128,126,175,83,79,105,84,240,64,22,170,174,98,55,226,114,204,142,67,88,59,116,97,152,139,30,12,136,206,20,19,200,23,224,237,62,97,202,17,192,70,237,128,1,211,109,57,71,106,49,82,0,65,4,188,204,68,180,102,7,188,47,232,8,31,106,24,72,148,235,254,247,216,89,65,252,165,116,33,113,36,161,177,173,104,84,106,119,67,35,91,155,215,21,198,194,90,141,247,4,87,111,51,178,145,156,77,112,117,254,244,146,83,153,203,191,2,180
I/GeckoConsole( 4523): cNinfo:  Content-Encoding: nonce
I/GeckoConsole( 4523): cNinfo:  67,111,110,116,101,110,116,45,69,110,99,111,100,105,110,103,58,32,110,111,110,99,101,0,80,45,50,53,54,0,0,65,4,12,193,228,136,131,61,120,120,16,177,69,66,54,128,126,175,83,79,105,84,240,64,22,170,174,98,55,226,114,204,142,67,88,59,116,97,152,139,30,12,136,206,20,19,200,23,224,237,62,97,202,17,192,70,237,128,1,211,109,57,71,106,49,82,0,65,4,188,204,68,180,102,7,188,47,232,8,31,106,24,72,148,235,254,247,216,89,65,252,165,116,33,113,36,161,177,173,104,84,106,119,67,35,91,155,215,21,198,194,90,141,247,4,87,111,51,178,145,156,77,112,117,254,244,146,83,153,203,191,2,180
I/GeckoConsole( 4523): gcmBits:  137,177,52,119,206,47,227,231,254,66,208,101,92,63,27,149
I/GeckoConsole( 4523): nonce:  220,90,96,90,203,215,211,76,104,40,161,18
I/GeckoConsole( 4523): encryptingData: [object Object]
I/GeckoConsole( 4523): iv:  220,90,96,90,203,215,211,76,104,40,161,18
I/GeckoConsole( 4523): echo -ne "\x30\xb3\x30\x30\xa\x4c\xa\xbb\xbd\xa\xce\xa\xa\xa\xa\xa\xa\xa\xe5\xa\x30\x26\x4c\xe0\x1f\x90\xa\xa\xa\xae\xa\xa\x7a\x06\x18\xa\x7e\x4e\x87\xa8\xa7\x85\xa\xa\xa\x0d\x28\xa\xa\xa\xa\xba\xfc\x28\xa\xa\x28\xa\xa\xa\x3c\xa\xa\xa\xac\xa\xa\xa\xa\x21\x21\xa\x52\xb0\xa\xa\x74\xae\xa\xa\xa\xde\xa\x8a\xa\x26\xa\xa\xa\x05\xe0\xa\xa\x65\xa\xa\x94\xb3\x4a\xa\xa\x89\x21\xa\xa\x9e\xa\xa\xa\x85\xa\xe0\xa\xa\xa\x59\x05\xa\xa\xa\x7e\xa\xe4\xa\xa\x85\xa" > encrypted.data;curl -v -X POST "https://updates.push.services.mozilla.com/wpush/v1/gAAAAABZ7ioYeydbbEwWpXfuZG9diqHJxPERKX0ossmqlFO33lHvlMGP0VTcALHcN65LNqUTO86pWDF2ELHPrKtO2plszfMFDT0A4yQ2vS1Bz5JxVuVNZxUsWjPdJ3H2osCgboljOC17"  -H "Authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJFUzI1NiJ9.eyJzdWIiOiJtYWlsdG86YWRtaW5AZXhhbXBsZS5jb20iLCJleHAiOjE1MDg4NjY5Njh9.cm6ruHMoFQT2pp4QLOsVlkFYWa7_piACe9FTi2tDlgmMeGmKRSbYo5tAQO0rMKCYk3B6qo-n6_5Cgff5K6gqPg"  -H "crypto-key: keyid=p256dh;dh=BLzMRLRmB7wv6AgfahhIlOv-99hZQfyldCFxJKGxrWhUandDI1ub1xXGwlqN9wRXbzOykZxNcHX-9JJTmcu_ArQ;p25
I/GeckoConsole( 4523): payload 111,9,90,111,176,116,167,74,103,179,78,164,172,135,222,235,212,133,106,180,23,45,89,48,122,58,223,186,175,99,190,228,24,40,32,204,101,10,13,63,6,17,224,249,192,38,33,250,224,243,225,27,82,33,180,248,33,148,144,150,60,141,133,168,12,158,135,243,138,53,46,236,52,4,187,189,5,99,206,160,161,14,252,68,165,45,171,170,169,76,48,168,175,36,140,146,57,9,7,174,158,126,46,189,214,100,229,130,246,17,238,48,168,193,244,22,76,222,201,188,101,167,31,146,249,17,137
I/GeckoConsole( 4523): Fetching: https://updates.push.services.mozilla.com/wpush/v1/gAAAAABZ7ioYeydbbEwWpXfuZG9diqHJxPERKX0ossmqlFO33lHvlMGP0VTcALHcN65LNqUTO86pWDF2ELHPrKtO2plszfMFDT0A4yQ2vS1Bz5JxVuVNZxUsWjPdJ3H2osCgboljOC17 [object Object]
I/GeckoConsole( 4523): request: [object Request]
I/GeckoConsole( 4523): Message sent 201
D/GeckoPushGCM( 4523): Message received.  Processing on background thread.
I/GeckoPushService( 4523): Google Play Services GCM message received; delivering.
I/GeckoPushService( 4523): Message directed to service: webpush
I/GeckoPushService( 4523): Delivering dom/push message to Gecko!
D/GeckoToolbar( 4523): onTabChanged: THUMBNAIL
D/GeckoBrowserApp( 4523): BrowserApp.onTabChanged: 0: THUMBNAIL
V/InputMethodManager( 4523): onWindowFocus: org.mozilla.gecko.GeckoView{11ae3500 VFE..... .F...... 0,0-1080,1701 #7f090108 app:id/layer_view} softInputMode=16 first=false flags=#81810100

It's clear that we're dumping _way_ too much information to the logcat in GeckoConsole (!) and also that the message is getting through GCM to our Java layer.  However, can't tell what's happening after that; we'll need somebody on snorp's team to investigate.  I would start investigating GeckoView-related messaging changes.  snorp, can you redirect?

Comment 12

[James Willcox (:snorp) ([e-mail]) (he/him)]

Eugen, please take a look.

Comment 13

[Ben Kelly [:bkelly, not reviewing]]

I upgraded my nexus 5x to android oreo last night.  Push notifications are now working in nightly 58 on this device.  Do the latest deps have an issue with older OS versions?

Comment 14

[Nick Alexander :nalexander [he/him]]

(In reply to Ben Kelly [:bkelly] from comment #13)
> I upgraded my nexus 5x to android oreo last night.  Push notifications are
> now working in nightly 58 on this device.  Do the latest deps have an issue
> with older OS versions?

I doubt it, but it's possible.  Certainly I'm running Android 5.1 underneath a custom skin called Flyme OS on my Android device.

Comment 16

[Eugen Sawin [:esawin]]

WFM on Android 7 and Android 8 on latest Nightly.

Comment 17

[JR Conlin [:jrconlin,:jconlin]]

Adding to the anecdotal evidence: 

Running on a Pixel2/Oreo with latest nightly. Didn't work.
Enabled developer, attached adb to watch the logs: and it started working.

I'm not 100% sure that this is a problem in our software at the moment.

Comment 18

[Nevin Chen(Not active on Bugzilla)]

After digging, we do recieve web push but had some trouble handling the display of Notification.
The code path arrives here.[1]...which should goes to dom/push/PushServiceAndroidGCM.jsm[2] but never goes to Java side[3]


[1] https://searchfox.org/mozilla-central/rev/1285ae3e810e2dbf2652c49ee539e3199fcfe820/mobile/android/base/java/org/mozilla/gecko/push/PushService.java#296

[2] https://searchfox.org/mozilla-central/source/dom/push/PushServiceAndroidGCM.jsm#84

[3] https://searchfox.org/mozilla-central/rev/1285ae3e810e2dbf2652c49ee539e3199fcfe820/mobile/android/geckoview/src/main/java/org/mozilla/gecko/GeckoAppShell.java#970


I don't have time to do further investigation for now, but I guess there are some changes between [1]~[3]

Comment 19

[Nevin Chen(Not active on Bugzilla)]

btw, Leanplum had different Notification display and GCM receive/register flow.. So it should not be related. Just tested it on latest local build and it worked.