Bug #5227
openWebsocket connection failures cause excessive retries
0%
Description
When running a wt (github 3.3.6-4-gb8d3cdf) application with web-sockets enabled, a client that supports websockets but is unable to successfully open a websocket to the server will enter a mode where it retries the websocket connection multiple times per minute for as long as the client session is active. Each connection attempt also results in the cancellation and restart of a POST (long poll). From the standpoint of application functionality, this activity appears to be harmless. However, it does consume some network bandwidth and CPU resources and generates log entries.
The easiest way to reproduce this behavior is to introduce a proxy between the client and server that does not support websockets. One possibility is mitmproxy. Another option is to use an older nginx or one that is not configured to support the websocket connection upgrade.
Attached is a patch that seems to help with this issue. The patch would certainly benefit from additional review and testing, especially given the wide range of environments that Wt supports. There are additional notes on the patch.
Files
Updated by Bruce Toll almost 8 years ago
- File widgetgallery_3.3.7-rc1-20-gf7010ec3_20170227a.log widgetgallery_3.3.7-rc1-20-gf7010ec3_20170227a.log added
- File widgetgallery_3.3.7-rc1-20-gf7010ec3_with_patch_20170227b.log widgetgallery_3.3.7-rc1-20-gf7010ec3_with_patch_20170227b.log added
Since there have been many updates and improvements to Wt.js since this report was filed, I recently retested with github 3.3.7-rc1-20-gf7010ec3. The issue was more difficult to reproduce than I remember, but it appears that it still exists. Here are detailed steps on how to drive it, along with some captured log files.
Configuration:
The server is running in a Debian Stretch (testing) VirtualBox. The tested app is the widgetgallery.wt example built with boost 1.62 using g 6.3.
The client-side testing is done with Debian GNU/Linux 8.7 (jessie), using the default packages for chromium:amd64 56.0.2924.76-1~deb8u1 and mitmproxy:all 0.10.1-2. I would have preferred to do all of the testing in the Debian Stretch VirtualBox, but the older version of mitmproxy in Debian Jessie proved helpful in reproducing the issue.
Testing:
On the server, the widgetgallery.wt app was started, listening on port 8091, with a deploy_path of /widgetgallery. The server's IP address was 192.168.1.113.
On the client, the mitmproxy was invoked as:
mitmproxy -p 8090 -P http://192.168.1.113:8091
The URL for the chromium browser on the client was pointed at: http://localhost:8090/widgetgallery
The output from the widgetgallery.wt server log is attached as: widgetgallery_3.3.7-rc1-20-gf7010ec3_20170227a.log
NOTE: Since the Debian Jessie version of mitmproxy does not support websockets, it displays the pattern of retries described in the original report. Newer versions of mitmproxy (such as the one currently included in Debian stretch) have some support for websockets and behave differently, even with the "---no-websockets" option.
For completeness, I have also attached 15 minutes of widgetgallery.wt logging with the attached patch applied in: widgetgallery_3.3.7-rc1-20-gf7010ec3_with_patch_20170227b.log. This log file shows that the websocket is retried twice with the default 5 minute keep-alive, and then discontinued. It may not be obvious from the log, but the patch also avoids having an outstanding POST (long poll) which can limit the number of simultaneous browser sessions to the host.
Additional Note:
I believe it's possible to get a rough estimate of how often this issue occurs (with or without the patch) by searching for lines matching 'request=ws' in the server log and counting the unique occurrences of each wtd. More than one occurrence of a wtd may indicate a failed websocket connection from a browser that Wt expects to support websockets.
If I can provide any additional information, please let me know.