Push Notifications problem on Android/Apache/NC13.0.4

Nextcloud version: 13.0.4
Operating system and version: OpenSuSE Leap 15
Apache or nginx version: Apache 2.4.33
PHP version: 7.2.5

The issue you are facing:

Push notifications work of web/desktop clients, but not on Android. I originally reported this to the NextCloud Talk app, but Mario suggested it was a problem with the server or server configuration.

When I first install & register the app a message briefly appears saying “push notifications disabled”.

Around that time, there are many next cloud log messages, which all look OK to my untrained eye, but one in the apache log may be pivotal is:

- uuuuu [27/Jun/2018:14:07:20 +1000] “POST /ocs/v2.php/apps/notifications/api/v2/push?proxyServer=https://push-notifications.nextcloud.com&devicePublicKey=-----BEGIN%20PUBLIC%20KEY----------END%20PUBLIC%20KEY-----%0A&pushTokenHash= < LOTS OF HEX > &format=json HTTP/1.1” 400 112

The result code of 400 is presumably a problem.

Is this the first time you’ve seen this error?: N

Steps to replicate it:

  1. Install NC, install talk app (in NC),
  2. install NextCloud Talk Android app (fresh install) on phone
  3. start android app, specify server, register -> Message appears briefly.

In the nextcloud logs I see two “login attempt” messages, followed by one “login success” message around the time of the above 400 result; both attempts are from the same device at the same time.

This double-attempt seems to happen always.

