What steps will reproduce the problem? 1. Connect a siskin.im iOS client to a prosody with mod_cloud_notify and mod_smacks enabled 2. Enable push notifications in the client's account settings. 3. Write a message to that account while it is still online and observe the debuglog to see mod_cloud_notify working and connecting to push.tigase.im 4. Put the client into background an wait for it to (forcibly) go offline. 5. Write another message to the account. What is the expected output? The suspended client should be woken up by a push message and reconnect. What do you see instead? The client is not woken up and remains offline. While the client properly configured a push service while it was online… ``` May 04 23:21:22 c2s563bcf523ce0 debug Received[c2s]: <iq id='CA306259-B02E-4ECE-A8FD-99F89F18FB48' type='set' to='push.tigase.im'> May 04 23:21:22 mod_s2s debug opening a new outgoing connection for this stanza May 04 23:21:22 mod_s2s debug stanza [iq] queued until connection complete May 04 23:21:22 s2sout563bcecee9a0 debug First attempt to connect to push.tigase.im, starting with SRV lookup... May 04 23:21:22 adns debug Records for _xmpp-server._tcp.push.tigase.im. not in cache, sending query (thread: 0x563bcfa80af0)... May 04 23:21:22 adns debug Sending DNS query to 127.0.0.1 May 04 23:21:22 socket debug new connection established. id: 563bcf627e00 May 04 23:21:22 socket debug try to close client connection with id: 563bcf627e00 May 04 23:21:22 socket debug closing client with id: 563bcf627e00 client to close May 04 23:21:22 adns debug Reply for _xmpp-server._tcp.push.tigase.im. (thread: 0x563bcfa80af0) May 04 23:21:22 s2sout563bcecee9a0 debug push.tigase.im has no SRV records, falling back to A/AAAA May 04 23:21:22 adns debug Records for push.tigase.im not in cache, sending query (thread: 0x563bcfab3d60)... May 04 23:21:22 adns debug Sending DNS query to 127.0.0.1 May 04 23:21:22 adns debug Records for push.tigase.im not in cache, sending query (thread: 0x563bcf7d29f0)... May 04 23:21:22 adns debug Sending DNS query to 127.0.0.1 May 04 23:21:22 socket debug new connection established. id: 563bcf7c1ba0 […] ay 04 23:21:29 s2sin563bcf471910 debug Sending[s2sin_unauthed]: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from=' orlives.de' id='3b0a12f6-b9a2-484d-990c-bf520fd248cc' to='push.tigase.im' version='1.0' xmlns='jabber:server'> May 04 23:21:29 orlives.de:saslauth debug Offering SASL EXTERNAL May 04 23:21:29 mod_s2s debug Sending stream features: <stream:features><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>EXTERNAL</mechanism></mechanisms><dialback xmlns='ur n:xmpp:features:dialback'/></stream:features> May 04 23:21:29 s2sin563bcf471910 debug Sending[s2sin_unauthed]: <stream:features> May 04 23:21:29 s2sin563bcf471910 debug Received[s2sin_unauthed]: <auth mechanism='EXTERNAL' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'> May 04 23:21:29 s2sin563bcf471910 debug Sending[s2sin_unauthed]: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'> May 04 23:21:29 orlives.de:saslauth info Accepting SASL EXTERNAL identity from push.tigase.im May 04 23:21:29 s2sin563bcf471910 debug connection push.tigase.im->orlives.de is now authenticated for push.tigase.im May 04 23:21:29 s2sin563bcf471910 info Incoming s2s connection push.tigase.im->orlives.de complete May 04 23:21:29 s2sin563bcf471910 debug Incoming s2s received <stream:stream xmlns='http://etherx.jabber.org/streams' version='1.0' to='orlives.de' from='push.tigase.im'> May 04 23:21:29 s2sin563bcf471910 debug Sending[s2sin]: <?xml version='1.0'?> May 04 23:21:29 s2sin563bcf471910 debug Sending[s2sin]: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='orlives.d e' id='8d562378-2fc3-4413-a554-48101ecd9c16' to='push.tigase.im' version='1.0' xmlns='jabber:server'> May 04 23:21:29 mod_s2s debug Sending stream features: <stream:features><dialback xmlns='urn:xmpp:features:dialback'/></stream:features> May 04 23:21:29 s2sin563bcf471910 debug Sending[s2sin]: <stream:features> May 04 23:21:29 s2sin563bcf471910 debug Received[s2sin]: <iq id='CA306259-B02E-4ECE-A8FD-99F89F18FB48' type='result' to='account@domain/client' from='push.tigase.im'> May 04 23:21:29 c2s563bcf523ce0 debug Sending[c2s]: <iq id='CA306259-B02E-4ECE-A8FD-99F89F18FB48' type='result' to='account@domain/client' from='push.tigase.im'> […] May 04 23:21:29 c2s563bcf523ce0 info Push notifications enabled for account@domain (push.tigase.im<token) ``` …after it goes offline due to being in background… ``` May 04 23:23:32 socket debug closing client with id: 563bcfe34ad0 closed May 04 23:23:32 c2s563bcf523ce0 info Client disconnected: closed May 04 23:23:32 c2s563bcf523ce0 debug Destroying session for account@domain/client: closed May 04 23:23:32 c2s563bcf523ce0 debug mod_smacks hibernating session for up to 600 seconds […] May 04 23:45:18 c2s563bcf863610 debug mod_smacks hibernation timeout reached... May 04 23:45:18 c2s563bcf863610 debug Destroying session for hibernating too long May 04 23:45:18 c2s563bcf863610 debug Destroying session for account@domain/client May 04 23:45:18 c2s563bcf863610 debug Destroying session with 5 unacked stanzas […] May 04 23:45:18 sessionmanager debug All resources of account are now offline May 04 23:45:18 c2s563bcf863610 debug Handled 17 incoming stanzas May 04 23:45:18 c2s563bcf863610 debug Received[c2s]: <presence type='unavailable'> May 04 23:45:18 orlives.de:pep debug get_pep_service("account") May 04 23:45:18 orlives.de:pep debug get_pep_service("account2") May 04 23:45:18 c2s563bcef6d1f0 debug Sending[c2s]: <presence type='unavailable' to='account2@domain' from='account@domain/client'> ``` …when sending a message to the now offline client is handled by mod_cloud_notify: ``` May 04 23:47:35 orlives.de:cloud_notify debug Invoking cloud handle_notify_request() for offline stanza ``` But after a brief look at the mod_cloud_notify sources I see there are further debug messages that should be invoked when actually sending the push message, e.g. in line 345. But this log message does *not* appear. So I see 2 likely causes: Either prosody/ mod_cloud_notify does not properly process and send the push messages, or the siskin.im client does not properly set up its `user_push_services` which are the precondition for even entering the for loop in line 304. What version of the product are you using? On what operating system? prosody 0.11.5 on openSUSE 15.1 with prosody-modules revision 4009:362997ededb1

