freswa / dovecot-xaps-daemon

MIT License
52 stars 11 forks source link

Push Stopped working #13

Closed myrsk closed 2 years ago

myrsk commented 2 years ago

Appreciate any support on this...

Push used to be working perfectly, and suddenly it has stopped working. No configuration changes were done.

tail /var/log/dovecot-lmtp.log (shows that the push notification is being sent)

Mar 02 09:36:50 lmtp(7374): Info: Connect from local
Mar 02 09:36:50 lmtp(me@domain.com)<7374><10VXCaIsH2LOHAAAsB2X3g>: Debug: Sending notification: {"Username":"me@domain.com","Mailbox":"INBOX","Events": ["MessageNew"]}
Mar 02 09:36:50 lmtp(me@domain.com)<7374><10VXCaIsH2LOHAAAsB2X3g>: Info: sieve: msgid=<790637A8-AC40-4D3A-9249-1B690E100AB8@domain.com>: stored mail into mailbox 'INBOX'
Mar 02 09:36:50 lmtp(7374): Debug: Notification sent successfully: 200 OK

I can see only one user entry in /var/lib/xapsd/database.json - for some reason other users or other accounts are not being registered there?

{
  "Users": {
    "me@domain.com": {
      "Accounts": {
        "77979361-B13A-46F9-ABB3-****REDACTED***": {
          "DeviceToken": "960087EB1D051D10F79***********REDACTED**********",
          "Mailboxes": [
            "Junk",
            "INBOX",
            "Sent",
            "Notes"
          ],
          "RegistrationTime": "2022-03-02T09:47:54.855456616+01:00"
        }
      }
    }
  },

I've tried countless times to restart and airplane mode the device (apple iphone), the device does not get any push. Nor do other devices seem to register?

I've also tried to recompile the plugin and use the updated .so files, no joy there either.

Dovecot version: 2.3.18

I've been using the original daemon from st3fan and also moved to this fork.

Any help is appreciated, thank you.

freswa commented 2 years ago

Could you post the logs of the daemon please?

myrsk commented 2 years ago
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:15] Unknown lvalue 'MemoryDenyWriteExecute' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:20] Unknown lvalue 'ProtectControlGroups' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:21] Unknown lvalue 'ProtectKernelModules' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:22] Failed to parse protect system value, ignoring: strict
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:23] Unknown lvalue 'RestrictRealtime' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:26] Unknown lvalue 'RestrictNamespaces' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:27] Unknown lvalue 'LockPersonality' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:28] Unknown lvalue 'RestrictSUIDSGID' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:29] Unknown lvalue 'ReadWritePaths' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:15] Unknown lvalue 'MemoryDenyWriteExecute' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:20] Unknown lvalue 'ProtectControlGroups' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:21] Unknown lvalue 'ProtectKernelModules' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:22] Failed to parse protect system value, ignoring: strict
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:23] Unknown lvalue 'RestrictRealtime' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:26] Unknown lvalue 'RestrictNamespaces' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:27] Unknown lvalue 'LockPersonality' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:28] Unknown lvalue 'RestrictSUIDSGID' in section 'Service'
Mar  2 08:59:29 server systemd: [/root/dovecot-xaps-daemon/configs/systemd/xapsd.service:29] Unknown lvalue 'ReadWritePaths' in section 'Service'
Mar  2 09:04:45 server xapsd: time="2022-03-02T09:04:45+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 09:05:49 server xapsd: time="2022-03-02T09:05:49+01:00" level=warning msg="No registration found for username: user@domain1.com"
Mar  2 09:09:41 server xapsd: time="2022-03-02T09:09:41+01:00" level=warning msg="No registration found for username: user@domain2.com"
Mar  2 09:34:40 server xapsd: time="2022-03-02T09:34:40+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 09:43:58 server xapsd: time="2022-03-02T09:43:58+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 09:45:12 server xapsd: time="2022-03-02T09:45:12+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 09:47:17 server xapsd: time="2022-03-02T09:47:17+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 10:09:38 server xapsd: time="2022-03-02T10:09:38+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 10:11:11 server xapsd: time="2022-03-02T10:11:11+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 10:12:50 server xapsd: time="2022-03-02T10:12:50+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 10:14:46 server xapsd: time="2022-03-02T10:14:46+01:00" level=warning msg="No registration found for username:  user@domain2.com"
Mar  2 10:29:18 server xapsd: time="2022-03-02T10:29:18+01:00" level=warning msg="No registration found for username: user2@domain.com"
myrsk commented 2 years ago

