RAD: UI displays the expected target, Router believs it displays another one

[holyjak]

I am running into an issue with Fulcro 3.4 and RAD 1.0.8 where the UI shows the (non-default) router target in an uninitialized state while the router believes that it is displaying the default target. I still cannot figure out why.

I have three nested routers (along with some other components): RootRouter > OrgRouter > OrgDashboard for org id=nnn > DetailsDisplayRouter with :targets [LatestBillRunList SubscriberList] and the URL .../org/123/subscribers and I expect to see the SubscriberList RAD report - which I do, but it is empty, even though the DB has the data, because the parent router believes it is displaying the other report . This only happens when I go to the URL in the browser, not when I click myself through the app to the state.

So how is it possible that DetailsDisplayRouter believes it is displaying LatestBillRunList while it should, and the UI does, show SubscriberList?!

I understand why the report is empty despite the presence of its data - Fulcro believes it is not showing so it does not send it any props - and I guess that the LatestBillRunList is there because it is the default target and somehow the routing to the deferred target of the SubscriberList has not completed correctly (no idea why/how, since the tx log shows :ready!) in which case the router falls back to the previous or default target. Noteworthy: the UISM state is as I expect it to be, only the router is wrong.

The state of of the DB seems inconsistent when I compare the router and the corresponding UISM:

uism/asm-id DetailsDisplayRouter:
 active-state :routed
 active-timers {}
 local-storage {:path-segment ["subscribers"], :pending-path-segment [], :target [::report/id :SubscriberList]}
dr/id DetailsDisplayRouter:
 current-route LatestBillRunList

so the router and its UISM have completely different view of the world?! How is that possible?

Transaction log extract

(the times, such as :40, are the seconds parts of the timestamps so newest comes first below)

:40 SM(DetailsDisplayRouter) :timeout! :event-data {}
:40 SM(DetailsDisplayRouter) :timeout! :event-data {}
:40 SM(RootRouter) :timeout!
:38 SM(SubscriberList) :event/loaded
:38 SM(OrgRouter) :ready!
:38 dr/target-ready {:target [:org-nr "123"]} ; -> could this confuse DR to believe it shows the default view?! 
:37 SM(DetailsDisplayRouter) :ready!
:37 LOAD subscribers ; the source for SubscriberList
:36 LOAD org "123" ; load!-ed from OrgDashboard
:36 dr/target-ready {:target [:com.fulcrologic.rad.report/id :SubscriberList]}
:34 SM(BEGIN): DetailsDisplayRouter {:path-segment ["subscribers"], :target [:com.fulcrologic.rad.report/id :SubscriberList]}

where "SM" means "State Machine"

Noteworthy:

1. We are load!-ing 2 things via deferred routes, the OrgDashboard data (for org-nr 123) and the SubscriberList report (that gets the org nr also passed and uses it in its query). The child - the report - finished earlier and so its target-ready is triggered earlier, followed by target-ready of its parent. Could this cause issues?

Console log

(newest last; UISM = [com.fulcrologic.fulcro.ui-state-machines:?], DR = [dynamic-routing:*])

...
UISM  Trigger DetailsDisplayRouter :ready!
[dynamic-routing:152] -  Applying route ident [:com.fulcrologic.rad.report/id SubscriberList] to router DetailsDisplayRouter
DR Activating state  :routed on DetailsDisplayRouter
DR Cancelling timer  :error-timer on :DetailsDisplayRouter due to event :ready!
...
TIMEOUT on RootRouter due to timer :error-timer after 5000 ms
TIMEOUT on OrgRouter due to timer :error-timer after 5000 ms
TIMEOUT on DetailsDisplayRouter due to timer :error-timer after 5000 ms
TIMEOUT on DetailsDisplayRouter due to timer :error-timer after 5000 ms

Weird stuff:

1. DetailsDisplayRouter is set to routed and its error-timer cancelled yet it gets a timeout due to this timer a while later
2. The :error-timer timeout for DetailsDisplayRouter is logged twice. That is not the case for its two ancestor routers that each gets it just once.

Questions

1. How is it possible that a router UISM and the router have inconsistent states?
2. How is it possible that the router is first set to :routed with the correct target and the error timer is cancelled yet a while later the error timer fires (and is logged / fires twice!)
3. How to troubleshoot this?

Replication

I have created https://github.com/holyjak/fulcro-rad-demo/tree/issue/reload%3Ddiscrepancy-UIxUISMxrouter to replicate the problem, see its README.

[holyjak]

FYI I am trying to replicate the problem in rad-demo, so far without success