logux / logux

Issues and roadmap
https://logux.org/
103 stars 3 forks source link

Endless loop upon page load #14

Closed uncaught closed 3 years ago

uncaught commented 4 years ago

I'm hitting an endless state-replace-loop on page load:

logux_endless_loop

I tried debugging, but I can't make sense of it. It keeps bouncing into replaceState with an undefined state, 471 actions and an undefinedpushHistory. The last action is@@redux/INIT`:

logux_endless_loop2

I've cleared my complete local storage and could reproduce the problem again. At first it's just a few loops, but with more actions added, it seems the list grows exponentially.

I'm on @logux/core@0.3.5

ai commented 4 years ago

How I can reproduce it too?

uncaught commented 4 years ago

That's going to be increasingly difficult because the app is growing and requires https to some degree.

It's definitely a problem related to the IndexedStore again. Without it, the problem is gone. I might just skip the offline-support for now. I'm using the localStorage already to have initial data available until the subscriptions go through.

I've added a logger to see every dispatched redux-action and I see a problem already without any action except of one subscription:

First page-load with an empty IndexedDb:

log.js:24 [HMR] Waiting for update signal from WDS... Store.ts:21 action {type: "@@redux/INIT7.p.4.h.y.k"} Store.ts:21 action {type: "@@redux/PROBE_UNKNOWN_ACTIONm.a.u.w.2.m"} Store.ts:21 action {type: "@@redux/INIT7.p.4.h.y.k"} log.js:58 Logux subscribed to channel groups/load log.js:58 Logux state is connecting log.js:58 Logux tab role is leader log.js:58 Logux state is sending. Client was connected to server:AkEFbQRK. log.js:58 Logux state is synchronized Store.ts:21 action {groups: Array(0), type: "groups/loaded"} log.js:58 Logux added groups/loaded action from server:AkEFbQRK {groups: Array(0), type: "groups/loaded"} {id: "1577635519189 server:AkEFbQRK 0", time: 1577635519189, reasons: Array(1), added: 2} log.js:58 Logux action 1577635518288 aad86489-a72d-40f2-9bdd-6717d4b45f7b:h98RXtOK:nvzvW_UY 0 was processed

2nd page-Load:

log.js:24 [HMR] Waiting for update signal from WDS... Store.ts:21 action {type: "@@redux/INITu.s.3.1.x"} Store.ts:21 action {type: "@@redux/PROBE_UNKNOWN_ACTIONe.z.2.o.v.5"} Store.ts:21 action {type: "@@redux/INITu.s.3.1.x"} Store.ts:21 action {groups: Array(0), type: "groups/loaded"} log.js:58 Logux subscribed to channel groups/load log.js:58 Logux state is connecting log.js:58 Logux tab role is leader log.js:58 Logux state is sending. Client was connected to server:AkEFbQRK. log.js:58 Logux state is synchronized Store.ts:21 action {groups: Array(0), type: "groups/loaded"} log.js:58 Logux added groups/loaded action from server:AkEFbQRK {groups: Array(0), type: "groups/loaded"} {id: "1577635593906 server:AkEFbQRK 0", time: 1577635593906, reasons: Array(1), added: 4} log.js:58 Logux action 1577635592976 aad86489-a72d-40f2-9bdd-6717d4b45f7b:h98RXtOK:VfYV570Q 0 was processed

3rd page-load:

