Register a endpoint and send it to your server. The server now is able to push update notifications to the device. After some time the endpoint stops working and the update notifications don't arrive anymore. This issue occurred to me on a Geeksphone Peak with the "wss://ua.push.tefdigital.com" push server. I use this code for my push updates: >window.navigator.mozSetMessageHandler('push-register', function(){ > App.updatePushServer(true); >}); > >window.navigator.mozSetMessageHandler('push', function(e){ > console.log('new push version: '+ e.version); > App.pullPushMessages(); >}); But I experience this problem with the Telegram app from the Marketplace too. Regards, Jovan

Hi, Can you share with us your endpoint? (the one used by your server to notify the mobile) If you're worried about publish it, send it to me privately (via e-mail). I'll use it to check what happened at server side. I'd simmilar behaviour in the past using the Mozilla PUSH server ... we need to detect the origin of the issue. Thank you in advance

Here are some old endpoints from the Telegram app: https://as.push.tefdigital.com/v1/notify/f01037cd8006f6d8f7d1d574b6341ff041caed1d33e4c6caceba1789c8f9a7d7 https://as.push.tefdigital.com/v1/notify/e357d6d554e2f8e3c2c46721284c6502117440fdb48c2a7b285b89c5d9e6cda1 https://as.push.tefdigital.com/v1/notify/8ee77b0ed36131f5d9d20f3cd504f06f3d3a96869e288ec00c13462296c19875 unfortunately I can't provide a endpoint form my own application since I already replaced it with a new one and unregistered them. I hope this helps.

(In reply to Jovan Gerodetti from comment #2) > Here are some old endpoints from the Telegram app: > > https://as.push.tefdigital.com/v1/notify/ > f01037cd8006f6d8f7d1d574b6341ff041caed1d33e4c6caceba1789c8f9a7d7 > https://as.push.tefdigital.com/v1/notify/ > e357d6d554e2f8e3c2c46721284c6502117440fdb48c2a7b285b89c5d9e6cda1 > https://as.push.tefdigital.com/v1/notify/ > 8ee77b0ed36131f5d9d20f3cd504f06f3d3a96869e288ec00c13462296c19875 > > > unfortunately I can't provide a endpoint form my own application since I > already replaced it with a new one and unregistered them. > > I hope this helps. Thank you, We'll investigate into our server logs and database what happened...

After some forensic works :) we saw: For endpoint "f01037cd8006f6d8f7d1d574b6341ff041caed1d33e4c6caceba1789c8f9a7d7" we don't have any version in the server's database, only the channel had been registered. We saw some connections from yesterday to that endpoint in the proxy server using POST method with curl. POST method is not allowed, PUT method shall be used [1] with a valid payload "version=xxxx" For endpoint "e357d6d554e2f8e3c2c46721284c6502117440fdb48c2a7b285b89c5d9e6cda1" which corresponds to channel "d8b48c4f-9598-429e-b427-33a7406f6968" the last version delivered was "1421271015" For endpoint "8ee77b0ed36131f5d9d20f3cd504f06f3d3a96869e288ec00c13462296c19875" which corresponds to channel "d5626139-17a2-4153-a23a-3cd624597ec3" the last version delivered was "1419961370" We continue working with this, but as a first impression, the server delivered all messages to the handset so we should check mobile code to. Can you provide PUSH traces from your mobile device? [1] https://wiki.mozilla.org/WebAPI/SimplePush#On_the_AppServer

>For endpoint "f01037cd8006f6d8f7d1d574b6341ff041caed1d33e4c6caceba1789c8f9a7d7" we don't have any version >in the server's database, only the channel had been registered. >We saw some connections from yesterday to that endpoint in the proxy server using POST method with curl. >POST method is not allowed, PUT method shall be used [1] with a valid payload "version=xxxx" Okay, that was me trying to check if the endpoint is actually dead. I thought that it also works to use POST but PUT should be used. As I said I can't provide any not working endpoints from my own project since I already needed to replace them and my current one is working at the moment. I'll set up a test app and regularly check if the endpoint still works. In case it breaks I'll provide it here. How do I provide a PUSH trace?

Hi Jovan, You should enable debug with ADB and enable console into the phone's developer menu to be able to get log traces with "adb logcat" Before use "adb logcat", you should also enable PUSH debug traces: You can use this script: https://gist.github.com/frsela/f1ae610563767684e389 use it as: get.omni.ja.from.phone.sh <folder_name> After it's execution, a new folder "folder_name" will be created on your computer with the contents of the phone's OMNI.JA. Modify the preferences file: <folder_name>/defaults/pref/b2g.js Changing the line: pref("services.push.debug", false); to pref("services.push.debug", true); After that, use this other script to update your phone with the changes: https://gist.github.com/frsela/8dd49d16ea429cf093d9 ./update.omni.ja <folder_name> Thank you in advace for your debugging time :)

okay, this[1] is definitely a dead endpoint, it does not work anymore and I watched out that it does not get unregistered. [1] https://as.push.tefdigital.com/v1/notify/bd07e632faed6e1e6bafc49c6f12c6d180ba46bb8fd7e0eeeaf362489986d6d5

