Loopback Context doesn't work with ES connector

[pulkitsinghal]

This issues is similar to the problems faced by other connectors in their younger days: https://github.com/othiym23/node-continuation-local-storage/issues/6 https://github.com/mongodb/node-mongodb-native/pull/1184

Alternatives: https://github.com/strongloop/loopback/issues/1423

@raymondfeng - please advise.

[pulkitsinghal]

If you want to clone the latest branch to see exactly what I'm working with ... minus the private datasource connection settings ... you can use: 1) https://github.com/ShoppinPal/warehouse/tree/feature/add-es-connector 2) https://github.com/ShoppinPal/warehouse/blob/feature/add-es-connector/server/server.js#L21-L47 3) https://github.com/ShoppinPal/warehouse/blob/feature/add-es-connector/common/models/store-config-model.js#L34-L37

[pulkitsinghal]

When the code from (2) runs I see in the logs:

shoppinpal:server:server loopbackContext +9s { name: 'loopback', 
active: {}, 
_set: [ null ], 
id: 
{ create: [Function], 
flags: 15, 
before: [Function], 
after: [Function], 
error: [Function], 
uid: 2, 
data: null } } 

shoppinpal:server:server currentUser +1ms { realm: 'portal', 
username: 'merchant2@shoppinpal.com', 
password: '$2a$10$Ac/.K362Z8qS28IzJoJLReOxvYXNoSDziDC3KI20if5odLfLFIUyC', 
email: 'merchant2@shoppinpal.com', 
id: 'gt1DxYYCQwWP3hfj0UgTFQ' }

And when the code from (3) runs, the user is undefined for some reason:

common:models:store-config-model ctx +136ms { name: 'loopback', 
active: {}, 
_set: [ null ], 
id: 
{ create: [Function], 
flags: 15, 
before: [Function], 
after: [Function], 
error: [Function], 
uid: 2, 
data: null } } 

common:models:store-config-model currentUser +0ms undefined

[pulkitsinghal]

Will explore https://github.com/strongloop/loopback/issues/1495 as a possible solution.

[pulkitsinghal]

@fuwaneko, @raymondfeng, @ritch - are you ready to have your mind blown?

It works all of a sudden! Without any changes from https://github.com/strongloop/loopback/issues/1495!

I don't know if it is because versions of loopback and its dependencies have been updated in package.json of my working branch (since this bug was originally discovered) or what!

But have a look at these logs which now show the loopbackContext as present in both the middleware AND the remote method:

Following logs show the middleware log output coming from my server/server.js file

  server:server loopbackContext +711ms { name: 'loopback',
  active: 
   { accessToken: 
      { id: '2hv4FhQ6ASCrumxf0yPYmYX5HrVIgTRss58GcWm7fES3ddItWNfcB9W6baCax2AQ',
        ttl: 1209600,
        created: Thu Jul 02 2015 11:10:26 GMT-0500 (CDT),
        userId: 'merchant1@shoppinpal.com' } },
  _set: [ null, { accessToken: [Object] }, { accessToken: [Object] } ],
  id: 
   { create: [Function],
     flags: 15,
     before: [Function],
     after: [Function],
     error: [Function],
     uid: 2,
     data: null } }
  server:server currentUser +1ms { username: 'merchant1@shoppinpal.com',
  realm: 'portal',
  email: 'merchant1@shoppinpal.com',
  seedWithRole: 'manager' }
  server:server loopbackContext afterwards +0ms { name: 'loopback',
  active: 
   { accessToken: 
      { id: '2hv4FhQ6ASCrumxf0yPYmYX5HrVIgTRss58GcWm7fES3ddItWNfcB9W6baCax2AQ',
        ttl: 1209600,
        created: Thu Jul 02 2015 11:10:26 GMT-0500 (CDT),
        userId: 'merchant1@shoppinpal.com' },
     currentUser: 
      { username: 'merchant1@shoppinpal.com',
        realm: 'portal',
        email: 'merchant1@shoppinpal.com',
        seedWithRole: 'manager' } },
  _set: 
   [ null,
     { accessToken: [Object], currentUser: [Object] },
     { accessToken: [Object], currentUser: [Object] } ],
  id: 
   { create: [Function],
     flags: 15,
     before: [Function],
     after: [Function],
     error: [Function],
     uid: 2,
     data: null } }

And then very surprisingly, the remote method logs coming from my model file now have a value for active{} in loopbackContext that they didn't before:

  common:models:report-model ctx +61ms { name: 'loopback',
  active: 
   { accessToken: 
      { id: '2hv4FhQ6ASCrumxf0yPYmYX5HrVIgTRss58GcWm7fES3ddItWNfcB9W6baCax2AQ',
        ttl: 1209600,
        created: Thu Jul 02 2015 11:10:26 GMT-0500 (CDT),
        userId: 'merchant1@shoppinpal.com' },
     currentUser: 
      { username: 'merchant1@shoppinpal.com',
        realm: 'portal',
        email: 'merchant1@shoppinpal.com',
        seedWithRole: 'manager' } },
  _set: 
   [ null,
     { accessToken: [Object], currentUser: [Object] },
     { accessToken: [Object], currentUser: [Object] } ],
  id: 
   { create: [Function],
     flags: 15,
     before: [Function],
     after: [Function],
     error: [Function],
     uid: 2,
     data: null } }
  common:models:report-model currentUser +1ms { username: 'merchant1@shoppinpal.com',
  realm: 'portal',
  email: 'merchant1@shoppinpal.com',
  seedWithRole: 'manager' }
  common:models:report-model inside ReportModel.getCurrentUserModel() - currentUser:  +0ms merchant1@shoppinpal.com

[pulkitsinghal]

I still plan on exploring https://github.com/strongloop/loopback/issues/1495 but just a little bit later, cause I have like a zillion support requests that are awaiting my response which I need to sort out.

[raymondfeng]

There must be some changes in transitive dependencies. Could be related to https://github.com/strongloop/loopback-datasource-juggler/issues/631?

[pulkitsinghal]

@raymondfeng - yes that point about async vesrioning is a bit of voodoo indeed: https://github.com/strongloop/loopback/issues/1442