The output of your Nextcloud log in Admin > Logging:



    {"reqId":"BX8jTwZaqnztBkj6768r","level":1,"time":"2018-06-27T04:07:19+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"--","app":"admin_audit","method":"GET","url":"\/ocs\/v2.php\/apps\/spreed\/api\/v1\/room","message":"Login attempt: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}


    {"reqId":"BX8jTwZaqnztBkj6768r","level":1,"time":"2018-06-27T04:07:19+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"<USER>","app":"admin_audit","method":"GET","url":"\/ocs\/v2.php\/apps\/spreed\/api\/v1\/room","message":"Login successful: \"<user>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}


    {"reqId":"Stv8fPiRNCXgkmur26EU","level":1,"time":"2018-06-27T04:07:20+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"--","app":"admin_audit","method":"POST","url":"\/ocs\/v2.php\/apps\/notifications\/api\/v2\/push?proxyServer=https:\/\/push-notifications.nextcloud.com&devicePublicKey=-----BEGIN%20PUBLIC%20KEY----- < STUFF > ----END%20PUBLIC%20KEY-----%0A&pushTokenHash=  < TOKEN  > & format=json","message":"Login attempt: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}


    {"reqId":"Stv8fPiRNCXgkmur26EU","level":1,"time":"2018-06-27T04:07:20+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"--","app":"admin_audit","method":"POST","url":"\/ocs\/v2.php\/apps\/notifications\/api\/v2\/push?proxyServer=https:\/\/push-notifications.nextcloud.com&devicePublicKey=-----BEGIN%20PUBLIC%20KEY--- < STUFF > ---END%20PUBLIC%20KEY-----%0A&pushTokenHash= < TOKEN > &format=json","message":"Login attempt: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}

    {"reqId":"Stv8fPiRNCXgkmur26EU","level":1,"time":"2018-06-27T04:07:20+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"<USER>","app":"admin_audit","method":"POST","url":"\/ocs\/v2.php\/apps\/notifications\/api\/v2\/push?proxyServer=https:\/\/push-notifications.nextcloud.com&devicePublicKey=-----BEGIN%20PUBLIC%20KEY--- < STUFF > ---END%20PUBLIC%20KEY-----%0A&pushTokenHash= < TOKEN > &format=json","message":"Login successful: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}

    {"reqId":"Hiz9sM16iBAUCy6nKem7","level":1,"time":"2018-06-27T04:07:20+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"--","app":"admin_audit","method":"GET","url":"\/ocs\/v2.php\/cloud\/capabilities","message":"Login attempt: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}

    {"reqId":"Hiz9sM16iBAUCy6nKem7","level":1,"time":"2018-06-27T04:07:20+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"--","app":"admin_audit","method":"GET","url":"\/ocs\/v2.php\/cloud\/capabilities","message":"Login attempt: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}

    {"reqId":"Hiz9sM16iBAUCy6nKem7","level":1,"time":"2018-06-27T04:07:20+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"<USER>","app":"admin_audit","method":"GET","url":"\/ocs\/v2.php\/cloud\/capabilities","message":"Login successful: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}

    {"reqId":"KkJrOrNcgwLtvWyKNY6n","level":1,"time":"2018-06-27T04:07:21+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"--","app":"admin_audit","method":"GET","url":"\/ocs\/v2.php\/apps\/spreed\/api\/v1\/room","message":"Login attempt: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}

    {"reqId":"KkJrOrNcgwLtvWyKNY6n","level":1,"time":"2018-06-27T04:07:21+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"--","app":"admin_audit","method":"GET","url":"\/ocs\/v2.php\/apps\/spreed\/api\/v1\/room","message":"Login attempt: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}

    {"reqId":"KkJrOrNcgwLtvWyKNY6n","level":1,"time":"2018-06-27T04:07:21+00:00","remoteAddr":"xxx.yyy.zzz.ttt","user":"<USER>","app":"admin_audit","method":"GET","url":"\/ocs\/v2.php\/apps\/spreed\/api\/v1\/room","message":"Login successful: \"<USER>\"","userAgent":"Mozilla\/5.0 (Android) Nextcloud-Talk v2.0.2","version":"13.0.4.0"}



The output of your config.php file in /path/to/nextcloud (make sure you remove any identifiable information!):

$CONFIG = array (
  'instanceid' => 'XXXXXX',
  'passwordsalt' => 'YYYYYY',
  'secret' => 'ZZZZZ',
  'trusted_domains' =>
  array (
    ...etc...
  ),
  'datadirectory' => '<DIR>',
  'overwrite.cli.url' => '<SOMETHING>',
  'dbtype' => 'sqlite3',
  'version' => '13.0.4.0',
  'logtimezone' => 'UTC',
  'installed' => true,
  'mail_smtpmode' => 'smtp',
  'mail_from_address' => '<HOST>',
  'mail_domain' => '<DOMAIN>',
  'mail_smtphost' => '<IP-ADDR>',
  'theme' => '',
  'maintenance' => false,
  'loglevel' => 1,
  'trashbin_retention_obligation' => 'auto',
  'updatechecker' => false,
  'memcache.local' => '\\OC\\Memcache\\Redis',
  'redis' =>
  array (
    'host' => 'localhost',
    'port' => 6379,
  ),
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'ldapIgnoreNamingRules' => false,
  'ldapProviderFactory' => '\\OCA\\User_LDAP\\LDAPProviderFactory',
);

The output of your Apache/nginx/system log in /var/log/____:

<IP ADDR> - uuuuu [27/Jun/2018:14:07:20 +1000] "POST /ocs/v2.php/apps/notifications/api/v2/push?proxyServer=https://push-notifications.nextcloud.com&devicePublicKey=-----BEGIN%20PUBLIC%20KEY-----<STUFF>-----END%20PUBLIC%20KEY-----%0A&pushTokenHash=<LOTS OF HEX>&format=json HTTP/1.1" 400 112

To further clarify: the app token the server generates on login is somehow not stored (check in Settings -> Security) so the app cannot register for push notifications.

When you say Settings->Security, I assume you mean on the server.

It shows < Phone > (Nextcloud Talk) with “Allow Filesystem access”.

And inside the “Admin”->“Security” area there are no oauth clients listed.

Oh hm. That wasn’t there when I last checked.

Strange.

Maybe interestingly, I just built the app locally and the ADB log says:

06-27 16:51:03.194 13122-13410/com.nextcloud.talk2 D/PlatformAlarmService: Run job, request{id=9, tag=PushRegistrationJob, transient=false}, waited 00:00:00, delay 00:00:00
06-27 16:51:03.234 13122-13410/com.nextcloud.talk2 I/JobExecutor: Executing request{id=9, tag=PushRegistrationJob, transient=false}, context PlatformAlarmService
06-27 16:51:03.244 13122-13167/com.nextcloud.talk2 I/JobExecutor: Finished job{id=9, finished=true, result=SUCCESS, canceled=false, periodic=false, class=PushRegistrationJob, tag=PushRegistrationJob}
06-27 16:51:03.244 13122-13410/com.nextcloud.talk2 D/PlatformAlarmService: Finished job, request{id=9, tag=PushRegistrationJob, transient=false} SUCCESS

which suggests it’s registering, but then the app hangs with the blue progress wheel and never gets the main activity.

If I press back a few times, I can restart app and it seems to work OK. Timing issue?

And I get an iteresting exception when pressing back:

06-27 16:53:51.624 13122-13122/com.nextcloud.talk2 E/AndroidRuntime: FATAL EXCEPTION: main
Process: com.nextcloud.talk2, PID: 13122
java.lang.SecurityException: caller uid 10265 is different than the authenticator’s uid
at android.os.Parcel.readException(Parcel.java:1540)
at android.os.Parcel.readException(Parcel.java:1493)
at android.accounts.IAccountManager$Stub$Proxy.getPassword(IAccountManager.java:628)
at android.accounts.AccountManager.getPassword(AccountManager.java:318)
at com.nextcloud.talk.utils.AccountUtils.getInformationFromAccount(AccountUtils.java:108)
at com.nextcloud.talk.utils.AccountUtils.findAccounts(AccountUtils.java:58)
at com.nextcloud.talk.controllers.ServerSelectionController.onViewBound(ServerSelectionController.java:140)
at com.nextcloud.talk.controllers.base.ButterKnifeController.onCreateView(ButterKnifeController.java:50)
at com.bluelinelabs.conductor.Controller.inflate(Controller.java:988)
at com.bluelinelabs.conductor.ControllerChangeHandler.executeChange(ControllerChangeHandler.java:190)
at com.bluelinelabs.conductor.ControllerChangeHandler.executeChange(ControllerChangeHandler.java:154)
at com.bluelinelabs.conductor.Router.performControllerChange(Router.java:774)
at com.bluelinelabs.conductor.Router.performControllerChange(Router.java:744)
at com.bluelinelabs.conductor.Router.performControllerChange(Router.java:726)
at com.bluelinelabs.conductor.Router.popController(Router.java:136)
at com.bluelinelabs.conductor.Router.popCurrentController(Router.java:118)
at com.bluelinelabs.conductor.Router.handleBack(Router.java:96)
at com.nextcloud.talk.activities.MainActivity.onBackPressed(MainActivity.java:158)
at android.app.Activity.onKeyUp(Activity.java:2495)
at android.view.KeyEvent.dispatch(KeyEvent.java:2672)
at android.app.Activity.dispatchKeyEvent(Activity.java:2746)
at android.support.v7.app.AppCompatActivity.dispatchKeyEvent(AppCompatActivity.java:534)
at android.support.v7.view.WindowCallbackWrapper.dispatchKeyEvent(WindowCallbackWrapper.java:58)
at android.support.v7.app.AppCompatDelegateImplBase$AppCompatWindowCallbackBase.dispatchKeyEvent(AppCompatDelegateImplBase.java:316)
at android.support.v7.view.WindowCallbackWrapper.dispatchKeyEvent(WindowCallbackWrapper.java:58)
at com.android.internal.policy.impl.PhoneWindow$DecorView.dispatchKeyEvent(PhoneWindow.java:2221)
at android.view.ViewRootImpl$ViewPostImeInputStage.processKeyEvent(ViewRootImpl.java:3918)
at android.view.ViewRootImpl$ViewPostImeInputStage.onProcess(ViewRootImpl.java:3880)
at android.view.ViewRootImpl$InputStage.deliver(ViewRootImpl.java:3449)
at android.view.ViewRootImpl$InputStage.onDeliverToNext(ViewRootImpl.java:3502)
at android.view.ViewRootImpl$InputStage.forward(ViewRootImpl.java:3468)
at android.view.ViewRootImpl$AsyncInputStage.forward(ViewRootImpl.java:3578)
at android.view.ViewRootImpl$InputStage.apply(ViewRootImpl.java:3476)
at android.view.ViewRootImpl$AsyncInputStage.apply(ViewRootImpl.java:3635)
at android.view.ViewRootImpl$InputStage.deliver(ViewRootImpl.java:3449)
at android.view.ViewRootImpl$InputStage.onDeliverToNext(ViewRootImpl.java:3502)
at android.view.ViewRootImpl$InputStage.forward(ViewRootImpl.java:3468)
at android.view.ViewRootImpl$InputStage.apply(ViewRootImpl.java:3476)
at android.view.ViewRootImpl$InputStage.deliver(ViewRootImpl.java:3449)
at android.view.ViewRootImpl$InputStage.onDeliverToNext(ViewRootImpl.java:3502)
at android.view.ViewRootImpl$InputStage.forward(ViewRootImpl.java:3468)
at android.view.ViewRootImpl$AsyncInputStage.forward(ViewRootImpl.java:3611)
at android.view.ViewRootImpl$ImeInputStage.onFinishedInputEvent(ViewRootImpl.java:3772)
at android.view.inputmethod.InputMethodManager$PendingEvent.run(InputMethodManager.java:2244)
at android.view.inputmethod.InputMethodManager.invokeFinishedInputEventCallback(InputMethodManager.java:1885)
at android.view.inputmethod.InputMethodManager.finishedInputEvent(InputMethodManager.java:1876)
at android.view.inputmethod.InputMethodManager$ImeInputEventSender.onInputEventFinished(InputMethodManager.java:2221)
at android.view.

Notifications work too?

SUCCESS in this case means the job finished, not that it finished succesfully.

Have you tried importing an account maybe?

Ah, OK will check with other phone…will take a little while.

Importing account from the Nextcloud app won’t work if you self-compile.

You are correct. Notifications do not work.

…anf leakcanary just croaked

AAAH. I just noticed one thing. In the query, is pushTokenHash really empty? Do you have Google Play Services installed?

P.S. I know I asked this and you said yes, but it’s really strange.

GPS definitely installed; pushTokenHash not blank…it put dummy text in LT and GT without spaces…will fix

@nickvergessen possible reasons of error 400 that I might have forgotten?