adobe/openwhisk-action-utils

wrap seems to not handle async properly

Closed this issue · 3 comments

Or we do not always use it properly.

For adobe/openwhisk-action-builder#106, I made some debugging and I found something suspicious, not about the log level but the logging itself which could be . a potential more generic issue with our wrap method:

This version of the main logs reliably (no async):

function main(params = {}) {
  const {
    __ow_logger: log,
  } = params;

  console.log('console.log');

  logger.trace('Logger.trace');

  log.error('log.error');
  log.info('log.info');
  log.log('log.log');

  return {
    body: 'Done.',
  };
}

module.exports.main = wrap(main)
  .with(epsagon)
  .with(status)
  .with(logger.trace)
  .with(logger);

This version of the main DOES NOT log reliably (async main returning an object)

async function main(params = {}) {
  const {
    __ow_logger: log,
  } = params;

  console.log('console.log');

  logger.trace('Logger.trace');

  log.error('log.error');
  log.info('log.info');
  log.log('log.log');

  return {
    body: 'Done.',
  };
}

module.exports.main = wrap(main)
  .with(epsagon)
  .with(status)
  .with(logger.trace)
  .with(logger);

This version of the main logs reliably (async returning a promise)

async function main(params = {}) {
  const {
    __ow_logger: log,
  } = params;

  console.log('console.log');

  logger.trace('Logger.trace');

  log.error('log.error');
  log.info('log.info');
  log.log('log.log');

  return Promise.resolve({
    body: 'Done.',
  });
}

module.exports.main = wrap(main)
  .with(epsagon)
  .with(status)
  .with(logger.trace)
  .with(logger);

I suspect the wrapping to be wrong somewhere because Openwhisk accepts a main function to be async or not, returning a promise or not.

This needs to be verified because we may have the case in multiple places: see for example https://github.com/adobe/helix-static/blob/master/src/index.js#L460 which return an object while the main is async. Not sure what really happens in that case.

cc @tripodsan @trieloff @stefan-guggisberg @dominique-pfister

FYI I do not have an Epsagon nor a Coralogix token defined.

I suspect the wrapping to be wrong somewhere because Openwhisk accepts a main function to be async or not, returning a promise or not.

an async function always returns a promise, whether you return a constant or a promise from it. eg:

async function return_promise() {
  return Promise.resolve('foo');
}

async function return_const() {
  return 'foo';
}

console.log(return_promise());
console.log(return_const());

/*

$ node test.js
Promise { <pending> }
Promise { 'foo' }

 */

so I don't see why this should make a difference.

also, the loggers are synchronous. so it should not matter if the function itself is sync or async....

btw, I can't reproduce your problem.... can you create a test?