[BUG] lifecycle callbacks called in wrong sequence for top level route.

[3cp]

I'm submitting a bug report

• Library Version:
  all
  It is a regression caused by aurelia-templating v1.8.2.
  But I am pretty sure this is a router bug (whether the buggy code is in this repo, I am not sure), the new aurelia-templating fix just made this router bug appears even worse.

• Operating System:
  OSX 10.13

• Node Version:
  8.11.3

• NPM Version:
  6.2.0

• JSPM OR Webpack AND Version
  NA

• Browser:
  all

• Language:
  all

Current behavior:
https://github.com/huochunpeng/router-bug2

app.js has one level router config with two pages (page-one.js and page-two.js), here is the log of lifecycle callbacks

with aurelia-templating 1.8.1 (with or without bluebird)
note bind() is in right order, but attached() is not (page-one should be attached before app)

[Log] app configureRouter (app-bundle.js, line 22)
[Log] app bind (app-bundle.js, line 34)
[Log] page-one bind (app-bundle.js, line 105)
[Log] app attached (app-bundle.js, line 38)
[Log] page-one attached (app-bundle.js, line 109)

with aurelia-templating 1.8.2 (with or without bluebird)
bind() is in wrong order, plus wrong attached() order

[Log] app configureRouter (app-bundle.js, line 22)
[Log] page-one bind (app-bundle.js, line 105)
[Log] app bind (app-bundle.js, line 34)
[Log] app attached (app-bundle.js, line 38)
[Log] page-one attached (app-bundle.js, line 109)

Due to the wrong bind() call sequence, the page-one now doesn't get correct inherit overrideContext from app.

User has reported missing variable (defined in top app.js) in router loaded component view template.
https://discourse.aurelia.io/t/using-require-breaks-router/1411/31?u=huochunpeng

This bug is related to #548, which can be fixed by #571. But that fix only fix lifecycle callbacks for nested route, not the top route (as top route is not delayed).

Expected/desired behavior:

No matter what aurelia-templating version in use, our sequence is NOT right.
aurelia-templating v1.8.2 made this bug even worse, and more noticeable to end user.

• What is the expected behavior?

• What is the motivation / use case for changing the behavior?

The user experienced missing variable (due to missing overrideContext) is not the bug we want to fix.
The wrong lifecycle callback sequence is the bug to be solved.

cc @bigopon @davismj @EisenbergEffect

aurelia-templating v1.8.2 just killed off everyone (intentionally or unintentionally) rely on the default inheritBindingContext behaviour of router loaded component.

[bigopon]

note bind() is in right order, but attached() is not (page-one should be attached before app)

This is not correct. Child element cannot have attached called before parent's attached gets called.

[3cp]

@bigopon right, so with 1.8.1, the behaviour is expected.

I just tested by removing router from the picture.

app.html

<template>
  <require from="./page-one"></require>
  <page-one></page-one>
</template>

Both 1.8.1 and 1.8.2 behaves same:

app bind
page-one bind
app attached
page-one attached

So this is likely still a router related bug.

[bigopon]

It's likely to be in templating-router + templating than router I think.

https://github.com/aurelia/templating-router/blob/e83bd1bc182350c7cdc66736404633a05cbb711b/src/router-view.js#L131-L136

It's a bit early compared to what we have in [email protected]

[3cp]

Means an easy fix for you?

[fkleuver]

For completeness sake I should point out I've done some digging into a potentially related issue a couple months back: aurelia/templating-router#26

The most relevant bit from that topic is this visualization of the lifecycle steps when there is a 300ms promise delay between the activates of 4 nested child routers:

Pay attention to the arrows:

35.298 [-view-model 1] activate
35.337 [-view-model 1] configureRouter
35.346 [-router-view 1] created
35.353 [-view-model 1] created
35.362 [-view-model 1] bind
35.377 [-router-view 1] bind <-------------
35.400 [--view-model 2] configureRouter
35.407 [---view-model 3] configureRouter
35.414 [----view-model 4] configureRouter
35.422 [--view-model 2] activate
35.726 [---view-model 3] activate
36.030 [----view-model 4] activate
36.335 [-router-view 1] process
36.351 [--router-view 2] created
36.359 [--router-view 2] process
36.366 [---router-view 3] created
36.371 [---router-view 3] process
36.377 [----router-view 4] created
36.381 [----router-view 4] process
36.393 [----router-view 4] swap
36.397 [---router-view 3] swap
36.401 [----view-model 4] created
36.404 [----view-model 4] bind
36.409 [----router-view 4] bind <-------------
36.413 [--router-view 2] swap
36.418 [---view-model 3] created
36.422 [---view-model 3] bind
36.426 [---router-view 3] bind <-------------
36.431 [-router-view 1] swap
36.435 [--view-model 2] created
36.439 [--view-model 2] bind
36.444 [--router-view 2] bind <-------------
36.451 [----router-view 4] _notify
36.454 [---router-view 3] _notify
36.455 [--router-view 2] _notify
36.455 [-router-view 1] _notify
36.458 [-view-model 1] attached
36.469 [--view-model 2] attached
36.471 [---view-model 3] attached
36.472 [----view-model 4] attached