I created a corresponding issue for the siskin.im client as well, as I think expertise from both sides is required for figuring out the root cause. https://github.com/tigase/siskin-im/issues/36

It turns out that mod_cloud_notify is broken with lua 5.1, as the used cache module is buggy under 5.1 and does not store the push subscriptions from some clients (e.g Siskin.im, Monal). The release notes of prosody 0.11 recommend to use lua5.2 anyway, but some distributions like openSUSE Leap 15.1 still ship it with lua5.1 tmolitor was so kind to provide a modified version to be used with lua5.1: https://files.orlives.de/pub/mod_cloud_notify.lua I can confirm that this solves this issue for me.

• tags Component-Community

util.cache is covered by hundreds of lines of tests, and we run these tests on all supported Lua versions, including 5.1. I'm not saying there definitely isn't a bug, but we (Prosody team) are definitely not aware of any. More details would be welcome.

I agree with Matt that this doesn't look like a bug in Prosody. I've been testing ChatSecure, Monal and Siskin months ago and only Siskin had trouble with push notifications. (Don't know how is it now but I doubt there were any critical changes). More thorough technical debugging would be needed to check for the root cause. Too bad that (to my knowledge) the Tigase push component used by Siskin is not open-source. This could make debugging easier.

@Wiktor, while debugging this together with tmolitor Monal had the same push issue as well. Conversations push was working fine at the same time, so it wasn't a total failure of the push module.

Might this be, among other things, `<x/>` not being a child of `<notification/>`? See traffic captured. https://gist.github.com/ivucica/8e0286a44b300da5fc2e25cee52d0bad 0.11.7 + prosody_modules b3e0295e14a3 (Wed Feb 03 18:03:12 2021 +0100): There's a (bad) fix there as well. I think upgrading to Lua 5.3 helped too (not 5.2, but I didn't feel like doing the work to get things onto 5.2).

FTR: mod_cloud_nofify does `pairs(util.cache.new():table())` which does not work under Lua 5.1 because it does not support the `__pairs` metamethod that is a thing in Lua 5.2 - http://www.lua.org/manual/5.2/manual.html#pdf-pairs