Calls plugin broken after 7.4 update

Troubleshooting
1

Hello there!

Here is a quick report on an issue just after an update to 7.4 :slight_smile:

Summary
Call plugin doesn’t load anymore after 7.4 update

Steps to reproduce

  • Having call plugin working well since it’s available in beta
  • Updating as usual, this time to 7.4
  • Plugin disappeared from the UI
  • Logs are complaining about an address already in use, despite I didn’t change anything in the configuration (Nginx as a reverse proxy):
oct. 20 09:19:50 myhost mattermost[820815]: {"timestamp":"2022-10-20 09:19:50.218 +02:00","level":"error","msg":"failed to get public IP address: listen udp4 :8443: bind: address already in use","caller":"app/plugin_api.go:974","plugin_id":"com.mattermost.calls","origin":"main.(*Plugin).OnActivate activate.go:126"}
oct. 20 09:19:50 myhost mattermost[820815]: {"timestamp":"2022-10-20 09:19:50.219 +02:00","level":"info","msg":"plugin process exited","caller":"plugin/hclog_adapter.go:61","plugin_id":"com.mattermost.calls","wrapped_extras":"pathplugins/com.mattermost.calls/server/dist/plugin-linux-amd64pid821238"}
oct. 20 09:19:50 myhost mattermost[820815]: {"timestamp":"2022-10-20 09:19:50.219 +02:00","level":"error","msg":"Unable to activate plugin","caller":"app/plugin.go:165","plugin_id":"com.mattermost.calls","error":"failed to get public IP address: listen udp4 :8443: bind: address already in use"}
oct. 20 09:19:50 myhost mattermost[820815]: {"timestamp":"2022-10-20 09:19:50.338 +02:00","level":"error","msg":"failed to get public IP address: listen udp4 :8443: bind: address already in use","caller":"app/plugin_api.go:974","plugin_id":"com.mattermost.calls","origin":"main.(*Plugin).OnActivate activate.go:126"}
oct. 20 09:19:50 myhost mattermost[820815]: {"timestamp":"2022-10-20 09:19:50.340 +02:00","level":"info","msg":"plugin process exited","caller":"plugin/hclog_adapter.go:61","plugin_id":"com.mattermost.calls","wrapped_extras":"pathplugins/com.mattermost.calls/server/dist/plugin-linux-amd64pid821247"}
oct. 20 09:19:50 myhost mattermost[820815]: {"timestamp":"2022-10-20 09:19:50.340 +02:00","level":"error","msg":"Unable to activate plugin","caller":"app/plugin.go:165","plugin_id":"com.mattermost.calls","error":"failed to get public IP address: listen udp4 :8443: bind: address already in use"}

I checked and the port 8443 is indeed used by Nginx, but it’s not new, it was the case all along before. That’s why I wonder what changed in that release regarding calls?

Expected behavior
Calls is working as usual

Thank you!

2

So I rebooted the VM and now it worked. So there’s something weird happening, since it’s the first time I had to reboot after a Mattermost update :thinking:

3

Hi Olivier and welcome to the Mattermost forums!

I’m pretty sure that some process was still using the port and therefore you could not start the application. nginx should NOT use udp/8443, in fact, nginx does not even support binding to UDP ports, but it’s hard to tell what the situation looked like now since you rebooted.
If that ever happens again, please run the command lsof -i :8443 to see what process IDs occupy the port.

Glad to hear you’re up and running now, though :slight_smile:

4

So the current result is a LOT of things on port 8443, but in UDP, only the plugin is using it :slight_smile:

5

OK, this is the expected result - if this ever happens again, try to remember this command, it will help with troubleshooting then.

6

Will do, thanks a lot!

7

The problem is back.

lsof -i :8443 | grep UDP
plugin-li  3573 mattermost   12u  IPv4   27517      0t0  UDP *:8443 
plugin-li  3573 mattermost   14u  IPv4   27518      0t0  UDP *:8443 
plugin-li  3573 mattermost   16u  IPv4   26236      0t0  UDP *:8443 
plugin-li  3573 mattermost   18u  IPv4   26237      0t0  UDP *:8443

Should I kill the process and try again to enable the plugin?

edit: here is the process detail:

3573 ?        Sl     0:22  \_ plugins/com.mattermost.calls/server/dist/plugin-linux-amd64
8

Okay, I did that and it worked (SIGTERM the process, disable/enable the plugin).

I wonder if the plugin is crashing somehow behind the scene, and then it stays up.

9

Yes, looks like that - this is the calls plugin which is occupying the port in this case. @streamer45 any idea why this could happen?

10

I’ve seen this happening a couple of times during development when trying to update the plugin when there are calls still on-going. Killing the process resolved it.

To understand further I’d need to see full server logs. @olivierlambert would you be able to share them? You can reach me through our community and share privately in a DM. Also I’d suggest to use SIGQUIT next time as it will force the app to output a goroutine dump which can be useful to debug this issue further.

11

I need to check if I have enough logs (back in time) to see something meaningful. Let me check on that.

Also, I will use SIGQUIT next time :+1: