websockets closing very fast

[Menelmacar]

I've installed mollysocket by downloading the binary and setting it up as per the install.md as systemd service.
I'm using an apache2 reverse proxy.
The service works and I get test notifications / push to Molly.

I'm wondering if it's normal that the process is using i/o and cpu all the time and the log is a constant stream of opening websocket and closing.

prod.toml:
db = '/opt/mollysocket/mollysocket.db'
allowed_endpoints = ['https://mypushserver.de']
allowed_uuids = ['b00cfa88-0e25-46ef-b26e-e88b7b0d1326']
webserver = true
port = 8020

Log:
mollysocket-log.txt

Mollylog: https://github.com/user-attachments/files/18039531/06_12-15-36-30_229.log

Prosody mod_unified_push log:
Prosody.log.txt

I'm on Debian stable, mollysocket 1.5.4
Molly: v7.26.1-1-FOSS on CalyxOS on Nexus7 Android 15
The push server is a prosody module, the distributor is my xmpp app conversations .

[p1gp1g]

Do you have logs from Molly android ? It looks like it is in a loop sending registration again and again

[p1gp1g]

Is there anything that may not be usual in your setup, or anything we should be aware of to debug that ?

[Menelmacar]

I updated above with some more info about the setup.
I did some tinkering and it seems this starts to happen if the app is force killed or if my android is restarted. It stopps if I put the app in the foreground. It will then log the websocket connected and then silence and no more excessive cpu or IO activity.

Edit: it can also happen if the app is in the foreground apparently . But sending a single message helps for a time.

It might be an issue with the client and not the sever too. I'm curious if someone else has experienced that.

I don't have Molly logs yet. I'm not doing this every day. I'll try to get some

[p1gp1g]

Ok, that's important to have those logs, something seems wrong on the client side

[Menelmacar]

06_12-15-36-30_229.log

This is a log of molly, the beginning corresponds with the mollysocket constantly destroying and establishing a new websocket. (Molly is in foreground and background, doesn't matter)
Then I send one message to a contact and mollysocket stays at the last log line with
[2024-12-06T14:36:57Z INFO mollysocket::ws::websocket_connection] WebSocket handshake has been successfully completed

[p1gp1g]

There is a new PR in progress: pcrockett/mollysocket-fly#17

[Menelmacar]

I wonder, should I rather report this to molly?

[p1gp1g]

@valldrac will transfer to mollyim-android it when he can

[p1gp1g]

@Menelmacar do you have the list of registered applications on Conversations ? It looks like they send a new endpoint everytime we register to it. We will avoid that loop on Molly. You should use the websocket for the moment to avoid draining your battery

[Menelmacar]

I'm also using fedilab with it.

I've other news:
if I change the push server away from the prosody module to https://up.conversations.im and continue using conversations as distributor the issue is gone.

Also if I change the distributor to nfty the issue is gone.

So there is either a bug or incompatibility with https://modules.prosody.im/mod_unified_push.html I think?

Thanks for your help so far. I'll also forward this to the prosody issue tracker.

[p1gp1g]

Is it possible you have configured your prosody module with ttl=0 ? IIRC up.conversations.im also use the same module

[Menelmacar]

I use the defaults.
prosodys module is lua based, https://modules.prosody.im/mod_unified_push.html (source at the bottom)

The conversations server uses the standalone software
"up" https://codeberg.org/iNPUTmice/up

I fear it might not send any ttl in the header , or I looked at the wrong things. (I can't code)
@mwild1?

[p1gp1g]

This is not regarding the TTL in the header, but time before changing the endpoint. From the logs, it looks like it changes everytime there is a new request

[Menelmacar]

Hm. I didnt set anything, if I understsnd correctly it should be one day then:
https://hg.prosody.im/prosody-modules/file/04d0ab97a678/mod_unified_push/mod_unified_push.lua#l2

I will try to get debug logs if fedilab also suffers in a similar way.

Edit: I see a lot of registration for the push server here within one second, then it stops. This happend on activating push in fedilab. I would think normal would these two unified_push log lines only once.
But here it stops after one second.
https://share.snikket.de/vaG7I5xKYOL1kxqyDq6HBnmV/c6a9d887-d657-469e-9f97-08f9fd4d9190.txt

[mwild1]

What backend are you using? If you're on Prosody trunk then it's probably using the PASETO backend, which is stateless (the registration info is stored in the returned token). The token will indeed differ after each registration, because it includes a nonce.

I'm not aware that the spec requires tokens to be stable across multiple registrations (please correct me if I'm wrong!).

A workaround on the Prosody side would be to set unified_push_backend = "jwt" or unified_push_backend = "storage" (be aware that changing backend will invalidate all existing tokens).

[p1gp1g]

https://unifiedpush.org/developers/spec/android/#orgunifiedpushandroiddistributorregister

The distributor SHOULD NOT create a new endpoint if a valid registration exist for the token and nothing has been updated.

This is not a MUST, but it may introduce buggy things

We have implemented a fix: mollyim/mollyim-android#410

You should probably open issues for other buggy apps

[mwild1]

Thanks! A SHOULD NOT is good enough for me. I'll think about the best solution...

[Menelmacar]

@mwild1
Yes. This is on prosody trunk. I will try another backend and see if that changes anything . And will test multible backends when I have the newest version of Molly that includes the fix .