Closed Bug 1752286 Opened 3 years ago Closed 3 years ago

Firefox can't establish connection to wss after a while and requires restart

Categories

(Core :: Networking: WebSockets, defect)

Firefox 96
defect

Tracking

()

RESOLVED INVALID

People

(Reporter: budimanjojo, Unassigned)

Details

Attachments

(2 files)

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:96.0) Gecko/20100101 Firefox/96.0

Steps to reproduce:

If I use Firefox for a while (usually after an hour), Firefox will eventually fails to establish connection to wss. The console will be filled with Firefox can’t establish a connection to the server at wss://blablabla
It happens on all pages that's using websocket (for example whatsapp and discord). If I close firefox and reopen the pages, it will work fine again. I have my system connected to Wireguard VPN all the time, if that's worth mentioning. On Chromium there's no such problem. I don't know what kind of log I should post here to help with debugging and I'm willing to post the log you need. Thank you.

The Bugbug bot thinks this bug should belong to the 'Core::Networking: WebSockets' component, and is moving the bug to that component. Please revert this change in case you think the bot is wrong.

Component: Untriaged → Networking: WebSockets
Product: Firefox → Core

Thank you for the bug report.
Please take a look at https://firefox-source-docs.mozilla.org/networking/submitting_networking_bugs.html
Here specifically it would be very useful if you could capture some https://firefox-source-docs.mozilla.org/networking/http/logging.html
Please add nsWebSocket:5 to the list of log modules. Thanks!

Flags: needinfo?(budimanjojo)
Attached file log.txt
Flags: needinfo?(budimanjojo)

Here's the log, the log file is over 50MB so I cut it from the bottom. Hope it helps.

Unfortunatelly the log doesn't contain the required info.
Please compress it to zip and attach it again. Alternatively you can put it in Google Drive and send us the link. Thanks!

Flags: needinfo?(budimanjojo)
Flags: needinfo?(budimanjojo)

Hi, Thank you for the log.
Were you able to add nsWebSocket:5 to the list of log modules? I don't see any websocket specific messages in the log.
Also, could you try capturing the logs using a new profile? The log you uploaded contains a lot of other unrelated navigations.

Also, is your DNS server blocking ads (or other domains)?
I'm asking because of this line in the logs:

nsHostResolver Address [0.0.0.0] is blocklisted for host [sdk.split.io].

This can probably mess with the behaviour of some components.
If this is intentional, I suggest using 127.0.0.1 instead of 0.0.0.0

Flags: needinfo?(budimanjojo)

Oops sorry I didn't add nsWebSocket:5. I'll do it again later with new profile.

Yes I'm using Unbound DNS on my Wireguard VPN host and Unbound is forwarding to 0.0.0.0 for blacklisted addresses. Should this be causing the problem?

(In reply to budimanjojo from comment #8)

Oops sorry I didn't add nsWebSocket:5. I'll do it again later with new profile.

Yes I'm using Unbound DNS on my Wireguard VPN host and Unbound is forwarding to 0.0.0.0 for blacklisted addresses. Should this be causing the problem?

It's quite possible. 0.0.0.0 has weird behaviours depending on the OS - especially on OSX.
If you could also test without the filtering that would be great! Please let me know what you find. Thanks!

Hello, I have added nsWebSocket:5 to the list of log modules and doing it from a new profile. Here's the log (I only start the log when the problem started though hence the smaller size)
https://drive.google.com/file/d/1YqNX10VRE7DVGBpLBRwe6A15DkXBF6Xc/view?usp=sharing

I haven't tested without DNS filtering entirely. But when the problem started, I tried disabling the adblocker and restarted unbound on my router and it doesn't fix the problem.

Flags: needinfo?(budimanjojo)

The severity field is not set for this bug.
:dragana, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(dd.mozilla)

I noticed these lines from the log:

2022-02-11 05:50:18.293941 UTC - [Parent 11888: Main Thread]: D/nsWebSocket WebSocketChannel::AsyncOpen() 7f9d49a25300
2022-02-11 05:50:18.293958 UTC - [Parent 11888: Main Thread]: D/nsWebSocket WebSocketChannel::AsyncOpen 7f9d49a25300 sessionCount=200 max=200
2022-02-11 05:50:18.293963 UTC - [Parent 11888: Main Thread]: D/nsWebSocket WebSocketChannel: max concurrency 200 exceeded (200)

It seems that the number of websocket connections is reached to 200, so Firefox disallows to create new websocket connection.
Could you try to close some tabs and see if you can create new wss connection?
If closing tab is not helpful, could you try to create a log as the following steps:

  1. Start Firefox.
  2. Start logging.
  3. Connect to any site that creates some wss connections.
  4. Close the tab and also stop logging.
    Maybe the log can reveal why a wss connection is not released.

Thanks.

Flags: needinfo?(budimanjojo)

Thanks!
So the max wss connections in firefox is set to 200 and the expected behavior of firefox is to close the oldest connections? But in my case, firefox is not closing the old connections and it instead forbid me to create new connection, hence the problem?
But when the problem occurs, then I hit refresh and wait for a while (around 2 minutes) I can connect to new wss connection, but 2 minutes of waiting for every refresh is annoying.

Does this mean there's a bad site that keeps creating new connection as time goes by? Because it usually happen without me doing anything for a long time and refreshing a page triggers it. I usually only have less than 10 tabs opened that need wss connection, so 200 is really not expected (or am I wrong?)

I will do those steps again and send another log. Can I just do the "close the tab and also stop logging" step to any tab? Because I don't really know which site triggers this behaviour 😅

Flags: needinfo?(budimanjojo)
Flags: needinfo?(dd.mozilla)

I think I have found the site that creates some wss connections, the site will literally just keep creating 2 or 3 new wss connections every half a minute or so and never releases the old connections. This explains the behavior happening even when I'm not doing anything. I can see the connections being made in the about:networking#websockets page. I think this is the problem of the site and not firefox? I'll attach the log and let you guys look at it. Feel free to close this issue if you're sure this is not Firefox`s bug and I will contact the site administrator instead. Thank.

The severity field is not set for this bug.
:dragana, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(dd.mozilla)

Thank you for the logs.
Indeed, it seems a bug in the website.

804b000d(NS_ERROR_CONNECTION_REFUSED) ⁃ http-status=n/a ⁃ url=https://api.qiscus.com/api/v2/sdk/sync?

I'm also seeing this connection refused error for some requests, which could be related to why the websocket connections keep being created.
This is because the DNS server is returning 0.0.0.0 for these requests.

Status: UNCONFIRMED → RESOLVED
Closed: 3 years ago
Flags: needinfo?(dd.mozilla)
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: