Azure-functions-host: [Bug] [Node.js] Strange timeout fixed with a simple console.log (weird)

[yvele]

Using :

• Azure Function : ~0.4 (and ~0.5)
• Node.js : 5.9.1 (and 6.4.0)

I've been using Azure Function with Node.js without any problem.
Then I decided to transpil my code with Babel.js to make use of await/async.
A strange bug appeared.. an Azure Function timeout.
I tried many things and after only adding logging, the timeout disappeared...

Here is the transpiled code with the console.log line.. If I remove this single line, my Azure Function will timeout.

Index.js

"use strict";

module.exports = require("./lib/handle");

lib/handle.js

"use strict";

Object.defineProperty(exports, "__esModule", {
  value: true
});
exports.default = handle;

var _EndPoint = require("./EndPoint");

var _EndPoint2 = _interopRequireDefault(_EndPoint);

function _interopRequireDefault(obj) { return obj && obj.__esModule ? obj : { default: obj }; }

// endPoint may be reused for many requests
const endPoint = new _EndPoint2.default();

/**
 * Basic Azure Function handle
 *
 * @param {Object} context Context object
 * @param {Object} req Request object
 */
function handle() {

  /* eslint no-console: 1 */
  // TODO: Next line is a hack to avoid timeout on Azure
  console.log("Starting...");

  endPoint.handle(...arguments);
}
module.exports = exports["default"];

Microsoft Support : I can give you my Azure Function URL in private

[christopheranderson]

Could you give us the pre and post transpiled code, clearly labeled? My guess is that the transpiled code is just non-functional. Fun bug, though.

[yvele]

@christopheranderson Yes sure.. I already gave post transpiled code but here is everything :

Before transpillation

Index.js

"use strict";

module.exports = require("./lib/handle");

src/handle.js

import EndPoint from "./EndPoint";

// May be reused for many requests
const endPoint = new EndPoint();

/**
 * Basic Azure Function handle
 *
 * @param {Object} context Context object
 * @param {Object} req Request object
 */
export default function handle(...args) {

  /* eslint no-console: 1 */
  // TODO: Next line is a hack to avoid timeout on Azure
  console.log("Starting...");

  endPoint.handleRaw(...args);
}

src/EndPoint.js

import BaseEndPoint from "@my-orga/helpers/lib/BaseEndPoint";

export default class EndPoint extends BaseEndPoint {
  async handleCore(req, res) {
    res.status = 200;
    res.body = {
      action  : "Herr Vector",
      headers : req.headers
    };
  }
}

@my-orga/helpers/BaseEndPoint.js

export default class BaseEndPoint {

  /**
   * Basic Azure Function handle
   *
   * @param {Object} context Context object
   * @param {Object} req Request object
   */
  handleRaw(context, req) {
    context.res = {};

    const promise = this.handle(req, context.res);
    if (!promise || !promise.then) {
      // Didn't returned a promise
      context.done();
      return;
    }

    promise.then(context::context.done, error => {

      // TODO: Proper error handling
      /* eslint no-console: 1 */
      console.error(error);

      // TODO: If security error then send a 404 instead
      context.done(error);
    });
  }

  /**
   * Handles the request
   *
   * @param {Object} req Request
   * @param {Object} res Response
   */
  async handle(req, res) {
    await this.handleCore(req, res);
  }

  /**
   * Handles the request at a domain level
   *
   * @param {Object} req Request
   * @param {Object} res Response
   */
  async handleCore(/* req, res */) {
    throw new Error("Method not implemented");
  }

}

Transpilled

"use strict";

module.exports = require("./lib/handle");

src/handle.js

"use strict";

Object.defineProperty(exports, "__esModule", {
  value: true
});
exports.default = handle;

var _EndPoint = require("./EndPoint");

var _EndPoint2 = _interopRequireDefault(_EndPoint);

function _interopRequireDefault(obj) { return obj && obj.__esModule ? obj : { default: obj }; }

// May be reused for many requests
const endPoint = new _EndPoint2.default();

/**
 * Basic Azure Function handle
 *
 * @param {Object} context Context object
 * @param {Object} req Request object
 */
function handle() {

  /* eslint no-console: 1 */
  // TODO: Next line is a hack to avoid timeout on Azure
  console.log("Starting...");

  endPoint.handleRaw(...arguments);
}
module.exports = exports["default"];

