I have a NodeJS server running with NestJS and deployed on AKS.
I've created an Interceptor so that if I send a HTTP header 'profile', it will run the usual code but instead of sending the response, it will replace the body with the profile output.
Here's the code:
import {
CallHandler, ExecutionContext, Injectable, NestInterceptor,
} from '@nestjs/common';
import { Observable } from 'rxjs';
import { map } from 'rxjs/operators';
import { Session } from 'inspector';
/**
* This interceptor will replace the body of the response with the result of the profiling
* if the request as a header 'profile'
*
* To use on a controller or a method, simply decorate it with @UseInterceptors(Profiler)
*/
@Injectable()
export class Profiler implements NestInterceptor {
intercept(context: ExecutionContext, next: CallHandler): Observable<any> | Promise<Observable<any>> {
const profile = context.switchToHttp().getRequest().get('profile');
// if the request doesn't have a 'profile' header, we deal with the request as usual
if (!profile) return next.handle();
// start a profiling session
const session = new Session();
session.connect();
return new Promise((resolve) => {
session.post('Profiler.enable', () => {
session.post('Profiler.start', () => {
resolve(next.handle().pipe(map(() => new Promise((resolve) => {
session.post('Profiler.stop', (_, { profile }) => {
resolve(profile);
});
}))));
});
});
});
}
}
Doing so, I'm able to get a JSON which I can then open with Chrome dev tool:
You can see that all the individual functions are only taking a few ms to run but in between, there are looooong breaks.
Here's an extract of my deployment.yaml file which shows that my pod should have 2GB of memory, which I believe should be enough.
spec:
serviceAccount: {{ include "api.fullname" . }}-service-account
containers:
- name: {{ .Chart.Name }}
image: "{{ .Values.image.repository }}:{{ .Values.image.tag }}"
imagePullPolicy: {{ .Values.image.pullPolicy }}
resources:
limits:
memory: "2000Mi"
requests:
memory: "2000Mi"
ports:
- name: http
containerPort: {{ .Values.port }}
protocol: TCP
So how can we explain these long breaks and how to prevent this?
By adding more logs around the database requests, we realised that the first few requests were taking around 2-3 seconds while the following ones were only ~10ms or less.
The solution was to use PgBouncer to maintain a connection pool with the database.
More info here:
https://techcommunity.microsoft.com/t5/azure-database-for-postgresql/steps-to-install-and-setup-pgbouncer-connection-pooling-proxy/ba-p/730555