Now the router-view 1 being first isn't necessarily weird or wrong, because that's the root. The App always gets a special treatment in the lifecycle.

What I see as a problem (as @StrahilKazlachev eluded on Discord, and others may have said this as well) is first of all that binding happens inside-out, and secondly that process happens before bind.

I have a feeling this is rooted in the router pipeline, but it's hard to know for sure. Time to put vCurrent in a monorepo and write some integration tests.. x)

[bigopon]

and secondly that process happens before bind.

Isn't this the expected behavior ? A view port (read <router-view/> element) should process (nav, route, router) before it bind the view and view model together

[StrahilKazlachev]

Does anything guarantee that the <router-view> itself is bound when this line is hit?

[bigopon]

I haven't had any immediately obvious fix for this atm, so the suggestion is to undo aurelia/templating#633 via following block

import { CompositionEngine } from 'aurelia-templating';

CompositionEngine.prototype._createControllerAndSwap = function(context) {
    return this.createController(context).then(controller => {
      controller.automate(context.overrideContext, context.owningView);

      if (context.compositionTransactionOwnershipToken) {
        return context
          .compositionTransactionOwnershipToken
          .waitForCompositionComplete()
          .then(() => {
            return this._swap(context, controller.view);
          })
          .then(() => controller);
      }

      return this._swap(context, controller.view).then(() => controller);
    });
  }

and avoid using bluebird to work around the original issue.

[StrahilKazlachev]

@bigopon why? Where is the code path that calls .compose, since I don't see how else you can reach _createControllerAndSwap? I can't find any code in aurelia-router that uses the CompositionEngine. <router-view> uses .createController, from there you can't reach _createControllerAndSwap, and then itself "automates" the Controllers.
I'm not so familiar with the router system so can you look at this. I'm unsure if this won't lock up the router and the application so ...

Edit: Scratch the above, so there is a .compose call, indirect, from Aurelia.prototype.setRoot through TemplatingEngine.prototype.compose to CompositionEngine.prototype.compose.
Also my mod did lock the startup of the app. Still find it strange there is no internal logic to at least throw if any of the .automate calls are made before the <router-view> is bound.

[bigopon]

The fix at aurelia/templating#633 pushes app root bind to happen after any <router-view/> view model bind(), which is a not nice change. Undoing that PR brings back the old behavior, which I think is a better temporary solution.

The way the root router & child router work, though may be not nice (bind happens inside out), but it's been there, & usable.

---

For StrahilKazlachev/templating-router@c54c706, Very nice solution, it also fixes the issue with bind happens inside out. A potential tweak is that depends on whether <router-view/> inside an if (or any other non repeat template controller with caching behavior) is a supported scenario, we may need to tweak it a little bit.

What the behavior is like with @StrahilKazlachev 's solution

(<view-1/> = level 1 router view, <sub-view/> = level 2 router view ... bad naming)

Though I cannot get it to work with child router without bringing back behavior of 1.8.1, did it work for you @StrahilKazlachev ?

Though I'm not confident we can fix the inside out behavior without a version bump.

cc @EisenbergEffect @fkleuver @davismj @huochunpeng

[StrahilKazlachev]

@bigopon my "solution" did lock the app startup with 1.8.2. Basically the .bind never gets called, the Promise never gets resolved.
I used the sample from the first comment.

[3cp]

@bigopon for nested child routes, if you bring #571, it might just works.

[jvlobo]

Hi there!!

I'm having this exact same issue... any news on it?

Cheers :)

[3cp]

@jvlobo unfortunately the team has decided to live with this bug at the moment. This is one of domino bugs, created by a chain of patches to fix some other nasty bugs. Comparing to other bugs, this one is the least serious one. We are bit lazy here, or should I say bit scared to create another new bug with another patch :-)

Don't worry, vNext will cleanup all of them :D (@fkleuver sweating heavily when reading this)

[jvlobo]

I've been having a lot of bugs recently with some of the updates :(
I'll try to do a workaround for this one too, since our app is in production.
Thank you.

[3cp]

@jvlobo sorry to hear that. Could you post some code to discourse forum so folks can help?

[jvlobo]

Where is the discourse forum? Thanks!

[3cp]

Man, on aurelia home page :-) https://discourse.aurelia.io

[fkleuver]

@huochunpeng vNext won't need to clean any of this up since the new core framework will make it much simpler to achieve the same things. Timing related issues will be pretty much nonexistent. I'm not sweating at all :)