Redux is spammed with `BACKEND_CONNECTION_UP` actions

Right now the HeartbeatBackendListener component in OverlayScreen.tsx dispatches an establishedBackendConnection action on every single message the frontend receives from the backend. With the current messaging settings, that means that the frontend is usually having to process an extra (redundant) action up to once every 10 ms. This is probably not the main performance bottleneck in our frontend, but it adds a ton of extra events into the Redux inspector (which makes it harder to catch other actions). The fix should be relatively straightforward to implement: only dispatch the establishedBackendConnection action if the backend is not already connected (as reported by the getBackendConnected selector).

It might be worth getting CPU usage measurements before and after this is fixed, just to get a sense of whether this issue has any measurable impact on CPU usage.

There also seems to be some kind of correctness problem with the triggering of establishedBackendConnection action dispatches. When I modify the backend's frontend send schedule to only send a state to the frontend once every 5 seconds, and I uncomment the backend's print code to print every single event sent by the backend to the frontend, I see that there's a flood of BACKEND_CONNECTION_UP actions (spaced ~5 ms apart) triggered after every single event sent by the backend. There should be no more than one such action triggered after every event from the backend. What I see now reminds me of the behavior we saw in #363. @rohanpurohit Can you see if you can reproduce those test conditions and this observation on your end? I first observed this on 2bbd755, but I would expect that it should also be reproducible on the develop branch (e.g. d71f11a).

