Nest: Problem with global and local interceptor execution

[RecuencoJones]

I'm submitting a...

[ ] Regression 
[x] Bug report
[ ] Feature request
[ ] Documentation issue or request
[ ] Support request => Please do not submit support request here, instead post your question on Stack Overflow.

Current behavior

I am trying to apply a global and a local interceptor to a NestJS application. The global interceptor is used for tracing every call in the application, logging incoming requests and outgoing responses. The local interceptor is used for caching some responses.

Once applied, the execution should go as described next:

1. First request to http://localhost:3000/ is not cached, calls controller and saves response in cache
2. Second request to http://localhost:3000/ replies from cache skipping controller

Which prints the following output:

Tracing (incoming) > Cache (incoming) > Controller > Tracing (outgoing) > Cache (outgoing) >
Tracing (incoming) > Cache (incoming) > Hit >

Here we observe two issues:

1. Order of interceptors is not reversed for response!
2. Tracing interceptor is not executed on response due to cache interceptor returning a new observer I guess

Expected behavior

Upon applying global and local interceptors, I would expect the execution to go like this:

Tracing (incoming) > Cache (incoming) > Controller > Cache (outgoing) > Tracing (outgoing) >
Tracing (incoming) > Cache (incoming) > Hit > Tracing (outgoing) >

Minimal reproduction of the problem with instructions

https://github.com/RecuencoJones/nestjs-interceptors

What is the motivation / use case for changing the behavior?

Consistent execution of interceptor pipeline

From https://github.com/nestjs/nest/issues/541#issuecomment-383287000:

Think about interceptors, they follow a simple request processing pipeline, being executed from global to concrete once the request wants to hit an end-handler, and then (in response pipeline), they are executed from concrete to global (if you attach some asynchronous/mapping logic inside them and so on).

Environment

Nest version: 5.2.2


For Tooling issues:
- Node version: 10.8.0  
- Platform: OS X High Sierra  

Others:

- npm version: 6.2.0
- IDE: Visual Studio Code

[kamilmysliwiec]

Thanks for reporting @RecuencoJones!

[gp187]

True. I just updated to the latest version and any controller with @UseInterceptors() doesn't execute anymore.
I tested with demo interceptors from documentation and get the same behavior. Connection hangs and eventually times out

UPDATE: even reverting back to the older versions in package.json doesn't change behavior. Everything fails. Renders it unusable

Tested on node v9 and v10, same.

[gp187]

The call Observable in the interceptor does not emit anything

```
@Injectable()
export class LoggerInterceptor implements NestInterceptor {
intercept(
context: ExecutionContext,
call$: Observable,
): Observable {
console.log('Before...');

call$.subscribe(x => {
  console.log(`xxxxxxxxxxxxxxxxxx`)
});

return call$.pipe(
  tap(() => console.log(`After... ${Date.now() - now}ms`)),
);

}
}
````

Nothing. The only output is Before.... I guess call$ Observable never completes?

UPDATE:
When a call is returned in the interceptors array, .toPromise expects something to be emitted, but the observable doesn't return anything nor does it complete, even if the http request is complete.

UPDATE: (possibly)
toPromise is essentially observable.last().subscribe()
If you add .take(1) just before you call toPromise then things will start to work.

[gp187]

SOLUTION: version fix, not latest

"rxjs": "6.2.2",
"rxjs-compat": "6.2.2",

The observable from the call$ stack doesn't complete so .toPromise doesn't fire so all interceptors in @UseInterceptors()

[RecuencoJones]

I did a simple proof and somehow got to fix it by changing the code in interceptors-consumer.ts based on how interceptors in @angular/core/http work:

-    const result$ = await interceptors.reduce(
-      async (stream$, interceptor) =>
-        await interceptor.intercept(context, await stream$),
-      Promise.resolve(start$),
+    const result$ = await interceptors.reduceRight(
+      async (stream$, interceptor: NestInterceptor) => {
+        const fn = await stream$;

+        return () => interceptor.intercept(context, fn);
+      },
+      Promise.resolve(() => start$),
    );
-    return await result$.toPromise();
+    return result$();

And then in the interceptors:

@Injectable()
export class CacheInterceptor implements NestInterceptor {
  private static cache = {}

  intercept(context: ExecutionContext, next: () => Observable<any>): Observable<any> {
    const url = '/'
    const value = CacheInterceptor.cache[url]

    process.stdout.write('Cache (incoming) > ')

    if (value) {
      process.stdout.write('Hit > ')

      return of(value)
    }

    return next().pipe(
      tap((val) => {
        CacheInterceptor.cache[url] = val

        process.stdout.write('Cache (outgoing) > ')
      })
    )
  }
}

@Injectable()
export class TracingInterceptor implements NestInterceptor {
  intercept(context: ExecutionContext, next: () => Observable<any>): Observable<any> {
    process.stdout.write('\nTracing (incoming) > ')

    return next().pipe(
      tap(() => {
        process.stdout.write('Tracing (outgoing) > ')
      })
    )
  }
}

This might not be the best approach, I couldn't spend much time understanding the codebase and didn't consider typechecks nor tests. Also, I guess it will be a problem to change the signature of intercept since it will be quite a breaking change.

EDIT: Execution after the changes was:

Tracing (incoming) > Cache (incoming) > Controller > Cache (outgoing) > Tracing (outgoing) >
Tracing (incoming) > Cache (incoming) > Hit > Tracing (outgoing) >

[RecuencoJones]

After some research, this is the resulting implementation:

// interceptors-consumer.ts
public async intercept(
  interceptors: NestInterceptor[],
  args: any[],
  instance: Controller,
  callback: (...args) => any,
  next: () => Promise<any>,
): Promise<any> {
  if (!interceptors || isEmpty(interceptors)) {
    return await await next();
  }
  const context = this.createContext(args, instance, callback);
  const result = interceptors.reduceRight(
    (_next, interceptor) => () => interceptor.intercept(context, _next),
    () => fromPromise(next()),
  );
  const result$ = await result();

  return result$.toPromise();
}

// nest-interceptor.interface.ts
import { Observable } from 'rxjs';
import { ExecutionContext } from './execution-context.interface';

export interface NestInterceptor<T = any, R = any> {
  intercept(
    context: ExecutionContext,
    next: () => Observable<T>,
  ): Observable<R>;
}

// nest-interceptor.interface.d.ts
import { Observable } from 'rxjs';
import { ExecutionContext } from './execution-context.interface';
export interface NestInterceptor<T = any, R = any> {
    intercept(context: ExecutionContext, next: () => Observable<T>): Observable<R>;
}

But we need to take in consideration the following:

• Do not allow async/await in interceptors, use plain Observables instead
• Change NestInterceptor signature to receive next function, which will invoke following interceptor or bypass it by returning a new Observable.

Please, let me know what you think about this

[kamilmysliwiec]

I have created a fix already, but it would be a breaking change anyway, so we have to wait with it until next major release 🙁

[RecuencoJones]

I understand, thanks @kamilmysliwiec, do you have a rough estimation for this to be released?

Also, is your fix checked in somewhere? I would very much like to see the code for it so I could create a fork to have this version temporarily available for now 😄

[JumpLink]

@kamilmysliwiec any update?

[kamilmysliwiec]

Fixed in 6.0.0

[lock[bot]]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.