fix(rest): log unexpected errors to console (#1058)

Revert back the recent change that moved error logs from console
to debug logs.

With this commit in place, when a request handler fails with a 5xx
error, this error is printed via `console.error()` to notify people
operating the application about a possible problem.

packages/rest/src/providers/log-error-provider.ts

@@ -6,20 +6,18 @@
 import {Provider} from '@loopback/context';
 import {ServerRequest} from 'http';
 import {LogError} from '../internal-types';
-import * as debugModule from 'debug';
-const debug = debugModule('loopback:rest:error');
 
 export class LogErrorProvider implements Provider<LogError> {
   value(): LogError {
     return (err, statusCode, req) => this.action(err, statusCode, req);
   }
 
   action(err: Error, statusCode: number, req: ServerRequest) {
-    if (statusCode < 400) {
+    if (statusCode < 500) {
       return;
     }
 
-    debug(
+    console.error(
       'Unhandled error in %s %s: %s %s',
       req.method,
       req.url,

packages/rest/test/acceptance/routing/routing.acceptance.ts

@@ -11,6 +11,7 @@ import {
   RestServer,
   RestComponent,
   RestApplication,
+  SequenceActions,
 } from '../../..';
 
 import {api, get, param} from '@loopback/openapi-v2';
@@ -27,6 +28,7 @@ import {expect, Client, createClientForHandler} from '@loopback/testlab';
 import {anOpenApiSpec, anOperationSpec} from '@loopback/openapi-spec-builder';
 import {inject, Context} from '@loopback/context';
 import {ControllerClass} from '../../../src/router/routing-table';
+import {createUnexpectedHttpErrorLogger} from '../../helpers';
 
 /* # Feature: Routing
  * - In order to build REST APIs
@@ -176,6 +178,8 @@ describe('Routing', () => {
     app.bind('hello.prefix').to('Hello');
     const server = await givenAServer(app);
     givenControllerInApp(app, MyController);
+    suppressErrorLogsForExpectedHttpError(app, 500);
+
     return expect(whenIMakeRequestTo(server).get('/greet?firstName=John'))
       .to.be.rejectedWith(
         'Cannot resolve injected arguments for ' +
@@ -572,6 +576,16 @@ describe('Routing', () => {
     app.component(RestComponent);
     return app;
   }
+
+  function suppressErrorLogsForExpectedHttpError(
+    app: Application,
+    skipStatusCode: number,
+  ) {
+    app
+      .bind(SequenceActions.LOG_ERROR)
+      .to(createUnexpectedHttpErrorLogger(skipStatusCode));
+  }
+
   async function givenAServer(app: Application) {
     return await app.getServer(RestServer);
   }

packages/rest/test/helpers.ts

@@ -0,0 +1,27 @@
+// Copyright IBM Corp. 2017,2018. All Rights Reserved.
+// Node module: @loopback/rest
+// This file is licensed under the MIT License.
+// License text available at https://opensource.org/licenses/MIT
+
+import {ServerRequest} from 'http';
+import {LogError} from '..';
+
+export function createUnexpectedHttpErrorLogger(
+  expectedStatusCode: number = 0,
+): LogError {
+  return function logUnexpectedHttpError(
+    err: Error,
+    statusCode: number,
+    req: ServerRequest,
+  ) {
+    if (statusCode === expectedStatusCode) return;
+
+    console.error(
+      'Unhandled error in %s %s: %s %s',
+      req.method,
+      req.url,
+      statusCode,
+      err.stack || err,
+    );
+  };
+}

packages/rest/test/integration/http-handler.integration.ts

@@ -6,7 +6,6 @@
 import {
   HttpHandler,
   DefaultSequence,
-  ServerRequest,
   writeResultToResponse,
   parseOperationArgs,
   RestBindings,
@@ -18,11 +17,10 @@ import {ControllerSpec, get} from '@loopback/openapi-v2';
 import {Context} from '@loopback/context';
 import {Client, createClientForHandler} from '@loopback/testlab';
 import * as HttpErrors from 'http-errors';
-import * as debugModule from 'debug';
 import {ParameterObject} from '@loopback/openapi-spec';
 import {anOpenApiSpec, anOperationSpec} from '@loopback/openapi-spec-builder';
+import {createUnexpectedHttpErrorLogger} from '../helpers';
 
-const debug = debugModule('loopback:rest:test');
 const SequenceActions = RestBindings.SequenceActions;
 
 describe('HttpHandler', () => {
@@ -473,7 +471,7 @@ describe('HttpHandler', () => {
       }
 
       givenControllerClass(TestController, spec);
-      logErrorsExcept(400);
+      logErrorsExcept(500);
 
       await client.get('/hello').expect(500, {
         statusCode: 500,
@@ -490,7 +488,9 @@ describe('HttpHandler', () => {
     rootContext
       .bind(SequenceActions.INVOKE_METHOD)
       .toProvider(InvokeMethodProvider);
-    rootContext.bind(SequenceActions.LOG_ERROR).to(logger);
+    rootContext
+      .bind(SequenceActions.LOG_ERROR)
+      .to(createUnexpectedHttpErrorLogger());
     rootContext.bind(SequenceActions.SEND).to(writeResultToResponse);
     rootContext.bind(SequenceActions.REJECT).toProvider(RejectProvider);
 
@@ -500,20 +500,10 @@ describe('HttpHandler', () => {
     rootContext.bind(RestBindings.HANDLER).to(handler);
   }
 
-  let skipStatusCode = 200;
-  function logger(err: Error, statusCode: number, req: ServerRequest) {
-    if (statusCode === skipStatusCode) return;
-    debug(
-      'Unhandled error in %s %s: %s %s',
-      req.method,
-      req.url,
-      statusCode,
-      err.stack || err,
-    );
-  }
-
   function logErrorsExcept(ignoreStatusCode: number) {
-    skipStatusCode = ignoreStatusCode;
+    rootContext
+      .bind(SequenceActions.LOG_ERROR)
+      .to(createUnexpectedHttpErrorLogger(ignoreStatusCode));
   }
 
   function givenControllerClass(
@@ -527,7 +517,10 @@ describe('HttpHandler', () => {
   function givenClient() {
     client = createClientForHandler((req, res) => {
       handler.handleRequest(req, res).catch(err => {
-        debug('Request failed.', err.stack);
+        // This should never happen. If we ever get here,
+        // then it means "handler.handlerRequest()" crashed unexpectedly.
+        // We need to make a lot of helpful noise in such case.
+        console.error('Request failed.', err.stack);
         if (res.headersSent) return;
         res.statusCode = 500;
         res.end();