Feature/cc 2166 speedup eventing websocket reconnect #2736

JanFellner · 2021-07-15T12:06:23Z

As followup from #2734

Changed the implementation for the reconnect from the handling inside the lws_service thread to the scheduler approach as shown in the libsocket example. (https://libwebsockets.org/git/libwebsockets/tree/minimal-examples/ws-client/minimal-ws-client-tx/minimal-ws-client.c)

The current approach is not working properly if the target is not localhost. The connection failed callback is triggered 5 seconds after the connect however the lws_service continues to sleep for 25 seconds.

Using the lws_sul_schedule the time when the next reconnect has to happen is exactly specified, so no need to do that in the lws_service loop and the loop just does the lws_service loop.

(!) Not yet tested with wsl 3.1 want to do that now but a short feedback in the mean time would be nice.

…reconnect) if target is not local host

…edup-eventing-websocket-reconnect # Conflicts: # events/janus_wsevh.c

januscla · 2021-07-15T12:06:24Z

Thanks for your contribution, @JanFellner! Please make sure you sign our CLA, as it's a required step before we can merge this.

lminiero · 2021-07-15T12:10:25Z

As I said in the issue, the schedule is a no go, because it's only available on newer versions of the library. Even doing two different implementations to accommodate both, I think will unneededly complicate things, especially considering your changes are a big refactoring already. I'd rather try and fix the one we have now for the issue you identified.

JanFellner · 2021-07-15T12:15:52Z

The code is aligned with what libwebsocket suggest for >= 3.2 (no own grown code, just the plain sample)

I understand your concerns, tried my best documenting the code, using readable function names.
The difference are two different thread method implementations.

I did not find a solution to get it working the lws_service with 3.2 just sleeps and i see no way in waking it up.

(Testing with 3.1 in the mean time, loosen to what happens with the PR)

…-reconnect

JanFellner · 2021-07-15T13:03:52Z

Updated PR to work with lws 3.1 (now building with 3.1 and 4.2)
For lws 3.1 the behaviour is absolutly the same, lws_service wakes up every 25 seconds.
Specified a timeout of 10 seconds but that does not change the behavior

JanFellner · 2021-07-15T13:14:11Z

CLA signed...
i am out now (received two pinball machines from italy need to check what i received :D)

atoppi

Thanks @JanFellner , I think this is a good enhancement.
You missed the handling of re-connection in case of LWS_CALLBACK_CLOSED.

I'm leaving some other notes that should be addressed.

events/janus_wsevh.c

atoppi · 2021-07-15T13:43:26Z

events/janus_wsevh.c

