KeystoneJS middleware works when calling MongoDB using Model.find ()

Question

I have a route that loads a list of Condos and displays them:

app.get( '/condo-list', middleware.loadCondoList, routes.views.condolist ); 

The loadCondoList middleware makes a call to the CondoBuilding model and sets the results to res.locals:

 exports.loadCondoList = function loadCondoList( req, res, next ) { console.log( 'request url: ' + req.url ); console.log( 'getting condo buildings...' ); CondoBuilding.model .find() .exec( ( err, condos ) => { if ( err ) { // pass error along next( err ); } else { // add CondoBuildings to locals res.locals.condoBuildings = condos; next(); } }); }; 

The call to the database is successful, and the page is displayed as expected. However, for some reason, the route works twice. The console output is as follows:

 request url: /condo-list getting condo buildings... GET /condo-list 304 344.532 ms request url: /condo-list getting condo buildings... GET /condo-list 304 317.631 ms 

I reproduced this behavior in several browsers (Chrome, Safari, Firefox) and confirmed that this does not happen on other routes.

If I remove the call to CondoBuilding.model.find() and just call next() in the body of loadCondoList() , this behavior will not happen.

I run Keystone 4 "keystone": "4.0.0-beta.5" , which uses Express 4 "express": "4.14.0"

Below is a complete list of the routes that I run in the application, in case this is relevant:

 // Setup Route Bindings exports = module.exports = function ( app ) { // Views app.get( '/', routes.views.index ); app.get( '/condo-list', middleware.loadCondoList, routes.views.condolist ); app.get( '/blog/:category?', routes.views.blog ); app.get( '/blog/post/:post', routes.views.post ); app.get( '/about', routes.views.about ); app.get( '/search', middleware.getAccountType, routes.views.search ); app.all( '/contact', routes.views.contact ); }; 

View CondoList:

 var keystone = require('keystone'); exports = module.exports = function (req, res) { var view = new keystone.View(req, res); var locals = res.locals; // locals.section is used to set the currently selected // item in the header navigation. locals.section = 'condolist'; // Render the view view.render('condolist'); }; 

I have been debugging this problem for a while, but I am at my end, which may cause this. Any help would be appreciated.

UPDATE

I followed @phuhgh advice and ran the application in express debug mode. While nothing slipped on me immediately, I noticed something strange while starting the application.

Here is a sequence of several prepared routes that behave normally:

 express:router:layer new / +0ms express:router:route new /blog/post/:post +0ms express:router:layer new /blog/post/:post +0ms express:router:route get /blog/post/:post +0ms express:router:layer new / +0ms express:router:route new /about +0ms express:router:layer new /about +0ms express:router:route get /about +0ms express:router:layer new / +0ms express:router:route new /search +1ms express:router:layer new /search +0ms express:router:route get /search +0ms 

The following is the sequence of the finished route of the condo list:

 express:router:layer new / +0ms express:router:route new /condo-list +0ms express:router:layer new /condo-list +0ms express:router:route get /condo-list +0ms express:router:layer new / +0ms express:router:route get /condo-list +0ms 

As you can see, the line express:router:route get /condo-list +0ms repeated. I have no idea why, but I guess this has something to do with the problem I am facing. I dig a little more in this corner, but again, any help from someone with a little more knowledge in this area would be very appreciated.

Update 2 - Stack Trace

I debugged and went step by step step by step. I can follow the path from function to function, and everything looks fine, but my basic normal situation looked at other routes that worked correctly. I honestly don’t know what to look for as soon as I am deeply immersed in the courage of Express.

Observations that I made while viewing the stack:

• The stack trace is exactly the same as the /condo-list traffic.
• The stack trace (minus loadCondoList middleware, of course) is exactly the same for other routes that work correctly (i.e. only once).
• If I add a call to loadCondoList on a different route, it also works correctly.
  • eg. I updated the definition of the /about route to the following: app.get( '/about', middleware.loadCondoList, routes.views.about ); and it loads the data correctly and only works once.

Is there something I should pay special attention to as I go through the Express lib code? I feel a little from there, and I'm not sure what to look for.

Answer 1

After several days of debugging, I finally found the culprit, and he was hiding in the most unlikely places: look!

Context

The view loads a pantry display of the condo buildings that can be filtered next door. Below is the corresponding fragment of the masonry itself:

 <!-- Condo List Masonry --> <div class="condo-items"> {{#each condoBuildings}} <div class="condo-item {{neighborhood.key}}"> <div class="condo-thumb"> <span class="condo-tag tag-art">{{neighborhood.name}}</span> <a href="/{{condoUrl}}"><img src="{{{cloudinaryUrl image}}}" alt="{{name}}" /></a> </div> <div class="condo-body"> <h3><a class="condo-name" href="#">{{name}}</a></h3> <p>{{condoDescription}}</p> </div> </div> {{/each}} </div> 

The problem was caused by the cloudinaryUrl on this line:

<a href="/{{condoUrl}}"><img src="{{{cloudinaryUrl image}}}" alt="{{name}}" /></a>

Here is the helper code:

 _helpers.cloudinaryUrl = function (context, options) { // if we dont pass in a context and just kwargs // then `this` refers to our default scope block and kwargs // are stored in context.hash if (!options && context.hasOwnProperty('hash')) { // strategy is to place context kwargs into options options = context; // bind our default inherited scope into context context = this; } // safe guard to ensure context is never null context = context === null ? undefined : context; if ((context) && (context.public_id)) { options.hash.secure = keystone.get('cloudinary secure') || false; var imageName = context.public_id.concat('.', context.format); return cloudinary.url(imageName, options.hash); } else { return null; } }; 

Problem

Some CondoBuilding models have not yet defined an image . This causes the context argument in the _helpers.cloudinaryUrl method _helpers.cloudinaryUrl be undefined . In these cases, the helper will return null . I'm still not sure why this causes the page to reload, but I'm sure it was a culprit.

Correction

Updates the Handelbars template to display only the <img> element if the image exists in the CondoBuilding model. The updated template code is as follows:

 <!-- Condo List Masonry --> <div class="condo-items"> {{#each condoBuildings}} <div class="condo-item {{neighborhood.key}}"> <div class="condo-thumb"> <span class="condo-tag tag-art">{{neighborhood.name}}</span> <a href="/{{condoUrl}}">{{#if image}}<img src="{{{cloudinaryUrl image}}}" alt="{{name}}" />{{/if}}</a> </div> <div class="condo-body"> <h3><a class="condo-name" href="#">{{name}}</a></h3> <p>{{condoDescription}}</p> </div> </div> {{/each}} 

With the addition of the {{#if image}} block to the template, the route only works once, as expected!

Next steps

An improvement to this implementation will be to use a placeholder image for all CondoBuildings for which image is not defined. I will add this functionality soon, but I could not resist updating with the answer, as I have been banging my head about this issue for several days.

Thank you all for your time and attention.