Given the timing of this flood of actions, it seems plausible to me that this could be making the frontend's CPU usage measurably higher than it's supposed to be, so we should definitely measure CPU usage before and after this is fixed. This flooding problem should be fixed before we suppress establishedBackendConnection dispatching when the backend is already connected (as specified in the main issue description for #411), as that suppression will make it harder to verify the correctness of the fix to this flooding problem.

There also seems to be some kind of correctness problem with the triggering of establishedBackendConnection action dispatches. When I modify the backend's frontend send schedule to only send a state to the frontend once every 5 seconds, and I uncomment the backend's print code to print every single event sent by the backend to the frontend, I see that there's a flood of BACKEND_CONNECTION_UP actions (spaced ~5 ms apart) triggered after every single event sent by the backend. There should be no more than one such action triggered after every event from the backend. What I see now reminds me of the behavior we saw in #363. @rohanpurohit Can you see if you can reproduce those test conditions and this observation on your end? I first observed this on 2bbd755, but I would expect that it should also be reproducible on the develop branch (e.g. d71f11a).

Given the timing of this flood of actions, it seems plausible to me that this could be making the frontend's CPU usage measurably higher than it's supposed to be, so we should definitely measure CPU usage before and after this is fixed. This flooding problem should be fixed before we suppress establishedBackendConnection dispatching when the backend is already connected (as specified in the main issue description for #411), as that suppression will make it harder to verify the correctness of the fix to this flooding problem.

(tested on https://github.com/pez-globo/pufferfish-software/commit/d71f11acfe92357142e66592ae671c153d40aa78 with backend running simulator) Just to confirm if I'm on the same page, I'll describe what I did and observed, changed FRONTEND_OUTPUT_MIN_INTERVAL in states.py to 5 seconds, uncommented the print code for events sent by the backend to the frontend

opened the redux console in chrome dev tools
after every event sent from the backend to frontend
there is a flood of backend_connection_up events in the redux console

so the code in OverlayScreen.tsx checks for the diff between two dates, const diff = Math.abs(new Date().valueOf() - new Date(heartbeat).valueOf()); and whether this is greater than 3 seconds, which is true when the backend is disconnected, but obviously not when it's connected. therefore it seems to me that we will be dispatching establishedBackendConnection almost all the time when the backend is connected regardless of the (connection timeout) and the 5ms delay is probably due to useEffect or latency in dispatch (I'm not sure).

so I think we should probably return early if the backend is connected? wouldn't that solve both the issues?

therefore it seems to me that we will be dispatching establishedBackendConnection almost all the time when the backend is connected regardless of the (connection timeout)

But what you describe is only a subset of the behavior I see: when the backend is connected, establishedBackendConnection is only dispatched (in a flood) for a finite duration after each message is received from the backend - it's not just one continuous flood as long as the backend is connected, but rather a discrete flood per message. During each flood, somehow the useEffect magically decides for itself when to end the current flood of action dispatches. This reminded me a lot of how the Rotary Encoder controller would decide for itself when to end its own flood of increment/decrement behaviors, i.e. some sort of circular dependency.

so I think we should probably return early if the backend is connected?

I expect this could solve the problem in the main description of this issue (to quote, "only dispatch the establishedBackendConnection action if the backend is not already connected (as reported by the getBackendConnected selector).").

Perhaps one thing we could do to make the useEffect less wasteful is to compute a boolean timedOut = diff > BACKEND_CONNECTION_TIMEOUT and pass that as a replacement for diff in the useEffect's list of dependencies. Then the useEffect should only be run when the timedOut variable's value changes, even though diff's value changes all the time. I also don't see clock and heartbeat actually being used inside the useEffect, so maybe we can remove them from the list of dependencies?

the 5ms delay is probably due to useEffect or latency in dispatch (I'm not sure).

I looked a bit more closely at the BACKEND_CONNECTION_UP actions in the Redux debugger log, and I saw that the action sometimes caused a diff of store.app.clock. This reminded me that actually the reducer for BACKEND_CONNECTION_UP updates the store.app.clock; but clock is also listed as a dependency in the HeartbeatBackendListener's useEffect, which dispatches BACKEND_CONNECTION_UP! This is probably the source of the circular dependency in our system. We could either:

remove clock from the list of dependencies in useEffect (if we never really needed the useEffect to be run whenever store.app.clock changes)
remove the clock-setting behavior of the reducer for BACKEND_CONNECTION_UP (if we never really needed that clock-setting behavior in that reducer in the first place)
or both

remove clock from the list of dependencies in useEffect (if we never really needed the useEffect to be run whenever store.app.clock changes)

remove the clock-setting behavior of the reducer for BACKEND_CONNECTION_UP (if we never really needed that clock-setting behavior in that reducer in the first place)

or both

@ethanjli It looks like the useEffect was mainly relying on the clock dependency to re-run the useEffect and therefore whenever that changed (and probably one of the other dependencies) it starts listening to whether it needs to dispatch a BACKEND_CONNECTION_DOWN OR BACKEND_CONNECTION_UP action
which is why when I removed the clock dependency in #412, we were not able to detect that backend was disconnected, which also raises concerns about the ambiguity of the useEffect.

so I feel we have two options:

keep clock as a dependency (but then useEffect essentially runs whenever clock changes but we also would want to remove that selector altogether in #415 )
remove it and here we have multiple options we could come up with, this is just one example: define a local state (which is sort of a timer) that changes state whenever we want (let's say 10 seconds) and that local state is added as a dependency to the useEffect, I'm not sure about the performance improvement or regression from this. I feel like we should try things that obviously give us the functionality we need and also a performance improvement and ultimately making the behavior of useEffect more deterministic.

one thing is Preact performance profiler is really ambiguous, I tried following the 2nd approach but I'm not sure if the component rendered more or less.

Oh, this is very interesting. It sounds like this useEffect is really awkwardly trying to do things made easy by redux-saga (e.g. checking some selectors and dispatching some actions at a regular time interval, forever). If clock does the job correctly, maybe we can keep it as a dependency in #412 (but add a code comment explaining why it's there), and then for #415 we'll completely refactor HeartbeatBackendListener from a useEffect into a saga?

Oh, this is very interesting. It sounds like this useEffect is really awkwardly trying to do things made easy by redux-saga (e.g. checking some selectors and dispatching some actions at a regular time interval, forever). If clock does the job correctly, maybe we can keep it as a dependency in #412 (but add a code comment explaining why it's there), and then for #415 we'll completely refactor HeartbeatBackendListener from a useEffect into a saga?

oh great, I think we can do that! I'll keep clock as a dependency and update the PR!

pez-globo / pufferfish-software

Redux is spammed with `BACKEND_CONNECTION_UP` actions #411