Adding server timing to measure performance (default value: false) #437

src/backend/middlewares/GalleryMWs.ts

@@ -18,10 +18,12 @@ import {VideoProcessing} from '../model/fileprocessing/VideoProcessing';
 import {SearchQueryDTO, SearchQueryTypes} from '../../common/entities/SearchQueryDTO';
 import {LocationLookupException} from '../exceptions/LocationLookupException';
 import {SupportedFormats} from '../../common/SupportedFormats';
+import {ServerTime} from './ServerTimingMWs';
 
 export class GalleryMWs {
 
 
+  @ServerTime('1.db', 'List Directory')
   public static async listDirectory(req: Request, res: Response, next: NextFunction): Promise<any> {
     const directoryName = req.params.directory || '/';
     const absoluteDirectoryName = path.join(ProjectPath.ImageFolder, directoryName);
@@ -57,6 +59,7 @@ export class GalleryMWs {
     }
   }
 
+  @ServerTime('1.zip', 'Zip Directory')
   public static async zipDirectory(req: Request, res: Response, next: NextFunction): Promise<any> {
     if (Config.Client.Other.enableDownloadZip === false) {
       return next();
@@ -108,6 +111,7 @@ export class GalleryMWs {
     }
   }
 
+  @ServerTime('3.cleanUp', 'Clean up')
   public static cleanUpGalleryResults(req: Request, res: Response, next: NextFunction): any {
     if (!req.resultPipe) {
       return next();
@@ -203,6 +207,7 @@ export class GalleryMWs {
   }
 
 
+  @ServerTime('1.db', 'Search')
   public static async search(req: Request, res: Response, next: NextFunction): Promise<any> {
     if (Config.Client.Search.enabled === false || !(req.params.searchQueryDTO)) {
       return next();
@@ -225,6 +230,7 @@ export class GalleryMWs {
   }
 
 
+  @ServerTime('1.db', 'Autocomplete')
   public static async autocomplete(req: Request, res: Response, next: NextFunction): Promise<any> {
     if (Config.Client.Search.AutoComplete.enabled === false) {
       return next();

src/backend/middlewares/ServerTimingMWs.ts

@@ -0,0 +1,60 @@
+import {NextFunction, Request, Response} from 'express';
+import {Config} from '../../common/config/private/Config';
+
+
+export class ServerTimeEntry {
+  public name: string;
+  startHR: any;
+  public endTime: number = null;
+
+
+  constructor(name: string) {
+    this.name = name;
+  }
+
+  public start(): void {
+    this.startHR = process.hrtime();
+  }
+
+  public end(): void {
+    const duration = process.hrtime(this.startHR);
+    this.endTime = (duration[0] * 1E3) + (duration[1] * 1e-6);
+  }
+}
+
+
+export const ServerTime = (id: string, name: string) => {
+  return (target: any, propertyName: string, descriptor: TypedPropertyDescriptor<any>): any => {
+    if (Config.Server.Log.logServerTiming === false) {
+      return;
+    }
+    const m = descriptor.value;
+    descriptor.value = (req: Request, res: Response, next: NextFunction) => {
+      req.timing = req.timing || {};
+      req.timing[id] = new ServerTimeEntry(name);
+      req.timing[id].start();
+      m(req, res, (err?: any) => {
+        req.timing[id].end();
+        next(err);
+      });
+    };
+  };
+};
+
+
+export class ServerTimingMWs {
+
+
+  /**
+   * Add server timing
+   */
+  public static async addServerTiming(req: Request, res: Response, next: NextFunction): Promise<any> {
+    if (Config.Server.Log.logServerTiming === false || !req.timing) {
+      next();
+    }
+    const l = Object.entries(req.timing).filter(e => e[1].endTime).map(e => `${e[0]};dur=${e[1].endTime};desc="${e[1].name}"`);
+    res.header('Server-Timing', l.join(', '));
+    next();
+  }
+
+}

src/backend/middlewares/thumbnail/ThumbnailGeneratorMWs.ts

@@ -10,9 +10,12 @@ import {ThumbnailSourceType} from '../../model/threading/PhotoWorker';
 import {MediaDTO} from '../../../common/entities/MediaDTO';
 import {PhotoProcessing} from '../../model/fileprocessing/PhotoProcessing';
 import {PersonWithSampleRegion} from '../../../common/entities/PersonDTO';
+import {ServerTime} from '../ServerTimingMWs';
 
 
 export class ThumbnailGeneratorMWs {
+
+  @ServerTime('2.th', 'Thumbnail decoration')
   public static async addThumbnailInformation(req: Request, res: Response, next: NextFunction): Promise<any> {
     if (!req.resultPipe) {
       return next();

src/backend/routes/AlbumRouter.ts

@@ -4,6 +4,7 @@ import {RenderingMWs} from '../middlewares/RenderingMWs';
 import {UserRoles} from '../../common/entities/UserDTO';
 import {VersionMWs} from '../middlewares/VersionMWs';
 import {AlbumMWs} from '../middlewares/AlbumMWs';
+import {ServerTimingMWs} from '../middlewares/ServerTimingMWs';
 
 export class AlbumRouter {
   public static route(app: Express): void {
@@ -23,6 +24,7 @@ export class AlbumRouter {
 
       // specific part
       AlbumMWs.listAlbums,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }
@@ -36,6 +38,7 @@ export class AlbumRouter {
 
       // specific part
       AlbumMWs.deleteAlbum,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }
@@ -49,6 +52,7 @@ export class AlbumRouter {
 
       // specific part
       AlbumMWs.createSavedSearch,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }

src/backend/routes/GalleryRouter.ts

@@ -8,6 +8,7 @@ import {ThumbnailSourceType} from '../model/threading/PhotoWorker';
 import {VersionMWs} from '../middlewares/VersionMWs';
 import {SupportedFormats} from '../../common/SupportedFormats';
 import {PhotoConverterMWs} from '../middlewares/thumbnail/PhotoConverterMWs';
+import {ServerTimingMWs} from '../middlewares/ServerTimingMWs';
 
 export class GalleryRouter {
   public static route(app: Express): void {
@@ -41,6 +42,7 @@ export class GalleryRouter {
       GalleryMWs.listDirectory,
       ThumbnailGeneratorMWs.addThumbnailInformation,
       GalleryMWs.cleanUpGalleryResults,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }
@@ -53,6 +55,7 @@ export class GalleryRouter {
       AuthenticationMWs.authorisePath('directory', true),
 
       // specific part
+      ServerTimingMWs.addServerTiming,
       GalleryMWs.zipDirectory
     );
   }
@@ -66,6 +69,7 @@ export class GalleryRouter {
 
       // specific part
       GalleryMWs.loadFile,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -80,6 +84,7 @@ export class GalleryRouter {
       // specific part
       GalleryMWs.loadFile,
       PhotoConverterMWs.convertPhoto,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -93,6 +98,7 @@ export class GalleryRouter {
 
       // specific part
       GalleryMWs.loadFile,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -107,6 +113,7 @@ export class GalleryRouter {
       // specific part
       GalleryMWs.loadFile,
       GalleryMWs.loadBestFitVideo,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -120,6 +127,7 @@ export class GalleryRouter {
 
       // specific part
       GalleryMWs.loadFile,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -134,6 +142,7 @@ export class GalleryRouter {
       // specific part
       GalleryMWs.getRandomImage,
       GalleryMWs.loadFile,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -148,6 +157,7 @@ export class GalleryRouter {
       // specific part
       GalleryMWs.loadFile,
       ThumbnailGeneratorMWs.generateThumbnailFactory(ThumbnailSourceType.Photo),
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -162,6 +172,7 @@ export class GalleryRouter {
       // specific part
       GalleryMWs.loadFile,
       ThumbnailGeneratorMWs.generateThumbnailFactory(ThumbnailSourceType.Video),
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -177,6 +188,7 @@ export class GalleryRouter {
       // specific part
       GalleryMWs.loadFile,
       ThumbnailGeneratorMWs.generateIconFactory(ThumbnailSourceType.Video),
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -191,6 +203,7 @@ export class GalleryRouter {
       // specific part
       GalleryMWs.loadFile,
       ThumbnailGeneratorMWs.generateIconFactory(ThumbnailSourceType.Photo),
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }
@@ -206,6 +219,7 @@ export class GalleryRouter {
       GalleryMWs.search,
       ThumbnailGeneratorMWs.addThumbnailInformation,
       GalleryMWs.cleanUpGalleryResults,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }
@@ -220,6 +234,7 @@ export class GalleryRouter {
 
       // specific part
       GalleryMWs.autocomplete,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }

src/backend/routes/NotificationRouter.ts

@@ -4,6 +4,7 @@ import {RenderingMWs} from '../middlewares/RenderingMWs';
 import {NotificationMWs} from '../middlewares/NotificationMWs';
 import {Express} from 'express';
 import {VersionMWs} from '../middlewares/VersionMWs';
+import {ServerTimingMWs} from '../middlewares/ServerTimingMWs';
 
 export class NotificationRouter {
   public static route(app: Express): void {
@@ -17,6 +18,7 @@ export class NotificationRouter {
       AuthenticationMWs.authorise(UserRoles.Guest),
       VersionMWs.injectGalleryVersion,
       NotificationMWs.list,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }

src/backend/routes/PersonRouter.ts

@@ -6,6 +6,7 @@ import {PersonMWs} from '../middlewares/PersonMWs';
 import {ThumbnailGeneratorMWs} from '../middlewares/thumbnail/ThumbnailGeneratorMWs';
 import {VersionMWs} from '../middlewares/VersionMWs';
 import {Config} from '../../common/config/private/Config';
+import {ServerTimingMWs} from '../middlewares/ServerTimingMWs';
 
 export class PersonRouter {
   public static route(app: Express): void {
@@ -25,6 +26,7 @@ export class PersonRouter {
 
       // specific part
       PersonMWs.updatePerson,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }
@@ -41,6 +43,7 @@ export class PersonRouter {
       // PersonMWs.addSamplePhotoForAll,
       ThumbnailGeneratorMWs.addThumbnailInfoForPersons,
       PersonMWs.cleanUpPersonResults,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }
@@ -55,6 +58,7 @@ export class PersonRouter {
       // specific part
       PersonMWs.getPerson,
       ThumbnailGeneratorMWs.generatePersonThumbnail,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderFile
     );
   }

src/backend/routes/PublicRouter.ts

@@ -8,6 +8,7 @@ import {AuthenticationMWs} from '../middlewares/user/AuthenticationMWs';
 import {CookieNames} from '../../common/CookieNames';
 import {ErrorCodes, ErrorDTO} from '../../common/entities/Error';
 import {UserDTO} from '../../common/entities/UserDTO';
+import {ServerTimeEntry} from '../middlewares/ServerTimingMWs';
 
 declare global {
   namespace Express {
@@ -15,6 +16,7 @@ declare global {
       locale?: string;
       localePath?: string;
       tpl?: any;
+      timing?: { [key: string]: ServerTimeEntry } ;
     }
 
     interface Response {
@@ -92,13 +94,13 @@ export class PublicRouter {
       });
 
     app.get('/heartbeat',
-      (req: Request, res: Response, next: NextFunction) => {
+      (req: Request, res: Response) => {
         res.sendStatus(200);
       }
     );
 
     app.get('/manifest.json',
-      (req: Request, res: Response, next: NextFunction) => {
+      (req: Request, res: Response) => {
         res.send({
           name: Config.Client.applicationTitle,
           icons: [

src/backend/routes/SharingRouter.ts

@@ -4,6 +4,7 @@ import {RenderingMWs} from '../middlewares/RenderingMWs';
 import {SharingMWs} from '../middlewares/SharingMWs';
 import * as express from 'express';
 import {QueryParams} from '../../common/QueryParams';
+import {ServerTimingMWs} from '../middlewares/ServerTimingMWs';
 
 export class SharingRouter {
   public static route(app: express.Express): void {
@@ -20,6 +21,7 @@ export class SharingRouter {
     app.post('/api/share/login',
       AuthenticationMWs.inverseAuthenticate,
       AuthenticationMWs.shareLogin,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderSessionUser
     );
   }
@@ -29,6 +31,7 @@ export class SharingRouter {
       AuthenticationMWs.authenticate,
       AuthenticationMWs.authorise(UserRoles.LimitedGuest),
       SharingMWs.getSharing,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderSharing
     );
   }
@@ -38,6 +41,7 @@ export class SharingRouter {
       AuthenticationMWs.authenticate,
       AuthenticationMWs.authorise(UserRoles.User),
       SharingMWs.createSharing,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderSharing
     );
   }
@@ -47,6 +51,7 @@ export class SharingRouter {
       AuthenticationMWs.authenticate,
       AuthenticationMWs.authorise(UserRoles.User),
       SharingMWs.updateSharing,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderSharing
     );
   }
@@ -57,6 +62,7 @@ export class SharingRouter {
       AuthenticationMWs.authenticate,
       AuthenticationMWs.authorise(UserRoles.Admin),
       SharingMWs.deleteSharing,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }
@@ -66,6 +72,7 @@ export class SharingRouter {
       AuthenticationMWs.authenticate,
       AuthenticationMWs.authorise(UserRoles.User),
       SharingMWs.listSharing,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderSharingList
     );
   }

src/backend/routes/UserRouter.ts

@@ -4,6 +4,7 @@ import {UserRoles} from '../../common/entities/UserDTO';
 import {AuthenticationMWs} from '../middlewares/user/AuthenticationMWs';
 import {UserRequestConstrainsMWs} from '../middlewares/user/UserRequestConstrainsMWs';
 import {RenderingMWs} from '../middlewares/RenderingMWs';
+import {ServerTimingMWs} from '../middlewares/ServerTimingMWs';
 
 export class UserRouter {
   public static route(app: Express): void {
@@ -23,6 +24,7 @@ export class UserRouter {
     app.post('/api/user/login',
       AuthenticationMWs.inverseAuthenticate,
       AuthenticationMWs.login,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderSessionUser
     );
   }
@@ -30,6 +32,7 @@ export class UserRouter {
   private static addLogout(app: Express): void {
     app.post('/api/user/logout',
       AuthenticationMWs.logout,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderOK
     );
   }
@@ -38,6 +41,7 @@ export class UserRouter {
   private static addGetSessionUser(app: Express): void {
     app.get('/api/user/me',
       AuthenticationMWs.authenticate,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderSessionUser
     );
   }
@@ -48,6 +52,7 @@ export class UserRouter {
       AuthenticationMWs.authenticate,
       UserRequestConstrainsMWs.forceSelfRequest,
       UserMWs.changePassword,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderOK
     );
   }
@@ -58,6 +63,7 @@ export class UserRouter {
       AuthenticationMWs.authenticate,
       AuthenticationMWs.authorise(UserRoles.Admin),
       UserMWs.createUser,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderOK
     );
   }
@@ -68,6 +74,7 @@ export class UserRouter {
       AuthenticationMWs.authorise(UserRoles.Admin),
       UserRequestConstrainsMWs.notSelfRequest,
       UserMWs.deleteUser,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderOK
     );
   }
@@ -78,6 +85,7 @@ export class UserRouter {
       AuthenticationMWs.authenticate,
       AuthenticationMWs.authorise(UserRoles.Admin),
       UserMWs.listUsers,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderResult
     );
   }
@@ -88,6 +96,7 @@ export class UserRouter {
       AuthenticationMWs.authorise(UserRoles.Admin),
       UserRequestConstrainsMWs.notSelfRequestOr2Admins,
       UserMWs.changeRole,
+      ServerTimingMWs.addServerTiming,
       RenderingMWs.renderOK
     );
   }

src/common/config/private/PrivateConfig.ts

@@ -161,6 +161,8 @@ export class ServerLogConfig {
   level: LogLevel = LogLevel.info;
   @ConfigProperty({type: SQLLogLevel})
   sqlLevel: SQLLogLevel = SQLLogLevel.error;
+  @ConfigProperty()
+  logServerTiming: boolean = false;
 }