Extension timeout even with callback

1

Hi,

Yet another question about GenieACS’s callback mechanism. I have a lot of questions about how GenieACS actually executes its extensions, for right now it seems like if it takes too long for the callback to get called, whether or not it’s running asynchronously, the extension halts with the time out error. I am working with an extension script that I am not wholly familiar with so I decided to try messing with the example script given in the documentation.

The example script as given does work, but I decided to try adding additional time out to the script in order to simulate my own extension, which takes a matter of seconds before it has a result that it can call back.

const http = require("http");

let cache = null;
let cacheExpire = 0;

function latlong(args,callback) {
        if (Date.now() < cacheExpire) {return callback(null, cache);}

        http
        .get("http://api.open-notify.org/iss-now.json", res => {
                if(res.statusCode !== 200)
                        return callback(
                                new Error('Request failed (status code: ${res.statusCode})')
                        );
                let rawData = "";
                res.on("data", (chunk) => (rawData += chunk));
                
                res.on("end", () => {
                        let pos=JSON.parse(rawData)["iss_position"];
                        cache = [+pos["latitude"], +pos["longitude"]];
                        cacheExpire = Date.now() + 10000;
                        callback(null,cache);
                });
        })
        .on("error", (err) => {
                callback(err);
        });
}

function test(args, callback)
{
        //Should be asynchronous, so extension is finished after adding this to the event queue.
        setTimeout(latlong(args,callback),5000);
}
exports.latlong = test;

AFAIK the setTimeout function should run asynchronously, so the script itself should finish executing, and then when the callback is called, GenieACS updates the value accordingly. Of course, this is not what happens, I get an extension timed out.

It seems like even with the callback, if an extension would take too long to return a value, GenieACS gives a time out anyways. What happens if there is a significant delay between when a script finishes executing and when the callback is finally called? Does the ACS interface give a temporary blank value to a parameter and then replace it with the actual parameter when the callback runs?

Hopefully that all makes sense. I know there have been several other questions about extensions and callbacks, but none of them seem to give me the clarification I’m seeking. I hope I’m not just really confused about how the callback works.

Thanks,

2

I know that I am not answering your exact question, might be unrelated to your problem, and others might disagree with me on this, but I had the same problem about extensions time-out, and ended up using a reverse approach. Instead of going out to the network to ask for information, it is our restapi server which goes to the ACS, using a web page as middle man, which in turn creates a JSON text file on filesystem using the serial number as filename and the content passed by the post as is. Each time our extension is executed, it simply loads the file and sends it back to the provision.

All of this was the result of having hundred of CPE going to the ACS at the same time during blackouts (Argentina here) which in turn created hundred of CPE faults on ACS side. So after a research I ended up discovering the real bottleneck was the network access, the software limit of 100 connections on MySQL and the number of workers set by NodeJS at ACS side (based on number of cores assigned to the virtual machine).

(I’m just saying all of this to put some context on why I did what I did).

I hope it helps.

3

That’s actually a really smart idea. Even if I get the call back working I may opt for implementing it that way instead due to the possible problems of lots of devices all making requests for data from an external provider’s API.

Thanks!

4

There are a few things wrong with what you have.

Extensions do not execute async (your comment on line 32), and trying to make it async is going to set yourself up for issue if you are trying to pass data back to the calling provision script. The setTimeout function doesn’t work the way you think its going to. Because you have an explicit function call as the first param, the latlong func will get called right away. If you want to make it execute as a callback, there are a few different ways to make that happen. The easiest way is to use a lambda () => latlong(args, callback).

Try changing the code to use a lambda. I bet that will resolve your issue.

5

Do you mean like this?

...
function test(args, callback)
{
        setTimeout(() => latlong(args,callback),5000);
}
exports.latlong = test;

It seems like it is still showing the same behavior, even after a restart of genieacs-cwmp.

6

Yes. Its still going to timeout because the 5000 ms you have specified is longer than the default timeout of 3000 ms.

You have two options, you can either drop the setTimeout (there is no reason to use it), or you can edit the genieacs.env file and set the GENIE_EXT_TIMEOUT param to something higher than 5000. You will need to restart the cwmp process after you change the value.

7

The point of the setTimeout was solely to emulate the lengthy delay the actual extension incurs. But if my understanding is correct, if it takes longer than GENIE_EXT_TIMEOUT milliseconds for an extension to execute the callback function, then the extension will time out?

Either way, it sounds like @rudymartin 's solution will work pretty well for me.

Thanks,

8

Your understanding is correct. If timeouts are a concern, you can increase the extension timeout.

9

Thank you!