Two external hosts not working even though approved

So I have two hosts, hooks.slack.com, and api.github.com both marked as “APPROVED” in the “Manage” section of our Backendless Application. However, when the deployed code is run, the requests are not being sent, they are being timed out I assume.
When I run the coderunner in debug mode, everything works as normal.

What is your application ID?

I believe this is what you are asking for, 30C66546-0714-7CF0-FFD1-F6797F56F700.

Thank you for your prompt response.

Yes, that’s exactly what I need. We’re looking into it.

Meanwhile, could you please confirm if your code invocation completes in less than 5 seconds?

Regards,
Mark

They appear to be executing between 2.8 and 3.9 seconds according to the logs.

Could you please run an invocation (or let me know what arguments I could use to invoke the service)? I’d like to see what data ends up in the log when there is a timeout.

Sure, I’ll run an invocation now. It’s difficult to send you the argument as it’s an entire github hook payload.

It just finished running @ 15:20 ET.

Here is the log output:


2017-01-04 20:20:12,620 | SERVER_CODE | INFO | [59AAD72C-3797-C64C-FFFA-73AE99144600] Processing started
2017-01-04 20:20:12,631 | SERVER_CODE | INFO | [59AAD72C-3797-C64C-FFFA-73AE99144600] [INVOKE SERVICE] services.GitHubHookService.pullRequest
2017-01-04 20:20:12,783 | SERVER_CODE | INFO | Building ServerCode Model for path (/var/lib/backendless/repo/30c66546-0714-7cf0-ffd1-f6797f56f700/files/servercode/services/CD2C1CC8-DFC8-F14E-FF1F-0E7D572EFD00)
2017-01-04 20:20:12,784 | SERVER_CODE | INFO | Reading /var/lib/backendless/repo/30c66546-0714-7cf0-ffd1-f6797f56f700/files/servercode/services/CD2C1CC8-DFC8-F14E-FF1F-0E7D572EFD00/app/services/github-hook-service.js…
2017-01-04 20:20:16,521 | SERVER_CODE | INFO | ServerCode Model built in 3738ms
2017-01-04 20:20:16,737 | CQManager | INFO | Package: saas-package-cq-shared_be_test_test-chris-24:0.1.4 released
2017-01-04 20:20:16,746 | SERVER_CODE | INFO | [59AAD72C-3797-C64C-FFFA-73AE99144600] Processing finished

Log file contains the following lines:

2017-01-04 20:20:12,620 | SERVER_CODE | INFO | [59AAD72C-3797-C64C-FFFA-73AE99144600] Processing started
2017-01-04 20:20:12,631 | SERVER_CODE | INFO | [59AAD72C-3797-C64C-FFFA-73AE99144600] [INVOKE SERVICE] services.GitHubHookService.pullRequest
2017-01-04 20:20:12,783 | SERVER_CODE | INFO | Building ServerCode Model for path (/var/lib/…path removed…)
2017-01-04 20:20:12,784 | SERVER_CODE | INFO | Reading /var/lib/backendless/repo/…path removed…/github-hook-service.js…
2017-01-04 20:20:16,521 | SERVER_CODE | INFO | ServerCode Model built in 3738ms
2017-01-04 20:20:16,737 | CQManager | INFO | Package: saas-package-cq-shared_be_test_test-chris-24:0.1.4 released
2017-01-04 20:20:16,746 | SERVER_CODE | INFO | [59AAD72C-3797-C64C-FFFA-73AE99144600] Processing finished

The line for the “CQManager” logger is printed from the returned Promise. All slack and github communication occur in the promise as well. By the time the “Package XXXX release” log line is printed, CodeRunner is running for a little over 4 seconds, which leaves less than a second for everything else within promise to run. As a result, the invocation is interrupted.

You can try purchasing the “expanded code execution” function pack and see if it makes a difference:
https://monosnap.com/file/8qqQZnft74XuRFQpsBBRWqOi9FTXop

Regards,
Mark

So, I purchased an upgrade to 20 seconds, and have the same problem. I can’t imagine that the simple calls I’m making are taking longer than that.

Could you add more logging calls into the returned promise code to see how far the invocation is getting?

Sure, no problem. I’ll do that and get right back to you.

So, it looks like the slack request is being called, but it’s not actually sending the request. It doesn’t appear like it’s even getting to the github calls.

I added before and after logging on each external call. There are three in total.

Could you add a catch block to the promise and see if there are any errors thrown out of the code?
Something like this:

.catch( function( error ) {
// log the error
})

My promise scopes aren’t being called when the service is deployed for some reason. The done block is being reached when I use debug mode.

Here is the code I am using, the npm module is “node-slack”.

It looks like it’s still not allowing me more than five seconds of execution.

logger.info("Slack request initiated"); 
let slackPromise = slack.send({ 
 // removed 
}); 
logger.info("Slack request completed"); 
 
slackPromise((body) => { 
 logger.info("Slack request completed successfully"); 
 console.log("Slack request completed successfully"); 
}).done((result) => { 
 logger.info("Slack request 'done' reached"); 
}, (err) => { 
 logger.warn("Slack request errored: " + err.message); 
 console.log("err", err.message); 
}); 



I see the following two lines in the log file:

2017-01-04 22:49:53,409 | CQManager |  INFO | Slack request initiated
2017-01-04 22:49:53,417 | CQManager |  INFO | Slack request completed

I will have some look into it in the morning. There may be more debugging information in coderunner to let us see what’s going on.

Regards,
Mark

I see those lines but it appears as though the actual request being done in the “send” call is not working as expected. Can you see if the requests to api.github.com and hooks.slack.com are going through as expected?

Hi Christopher

See from the Troubleshooting Guide :

If you see that the Business Logic execution was interrupted (for example, you see some of the console.logmessages, but don’t see the others), that means that you have some undeclared asynchronous IO operations, which were interrupted by the CodeRunner. This happens when asynchronous operations started by your code are not properly returned to CodeRunner. Business logic method must return a Promise to CodeRunner which should be resolved only when all asynchronous jobs are finished.

The promise chain you return from your API Service Business Logic doesn’t include three asynchronous operations (slack.send, registryThirdPartyAuth.find, and github.repos.createRelease). You have to fix this.

This is what you have now :

http://take.ms/Mr1kD</img>

It should be fixed as :

http://take.ms/pJioD</img>

See also :

This makes perfect sense.

Thank you so much, I’ll refactor my code and try again.