In case this helps too

/etc/dovecot/conf.d/95-xaps.conf

protocol imap {
  mail_plugins = $mail_plugins notify push_notification xaps_push_notification xaps_imap
}

protocol lda {
  mail_plugins = $mail_plugins notify push_notification xaps_push_notification
}

protocol lmtp {
  mail_plugins = $mail_plugins notify push_notification xaps_push_notification
}

plugin {
    # xaps_config contains xaps specific configuration parameters
    # url:              protocol, hostname and port under which xapsd listens
    # user_lookup: Use if you want to determine the username used for PNs from environment variables provided by
    #                   login mechanism. Value is variable name to look up.
    # max_retries:      maximum num of retries the http client connects to the xaps daemon
    # timeout_msecs     http timeout of the http connection
        xaps_config = url=http://localhost:11619 user_lookup=theattribute max_retries=6 timeout_msecs=5000
        push_notification_driver = xaps
}
myrsk commented 2 years ago

It's very weird that it registers only one account in /var/lib/xapsd/database.json

Even the one registered there, does not get the push notification, albeit the logs show as

Mar 02 09:36:50 lmtp(7374): Debug: Notification sent successfully: 200 OK

freswa commented 2 years ago

The lmtp logs only show, that the request is fine it doesn't state whether a user is in the database or not. Did you recently move between the daemon versions?

myrsk commented 2 years ago

Actually for testing purposes, i removed the user entry in the database, and lmtp shows error 404 not found for push notification.

I've changed the daemons log level to debug, and now its showing below, which is normal:

Mar  2 11:14:28 server xapsd: time="2022-03-02T11:14:28+01:00" level=debug msg="Opening databasefile at /var/lib/xapsd/database.json"
Mar  2 11:14:28 server xapsd: time="2022-03-02T11:14:28+01:00" level=debug msg="APNS for non NewMessage events will be delayed for 30s"
Mar  2 11:14:28 server xapsd: time="2022-03-02T11:14:28+01:00" level=debug msg="Trying to get existing certs from the DB"
Mar  2 11:14:28 server xapsd: time="2022-03-02T11:14:28+01:00" level=info msg="Certificate valid until 2023-02-28 18:06:16 +0000 UTC"
Mar  2 11:14:28 server xapsd: time="2022-03-02T11:14:28+01:00" level=debug msg="Topic is com.apple.mail.XServer.9baeb46c-1c29-4ef8-98bd-1706568a81a7"
Mar  2 11:14:48 server xapsd: time="2022-03-02T11:14:48+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:15:08 server xapsd: time="2022-03-02T11:15:08+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:15:28 server xapsd: time="2022-03-02T11:15:28+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:15:48 server xapsd: time="2022-03-02T11:15:48+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:16:08 server xapsd: time="2022-03-02T11:16:08+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:16:28 server xapsd: time="2022-03-02T11:16:28+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:16:48 server xapsd: time="2022-03-02T11:16:48+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:17:08 server xapsd: time="2022-03-02T11:17:08+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:17:28 server xapsd: time="2022-03-02T11:17:28+01:00" level=debug msg="Checking all delayed APNS"
Mar  2 11:17:48 server xapsd: time="2022-03-02T11:17:48+01:00" level=debug msg="Checking all delayed APNS"

