Cache lookup always fails on Edge Microgateway first time

[#1]

Cache lookup always fails on Edge Microgateway first time. Second and subsequent attempts work correctly. We tried using different caching modules such as volos-cache-memory, lru-cache and memory-cache, but same results. Here is the code snippet to test it out.

Code snippet:

'use strict'; var debug = require('debug')('plugin:idam_<wbr>validate'); var cm = require('volos-cache-memory'); module.exports.init = function(config, logger, stats) { return { onrequest: function(req, res, next) { console.log('on request...'); var cache = cm.create('name', { ttl: 10000 }); // specifies default ttl as 1000 ms console.log(JSON.stringify(<wbr>req.headers)); var tokenValue = ''; var ssoToken = 'ssosessionkey'; if( ssoToken ){ //getting from cache' cache.get(ssoToken, function(err,val){ tokenValue = val}); } if(tokenValue != null){ // cache found. proceed console.log('tokenValue found. ' + JSON.stringify(tokenValue)); } else{//setting cache cache.set(ssoToken, 'value'); console.log('putting in cache'); } next(); } }; }

[#2]

We noticed this behavior only when the cache is used from the MGW plugin, if we use the same cache module/code in a nodejs server it works correctly on the first attempt (after put in the cache).

[williamssean]

Reposting code so it is properly formatted and easier to read.

 'use strict';
 var debug = require('debug')('plugin:idam_<wbr>validate');
 var cm = require('volos-cache-memory');
 module.exports.init = function(config, logger, stats) {
     return {
         onrequest: function(req, res, next) {
             console.log('on request...');
             var cache = cm.create('name', {
                 ttl: 10000
             }); // specifies default ttl as 1000 ms 
             console.log(JSON.stringify( < wbr > req.headers));
             var tokenValue = '';
             var ssoToken = 'ssosessionkey';
             if (ssoToken) { //getting from cache' 
                 cache.get(ssoToken, function(err, val) {
                     tokenValue = val
                 });
             }
             if (tokenValue != null) { // cache found. proceed 
                 console.log('tokenValue found. ' + JSON.stringify(tokenValue));
             } else { //setting cache 
                 cache.set(ssoToken, 'value');
                 console.log('putting in cache');
             }
             next();
         }
     };
 }

[williamssean]

@jitendraarvikar

I ran your plugin code on my Edge Microgateway 2.3.1 instance and it always displays "putting in cache" for every request. But this is not the behavior that you are experiencing.

The reason I think this happens is due to the fact that the cache is being created on every request. I'm surprised that this code works for you on your EM instance.

Which version of EM are you running?

[#5]

@swilliams

current nodejs version is v4.2.6

current edgemicro version is 2.3.3

Running curl 3 times,

curl -i 'http://127.0.0.1:8000/listUsers'

Here is the output we get (3rd call gets the value from cache).

on request...

{"host":"127.0.0.1:8000","user-agent":"curl/7.47.0","accept":"*/*"}

putting in cache

on request...

{"host":"127.0.0.1:8000","user-agent":"curl/7.47.0","accept":"*/*"}

putting in cache

on request...

{"host":"127.0.0.1:8000","user-agent":"curl/7.47.0","accept":"*/*"}

tokenValue found. {"type":"Buffer","data":[118,97,108,117,101]}

[williamssean]

@jitendraarvikar

Edge Microgateway starts in cluster mode by default starting with version 2.3.1, which means that it will spawn multiple processes depending on the number of cores available. If you only have 1 core (think container or VM), then it starts with 2 processes.

You can examine the startup output logged to the console to determine how many processes were spawned. I have pasted mine below. Notice that there are 4 processes started on my machine.

3b5c2460-ff5b-11e6-b17b-5932b062db36 edge micro listening on port 8000
3b5b12f0-ff5b-11e6-8108-b92c5e6887df edge micro listening on port 8000
installed plugin from edgemicro-plugins-xml2json
installed plugin from accumulate-response
3b6c7810-ff5b-11e6-8481-ed22f97be8a9 edge micro listening on port 8000
3b6cc630-ff5b-11e6-a6d0-d14638b16c41 edge micro listening on port 8000

When I run your code I get the same results, except it takes 5 requests before the key is found in the cache. My output is shown below.

**Request 1**  
plugin:volos-cache-memory on request...1 +0ms
  plugin:volos-cache-memory {"host":"localhost:8000","user-agent":"curl/7.43.0","accept":"*/*"} +1ms
  plugin:volos-cache-memory localhost:8000 +2ms
  plugin:volos-cache-memory tokenValue is undefined +1ms
  plugin:volos-cache-memory setting cache with key and value: /edgemicro_weather/forcastrss: localhost:8000 +0ms
  plugin:volos-cache-memory putting in cache +1ms
  
  **Request 2**
  
  plugin:volos-cache-memory on request...1 +0ms
  plugin:volos-cache-memory {"host":"localhost:8000","user-agent":"curl/7.43.0","accept":"*/*"} +1ms
  plugin:volos-cache-memory localhost:8000 +1ms
  plugin:volos-cache-memory tokenValue is undefined +1ms
  plugin:volos-cache-memory setting cache with key and value: /edgemicro_weather/forcastrss: localhost:8000 +0ms
  plugin:volos-cache-memory putting in cache +0ms
  
  **Request 3**
  
  plugin:volos-cache-memory on request...1 +0ms
  plugin:volos-cache-memory {"host":"localhost:8000","user-agent":"curl/7.43.0","accept":"*/*"} +1ms
  plugin:volos-cache-memory localhost:8000 +1ms
  plugin:volos-cache-memory tokenValue is undefined +0ms
  plugin:volos-cache-memory setting cache with key and value: /edgemicro_weather/forcastrss: localhost:8000 +1ms
  plugin:volos-cache-memory putting in cache +0ms
  
  **Request 4**
  
  plugin:volos-cache-memory on request...1 +0ms
  plugin:volos-cache-memory {"host":"localhost:8000","user-agent":"curl/7.43.0","accept":"*/*"} +1ms
  plugin:volos-cache-memory localhost:8000 +1ms
  plugin:volos-cache-memory tokenValue is undefined +1ms
  plugin:volos-cache-memory setting cache with key and value: /edgemicro_weather/forcastrss: localhost:8000 +1ms
  plugin:volos-cache-memory putting in cache +0ms
  
  **Request 5**
  
   plugin:volos-cache-memory on request...2 +7s
  plugin:volos-cache-memory {"host":"localhost:8000","user-agent":"curl/7.43.0","accept":"*/*"} +0ms
  plugin:volos-cache-memory localhost:8000 +0ms
  plugin:volos-cache-memory tokenValue is localhost:8000 +0ms
  plugin:volos-cache-memory tokenValue found. localhost:8000 +0ms

Please example the Microgateway startup log and confirm that two processes are started on your machine. This will be the reason that it always fails twice and finds it on the third request.

Also, I think there may be another problem in your plugin. I noticed that you create the cache in the onrequest method. Volos-cache-memory is based on volos-cache-common and if you examine the note there it says that you should "avoid creating multiple caches with the same name, the results are not defined by the interface and may vary by implementation."

You can move the cache create step out of the onrequest method as shown below.

var cm = require('volos-cache-memory');
var cache = cm.create('name', {
     ttl: 10000
 }); // specifies default ttl as 1000 ms
 var counter = 0;

 module.exports.init = function(config, logger, stats) {...