(In reply to Jovan Gerodetti from comment #7) > okay, this[1] is definitely a dead endpoint, it does not work anymore and I > watched out that it does not get unregistered. > > > [1] > https://as.push.tefdigital.com/v1/notify/ > bd07e632faed6e1e6bafc49c6f12c6d180ba46bb8fd7e0eeeaf362489986d6d5 Hi Jovan, Looking into the server's database, the last version delivered for that endpoint is: 1421781261514 The server received the ACK from the mobile and doesn't have any pending notification for this endpoint. I suspect the issue is in the mobile side ... Adding Nikhil for checking and next steps. Nikhil, can Jovan check if the Push database has all the expected endpoints and correctly mapped with the app? Also, Jovan, remember that the version shall always be bigger than previous received, if not, the server will deliver it to the mobile but the mobile won't deliver it to the webapp.

Hello Fernando, I always use Date.now() for the new push version. Could this cause any problems?

(In reply to Jovan Gerodetti from comment #9) > Hello Fernando, > > I always use Date.now() for the new push version. Could this cause any > problems? No, this is perfect since it's always bigger :)

yea, thats why I choose it ;) So this is then a device / system problem rather than a server problem.

(In reply to Fernando R. Sela (no CC, needinfo please) [:frsela] from comment #8) > (In reply to Jovan Gerodetti from comment #7) > > okay, this[1] is definitely a dead endpoint, it does not work anymore and I > > watched out that it does not get unregistered. > > > > > > [1] > > https://as.push.tefdigital.com/v1/notify/ > > bd07e632faed6e1e6bafc49c6f12c6d180ba46bb8fd7e0eeeaf362489986d6d5 > > Hi Jovan, > > Looking into the server's database, the last version delivered for that > endpoint is: 1421781261514 > The server received the ACK from the mobile and doesn't have any pending > notification for this endpoint. > > I suspect the issue is in the mobile side ... Adding Nikhil for checking and > next steps. > Nikhil, can Jovan check if the Push database has all the expected endpoints > and correctly mapped with the app? > > Also, Jovan, remember that the version shall always be bigger than previous > received, if not, the server will deliver it to the mobile but the mobile > won't deliver it to the webapp. Have the app call push.getRegistrations() to get a list of registrations. If the services.push.debug pref is set, all of this will also be logged to console. Jovan, can you check if the UAID is changing? The device is assigned an identifier when it first connects to the push service, and the push service can change this UAID under certain conditions, in which case all the registrations are thrown away. Ideally your app should receive the push-register message when this happens, but maybe it isn't receiving it. The problem with the logging though is that the device needs to be connected to the computer, but in that case it may not go to sleep and lose the connection in the first place :/

okay, so I called navigator.push.registrations() with the services.push.debug enabled and this is my ADB logcat output: >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:347 in anonymous: checkLogin >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:348 in anonymous: start >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:370 in anonymous: checkLogin >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:377 in anonymous: loadingData >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:378 in anonymous: applicationStates >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:383 in anonymous: applicationStates >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/js/net.js:307 in interface.syncContacts/</scheduleNext: contacts are synchronized again in 27 minutes! >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:404 in anonymous: --directMessages >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:416 in anonymous: --timeline >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/ui.js:174 in interface.renderChats/<: loadingConversations >I/GeckoDump( 705): LOG: cronsync-main: wake locks acquired: [object MozWakeLock] for account IDs: 2 >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/bindings.js:179 in navigation/<: renderChat >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:409 in anonymous: --directMessages >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/ui.js:177 in interface.renderChats/</<: loadingConversations >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/ui.js:179 in interface.renderChats/</<: loadingMessages >I/Gecko ( 705): WLOG: Email knows that it is: online and previously was: online >I/Gecko ( 705): WLOG: deferring getConfig call until ready >I/Gecko ( 705): WLOG: main thread reports DB ready >I/Gecko ( 705): WLOG: issuing getConfig call to main thread >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/ui.js:194 in interface.renderChats/</</<: loadingMessages >I/Gecko ( 705): WLOG: cronsync: ensureSync called >I/Gecko ( 705): >I/Gecko ( 705): WLOG: Mail universe/bridge created and notified! >I/Gecko ( 705): WLOG: cronsync: received an alarm via a message handler >I/Gecko ( 705): >I/GeckoDump( 705): LOG: cronsync-main: ensureSync called >I/GeckoDump( 705): LOG: email oncronsyncstart: 2 >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: http://pbs.twimg.com/media/B731Rg0IgAAZrc9.png >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: http://pbs.twimg.com/media/B730akeIMAIJ0ee.jpg >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: http://pbs.twimg.com/media/B73q0wPCEAAuQLo.png >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: http://pbs.twimg.com/media/B73eEDiIIAEy1PE.png >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:427 in anonymous: --timeline >I/GeckoDump( 705): LOG: cronsync-main: success! >I/Gecko ( 705): WLOG: syncDateRange: 1421798400000 null >I/Gecko ( 705): WLOG: Skewed DB lookup. Start: 1421827200000 Wed, 21 Jan 2015 08:00:00 GMT End: null null >I/Gecko ( 705): WLOG: [slog] oauth:credentials-ok >I/GeckoDump( 705): LOG: cronsync-main: success: mozAlarms.add for IDs: 2 at 300000ms >I/GeckoDump( 705): LOG: cronsync-main: ensureSync completed >I/Gecko ( 705): WLOG: cronsync: received an syncEnsured via a message handler >I/Gecko ( 705): >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: https://ton.twitter.com/1.1/ton/data/dm/558018692634537984/558018692676472832/tDaioOb7.jpg >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:435 in anonymous: loadingData >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/js/app.js:151 in this.updatePushServer: push server already registered! >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/bindings.js:181 in navigation/</<: renderChat >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:449 in anonymous: start >I/Gecko ( 705): WINF: [slog] imap:connected {"hostname":"imap.gmail.com","port":"993","crypto":"ssl"} >I/Gecko ( 705): WLOG: SERVER UIDS 18 60 >I/Gecko ( 705): WLOG: onNewHeader: [object Object] >I/Gecko ( 705): WLOG: FETCHED 0 known id 11498 known srvid 27881 actual id 27841 >I/Gecko ( 705): WLOG: FETCHED 1 known id 11497 known srvid 27880 actual id 27853 >I/Gecko ( 705): WLOG: FETCHED 2 known id 11496 known srvid 27879 actual id 27855 >I/Gecko ( 705): WLOG: FETCHED 3 known id 11462 known srvid 27877 actual id 27856 >I/Gecko ( 705): WLOG: FETCHED 4 known id 11450 known srvid 27875 actual id 27858 >I/Gecko ( 705): WLOG: FETCHED 5 known id 11424 known srvid 27870 actual id 27859 >I/Gecko ( 705): WLOG: FETCHED 6 known id 11423 known srvid 27869 actual id 27863 >I/Gecko ( 705): WLOG: FETCHED 7 known id 11421 known srvid 27867 actual id 27865 >I/Gecko ( 705): WLOG: FETCHED 8 known id 11420 known srvid 27866 actual id 27866 >I/Gecko ( 705): WLOG: FETCHED 9 known id 11419 known srvid 27865 actual id 27867 >I/Gecko ( 705): WLOG: FETCHED 10 known id 11417 known srvid 27863 actual id 27869 >I/Gecko ( 705): WLOG: FETCHED 11 known id 11413 known srvid 27859 actual id 27870 >I/Gecko ( 705): WLOG: FETCHED 12 known id 11412 known srvid 27858 actual id 27875 >I/Gecko ( 705): WLOG: FETCHED 13 known id 11410 known srvid 27856 actual id 27877 >I/Gecko ( 705): WLOG: FETCHED 14 known id 11409 known srvid 27855 actual id 27879 >I/Gecko ( 705): WLOG: FETCHED 15 known id 11408 known srvid 27853 actual id 27880 >I/Gecko ( 705): WLOG: FETCHED 16 known id 11399 known srvid 27841 actual id 27881 >I/Gecko ( 705): WLOG: Sync Completed! null days 18 messages synced >I/Gecko ( 705): WLOG: folder message count 53 dbCount 74 syncedThrough null oldest known 1421627677000 >I/Gecko ( 705): WLOG: [slog] mailslice:mutex-released {"folderId":"2/0"} >I/Gecko ( 705): WLOG: cronsync: Asking for snippets for 1 headers >I/Gecko ( 705): >I/Gecko ( 705): WLOG: queueOp 2 downloadBodies pre-queues: local: 0 server: 0 >I/Gecko ( 705): WLOG: runOp(do: >{"type":"downloadBodies","longtermId":"2/6S","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{") >I/Gecko ( 705): WLOG: [slog] mailslice:mutex-released {"folderId":"2/0","err":null} >I/Gecko ( 705): WLOG: runOp_end(do: {"type":"downloadBodies","longtermId":"2/6S","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{") >I/Gecko ( 705): >I/Gecko ( 705): WLOG: cronsync: Notifying for 1 headers >I/Gecko ( 705): >I/Gecko ( 705): WLOG: Killing unused IMAP connection. >I/GeckoDump( 705): LOG: email oncronsyncstop: 2 >I/GeckoDump( 705): LOG: Notification sent for 2 >I/GeckoDump( 705): LOG: email: clearing wake locks for "id2" >I/GeckoDump( 705): LOG: mail sync complete, closing mail app 20414.173327 >I/Gecko ( 845): -*- Push.js: init() >I/Gecko ( 845): -*- Push.js: registrations() >I/Gecko ( 122): -*- PushService.jsm: receiveMessage(): Push:Registrations >I/Gecko ( 122): -*- PushService.jsm: registrations() >I/Gecko ( 122): -*- PushService.jsm: getAllByManifestURL() >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 0360589f-de14-41d3-8343-93cf45e6f54c >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 04af449e-8144-4a07-9c27-46185befd10b >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 2b184f39-b21e-411c-9c71-c033b4601ab7 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4ab849ce-ff20-45ca-9339-22a5381eb635 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4ce7e860-62f0-456c-a23d-c03e9be091fe >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4d589d92-50c8-4977-abd5-a092c012c3aa >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 68135adc-fdb9-425a-bdae-6d9e0c880ded >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 932ff078-2d26-4afe-996e-e50b84692db1 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp a8e8a5da-d8bf-4ed2-9650-f539aca8e629 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp b59e6ba0-5673-4d37-94a1-f54fea7431d7 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c06d4317-0fb3-4fdc-9fae-448e35c7337f >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c229cdc4-eaa6-418c-a0b2-ff20be60999f >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c43933c6-3b1b-4d8a-a6af-336b95e075dd >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp e3e8e618-f426-47f3-b6d3-34abe774691e >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp ea026fbf-bbbd-494f-b890-c88b43677e4c >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp f67e356c-8e24-4605-a991-4c48317dd88b >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp fcab05cd-2a59-417c-88c4-819fd246d8f2 >I/Gecko ( 845): -*- Push.js: receiveMessage() >E/GeckoConsole( 852): [JavaScript Error: "downloadable font: OS/2: bad linegap: -32 (font-family: "gaia-icons" style:normal weight:normal stretch:normal src index:0) >E/GeckoConsole( 852): source: data:application/x-font-ttf;charset=utf-8;base64,AAEAAAALAIAAAwAwT1MvMggi/aoAAAC8AAAAYGNtYXAaVc1LAAABHAAAAExnYXNwAAAAEAAAAWgAAAAIZ2x5ZnYZ6DIAAAFwAADXQGhlYWQEQOEjAADYsAAAADZoaGVhBtH/6wAA2OgAAAAkaG10eOsAVAsAANkMAAAD5GxvY2EPIEZIAADc8AAAAfRtYXhwAQwBmAAA3uQAAAAgbmFtZVcZpu4AAN8EAAABRXBvc3QAAwAAAADgTAAAACAAAwIAAZAABQAAAUwBZgAAAEcBTAFmAAAA9QAZAIQAAAAAAAAAAAAAAAAAAAABEAAAAAAAAAAAAAAAAAAAAABAAADm9AHg/+D/4AHgACAAAAABAAAAAAAAAAAAAAAgAAAAAAACAAAAAwAAABQAAwABAAAAFAAEADgAAAAKAAgAAgACAAEAIOb0//3//wAAAAAAIOYA//3//wAB/+MaBAADAAEAAAAAAAAAAAAAAAEAAf//AA8AAQAAAAAAAAAAAAIAADc5AQAAAAABAAAAAAAAAAAAAgAANzkBAAAAAAEAAAAAAAAAAAACAAA3OQEAAAAAAgCTAFABbQFgAA0ARAAAJSImJy4BNTMUBgcOASM3IyImPwE+ATc+ATUxNTM+ATc+ATc0JjE0Njc+ATMyFhceAR0BHgEXHgEXMxUUFhceAR8BFgYjAQAHDAQFBkQGBQQMB2DADAUEAwYJAwQEAQEHBgYQCQEGBAUNBwcNBAUFCRAGBgcBAQQEAwkGAwQFDVAFBAULBwcLBQQFMBwEBAQKBQYMBzUJDwcHCgQBAggMBQUFBQUFDAgEAwsHBh >E/GeckoConsole( 959): [JavaScript Warning: "Unknown property 'will-change'. Declaration dropped." {file: "resource://gre-resources/full-screen-override.css" line: 24 column: 13 source: " will-change: initial !important;"}] >I/Gecko ( 959): ###################################### forms.js loaded >I/Gecko ( 959): ############################### browserElementPanning.js loaded >I/Gecko ( 959): ######################## BrowserElementChildPreload.js loaded >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] app://grape-tweet.com/manifest.webapp ran for 198 >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] Saved app usage data >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] app://lockscreen.gaiamobile.org/index.html/manifest.webapp ran for 4 >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] Saved app usage data >I/GeckoDump( 122): XXX FIXME : Got a mozContentEvent: remote-debugger-prompt >I/Gecko ( 845): -*- Push.js: registrations() >I/Gecko ( 122): -*- PushService.jsm: receiveMessage(): Push:Registrations >I/Gecko ( 122): -*- PushService.jsm: registrations() >I/Gecko ( 122): -*- PushService.jsm: getAllByManifestURL() >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 0360589f-de14-41d3-8343-93cf45e6f54c >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 04af449e-8144-4a07-9c27-46185befd10b >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 2b184f39-b21e-411c-9c71-c033b4601ab7 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4ab849ce-ff20-45ca-9339-22a5381eb635 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4ce7e860-62f0-456c-a23d-c03e9be091fe >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4d589d92-50c8-4977-abd5-a092c012c3aa >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 68135adc-fdb9-425a-bdae-6d9e0c880ded >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 932ff078-2d26-4afe-996e-e50b84692db1 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp a8e8a5da-d8bf-4ed2-9650-f539aca8e629 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp b59e6ba0-5673-4d37-94a1-f54fea7431d7 >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c06d4317-0fb3-4fdc-9fae-448e35c7337f >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c229cdc4-eaa6-418c-a0b2-ff20be60999f >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c43933c6-3b1b-4d8a-a6af-336b95e075dd >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp e3e8e618-f426-47f3-b6d3-34abe774691e >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp ea026fbf-bbbd-494f-b890-c88b43677e4c >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp f67e356c-8e24-4605-a991-4c48317dd88b >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp fcab05cd-2a59-417c-88c4-819fd246d8f2 >I/Gecko ( 845): -*- Push.js: receiveMessage() >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] app://grape-tweet.com/manifest.webapp ran for 92 >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] Saved app usage data >E/GeckoConsole( 1057): [JavaScript Warning: "Unknown property 'will-change'. Declaration dropped." {file: "resource://gre-resources/full-screen-override.css" line: 24 column: 13 source: " will-change: initial !important;"}] >I/Gecko ( 1057): ###################################### forms.js loaded >I/Gecko ( 1057): ############################### browserElementPanning.js loaded >I/Gecko ( 1057): ######################## BrowserElementChildPreload.js loaded >I/GeckoDump( 959): LOG: email startedInBackground >I/GeckoDump( 959): LOG: cronsync-main: wake locks acquired: [object MozWakeLock] for account IDs: 2 >I/Gecko ( 959): WLOG: Email knows that it is: online and previously was: online >I/Gecko ( 959): WLOG: deferring getConfig call until ready >I/Gecko ( 959): WLOG: main thread reports DB ready >I/Gecko ( 959): WLOG: issuing getConfig call to main thread >I/Gecko ( 959): WLOG: cronsync: ensureSync called >I/Gecko ( 959): >I/Gecko ( 959): WLOG: Mail universe/bridge created and notified! >I/Gecko ( 959): WLOG: cronsync: received an alarm via a message handler >I/Gecko ( 959): >I/GeckoDump( 959): LOG: cronsync-main: ensureSync called >I/GeckoDump( 959): LOG: email oncronsyncstart: 2 >I/GeckoDump( 959): LOG: cronsync-main: success! >I/GeckoDump( 959): LOG: cronsync-main: success: mozAlarms.add for IDs: 2 at 300000ms >I/GeckoDump( 959): LOG: cronsync-main: ensureSync completed >I/Gecko ( 959): WLOG: cronsync: received an syncEnsured via a message handler >I/Gecko ( 959): >I/Gecko ( 959): WLOG: syncDateRange: 1421798400000 null >I/Gecko ( 959): WLOG: Skewed DB lookup. Start: 1421827200000 Wed, 21 Jan 2015 08:00:00 GMT End: null null >I/Gecko ( 959): WLOG: [slog] oauth:credentials-ok >I/Gecko ( 959): WINF: [slog] imap:connected {"hostname":"imap.gmail.com","port":"993","crypto":"ssl"} >I/Gecko ( 959): WLOG: SERVER UIDS 18 60 >I/Gecko ( 959): WLOG: FETCHED 0 known id 11499 known srvid 27882 actual id 27841 >I/Gecko ( 959): WLOG: FETCHED 1 known id 11498 known srvid 27881 actual id 27853 >I/Gecko ( 959): WLOG: FETCHED 2 known id 11497 known srvid 27880 actual id 27855 >I/Gecko ( 959): WLOG: FETCHED 3 known id 11496 known srvid 27879 actual id 27856 >I/Gecko ( 959): WLOG: FETCHED 4 known id 11462 known srvid 27877 actual id 27858 >I/Gecko ( 959): WLOG: FETCHED 5 known id 11450 known srvid 27875 actual id 27859 >I/Gecko ( 959): WLOG: FETCHED 6 known id 11424 known srvid 27870 actual id 27863 >I/Gecko ( 959): WLOG: FETCHED 7 known id 11423 known srvid 27869 actual id 27865 >I/Gecko ( 959): WLOG: FETCHED 8 known id 11421 known srvid 27867 actual id 27866 >I/Gecko ( 959): WLOG: FETCHED 9 known id 11420 known srvid 27866 actual id 27867 >I/Gecko ( 959): WLOG: FETCHED 10 known id 11419 known srvid 27865 actual id 27869 >I/Gecko ( 959): WLOG: FETCHED 11 known id 11417 known srvid 27863 actual id 27870 >I/Gecko ( 959): WLOG: FETCHED 12 known id 11413 known srvid 27859 actual id 27875 >I/Gecko ( 959): WLOG: FETCHED 13 known id 11412 known srvid 27858 actual id 27877 >I/Gecko ( 959): WLOG: FETCHED 14 known id 11410 known srvid 27856 actual id 27879 >I/Gecko ( 959): WLOG: FETCHED 15 known id 11409 known srvid 27855 actual id 27880 >I/Gecko ( 959): WLOG: FETCHED 16 known id 11408 known srvid 27853 actual id 27881 >I/Gecko ( 959): WLOG: FETCHED 17 known id 11399 known srvid 27841 actual id 27882 >I/Gecko ( 959): WWAR: FLAGS: "" VS "\Answered,\Seen" >I/Gecko ( 959): WLOG: Sync Completed! null days 18 messages synced >I/Gecko ( 959): WLOG: folder message count 53 dbCount 74 syncedThrough null oldest known 1421627677000 >I/Gecko ( 959): WLOG: [slog] mailslice:mutex-released {"folderId":"2/0"} >I/Gecko ( 959): WLOG: Killing unused IMAP connection. >I/GeckoDump( 959): LOG: email oncronsyncstop: 2 >I/GeckoDump( 959): LOG: email: clearing wake locks for "id2" >I/GeckoDump( 959): LOG: mail sync complete, closing mail app 14121.348338 my current UAID (services.push.userAgentID) is 93227901-7103-431c-9a23-e4978afed71b@2fcc633ac3011dc0f1d662b0ef6dc07f7dc2c64d but at the moment I can't tell if it changed.

(In reply to Jovan Gerodetti from comment #13) > okay, so I called navigator.push.registrations() with the > services.push.debug enabled and this is my ADB logcat output: > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:347 in anonymous: checkLogin > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:348 in anonymous: start > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:370 in anonymous: checkLogin > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:377 in anonymous: loadingData > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:378 in anonymous: applicationStates > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:383 in anonymous: applicationStates > >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/js/net.js:307 in interface.syncContacts/</scheduleNext: contacts are synchronized again in 27 minutes! > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:404 in anonymous: --directMessages > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/app.js:416 in anonymous: --timeline > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/ui.js:174 in interface.renderChats/<: loadingConversations > >I/GeckoDump( 705): LOG: cronsync-main: wake locks acquired: [object MozWakeLock] for account IDs: 2 > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/bindings.js:179 in navigation/<: renderChat > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:409 in anonymous: --directMessages > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/ui.js:177 in interface.renderChats/</<: loadingConversations > >E/GeckoConsole( 845): Content JS TIME at app://grape-tweet.com/js/ui.js:179 in interface.renderChats/</<: loadingMessages > >I/Gecko ( 705): WLOG: Email knows that it is: online and previously was: online > >I/Gecko ( 705): WLOG: deferring getConfig call until ready > >I/Gecko ( 705): WLOG: main thread reports DB ready > >I/Gecko ( 705): WLOG: issuing getConfig call to main thread > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/ui.js:194 in interface.renderChats/</</<: loadingMessages > >I/Gecko ( 705): WLOG: cronsync: ensureSync called > >I/Gecko ( 705): > >I/Gecko ( 705): WLOG: Mail universe/bridge created and notified! > >I/Gecko ( 705): WLOG: cronsync: received an alarm via a message handler > >I/Gecko ( 705): > >I/GeckoDump( 705): LOG: cronsync-main: ensureSync called > >I/GeckoDump( 705): LOG: email oncronsyncstart: 2 > >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: http://pbs.twimg.com/media/B731Rg0IgAAZrc9.png > >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: http://pbs.twimg.com/media/B730akeIMAIJ0ee.jpg > >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: http://pbs.twimg.com/media/B73q0wPCEAAuQLo.png > >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: http://pbs.twimg.com/media/B73eEDiIIAEy1PE.png > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:427 in anonymous: --timeline > >I/GeckoDump( 705): LOG: cronsync-main: success! > >I/Gecko ( 705): WLOG: syncDateRange: 1421798400000 null > >I/Gecko ( 705): WLOG: Skewed DB lookup. Start: 1421827200000 Wed, 21 Jan 2015 08:00:00 GMT End: null null > >I/Gecko ( 705): WLOG: [slog] oauth:credentials-ok > >I/GeckoDump( 705): LOG: cronsync-main: success: mozAlarms.add for IDs: 2 at 300000ms > >I/GeckoDump( 705): LOG: cronsync-main: ensureSync completed > >I/Gecko ( 705): WLOG: cronsync: received an syncEnsured via a message handler > >I/Gecko ( 705): > >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/af/modules/connections.js:327 in ._init/OAuthRequest.prototype.send/<: https://ton.twitter.com/1.1/ton/data/dm/558018692634537984/558018692676472832/tDaioOb7.jpg > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:435 in anonymous: loadingData > >E/GeckoConsole( 845): Content JS LOG at app://grape-tweet.com/js/app.js:151 in this.updatePushServer: push server already registered! > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/bindings.js:181 in navigation/</<: renderChat > >E/GeckoConsole( 845): Content JS TIMEEND at app://grape-tweet.com/js/app.js:449 in anonymous: start > >I/Gecko ( 705): WINF: [slog] imap:connected {"hostname":"imap.gmail.com","port":"993","crypto":"ssl"} > >I/Gecko ( 705): WLOG: SERVER UIDS 18 60 > >I/Gecko ( 705): WLOG: onNewHeader: [object Object] > >I/Gecko ( 705): WLOG: FETCHED 0 known id 11498 known srvid 27881 actual id 27841 > >I/Gecko ( 705): WLOG: FETCHED 1 known id 11497 known srvid 27880 actual id 27853 > >I/Gecko ( 705): WLOG: FETCHED 2 known id 11496 known srvid 27879 actual id 27855 > >I/Gecko ( 705): WLOG: FETCHED 3 known id 11462 known srvid 27877 actual id 27856 > >I/Gecko ( 705): WLOG: FETCHED 4 known id 11450 known srvid 27875 actual id 27858 > >I/Gecko ( 705): WLOG: FETCHED 5 known id 11424 known srvid 27870 actual id 27859 > >I/Gecko ( 705): WLOG: FETCHED 6 known id 11423 known srvid 27869 actual id 27863 > >I/Gecko ( 705): WLOG: FETCHED 7 known id 11421 known srvid 27867 actual id 27865 > >I/Gecko ( 705): WLOG: FETCHED 8 known id 11420 known srvid 27866 actual id 27866 > >I/Gecko ( 705): WLOG: FETCHED 9 known id 11419 known srvid 27865 actual id 27867 > >I/Gecko ( 705): WLOG: FETCHED 10 known id 11417 known srvid 27863 actual id 27869 > >I/Gecko ( 705): WLOG: FETCHED 11 known id 11413 known srvid 27859 actual id 27870 > >I/Gecko ( 705): WLOG: FETCHED 12 known id 11412 known srvid 27858 actual id 27875 > >I/Gecko ( 705): WLOG: FETCHED 13 known id 11410 known srvid 27856 actual id 27877 > >I/Gecko ( 705): WLOG: FETCHED 14 known id 11409 known srvid 27855 actual id 27879 > >I/Gecko ( 705): WLOG: FETCHED 15 known id 11408 known srvid 27853 actual id 27880 > >I/Gecko ( 705): WLOG: FETCHED 16 known id 11399 known srvid 27841 actual id 27881 > >I/Gecko ( 705): WLOG: Sync Completed! null days 18 messages synced > >I/Gecko ( 705): WLOG: folder message count 53 dbCount 74 syncedThrough null oldest known 1421627677000 > >I/Gecko ( 705): WLOG: [slog] mailslice:mutex-released {"folderId":"2/0"} > >I/Gecko ( 705): WLOG: cronsync: Asking for snippets for 1 headers > >I/Gecko ( 705): > >I/Gecko ( 705): WLOG: queueOp 2 downloadBodies pre-queues: local: 0 server: 0 > >I/Gecko ( 705): WLOG: runOp(do: >{"type":"downloadBodies","longtermId":"2/6S","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{") > >I/Gecko ( 705): WLOG: [slog] mailslice:mutex-released {"folderId":"2/0","err":null} > >I/Gecko ( 705): WLOG: runOp_end(do: {"type":"downloadBodies","longtermId":"2/6S","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{") > >I/Gecko ( 705): > >I/Gecko ( 705): WLOG: cronsync: Notifying for 1 headers > >I/Gecko ( 705): > >I/Gecko ( 705): WLOG: Killing unused IMAP connection. > >I/GeckoDump( 705): LOG: email oncronsyncstop: 2 > >I/GeckoDump( 705): LOG: Notification sent for 2 > >I/GeckoDump( 705): LOG: email: clearing wake locks for "id2" > >I/GeckoDump( 705): LOG: mail sync complete, closing mail app 20414.173327 > >I/Gecko ( 845): -*- Push.js: init() > >I/Gecko ( 845): -*- Push.js: registrations() > >I/Gecko ( 122): -*- PushService.jsm: receiveMessage(): Push:Registrations > >I/Gecko ( 122): -*- PushService.jsm: registrations() > >I/Gecko ( 122): -*- PushService.jsm: getAllByManifestURL() > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 0360589f-de14-41d3-8343-93cf45e6f54c > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 04af449e-8144-4a07-9c27-46185befd10b > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 2b184f39-b21e-411c-9c71-c033b4601ab7 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4ab849ce-ff20-45ca-9339-22a5381eb635 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4ce7e860-62f0-456c-a23d-c03e9be091fe > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4d589d92-50c8-4977-abd5-a092c012c3aa > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 68135adc-fdb9-425a-bdae-6d9e0c880ded > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 932ff078-2d26-4afe-996e-e50b84692db1 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp a8e8a5da-d8bf-4ed2-9650-f539aca8e629 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp b59e6ba0-5673-4d37-94a1-f54fea7431d7 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c06d4317-0fb3-4fdc-9fae-448e35c7337f > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c229cdc4-eaa6-418c-a0b2-ff20be60999f > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c43933c6-3b1b-4d8a-a6af-336b95e075dd > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp e3e8e618-f426-47f3-b6d3-34abe774691e > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp ea026fbf-bbbd-494f-b890-c88b43677e4c > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp f67e356c-8e24-4605-a991-4c48317dd88b > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp fcab05cd-2a59-417c-88c4-819fd246d8f2 > >I/Gecko ( 845): -*- Push.js: receiveMessage() > >E/GeckoConsole( 852): [JavaScript Error: "downloadable font: OS/2: bad linegap: -32 (font-family: "gaia-icons" style:normal weight:normal stretch:normal src index:0) > >E/GeckoConsole( 852): source: data:application/x-font-ttf;charset=utf-8;base64,AAEAAAALAIAAAwAwT1MvMggi/aoAAAC8AAAAYGNtYXAaVc1LAAABHAAAAExnYXNwAAAAEAAAAWgAAAAIZ2x5ZnYZ6DIAAAFwAADXQGhlYWQEQOEjAADYsAAAADZoaGVhBtH/6wAA2OgAAAAkaG10eOsAVAsAANkMAAAD5GxvY2EPIEZIAADc8AAAAfRtYXhwAQwBmAAA3uQAAAAgbmFtZVcZpu4AAN8EAAABRXBvc3QAAwAAAADgTAAAACAAAwIAAZAABQAAAUwBZgAAAEcBTAFmAAAA9QAZAIQAAAAAAAAAAAAAAAAAAAABEAAAAAAAAAAAAAAAAAAAAABAAADm9AHg/+D/4AHgACAAAAABAAAAAAAAAAAAAAAgAAAAAAACAAAAAwAAABQAAwABAAAAFAAEADgAAAAKAAgAAgACAAEAIOb0//3//wAAAAAAIOYA//3//wAB/+MaBAADAAEAAAAAAAAAAAAAAAEAAf//AA8AAQAAAAAAAAAAAAIAADc5AQAAAAABAAAAAAAAAAAAAgAANzkBAAAAAAEAAAAAAAAAAAACAAA3OQEAAAAAAgCTAFABbQFgAA0ARAAAJSImJy4BNTMUBgcOASM3IyImPwE+ATc+ATUxNTM+ATc+ATc0JjE0Njc+ATMyFhceAR0BHgEXHgEXMxUUFhceAR8BFgYjAQAHDAQFBkQGBQQMB2DADAUEAwYJAwQEAQEHBgYQCQEGBAUNBwcNBAUFCRAGBgcBAQQEAwkGAwQFDVAFBAULBwcLBQQFMBwEBAQKBQYMBzUJDwcHCgQBAggMBQUFBQUFDAgEAwsHBh > >E/GeckoConsole( 959): [JavaScript Warning: "Unknown property 'will-change'. Declaration dropped." {file: "resource://gre-resources/full-screen-override.css" line: 24 column: 13 source: " will-change: initial !important;"}] > >I/Gecko ( 959): ###################################### forms.js loaded > >I/Gecko ( 959): ############################### browserElementPanning.js loaded > >I/Gecko ( 959): ######################## BrowserElementChildPreload.js loaded > >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] app://grape-tweet.com/manifest.webapp ran for 198 > >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] Saved app usage data > >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] app://lockscreen.gaiamobile.org/index.html/manifest.webapp ran for 4 > >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] Saved app usage data > >I/GeckoDump( 122): XXX FIXME : Got a mozContentEvent: remote-debugger-prompt > >I/Gecko ( 845): -*- Push.js: registrations() > >I/Gecko ( 122): -*- PushService.jsm: receiveMessage(): Push:Registrations > >I/Gecko ( 122): -*- PushService.jsm: registrations() > >I/Gecko ( 122): -*- PushService.jsm: getAllByManifestURL() > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 0360589f-de14-41d3-8343-93cf45e6f54c > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 04af449e-8144-4a07-9c27-46185befd10b > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 2b184f39-b21e-411c-9c71-c033b4601ab7 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4ab849ce-ff20-45ca-9339-22a5381eb635 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4ce7e860-62f0-456c-a23d-c03e9be091fe > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 4d589d92-50c8-4977-abd5-a092c012c3aa > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 68135adc-fdb9-425a-bdae-6d9e0c880ded > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp 932ff078-2d26-4afe-996e-e50b84692db1 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp a8e8a5da-d8bf-4ed2-9650-f539aca8e629 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp b59e6ba0-5673-4d37-94a1-f54fea7431d7 > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c06d4317-0fb3-4fdc-9fae-448e35c7337f > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c229cdc4-eaa6-418c-a0b2-ff20be60999f > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp c43933c6-3b1b-4d8a-a6af-336b95e075dd > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp e3e8e618-f426-47f3-b6d3-34abe774691e > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp ea026fbf-bbbd-494f-b890-c88b43677e4c > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp f67e356c-8e24-4605-a991-4c48317dd88b > >I/Gecko ( 122): -*- PushService.jsm: app://grape-tweet.com/manifest.webapp fcab05cd-2a59-417c-88c4-819fd246d8f2 > >I/Gecko ( 845): -*- Push.js: receiveMessage() > >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] app://grape-tweet.com/manifest.webapp ran for 92 > >E/GeckoConsole( 122): Content JS LOG at app://system.gaiamobile.org/js/app_usage_metrics.js:120 in debug: [AppUsage] Saved app usage data > >E/GeckoConsole( 1057): [JavaScript Warning: "Unknown property 'will-change'. Declaration dropped." {file: "resource://gre-resources/full-screen-override.css" line: 24 column: 13 source: " will-change: initial !important;"}] > >I/Gecko ( 1057): ###################################### forms.js loaded > >I/Gecko ( 1057): ############################### browserElementPanning.js loaded > >I/Gecko ( 1057): ######################## BrowserElementChildPreload.js loaded > >I/GeckoDump( 959): LOG: email startedInBackground > >I/GeckoDump( 959): LOG: cronsync-main: wake locks acquired: [object MozWakeLock] for account IDs: 2 > >I/Gecko ( 959): WLOG: Email knows that it is: online and previously was: online > >I/Gecko ( 959): WLOG: deferring getConfig call until ready > >I/Gecko ( 959): WLOG: main thread reports DB ready > >I/Gecko ( 959): WLOG: issuing getConfig call to main thread > >I/Gecko ( 959): WLOG: cronsync: ensureSync called > >I/Gecko ( 959): > >I/Gecko ( 959): WLOG: Mail universe/bridge created and notified! > >I/Gecko ( 959): WLOG: cronsync: received an alarm via a message handler > >I/Gecko ( 959): > >I/GeckoDump( 959): LOG: cronsync-main: ensureSync called > >I/GeckoDump( 959): LOG: email oncronsyncstart: 2 > >I/GeckoDump( 959): LOG: cronsync-main: success! > >I/GeckoDump( 959): LOG: cronsync-main: success: mozAlarms.add for IDs: 2 at 300000ms > >I/GeckoDump( 959): LOG: cronsync-main: ensureSync completed > >I/Gecko ( 959): WLOG: cronsync: received an syncEnsured via a message handler > >I/Gecko ( 959): > >I/Gecko ( 959): WLOG: syncDateRange: 1421798400000 null > >I/Gecko ( 959): WLOG: Skewed DB lookup. Start: 1421827200000 Wed, 21 Jan 2015 08:00:00 GMT End: null null > >I/Gecko ( 959): WLOG: [slog] oauth:credentials-ok > >I/Gecko ( 959): WINF: [slog] imap:connected {"hostname":"imap.gmail.com","port":"993","crypto":"ssl"} > >I/Gecko ( 959): WLOG: SERVER UIDS 18 60 > >I/Gecko ( 959): WLOG: FETCHED 0 known id 11499 known srvid 27882 actual id 27841 > >I/Gecko ( 959): WLOG: FETCHED 1 known id 11498 known srvid 27881 actual id 27853 > >I/Gecko ( 959): WLOG: FETCHED 2 known id 11497 known srvid 27880 actual id 27855 > >I/Gecko ( 959): WLOG: FETCHED 3 known id 11496 known srvid 27879 actual id 27856 > >I/Gecko ( 959): WLOG: FETCHED 4 known id 11462 known srvid 27877 actual id 27858 > >I/Gecko ( 959): WLOG: FETCHED 5 known id 11450 known srvid 27875 actual id 27859 > >I/Gecko ( 959): WLOG: FETCHED 6 known id 11424 known srvid 27870 actual id 27863 > >I/Gecko ( 959): WLOG: FETCHED 7 known id 11423 known srvid 27869 actual id 27865 > >I/Gecko ( 959): WLOG: FETCHED 8 known id 11421 known srvid 27867 actual id 27866 > >I/Gecko ( 959): WLOG: FETCHED 9 known id 11420 known srvid 27866 actual id 27867 > >I/Gecko ( 959): WLOG: FETCHED 10 known id 11419 known srvid 27865 actual id 27869 > >I/Gecko ( 959): WLOG: FETCHED 11 known id 11417 known srvid 27863 actual id 27870 > >I/Gecko ( 959): WLOG: FETCHED 12 known id 11413 known srvid 27859 actual id 27875 > >I/Gecko ( 959): WLOG: FETCHED 13 known id 11412 known srvid 27858 actual id 27877 > >I/Gecko ( 959): WLOG: FETCHED 14 known id 11410 known srvid 27856 actual id 27879 > >I/Gecko ( 959): WLOG: FETCHED 15 known id 11409 known srvid 27855 actual id 27880 > >I/Gecko ( 959): WLOG: FETCHED 16 known id 11408 known srvid 27853 actual id 27881 > >I/Gecko ( 959): WLOG: FETCHED 17 known id 11399 known srvid 27841 actual id 27882 > >I/Gecko ( 959): WWAR: FLAGS: "" VS "\Answered,\Seen" > >I/Gecko ( 959): WLOG: Sync Completed! null days 18 messages synced > >I/Gecko ( 959): WLOG: folder message count 53 dbCount 74 syncedThrough null oldest known 1421627677000 > >I/Gecko ( 959): WLOG: [slog] mailslice:mutex-released {"folderId":"2/0"} > >I/Gecko ( 959): WLOG: Killing unused IMAP connection. > >I/GeckoDump( 959): LOG: email oncronsyncstop: 2 > >I/GeckoDump( 959): LOG: email: clearing wake locks for "id2" > >I/GeckoDump( 959): LOG: mail sync complete, closing mail app 14121.348338 > > my current UAID (services.push.userAgentID) is > 93227901-7103-431c-9a23-e4978afed71b@2fcc633ac3011dc0f1d662b0ef6dc07f7dc2c64d > > but at the moment I can't tell if it changed. Leave the device disconnected from USB for a while (few hours at least) and then connect again and see if the UAID has changed.

okay I just checked my UAID again, since it passed a few days now. currently its: 93227901-7103-431c-9a23-e4978afed71b@2fcc633ac3011dc0f1d662b0ef6dc07f7dc2c64d but this looks like its still the same.

More related information. I left running all the night a tesing app in a Flame with the 2.1 branch sending a push message each second. This morning, I didn't receive more push messages but in the log traces I can see that the device is receiving it really well: I/Gecko ( 3305): -*- PushService.jsm: wsOnMessageAvailable() {"messageType":"notification","updates":[{"version":"1423049181000","channelID":"51f8c686-5716-49b8-b8f1-c59411838519"}]} I/Gecko ( 3305): -*- PushService.jsm: Reseting _retryFailCount and _pingIntervalRetryTimes I/Gecko ( 3305): -*- PushService.jsm: Stopped existing alarm 1426 I/Gecko ( 3305): -*- PushService.jsm: handleNotificationReply() I/Gecko ( 3305): -*- PushService.jsm: Reply updates: 1 I/Gecko ( 3305): -*- PushService.jsm: Update: 51f8c686-5716-49b8-b8f1-c59411838519: 1423049181000 I/Gecko ( 3305): -*- PushService.jsm: Updating: 51f8c686-5716-49b8-b8f1-c59411838519 -> 1423049181000 I/Gecko ( 3305): -*- PushService.jsm: getByChannelID() I/Gecko ( 3305): -*- PushService.jsm: sendAck() I/Gecko ( 3305): -*- PushService.jsm: send() I/Gecko ( 3305): -*- PushService.jsm: Queued ack I/Gecko ( 3305): -*- PushService.jsm: _processNextRequestInQueue() I/Gecko ( 3305): -*- PushService.jsm: Sending message: {"updates":[{"channelID":"51f8c686-5716-49b8-b8f1-c59411838519","version":1423049181000}],"messageType":"ack"} I/Gecko ( 3305): -*- PushService.jsm: _processNextRequestInQueue() I/Gecko ( 3305): -*- PushService.jsm: Request queue empty I/Gecko ( 3305): -*- PushService.jsm: Fetch successful [object Object] I/Gecko ( 3305): -*- PushService.jsm: compareRecordVersionAndNotify() I/Gecko ( 3305): -*- PushService.jsm: Version changed, notifying app and updating DB I/Gecko ( 3305): -*- PushService.jsm: notifyApp() app://1308ed8b-66d6-442c-8a02-657e3c1cfb20/index.html app://1308ed8b-66d6-442c-8a02-657e3c1cfb20/manifest.webapp I/Gecko ( 3305): -*- PushService.jsm: updatePushRecord() I/Gecko ( 3305): -*- PushService.jsm: put() I/Gecko ( 3305): -*- PushService.jsm: Going to put 51f8c686-5716-49b8-b8f1-c59411838519 I/Gecko ( 3305): -*- PushService.jsm: Request successful. Updated record ID: 51f8c686-5716-49b8-b8f1-c59411838519 I/Gecko ( 3305): -*- PushService.jsm: Set alarm 1366875 in the future 1427 But the application didn't receives the System message. It's important to say that navigator.push and navigator.mozAlarms doesn't exists anymore (also if we re-start the app) so we shall reboot the phone. W/PushTester(30221): [JavaScript Error: "TypeError: navigator.mozAlarms is undefined" {file: "app://1308ed8b-66d6-442c-8a02-657e3c1cfb20/js/alarm.js" line: 3}] (When checking for navigator.push): I/PushTester( 5761): Content JS LOG: [PushTester] The browser doesn't support notifications push

[Blocking Requested - why for this release]:

Why do the APIs disappear? That is completely unrelated to push as such. Is this due to permissions being lost? Can you check the app still has permissions (I don't know if there is any API to check this).

(In reply to Nikhil Marathe [:nsm] (needinfo? please) from comment #18) > Why do the APIs disappear? That is completely unrelated to push as such. Is > this due to permissions being lost? Can you check the app still has > permissions (I don't know if there is any API to check this). Sure, this isn't a push related issue, fully agree. But push was the road to discover it ;) I asked you to know your opinion about the issue or if you have any idea or if you can put some light to the investigation ;) I continue getting traces to try to discover why these APIs dissapear. I didn't see any error trace, so as you said, could be a permission lost? I don't know.

Hi Fernando, You worked sometime ago in a permissions issue. Could that have a relationship with this one? Thanks in advance

Might be a permissions issue, but I cannot tell looking at these logs. I believe you can dump permission manager information to the logcat by enabling a setting from the developer menu in the Gaia Settings app. Alternatively you can check the permission DB by running the checkPermissions.sh script from https://github.com/AntonioMA/gaiatools You should be able to verify if the app is really loosing the permissions this way.

I don't think my script is going to help here. The script only dumps the information that's persistently stored on the permission database, and that information is correct (since restarting the phone reinstates the missing functionality for the affected apps). When it fails the failure seems restricted to a concrete app, since restarting that application doesn't restore the functionality, but any other app that uses push works correctly. Since the permission table is cached in memory, what might be corrupted is the in-memory permission table. I hazily remember that some months ago we had a similar problem with loop and transient permissions (PROMPT permissions weren't always shared correctly from the parent to the template process and so the next time the app was launched it would randomly fail). I'm trying to remember what bug was that and how we fixed it.

This was the other bug were we ran into permission problems with preallocated processes: https://bugzilla.mozilla.org/show_bug.cgi?id=1068635 This one might not be the same because the process starts correctly and after some time it loses the permission forever (where forever means until the phone is restarted).

Adding more info. I added some traces in CheckPermissions in dom/bindings/BindingUtils.cpp I realized that after the crash, if we close and re-open the affected app, all permissions are REJECTED. Also, the test app is only asking for Alarms and push but the checkpermissions traces show errors for: I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... idle # PID: 9449 I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... feature-detection # PID: 9449 I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... power # PID: 9449 I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... mobileconnection # PID: 9449 I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... telephony # PID: 9449 I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... bluetooth # PID: 9449 I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... fmradio # PID: 9449 I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... time # PID: 9449 I/Gecko ( 9449): FRS: CheckPermissions - Rejected permission ... push # PID: 9449 So, as Nikhil told on comment #18 this is a permissions issue and not push related one. Renaming and changing component

Not sure if there are still triages for version 2.1, but I think this is an important bug that should be fixed. What do you think?

This looks pretty serious. 2.1+ Please also include a 2.1 patch and a risk/areas to test feedback.

(In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from comment #26) > This looks pretty serious. 2.1+ > Please also include a 2.1 patch and a risk/areas to test feedback. agree.

Hi Paul, may need you advice for the next step here. thanks.

(In reply to Steven Yang [:styang] from comment #28) > Hi Paul, may need you advice for the next step here. thanks. Not sure what you are asking? Can you elaborate what advice you are after? I'd guess the first step is to reliably induce the scenario where an app loses permissions. It's unclear to me from the posts above if that has been done yet, and I could only speculate at the cause at this point. If you can reproduce, then maybe look at the list of permissions which the child gets told it has in nsPermissionManager::FetchPermissions() [1] IIUC this will at least help you work out if its the parent process or the child process with the wrong list of permissions. [1] https://mxr.mozilla.org/mozilla-central/source/extensions/cookie/nsPermissionManager.cpp#2215

This is a 2.1+ worthy to fix. Can you please make some progress here? Setting several NIs but not sure who should be in charge (sorry).

Still trying to figure out how to reproduce this issue. Based on the bug, it seemed to have morphed to the permissions test. I tried using jsmith's permission test app http://mozilla-b2g.github.io/qa-testcase-data/webapi/apps/ I think the problem in why we didn't catch this is that there had been changes to that busted the app and jsmith had left a while ago. Will need help ramping up on webapi/permissions. If anyone wants to help fix the app, the github repository is found: https://github.com/mozilla-b2g/qa-testcase-data

:brg, can anyone on your side help with a simple testcase here? :fabrice might have some cycles to look at this but if you can help with a simple test app it will go a long way.

We are losing the permissions in the child process right?

A way to reproduce it would be to use an app with push notifications for some time (it can take several hours). Sending needinfo to Fernando for providing more details and a testing app.

per comment 34

I used this app [1], after getting the push endpoint, I used this shell script to send Push messages in a continous way to my device: while true; do curl -X PUT -k -d "version=`date +%s`000" https://endpointURL > /dev/null; sleep 1; done You'll see the device receiving all messages but after some hours, it stops and the mozAlarms, push and others could be accessed until you restart the app. [1] https://github.com/TelefonicaPushServer/PushTester

Maybe unrelated, maybe not: http://mxr.mozilla.org/mozilla-central/source/extensions/cookie/nsPermissionManager.cpp#593

I am able to use the test app and see the push notification working. Thanks! Having said that I haven't gotten the repro of this bug as of yet. 1) I have tried the app in the foreground and the device going to sleep ( ~ 30 mins of inactivity ) and it still is responding correctly. I did notice some latency of the homescreen on wake ( which would be a separate issue ) 2) Currently trying to do app in the background and letting the device go to sleep.

Can't seem to repro this on master at this moment in time. Going to try unplugging the device and letting it sleep and then seeing if it reproduces. Now that I think about this, I think this issue might partially be due to bug 1080752 which has been fixed for master and 2.2 We had some issue with push notification when the device goes to sleep ( hence idle for more than 30 minutes as the title of the bug ) Fernando, were you strictly testing on 2.1? Or did you also try master/2.2?

I tried running it on master for some hours unplugged even. There was one time when it wifi had for some reason dropped ( not sure why as I hadn't moved the device ) One I reconnected wifi and nothing further, the push connection started working again looking at logcat. There were no alarm or permissions issues in the logcat, and when I brought the app to the foreground, I got a alarm beep. I think the issue is resolved in master. If this is needed for 2.1, perhaps we should see about getting the patch in bug 1080752 onto the gecko for 2.1 and testing the patch to see if that fixes the issue?

Fernando will test in parallel to check if we had same results. Naoki, can you test in v2.1 as well before and after applying the patch you mentioned in comment 40?

Sure. I will take a look. To note, make sure you pull in the latest version of gecko for 2.1 as : bug 1118272 landed. I am not sure if that would impact as well.

To make things easier for people not using reviewboard, I posted the patch here. I had some issues getting the patch, the patch itself applied cleanly it seems.

:nhirata what kind of info do you need from me?

Jovan, I was wondering if you had tried with the patch that I attached? I was able to successfully create a build. I had my pathing in my .userconfig wrong when point to a hg/gecko 2.1 version for my b2g dir. Apparantly the / at the end will break the building process in bluetooth.

On testing, it looks like somewhere when I had the device disconnected, it lost wifi and then the connection to the app. The app itself no longer had the url. When I relaunched the app, it seemed to connect just fine. I am not getting a permission issue. I think we might need to investigate the wifi/url dropping ( in a separate bug ). I am continuing my test until tomorrow on one device.

(In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from comment #39) > Can't seem to repro this on master at this moment in time. > Going to try unplugging the device and letting it sleep and then seeing if > it reproduces. > > Now that I think about this, I think this issue might partially be due to > bug 1080752 which has been fixed for master and 2.2 > > We had some issue with push notification when the device goes to sleep ( > hence idle for more than 30 minutes as the title of the bug ) > > Fernando, were you strictly testing on 2.1? Or did you also try master/2.2? I'll leave my device this weekend for testing again

(In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from comment #46) > On testing, it looks like somewhere when I had the device disconnected, it > lost wifi and then the connection to the app. The app itself no longer had > the url. When I relaunched the app, it seemed to connect just fine. I am > not getting a permission issue. > > I think we might need to investigate the wifi/url dropping ( in a separate > bug ). > I am continuing my test until tomorrow on one device. I suspect this is out of the scope of this bug. Please open a new bug attaching log traces

I had all the week-end a Flame running with version 2.2.1 (Gecko b86bf7e and Gaia 8d14361) It didn't fail and now is running without any issue. Probably this bug had been fixed \o/

Agreed: Wifi dropping is out of the scope of this bug. I will open a new bug if I figure out a way to reproduce this. I ran over the weekend as well and I could not reproduce the initial bug. My thought is that the patch from bug 1080752 needs to land in 2.1 It should apply cleanly.

I've running another test with version 2.1 (Gecko 60d685 and Gaia c80865c) I'll inform test results on monday.

Thanks. I'll try to monitor this bug. FYI : there's some weirdness with the alarm sounding : bug 1160923 I suspect that this might be the case for 2.1 in general.

Running the test in 2.1 (Gecko 60d685 and Gaia c80865c) since thursday 14th. Currently (monday 18th) is running without any issue. I consider the "permission lost" bug had been solved. Thank you !

(In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from comment #52) > Thanks. I'll try to monitor this bug. > > FYI : there's some weirdness with the alarm sounding : bug 1160923 > I suspect that this might be the case for 2.1 in general. Hi Naoki, The bug you refer, I think it's at startup, isn't it?

Thanks Fernando and Naoki for the investigation, can we close this issue?

(In reply to Beatriz Rodríguez [:brg] from comment #55) > Thanks Fernando and Naoki for the investigation, can we close this issue? It's ok for me

Naoki, WDYT after knowing :frsela results?

Yes, I think we can close the issue since bug 1080752 was pushed to 2.1 and 2.1/s

Clearing tags on a closed issue.