+ * Schedules a connect attempt using the lws scheduler as 
+ */
+void janus_wsevh_schedule_connect_attempt(void) {
+	#if (LWS_LIBRARY_VERSION_MAJOR >= 3 && LWS_LIBRARY_VERSION_MINOR > 2) || (LWS_LIBRARY_VERSION_MAJOR > 3)


LWS_LIBRARY_VERSION_MAJOR >= 4

events/janus_wsevh.c

JanFellner · 2021-07-16T07:26:36Z

@atoppi are you using any kind for code formatting with rules? (using the same env as you vscode)
Could not find any clang rules in the repo but i guess some sort of automation is needed that you don´t need to comment PR by coding style (which i don´t care i just use any ruleset available).
If not i will just follow your comments 😉

…ult with 5 seconds is faster

atoppi · 2021-07-16T09:08:34Z

@JanFellner No I'm not applying any kind of template in the IDE, just following the style in the rest of code.

atoppi

The PR is still missing the reconnection schedule in case of LWS_CALLBACK_CLOSED.
I've left other notes to address.

events/janus_wsevh.c

atoppi · 2021-07-16T09:26:19Z

events/janus_wsevh.c

+/* Forward declarations */
+void janus_wsevh_schedule_connect_attempt(void);
+void janus_wsevh_calculate_reconnect_delay_on_fail(void);
+// lws_sorted_usec_list_t is defined starting with lws 3.2


please use /* syntax for comments

events/janus_wsevh.c

JanFellner · 2021-07-16T10:52:08Z

While working on the code changes i lost the closed in mind, will address it

… Toppi

JanFellner · 2021-07-16T11:19:21Z

Hope i did now cover everything :)

JanFellner · 2021-07-16T11:32:00Z

As much of the comments were styling related, i wonder if you ever discussed using code formatters.
I did not until 2 years ago and i regret not having used them before.
It just releases you from the burden of having to communicate how code should look like. The rule just formats it.
(We started with just specifying what is common in the team and not with rules that have conflict potential like line length limits)

events/janus_wsevh.c

… Toppi

atoppi · 2021-07-16T11:42:28Z

@JanFellner nope, never discussed about this.
Are you thinking about a simple text document describing the common rules to follow or a specific file that auto-format your code in the IDE (like VSC clang-format) ?
If the latter, consider that @lminiero afaik is using geany to write code, so I'm not sure how he could use or validate it.

JanFellner · 2021-07-16T11:48:36Z

I am a friend about automation.
If you specify it in a standard you can also apply automated tools that validated stuff e.g. in a PR. so no unformatted code comes in the repo. So a clang file would for me be a starting point but it´s something you need to discuss.
The main task in the beginning is to setup the tooling, in vscode it´s just the plugin that you need to enable. That finds the file and does the magic for you. Other editors other ways...

and see it loosen from the rules you apply. What you want to specify, specify it. (or in other words, what you have to comment in a PR more than 5 times get it automated ;] )

atoppi · 2021-07-16T12:03:55Z

It seems to work as intended on lws v4.2 :-)

However when specifying an invalid address, the timeout on my machine is 15 seconds.
I guess, if not specified, it is falling back to a default environment specific value.
I confirm that setting the timeout (e.g. to 5) the connection goes in failed state quicker.

…double disconnected log entry

JanFellner · 2021-07-16T14:39:14Z

Added a connected log entry and removed a duplicate disconnected log entry

JanFellner · 2021-07-16T14:46:50Z

However when specifying an invalid address, the timeout on my machine is 15 seconds.
I guess, if not specified, it is falling back to a default environment specific value.
I confirm that setting the timeout (e.g. to 5) the connection goes in failed state quicker.

I added that value with d914fa4 for lws>=3.2

I used it now the whole day while developing debugging the signalling server.
The connection is always setup super fast and reliably (using lws 4.2)
looks good to me

…dded with lws 4.1

atoppi · 2021-07-19T10:14:27Z

@JanFellner lgtm 👍
waiting for @lminiero feedback before merging.

lminiero

Thanks! Added some editorial notes and a question inline.

lminiero · 2021-07-19T10:45:13Z

events/janus_wsevh.c

+/*
+* Websocket thread loop for websocket library newer than 3.2
+* The reconnect is handled in a dedicated lws scheduler janus_wsevh_schedule_connect_attempt
+*/


Code style: comments should be in the style below

/* Bla bla * bla bla */

lminiero · 2021-07-19T10:46:21Z

events/janus_wsevh.c

+	JANUS_LOG(LOG_VERB, "Joining WebSocketsEventHandler (lws>=3.2) client thread\n");
+	int n = 0;
+	while(n >= 0 && g_atomic_int_get(&initialized) && !g_atomic_int_get(&stopping))
+		n = lws_service(context, 0);


What can cause lws_service to return a negative integer? I'm thinking of intermittent errors that could cause this loop to break before Janus is shutdown.

It´s copy pasted from the sample actually.

https://libwebsockets.org/git/libwebsockets/tree/minimal-examples/ws-client/minimal-ws-client/minimal-ws-client.c#n210

I will check inside libwebsocket if it returns a different value and what might be conditions

If you follow the functions through the lib there are some places where the function returns -1,
I did not validate them all but to me it looks like those are scenarios where the context is not properly settled and therefore further execution does not make sense...

lws_service() returns 1 or lws_plat_service()

lws_plat_service() returns _lws_plat_service_tsi()

_lws_plat_service_tsi() returns on seldom cases -1 but the main negative returns are here lws_service_fd_tsi()

https://libwebsockets.org/git/libwebsockets/tree/lib/core-net/service.c?h=v4.2-stable#n624

The question is whats better in the end.
A non sleeping 100% core consuming thread or a thread termination :)