I have not changed daemon versions previously, but due to it not working, I tried your daemon.

freswa commented 2 years ago

You need my daemon and my plugin to work. They evolved from the original toolset to have a completely different protocol. When you updated both, trigger re-register on your phone by selecting some different push folders. The device should then end up in the database within seconds.

myrsk commented 2 years ago

The only thing I did was change the log level to debug, now I am seeing more users in the database.json file actually .... weird?

However, push is not recieved on the device. As per log, it is ok:

Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Found registration 77979361-B13A-46F9-ABB3-9C2F81CDCC12 with token 960087EB1D051D10F79025A9059CA8B2F53F1B2C40B6AAD5982F0E0C6C1377A9 for username: user@domain.com"
Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Sending notification to 77979361-B13A-46F9-ABB3-9***REDACTED***CDCC12 / 960087EB1D051D10F79025A9059CA8B2F53F1B2C***REDACTED***377A9"
Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Sending: {\"aps\":{\"account-id\":\"77979361-B1***REDACTED***CDCC12\"}}"
Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Apple returned 200 for notification to 7797936***REDACTED***DCC12 / 960087EB1D051***REDACTED***0C6C1377A9"
Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Ignoring non INBOX event for: Sent"
Mar  2 11:22:08 server xapsd: time="2022-03-02T11:22:08+01:00" level=debug msg="Checking all delayed APNS"
myrsk commented 2 years ago

Yes, I am using your daemon, and now also changed to your plugin.

Unfortunately, I am not seeing updates on database.json anymore.

Nonetheless, it should be sending out the push notification as the device token and account exist in database.json but still not receiving the push

Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Found registration 77979361-B13A-46F9-ABB3-9C2F81CDCC12 with token 960087EB1D051D10F79025A9059CA8B2F53F1B2C40B6AAD5982F0E0C6C1377A9 for username: user@domain.com"
Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Sending notification to 77979361-B13A-46F9-ABB3-9***REDACTED***CDCC12 / 960087EB1D051D10F79025A9059CA8B2F53F1B2C***REDACTED***377A9"
Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Sending: {\"aps\":{\"account-id\":\"77979361-B1***REDACTED***CDCC12\"}}"
Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Apple returned 200 for notification to 7797936***REDACTED***DCC12 / 960087EB1D051***REDACTED***0C6C1377A9"
Mar  2 11:21:57 server xapsd: time="2022-03-02T11:21:57+01:00" level=debug msg="Ignoring non INBOX event for: Sent"
Mar  2 11:22:08 server xapsd: time="2022-03-02T11:22:08+01:00" level=debug msg="Checking all delayed APNS"
myrsk commented 2 years ago

Okay, it seems it updates the database.json file when i force restart the xapsd daemon service, but then any other changes later on to the subscribed folders, are not going through, and actually when I go back to the folders on iphone, its showing the same folders as per the one in the database.json.

For example, removing the tick on Junk folder, and then going back in, shows that Junk is ticked.

Weird that it only writes once to the database.json file though, and nothing in the debug logs of any reason or any failure ...

freswa commented 2 years ago

If you see Apple returned 200 for notification in the daemon log, the notification is send out and very probable also delivered to your device. The problem lies on your device locally then. It can be due to low battery, low app usage and more. That's something I can't help with.

myrsk commented 2 years ago

Will check with another device, but the device has a lot of spare storage, as well as at 82% battery.

Will check and reply back if I can find the find. Thanks @freswa :)

myrsk commented 2 years ago

Great news ... resolved!

As you rightly said, the issue was from the device itself. Came back to leave the fix for others in the future :)

What is weird is that I have not changed any settings on the device it self, and I have done all the basics, like deleting the email accounts and readding them.

After countless reddit and google searches, it appears to be a bug in the. latest IOS with some devices. The bug automatically toggles the setting off.

To fix it: Settings > Notifications > mail > customize notifications > click on your account > turn alerts to on

Thanks.