EndPoint.js

"use strict";

Object.defineProperty(exports, "__esModule", {
  value: true
});

var _BaseEndPoint = require("@my-orga/helpers/lib/BaseEndPoint");

var _BaseEndPoint2 = _interopRequireDefault(_BaseEndPoint);

function _interopRequireDefault(obj) { return obj && obj.__esModule ? obj : { default: obj }; }

function _asyncToGenerator(fn) { return function () { var gen = fn.apply(this, arguments); return new Promise(function (resolve, reject) { function step(key, arg) { try { var info = gen[key](arg); var value = info.value; } catch (error) { reject(error); return; } if (info.done) { resolve(value); } else { return Promise.resolve(value).then(function (value) { return step("next", value); }, function (err) { return step("throw", err); }); } } return step("next"); }); }; } /* eslint import/no-unresolved: 1 */


class EndPoint extends _BaseEndPoint2.default {

  handleCore(req, res) {
    return _asyncToGenerator(function* () {
      res.status = 200;
      res.body = {
        action: "Herr Vector",
        headers: req.headers
      };
    })();
  }

}
exports.default = EndPoint;
module.exports = exports["default"];

@my-orga/helpers/BaseEndPoint.js

"use strict";

Object.defineProperty(exports, "__esModule", {
  value: true
});

function _interopRequireDefault(obj) { return obj && obj.__esModule ? obj : { default: obj }; }

function _asyncToGenerator(fn) { return function () { var gen = fn.apply(this, arguments); return new Promise(function (resolve, reject) { function step(key, arg) { try { var info = gen[key](arg); var value = info.value; } catch (error) { reject(error); return; } if (info.done) { resolve(value); } else { return Promise.resolve(value).then(function (value) { return step("next", value); }, function (err) { return step("throw", err); }); } } return step("next"); }); }; }

class BaseEndPoint {

  /**
   * Basic Azure Function handle
   *
   * @param {Object} context Context object
   * @param {Object} req Request object
   */
  handleRaw(context, req) {
    context.res = {};

    const promise = this.handle(req, context.res);
    if (!promise || !promise.then) {
      // Didn't returned a promise
      context.done();
      return;
    }

    promise.then(context.done.bind(context), error => {

      // TODO: Proper error handling
      /* eslint no-console: 1 */
      console.error(error);

      // TODO: If security error then send a 404 instead
      context.done(error);
    });
  }

  /**
   * Handles the request
   *
   * @param {Object} req Request
   * @param {Object} res Response
   */
  handle(req, res) {
    var _this = this;

    return _asyncToGenerator(function* () {
        yield _this.handleCore(req, res);
    })();
  }

  /**
   * Handles the request at a domain level
   *
   * @param {Object} req Request
   * @param {Object} res Response
   */
  handleCore() /* req, res */{
    return _asyncToGenerator(function* () {
      throw new Error("Method not implemented");
    })();
  }

}
exports.default = BaseEndPoint;
module.exports = exports["default"];

---

All dependencies are copied into node_modules
I'm transpilling with babel.js :

.babelrc

{
  "presets": ["es2015-node5", "stage-0"],
  "plugins": [
    "add-module-exports"
  ]
}

I'm publishing the code to Azure via git

function.json

{
  "disabled" : false,
  "bindings" : [
    {
      "authLevel" : "anonymous",
      "type"      : "httpTrigger",
      "direction" : "in",
      "name"      : "req"
    }, {
      "type"      : "http",
      "direction" : "out",
      "name"      : "res"
    }
  ]
}

[yvele]

@christopheranderson Any clue on this? I haven't tried yet to remove the hack with ~0.5

[mathewc]

@mamaso Is this fixed with your recent changes?

[yvele]

@mathewc @mamaso I tried today with ~0.5 and the problem has not gone away
Have you managed to reproduce it?

[mathewc]

I'm referring to some changes we've made that haven't been released yet. We'll be releasing those changes soon as part of a 0.6 release. @mamaso is going to do a quick check to see if these will also address your issues.

[yvele]

Ok, thanks

[mamaso]

@yvele @mathewc I ran a scenario with the _asyncToGenerator(fn) and it works after adding the #664 fix. Without #664 we encounter the hang. This should be working in release 0.6.

[yvele]

@mamaso All right! Thanks!

[yvele]

PS: I confirm it's working with 0.6