log.js:24 [HMR] Waiting for update signal from WDS... Store.ts:21 action {type: "@@redux/INITo.o.z.u.5"} Store.ts:21 action {type: "@@redux/PROBE_UNKNOWN_ACTIONb.6.j.h.1.b"} Store.ts:21 action {type: "@@redux/INITo.o.z.u.5"} Store.ts:21 action {groups: Array(0), type: "groups/loaded"} log.js:58 Logux subscribed to channel groups/load Store.ts:21 action {type: "@@redux/INIT"} Store.ts:21 action {groups: Array(0), type: "groups/loaded"} Store.ts:21 action {groups: Array(0), type: "groups/loaded"} log.js:58 Logux state is connecting log.js:58 Logux tab role is leader log.js:58 Logux state is sending. Client was connected to server:AkEFbQRK. log.js:58 Logux state is synchronized Store.ts:21 action {groups: Array(0), type: "groups/loaded"} log.js:58 Logux added groups/loaded action from server:AkEFbQRK {groups: Array(0), type: "groups/loaded"} {id: "1577635633536 server:AkEFbQRK 0", time: 1577635633537, reasons: Array(1), added: 6} log.js:58 Logux action 1577635632641 aad86489-a72d-40f2-9bdd-6717d4b45f7b:h98RXtOK:zArI7cbf 0 was processed

And so on... I would assume with more than just one action in the mix, this will get out of hand quickly.

uncaught commented 4 years ago

I've just added a start-script to make it easier.

git clone https://gitlab.com/uncaught/doko.git
cd doko
./start.sh

Then open http://127.0.0.1:3333/groups

Alternatively, I've deployed the dev-system on my server: http://correnz.net:3333/groups

Open either URL, open the dev-tools and reload the page several times and see how the actions are getting more and more.

ai commented 4 years ago

It's definitely a problem related to the IndexedStore again. Without it, the problem is gone. I might just skip the offline-support for now.

I will try to debug IndexedDB first. Sorry, I didn't have a good example for IndexedDB, this is why current implementation is not perfect.

uncaught commented 4 years ago

No worries! But I thought the IndexedStore was required for offline support, is it not? I thought with offline-first design, this would be the default :)

ai commented 4 years ago

But I thought the IndexedStore was required for offline support, is it not?

Yeap, we need it for a case like:

  1. Disconnect from internet
  2. Do some changes
  3. Close website without saving
  4. Connect again
  5. Open website and save your changes
ai commented 4 years ago

Hi. Sorry for the delay. I had traveled to SF and Mexico for a bachelor's party. I am now back to help you with this issue.

Seems like lock happens here: https://github.com/logux/redux/blob/fc4204230af370fa48224fa167e7db29196e3769/create-logux-creator.js#L288-L291

Can you put console.log(replaying) before return replaying.then(function () { and another before if (wait[meta.id]) {? My theory that Promise can be resolved but replaying was not cleaned for some reason.

oliverreich commented 3 years ago

hey there!

first of all, I think logux is very very interesting and really well implemented. Good job! :)

For me, the problem occurs with vuex as well, although it is not necessarily an infinite loop (or better: it may depend on number of actions stored and result in call stack size problems (?)). It seems that store commit in vuex is called exponentially more often than there are actions in store (which should not happen if every action is commited only once?)

I started to chase it down by setting a breakpoint to the get() function of indexedStore (since the problem is only obvious when using indexedStore, however I assume the problem is there as well when using the in memory store but not as noticeable)

Here is what I found and where I think the problem lies:

1) createStore$ calls log.each() in order to put all actions to an array previous (vuex.js line 475) ( log.each() iterates through all the actions in store every time it is called which is important later on) 2) For every action in previous, process() is called 3) process() calls replay() 4) replay() calls log.each() which in turn now calls get() on indexedStore and iterates through ALL actions and calls the supplied callback

As a result, replaceState() (and the store mutation) are called [number of actions]*[number of actions] times (or even more often). Is this expected behavior?

Interestingly this does not necessarily lead to wrong results in app state, at least not with less than a couple hundred actions. I assume this is because we replay the whole history just n times and start every iteration cycle with a fresh origin state. However, having 1000+ increment/decrement mutations on a single state property, things start to get weird and performance drops quite heavy :(

Hope my thoughts are in any way helpful. If not, I'd be happy for hints on how I can help :)

ai commented 3 years ago

We are planning to introduce a new state manager soon, which could solve this problem: https://github.com/logux/state

ai commented 3 years ago

Logux State is ready