The problem is that this could result in a fatal scenario due to a temporary issue: as a first integration of the return value, I'd just print the negative value in case of errors, but I'd move on with the loop (so no n>=0 in the while). This would give us some more information from people's logs, in case it ever happens.

Check 78bf993

lminiero · 2021-07-19T10:46:34Z

events/janus_wsevh.c

+/*
+* Websocket thread loop for websocket library prior to (less than) 3.2
+* The reconnect is handled in the loop for lws < 3.2
+*/


See above on comments style.

lminiero · 2021-07-19T10:47:26Z

events/janus_wsevh.c

-				JANUS_LOG(LOG_WARN, "Error attempting reconnection...\n");
-				continue;
+			janus_wsevh_connect_attempt(NULL);
+			if (!wsi) {


Code style: no space between 'if` and the bracket.

lminiero · 2021-07-19T10:48:22Z

events/janus_wsevh.c

 			disconnected = janus_get_monotonic_time();
 			reconnect = TRUE;
+			JANUS_LOG(LOG_WARN, "WebSocketsEventHandler: Error attempting connection... (next retry in %ds)\n", reconnect_delay);


We already have a log error above: please add the retry info there.

lminiero · 2021-07-19T10:50:06Z

events/janus_wsevh.c

+		reconnect_delay = 1;
+	else if (reconnect_delay < JANUS_WSEVH_MAX_RETRY_SECS) {
+		reconnect_delay += reconnect_delay;
+		if (reconnect_delay > JANUS_WSEVH_MAX_RETRY_SECS)


The two if above have an extra space that per code style shouldn't be there.

lminiero · 2021-07-19T10:50:17Z

events/janus_wsevh.c

+
+/**
+ * Schedules a connect attempt using the lws scheduler as 
+ */


See above on comments style.

lminiero · 2021-07-19T10:50:29Z

events/janus_wsevh.c

+	#if (LWS_LIBRARY_VERSION_MAJOR >= 3 && LWS_LIBRARY_VERSION_MINOR >= 2) || (LWS_LIBRARY_VERSION_MAJOR >= 4)
+		lws_sul_schedule(context, 0, &sul_stagger, janus_wsevh_connect_attempt, reconnect_delay * LWS_US_PER_SEC);
+	#endif
+}


There's a missing empty line at the end.

lminiero · 2021-07-19T10:51:21Z

events/janus_wsevh.c

+#if !(((LWS_LIBRARY_VERSION_MAJOR == 3 && LWS_LIBRARY_VERSION_MINOR >= 2) || LWS_LIBRARY_VERSION_MAJOR >= 4))
+	#define lws_sorted_usec_list_t void
+#endif
+static void janus_wsevh_connect_attempt(lws_sorted_usec_list_t* sul);


Per code style, the * should be next to the pointer, not the type:

lws_sorted_usec_list_t *sul

lminiero · 2021-07-19T10:52:09Z

events/janus_wsevh.c

+ * Implements the connecting attempt to the upstream websocket server
+ * sets the connection result (lws_client_connect_info) to static wsi
+ */
+static void janus_wsevh_connect_attempt(lws_sorted_usec_list_t* sul) {


Same here (* next to the pointer, not type).

JanFellner · 2021-07-19T11:39:44Z

Thanks @lminiero for the comments, will check those now...

…ents

JanFellner · 2021-07-19T12:10:27Z

Pushed

That one needs to be nailed down. I can also remove the negative check, i just took it from the samples...
Check my comments i made.
#2736 (comment)

Concerning the styling stuff please do also check #2736 (comment) and the following two posts as suggestion...
(Even if you don´t use it it would help others to use the style you are using without having to comment them on PRs :) )

JanFellner · 2021-07-19T14:04:22Z

Logging lws_service result if it gets negative and just in case if it reverts back from negativ (or changes) as well.
Both classified as errors just to have them both in the log and not just one of them

lminiero · 2021-07-20T08:01:16Z

Looks good to me too, now! Thanks for the quick feedback and fixes, merging ✌️

lminiero · 2021-07-20T08:01:54Z

PS: just noticed the automated builds weren't started, I'll do those before merging just to be sure everything's fine.

JanFellner added 3 commits July 15, 2021 13:42

2734 CC-2166 Improve websocket connection handling on fail (speed up …

6233ca4

…reconnect) if target is not local host

Merge remote-tracking branch 'origin/master' into feature/CC-2166-spe…

6ae301f

…edup-eventing-websocket-reconnect # Conflicts: # events/janus_wsevh.c

2734 CC-2166 Changed logginginfo to verb

c8e3c20

JanFellner and others added 2 commits July 15, 2021 15:00

2734 CC-2166 fixed build wwith lws 3.1

5bf48ce

Merge branch 'master' into feature/CC-2166-speedup-eventing-websocket…

d3078e8

…-reconnect

atoppi reviewed Jul 15, 2021

View reviewed changes

JanFellner added 2 commits July 16, 2021 09:59

2734 CC-2166 Adopted PR according to comments from Alessandro Toppi

e2c391d

2734 CC-2166removed timeout_secs=10 when creating context as the defa…

d5c0f86

…ult with 5 seconds is faster

atoppi reviewed Jul 16, 2021

View reviewed changes

2734 CC-2166 AAnother aopted PR according to comments from Alessandro…

aa2a0e9

… Toppi

atoppi reviewed Jul 16, 2021

View reviewed changes

events/janus_wsevh.c Outdated Show resolved Hide resolved

events/janus_wsevh.c Outdated Show resolved Hide resolved

2734 CC-2166 AAnother aopted PR according to comments from Alessandro…

9d52173

… Toppi

2734 CC-2166 Add client connect log message (there was none) removed …

be2c6cc

…double disconnected log entry

2734 CC-2166 Specify a maximum connect time for lws >= 3.2 (5 seconds)

d914fa4

2734 CC-2166 trivial (removed whitespace)

a74c34e

2734 CC-2166 fixed build for lws >3.2 <4.1 connect_timeout_secs was a…

0029cff

…dded with lws 4.1

lminiero reviewed Jul 19, 2021

View reviewed changes

2734 CC-2166 changed coding style according to Lorenzo Miniero s comm…

38dc2cc

…ents

JanFellner added 2 commits July 19, 2021 14:35

2734 CC-2Fixed comment style

b3550eb

2734 CC-2166 Log lws_service result on negative result

78bf993

lminiero merged commit 1b9c4e2 into meetecho:master Jul 20, 2021

JanFellner deleted the feature/CC-2166-speedup-eventing-websocket-reconnect branch July 20, 2021 09:13

Feature/cc 2166 speedup eventing websocket reconnect #2736

Feature/cc 2166 speedup eventing websocket reconnect #2736

Conversation

JanFellner commented Jul 15, 2021

januscla commented Jul 15, 2021

lminiero commented Jul 15, 2021 • edited Loading

JanFellner commented Jul 15, 2021

JanFellner commented Jul 15, 2021

JanFellner commented Jul 15, 2021

atoppi left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JanFellner commented Jul 16, 2021

atoppi commented Jul 16, 2021

atoppi left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JanFellner commented Jul 16, 2021

JanFellner commented Jul 16, 2021

JanFellner commented Jul 16, 2021 • edited Loading

atoppi commented Jul 16, 2021

JanFellner commented Jul 16, 2021 • edited Loading

atoppi commented Jul 16, 2021

JanFellner commented Jul 16, 2021

JanFellner commented Jul 16, 2021 • edited Loading

atoppi commented Jul 19, 2021

lminiero left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JanFellner Jul 19, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JanFellner Jul 19, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JanFellner commented Jul 19, 2021

JanFellner commented Jul 19, 2021 • edited Loading

JanFellner commented Jul 19, 2021

lminiero commented Jul 20, 2021

lminiero commented Jul 20, 2021

lminiero commented Jul 15, 2021 •

edited

Loading

JanFellner commented Jul 16, 2021 •

edited

Loading

JanFellner commented Jul 16, 2021 •

edited

Loading

JanFellner commented Jul 16, 2021 •

edited

Loading

JanFellner Jul 19, 2021 •

edited

Loading

JanFellner Jul 19, 2021 •

edited

Loading

JanFellner commented Jul 19, 2021 •

edited

Loading