dart-backend / angel

A polished, production-ready backend framework in Dart for the VM, AOT, and Flutter.
https://github.com/dukefirehawk/angel
BSD 3-Clause "New" or "Revised" License
171 stars 22 forks source link

serious performance problem on the Angel router when using chain and group to group routes and apply the same Middleware #114

Open insinfo opened 7 months ago

insinfo commented 7 months ago

serious performance problem on the Angel router when using chain and group to group routes and apply the same Middleware

with just one route defined I can get 13767.22 requests per second

isaque@pmro174330:~/wrk-cmm$ ./wrk -t12 -c400 -d30s http://192.168.66.123:3350/
Running 30s test @ http://192.168.66.123:3350/
  12 threads and 400 connections
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency    28.76ms   10.43ms   91.30ms    1.71ms   73.37%
    Req/Sec     1.15k    72.07      2.22k   585.00     72.95%
  413532 requests in 30.04s, 105.71MB read
Requests/sec:  13767.22
Transfer/sec:      3.52MB

with 122 defined routes grouped using chain and group I only get 156.68 requests per second

unable to record first byte metrics
unabe to record last byte metrics 1699474363297116 - 1699474361169768 = 2127348
unable to record first byte metrics
unabe to record last byte metrics 1699474363320014 - 1699474361217196 = 2102818
unable to record first byte metrics
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.55s   442.53ms    2.00s   146.73ms   82.66%
    Req/Sec    16.79     12.38    160.00      0.00     74.18%
  4716 requests in 30.10s, 1.23MB read
  Socket errors: connect 0, read 0, write 465, timeout 3522
Requests/sec:    156.68
Transfer/sec:     41.93KB

If I don't use chain and group, and only use addRoute, passing the suffix concatenated with the path and the middleware, performance improves a lot, reaching 3487.82 requests per second

isaque@pmro174330:~/wrk-cmm$ ./wrk -t12 -c400 -d30s http://192.168.66.123:3350/
Running 30s test @ http://192.168.66.123:3350/
  12 threads and 400 connections
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency   112.15ms   30.61ms  451.83ms   29.18ms   90.85%
    Req/Sec   296.09     40.34    505.00      1.00     80.06%
  104819 requests in 30.05s, 26.80MB read
  Socket errors: connect 0, read 0, write 638, timeout 0
Requests/sec:   3487.82
Transfer/sec:      0.89MB

minimal app to reproduce the issue

import 'package:angel3_framework/angel3_framework.dart';
import 'package:angel3_production/angel3_production.dart';
import 'package:angel3_cors/angel3_cors.dart';
import 'dart:convert';
import 'package:file/file.dart' as file;
import 'package:angel3_static/angel3_static.dart' as static_file_server;
import 'dart:async';
import 'package:file/local.dart';

//dart ./bin/main.dart -p 3350 -a 0.0.0.0 -j 4
main(List<String> args) async {
  return Runner('angel', configureServer).run(args);
}

Future configureServer(Angel app) async {
  final options = CorsOptions();
  app.fallback(cors(options));
  final fs = const LocalFileSystem();
  await app.configure(configureRoutes(fs));
}

AngelConfigurer configureRoutes(file.FileSystem fileSystem) {
  return (Angel app) {
    app.get('/', (req, res) => res.write('angel'));   

    app.chain([simulatedMiddleware]).group('/api/v1', (router) {
      for (final sr in simulatedRoutes) {
        final method = sr.keys.first.toUpperCase();
        final path = sr.values.first;
        router.addRoute(method, path, (req, res) => simulatedWork);
      }
    });

    // for (final sr in simulatedRoutes) {
    //   final method = sr.keys.first.toUpperCase();
    //   final path = sr.values.first;
    //   app.addRoute(method, '/api/v1' + path, (req, res) => simulatedWork,middleware: [simulatedMiddleware]);
    // }

    if (!app.environment.isProduction) {
      var vDir = static_file_server.VirtualDirectory(
        app,
        fileSystem,
        source: fileSystem.directory('storage'),
      );
      app.fallback(vDir.handleRequest);
    }

    app.fallback((req, res) {
      res.headers['Content-Type'] = 'application/json;charset=utf-8';
      res.statusCode = 404;
      return res.write(jsonEncode({
        'message': 'Rota não existe',
        'exception': 'Rota não existe',
        'stackTrace': ''
      }));
    });

    final oldErrorHandler = app.errorHandler;
    app.errorHandler = (e, req, res) async {
      if (req.accepts('text/html', strict: true)) {
        if (e.statusCode == 404 && req.accepts('text/html', strict: true)) {
          await res
              .render('error', {'message': 'Arquivo não existe ${req.uri}.'});
        } else {
          await res.render('error', {'message': e.message});
        }
      } else {
        return await oldErrorHandler(e, req, res);
      }
    };
  };
}

final simulatedRoutes = [
  {'get': '/administracao/paises'},
  {'get': '/administracao/ufs'},
  {'get': '/administracao/municipios'},
  {'get': '/administracao/modulos'},
  {'get': '/administracao/permissoes/:numCgm/:anoExercicio'},
  {'put': '/administracao/permissoes/:numCgm/:anoExercicio'},
  {'get': '/administracao/escolaridades'},
  {'get': '/administracao/tiposlogradouro'},
  {'get': '/administracao/orgaos'},
  {'get': '/administracao/unidades'},
  {'get': '/administracao/departamentos'},
  {'get': '/administracao/setores'},
  {'get': '/administracao/gestao'},
  {'get': '/administracao/usuarios'},
  {'get': '/administracao/usuarios/:numcgm'},
  {'post': '/administracao/usuarios'},
  {'put': '/administracao/usuarios'},
  {'get': '/administracao/cgm'},
  {'get': '/administracao/cgm/:cgm'},
  {'get': '/administracao/auditorias'},
  {'post': '/administracao/auditorias'},
  {'get': '/administracao/configuracao'},
  {'get': '/administracao/configuracao/by/filtro'},
  {'get': '/administracao/funcionalidades'},
  {'get': '/administracao/menu/:cgm'},
  {'get': '/administracao/organograma/hierarquia'},
  {'get': '/administracao/acoes'},
  //auth
  {'post': '/change/pass'},
  {'get': '/auth/check/permissao/:cgm'},
  {'post': '/auth/login'},
  {'post': '/auth/check'},
  {'get': '/auth/check/toke'},
  //cgm
  {'get': '/cgm/full'},
  {'get': '/cgm/full/:cgm'},
  {'delete': '/cgm'},
  {'post': '/cgm/full'},
  {'post': '/cgm/full/interno'},
  {'put': '/cgm/full'},
  {'get': '/cgm/atributos'},
  {'get': '/cgm/atributos/:cgm'},
  {'get': '/cgm/categoriashabilitacao'},
  {'get': '/cgm/tiposlogradouro'},
  //
  {'get': '/estatistica/processos/ano'},
  {'get': '/estatistica/processos/periodo/setor/primero/tramite'},
  {'get': '/estatistica/processos/situacao'},
  {'get': '/estatistica/processos/classificacao'},
  {'get': '/estatistica/processos/assunto'},
  //
  {'get': '/norma/normas'},
  //
  {'get': '/protocolo/processos/favoritos/cgm/:cgm'},
  {'post': '/protocolo/processos/favoritos'},
  {'post': '/protocolo/processos/favoritos/:codProcesso/:anoExercicio'},
  {'put': '/protocolo/processos/favoritos'},
  {'delete': '/protocolo/processos/favoritos/:id'},
  {'delete': '/protocolo/processos/favoritos/:codProcesso/:anoExercicio'},
  {'get': '/protocolo/acoes/favoritas/cgm/:cgm'},
  {'post': '/protocolo/acoes/favoritas'},
  {'post': '/protocolo/acoes/favoritas/:codAcao'},
  {'put': '/protocolo/acoes/favoritas'},
  {'delete': '/protocolo/acoes/favoritas/:id'},
  {'delete': '/protocolo/acoes/favoritas/:codAcao'},
  {'get': '/protocolo/assuntos'},
  {'post': '/protocolo/assuntos'},
  {'put': '/protocolo/assuntos'},
  {'delete': '/protocolo/assuntos'},
  {'get': '/protocolo/assuntos/:codAssunto/:codClassificacao'},
  {'get': '/protocolo/classificacoes'},
  {'post': '/protocolo/classificacoes'},
  {'put': '/protocolo/classificacoes'},
  {'delete': '/protocolo/classificacoes'},
  {'get': '/protocolo/despachospadrao'},
  {'post': '/protocolo/despachospadrao'},
  {'put': '/protocolo/despachospadrao'},
  {'delete': '/protocolo/despachospadrao'},
  {'get': '/protocolo/tramites'},
  {'post': '/protocolo/tramites'},
  {
    'put':
        '/protocolo/tramites/:codClassiOld/:codAssuntoOld/:ordemOld/:exercicioOld'
  },
  {'delete': '/protocolo/tramites'},
  {'get': '/protocolo/processos/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/em/apenso/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/apenso/a/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/andamentos/:anoExercicio/:codProcesso'},
  {
    'get':
        '/protocolo/processos/despachos/:anoExercicio/:codProcesso/:codAndamento/:codUsuario/:timestamp'
  },
  {'get': '/protocolo/processos'},
  {'get': '/protocolo/processos/areceber'},
  {'get': '/protocolo/processos/aemcaminhar'},
  {'get': '/protocolo/processos/byfiltros'},
  {'get': '/protocolo/processos/aapensara'},
  {'get': '/protocolo/processos/adesapensar'},
  {'get': '/protocolo/processos/adespachar'},
  {'get': '/protocolo/processos/aalterar'},
  {'get': '/protocolo/processos/acancelar'},
  {'get': '/protocolo/processos/aarquivar'},
  {'get': '/protocolo/processos/adesarquivar'},
  {'post': '/protocolo/processos'},
  {'post': '/protocolo/processos/implantar'},
  {'put': '/protocolo/processos'},
  {'post': '/protocolo/processos/receber/lote'},
  {'post': '/protocolo/processos/despachar/lote'},
  {'post': '/protocolo/processos/encaminhar/lote'},
  {'post': '/protocolo/processos/cancelarencaminhamento/lote'},
  {'post': '/protocolo/processos/apensar/lote'},
  {'post': '/protocolo/processos/desapensar/lote'},
  {'post': '/protocolo/processos/arquivar/lote'},
  {'post': '/protocolo/processos/desarquivar/lote'},
  {'post': '/protocolo/processos/anexos'},
  {'get': '/protocolo/processos/anexos/:codProcesso/:anoExercicio'},
  {'get': '/protocolo/situacoes'},
  {'get': '/protocolo/historicoarquivamento'},
  {'post': '/protocolo/historicoarquivamento'},
  {'put': '/protocolo/historicoarquivamento'},
  {'delete': '/protocolo/historicoarquivamento'},
  {'get': '/protocolo/listagemprocessos'},
  {'post': '/protocolo/listagemprocessos'},
  {'get': '/protocolo/documentos'},
  {'post': '/protocolo/documentos'},
  {'put': '/protocolo/documentos'},
  {'delete': '/protocolo/documentos'},
  {'get': '/protocolo/atributosprotocolo'},
  {'post': '/protocolo/atributosprotocolo'},
  {'put': '/protocolo/atributosprotocolo'},
  {'delete': '/protocolo/atributosprotocolo'},
  {'get': '/protocolo/processos/public/site/:anoExercicio/:codProcesso'},
];

Future<dynamic> simulatedWork(RequestContext req, ResponseContext res) async {
  try {
    // ignore: unused_local_variable
    final filters = req.queryParameters;
    final listItems = List.generate(150, (int index) => {'name': 'Jon_$index'});
    res.statusCode = 200;
    res.headers['Content-Type'] = 'application/json;charset=utf-8';
    res.headers['total-records'] = '150';
    res.write(jsonEncode(listItems));
  } catch (e, s) {
    print('simulatedWork@all $e $s');
    var v = jsonEncode({
      'is_error': true,
      'status_code': 400,
      'message': 'Error',
      'exception': e.toString(),
      'stackTrace': s.toString()
    });
    res.statusCode = 400;
    res.headers['Content-Type'] = 'application/json;charset=utf-8';
    res.write(v);
  }
}

Future<bool> simulatedMiddleware(
    RequestContext req, ResponseContext res) async {
  try {
    return true;
  } catch (e, s) {
    print('simulatedMiddleware: $s $s');
    throw AngelHttpException.notAuthenticated(message: '$e $s');
  }
}
dukefirehawk commented 7 months ago

Can you try with -j 100 to see if that improves performance? Anyway this is a good test feedback for tuning Angel3 performance.

insinfo commented 7 months ago

from -j 4 there is practically no difference in performance, I believe that perhaps a refactoring of the router is the way to achieve an increase in performance, see that in the previous post, not using the group and the chain already has an absurd improvement in performance.

https://github.com/ibraheemdev/matchit#benchmarks https://github.com/julienschmidt/httprouter https://github.com/darpi-rs/darpi/tree/master/gonzales https://www.npopov.com/2014/02/18/Fast-request-routing-using-regular-expressions.html https://github.com/mrjgreen/phroute

 Processor Intel Core i5-10500T CPU @ 2.30GHz, max @ 3.80 GHz , 6 cores, 12 threads 

-j 1
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.26s   437.46ms    1.90s    19.60ms   62.88%
    Req/Sec    19.10     14.46     70.00      0.00     78.19%
  1980 requests in 30.09s, 518.20KB read
  Socket errors: connect 0, read 26, write 0, timeout 94
Requests/sec:     65.79
Transfer/sec:     17.22KB
-j 2
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.24s   426.92ms    2.00s    20.60ms   66.53%
    Req/Sec    17.06     12.41     90.00      0.00     68.51%
  6348 requests in 1.00m, 1.62MB read
  Socket errors: connect 0, read 12, write 0, timeout 3620
Requests/sec:    105.62
Transfer/sec:     27.64KB
-j 3
 Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.35s   464.01ms    2.00s    24.56ms   63.60%
    Req/Sec    20.11     14.99     90.00      0.00     72.19%
  4342 requests in 30.08s, 1.11MB read
  Socket errors: connect 0, read 28, write 0, timeout 795
Requests/sec:    144.33
Transfer/sec:     37.77KB
-j 4
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.42s   486.06ms    2.00s    20.23ms   60.31%
    Req/Sec    24.62     18.82    120.00      0.00     74.51%
  6070 requests in 30.08s, 1.55MB read
  Socket errors: connect 0, read 0, write 0, timeout 287
Requests/sec:    201.79
Transfer/sec:     52.81KB
-j 5
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.40s   420.96ms    2.00s    32.15ms   82.17%
    Req/Sec    23.01     15.12    140.00      0.00     78.71%
  6825 requests in 30.07s, 1.74MB read
  Socket errors: connect 0, read 0, write 0, timeout 273
Requests/sec:    227.01
Transfer/sec:     59.42KB
-j 6
 Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.40s   367.99ms    1.99s    28.91ms   82.53%
    Req/Sec    24.50     16.51    111.00      0.00     79.72%
  7187 requests in 30.05s, 1.84MB read
  Socket errors: connect 0, read 0, write 0, timeout 256
Requests/sec:    239.18
Transfer/sec:     62.60KB
-j 7
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.40s   404.55ms    2.00s    29.63ms   73.35%
    Req/Sec    23.31     15.61    130.00      0.00     74.22%
  7113 requests in 30.07s, 1.82MB read
  Socket errors: connect 0, read 0, write 0, timeout 745
Requests/sec:    236.52
Transfer/sec:     61.90KB
-j 8
 Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.43s   377.78ms    2.00s    27.01ms   73.58%
    Req/Sec    23.69     16.21    151.00      0.00     76.08%
  7340 requests in 30.04s, 1.88MB read
  Socket errors: connect 0, read 0, write 0, timeout 278
Requests/sec:    244.32
Transfer/sec:     63.94KB
-j 9
  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.52s   378.66ms    2.00s    42.14ms   81.54%
    Req/Sec    22.23     14.49    131.00      0.00     76.65%
  6997 requests in 30.10s, 1.79MB read
  Socket errors: connect 0, read 0, write 0, timeout 252
Requests/sec:    232.47
Transfer/sec:     60.84KB
-j 10
 Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.50s   337.60ms    1.96s    50.55ms   85.89%
    Req/Sec    22.46     14.44    160.00      0.00     80.48%
  7230 requests in 30.05s, 1.85MB read
  Socket errors: connect 0, read 0, write 0, timeout 178
Requests/sec:    240.61
Transfer/sec:     62.97KB
-j 12
 Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.47s   296.79ms    1.99s    51.13ms   87.45%
    Req/Sec    24.16     16.53    130.00      0.00     83.00%
  7451 requests in 30.07s, 1.90MB read
  Socket errors: connect 0, read 0, write 0, timeout 159
Requests/sec:    247.80
Transfer/sec:     64.85KB
-j 100
   Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency     1.60s   335.22ms    2.00s    69.72ms   85.09%
    Req/Sec    20.45     13.28    140.00      0.00     80.55%
  6443 requests in 30.07s, 1.65MB read
  Socket errors: connect 0, read 0, write 0, timeout 983
Requests/sec:    214.29
Transfer/sec:     56.09KB
insinfo commented 7 months ago

I made an app similar to the previous post to test with shelf with the same routes, and performance was much better than angel

image

image

  Thread Stats   Avg     Stdev       Max       Min   +/- Stdev
    Latency    21.20ms   72.32ms    1.21s   309.00us   98.45%
    Req/Sec     2.51k   546.87      3.90k     0.00     91.45%
  869599 requests in 30.06s, 439.54MB read
Requests/sec:  28930.91
Transfer/sec:     14.62MB
import 'dart:async';
import 'dart:convert';
import 'dart:isolate';
import 'package:args/args.dart';
import 'package:prometheus_client/format.dart' as format;
import 'package:prometheus_client/prometheus_client.dart';
import 'package:prometheus_client/runtime_metrics.dart' as runtime_metrics;
import 'package:shelf/shelf.dart';
import 'package:shelf/shelf_io.dart' as io;
import 'package:shelf_router/shelf_router.dart';
import 'package:shelf_router/src/router_entry.dart';
import 'package:stack_trace/stack_trace.dart';

import 'package:dart_segment_fault/dependencies/shelf_cors_headers_base/shelf_cors_headers_base.dart';
import 'package:dart_segment_fault/dependencies/stream_isolate/stream_isolate.dart';
// to compile
// dart compile exe -o backend.exe .\bin\backend.dart
// to test
// xargs -I % -P 8 curl "http:/192.168.66.123:3161/api/v1/protocolo/processos/public/site/2023/10" < <(printf '%s\n' {1..400})
//./wrk -t12 -c400 -d30s http://172.30.82.2:3350

const defaultHeaders = {'Content-Type': 'application/json;charset=utf-8'};
final streamIsolates = <Map<int, BidirectionalStreamIsolate>>[];
void main(List<String> args) async {
  final parser = ArgParser()
    ..addOption('address', abbr: 'a', defaultsTo: '0.0.0.0')
    ..addOption('port', abbr: 'p', defaultsTo: '3161')
    ..addOption('isolates', abbr: 'j', defaultsTo: '3');

  final argsParsed = parser.parse(args);
  final arguments = [argsParsed['address'], int.parse(argsParsed['port'])];

  final numberOfIsolates = int.parse(argsParsed['isolates']);
  for (var i = 0; i < numberOfIsolates - 1; i++) {
    final streamIsolate = await StreamIsolate.spawnBidirectional(isolateMain,
        debugName: i.toString(), argument: [i, ...arguments]);
    streamIsolates.add({i: streamIsolate});
    streamIsolate.stream.listen((event) => receiveAndPass(event, i));
  }
}

/// receive msg from isolate and send to all isolates
void receiveAndPass(event, int idx) {
  streamIsolates.forEach((item) {
    item.values.first.send(event);
  });
}

Stream isolateMain(Stream inc, dynamic args) {
  final arguments = args as List;
  int id = arguments[0];
  String address = arguments[1];
  int port = arguments[2];

  final streamController = StreamController.broadcast();

  final reg = CollectorRegistry(); //CollectorRegistry.defaultRegistry;
  // Register default runtime metrics
  runtime_metrics.register(reg);
  // Register http requests total
  final http_requests_total = Counter(
      name: 'http_requests_total', help: 'Total number of http api requests');
  http_requests_total.register(reg);
  // listen msg from main
  inc.listen((msg) {
    http_requests_total.inc();
  });

  _startServer([id, streamController, reg, address, port]);
  return streamController.stream;
}

void _startServer(List args) async {
  final streamController = args[1] as StreamController;
  final reg = args[2] as CollectorRegistry;
  String address = args[3];
  int port = args[4];

  final app = Router();
  routes(app, reg);

  final handler =
      Pipeline().addMiddleware(corsHeaders()).addMiddleware((innerHandler) {
    return (request) async {
      // Every time http_request is called, increase the counter by one
      final resp = await innerHandler(request);
      if (!request.url.path.contains('metrics')) {
        //send msg to main
        streamController.add('+1');
      }
      return resp;
    };
  })
          //.addMiddleware(logRequestsCustom())
          .addHandler(app);

  final server = await io.serve(handler, address, port, shared: true);
  server.defaultResponseHeaders.remove('X-Frame-Options', 'SAMEORIGIN');
  print('Serving at http://${server.address.host}:${server.port}');
}

void routes(Router app, CollectorRegistry reg) {
  app.get('/', (Request request) async {
    return Response.ok('shelf');
  });

  // Register a handler to expose the metrics in the Prometheus text format
  app.get('/metrics', (Request request) async {
    final buffer = StringBuffer();
    final metrics = await reg.collectMetricFamilySamples();
    format.write004(buffer, metrics);
    return Response.ok(
      buffer.toString(),
      headers: {'Content-Type': format.contentType},
    );
  });
  app.group('/api/v1', (router) {
    for (final sr in simulatedRoutes) {
      final method = sr.keys.first.toUpperCase();
      final path = sr.values.first;
      router.add(method, path, simulatedWork);
    }
  },middleware: simulatedMiddleware);
}

class RouterContext {
  final Router _router;
  final String basePath;
  final Middleware? middleware;
  RouterContext(
    this._router, {
    required this.basePath,
    this.middleware,
  });
  void add(
      String verb, String route, FutureOr<Response> Function(Request) handler) {
    if (middleware != null) {
      _router.add(verb, basePath + route, middleware!(handler));
    } else {
      _router.add(verb, basePath + route, handler);
    }
  }
}

extension RouterExtension on Router {
  void group(String basePath, Function(RouterContext) callback,
      {Middleware? middleware}) {
    final ctx = RouterContext(this, basePath: basePath);
    callback(ctx);
  }
}

FutureOr<Response> Function(Request) simulatedMiddleware(innerHandler) {
  return (request) async {
    final resp = await innerHandler(request);
    return resp;
  };
}

Future<Response> simulatedWork(Request request) async {
  try {
    final listItems = List.generate(150, (int index) => {'name': 'Jon_$index'});
    return Response.ok(
      jsonEncode(listItems),
      headers: defaultHeaders,
    );
  } catch (e, s) {
    print('simulatedWork@all $e $s');
    return Response.badRequest();
  }
}

final simulatedRoutes = [
  {'get': '/administracao/paises'},
  {'get': '/administracao/ufs'},
  {'get': '/administracao/municipios'},
  {'get': '/administracao/modulos'},
  {'get': '/administracao/permissoes/:numCgm/:anoExercicio'},
  {'put': '/administracao/permissoes/:numCgm/:anoExercicio'},
  {'get': '/administracao/escolaridades'},
  {'get': '/administracao/tiposlogradouro'},
  {'get': '/administracao/orgaos'},
  {'get': '/administracao/unidades'},
  {'get': '/administracao/departamentos'},
  {'get': '/administracao/setores'},
  {'get': '/administracao/gestao'},
  {'get': '/administracao/usuarios'},
  {'get': '/administracao/usuarios/:numcgm'},
  {'post': '/administracao/usuarios'},
  {'put': '/administracao/usuarios'},
  {'get': '/administracao/cgm'},
  {'get': '/administracao/cgm/:cgm'},
  {'get': '/administracao/auditorias'},
  {'post': '/administracao/auditorias'},
  {'get': '/administracao/configuracao'},
  {'get': '/administracao/configuracao/by/filtro'},
  {'get': '/administracao/funcionalidades'},
  {'get': '/administracao/menu/:cgm'},
  {'get': '/administracao/organograma/hierarquia'},
  {'get': '/administracao/acoes'},
  //auth
  {'post': '/change/pass'},
  {'get': '/auth/check/permissao/:cgm'},
  {'post': '/auth/login'},
  {'post': '/auth/check'},
  {'get': '/auth/check/toke'},
  //cgm
  {'get': '/cgm/full'},
  {'get': '/cgm/full/:cgm'},
  {'delete': '/cgm'},
  {'post': '/cgm/full'},
  {'post': '/cgm/full/interno'},
  {'put': '/cgm/full'},
  {'get': '/cgm/atributos'},
  {'get': '/cgm/atributos/:cgm'},
  {'get': '/cgm/categoriashabilitacao'},
  {'get': '/cgm/tiposlogradouro'},
  //
  {'get': '/estatistica/processos/ano'},
  {'get': '/estatistica/processos/periodo/setor/primero/tramite'},
  {'get': '/estatistica/processos/situacao'},
  {'get': '/estatistica/processos/classificacao'},
  {'get': '/estatistica/processos/assunto'},
  //
  {'get': '/norma/normas'},
  //
  {'get': '/protocolo/processos/favoritos/cgm/:cgm'},
  {'post': '/protocolo/processos/favoritos'},
  {'post': '/protocolo/processos/favoritos/:codProcesso/:anoExercicio'},
  {'put': '/protocolo/processos/favoritos'},
  {'delete': '/protocolo/processos/favoritos/:id'},
  {'delete': '/protocolo/processos/favoritos/:codProcesso/:anoExercicio'},
  {'get': '/protocolo/acoes/favoritas/cgm/:cgm'},
  {'post': '/protocolo/acoes/favoritas'},
  {'post': '/protocolo/acoes/favoritas/:codAcao'},
  {'put': '/protocolo/acoes/favoritas'},
  {'delete': '/protocolo/acoes/favoritas/:id'},
  {'delete': '/protocolo/acoes/favoritas/:codAcao'},
  {'get': '/protocolo/assuntos'},
  {'post': '/protocolo/assuntos'},
  {'put': '/protocolo/assuntos'},
  {'delete': '/protocolo/assuntos'},
  {'get': '/protocolo/assuntos/:codAssunto/:codClassificacao'},
  {'get': '/protocolo/classificacoes'},
  {'post': '/protocolo/classificacoes'},
  {'put': '/protocolo/classificacoes'},
  {'delete': '/protocolo/classificacoes'},
  {'get': '/protocolo/despachospadrao'},
  {'post': '/protocolo/despachospadrao'},
  {'put': '/protocolo/despachospadrao'},
  {'delete': '/protocolo/despachospadrao'},
  {'get': '/protocolo/tramites'},
  {'post': '/protocolo/tramites'},
  {
    'put':
        '/protocolo/tramites/:codClassiOld/:codAssuntoOld/:ordemOld/:exercicioOld'
  },
  {'delete': '/protocolo/tramites'},
  {'get': '/protocolo/processos/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/em/apenso/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/apenso/a/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/andamentos/:anoExercicio/:codProcesso'},
  {
    'get':
        '/protocolo/processos/despachos/:anoExercicio/:codProcesso/:codAndamento/:codUsuario/:timestamp'
  },
  {'get': '/protocolo/processos'},
  {'get': '/protocolo/processos/areceber'},
  {'get': '/protocolo/processos/aemcaminhar'},
  {'get': '/protocolo/processos/byfiltros'},
  {'get': '/protocolo/processos/aapensara'},
  {'get': '/protocolo/processos/adesapensar'},
  {'get': '/protocolo/processos/adespachar'},
  {'get': '/protocolo/processos/aalterar'},
  {'get': '/protocolo/processos/acancelar'},
  {'get': '/protocolo/processos/aarquivar'},
  {'get': '/protocolo/processos/adesarquivar'},
  {'post': '/protocolo/processos'},
  {'post': '/protocolo/processos/implantar'},
  {'put': '/protocolo/processos'},
  {'post': '/protocolo/processos/receber/lote'},
  {'post': '/protocolo/processos/despachar/lote'},
  {'post': '/protocolo/processos/encaminhar/lote'},
  {'post': '/protocolo/processos/cancelarencaminhamento/lote'},
  {'post': '/protocolo/processos/apensar/lote'},
  {'post': '/protocolo/processos/desapensar/lote'},
  {'post': '/protocolo/processos/arquivar/lote'},
  {'post': '/protocolo/processos/desarquivar/lote'},
  {'post': '/protocolo/processos/anexos'},
  {'get': '/protocolo/processos/anexos/:codProcesso/:anoExercicio'},
  {'get': '/protocolo/situacoes'},
  {'get': '/protocolo/historicoarquivamento'},
  {'post': '/protocolo/historicoarquivamento'},
  {'put': '/protocolo/historicoarquivamento'},
  {'delete': '/protocolo/historicoarquivamento'},
  {'get': '/protocolo/listagemprocessos'},
  {'post': '/protocolo/listagemprocessos'},
  {'get': '/protocolo/documentos'},
  {'post': '/protocolo/documentos'},
  {'put': '/protocolo/documentos'},
  {'delete': '/protocolo/documentos'},
  {'get': '/protocolo/atributosprotocolo'},
  {'post': '/protocolo/atributosprotocolo'},
  {'put': '/protocolo/atributosprotocolo'},
  {'delete': '/protocolo/atributosprotocolo'},
  {'get': '/protocolo/processos/public/site/:anoExercicio/:codProcesso'},
];

Middleware logRequestsCustom(
        {void Function(String message, bool isError)? logger}) =>
    (innerHandler) {
      final theLogger = logger ?? _defaultLogger;
      return (request) {
        var startTime = DateTime.now();
        var watch = Stopwatch()..start();
        return Future.sync(() => innerHandler(request)).then((response) {
          var msg = _message(startTime, response.statusCode,
              request.requestedUri, request.method, watch.elapsed);
          theLogger(msg, false);
          return response;
        }, onError: (Object error, StackTrace stackTrace) {
          if (error is HijackException) throw error;
          var msg = _errorMessage(startTime, request.requestedUri,
              request.method, watch.elapsed, error, stackTrace);
          theLogger(msg, true);
          // ignore: only_throw_errors
          throw error;
        });
      };
    };

String _formatQuery(String query) {
  return query == '' ? '' : '?$query';
}

String _message(DateTime requestTime, int statusCode, Uri requestedUri,
    String method, Duration elapsedTime) {
  return '${requestTime.toIso8601String()} '
      '${elapsedTime.toString().padLeft(15)} '
      '${method.padRight(7)} [$statusCode] ' // 7 - longest standard HTTP method
      '${requestedUri.path}${_formatQuery(requestedUri.query)}'
      '  isolate: ${Isolate.current.debugName}';
}

String _errorMessage(DateTime requestTime, Uri requestedUri, String method,
    Duration elapsedTime, Object error, StackTrace? stack) {
  var chain = Chain.current();
  if (stack != null) {
    chain = Chain.forTrace(stack)
        .foldFrames((frame) => frame.isCore || frame.package == 'shelf')
        .terse;
  }

  var msg = '$requestTime\t$elapsedTime\t$method\t${requestedUri.path}'
      '${_formatQuery(requestedUri.query)}\n$error';

  return '$msg\n$chain';
}

void _defaultLogger(String msg, bool isError) {
  if (isError) {
    print('[ERROR] $msg');
  } else {
    print(msg);
  }
}
dukefirehawk commented 7 months ago

Will take a look at what causes the bottleneck.

insinfo commented 7 months ago

I implemented a router based on the shelf router for the angel. seems to be extremely faster than the angel router

example

main(List<String> args) async {
  return production.Runner('angel', configureServer).run(args);
}

Future configureServer(Angel app) async {
  final options = CorsOptions();
  app.fallback(cors(options));
  final fs = const LocalFileSystem();
  await app.configure(configureRoutes(fs));
}

AngelConfigurer configureRoutes(file.FileSystem fileSystem) {
  return (Angel app) {
    final myMiddleware = (innerHandler) {
      return (request, res) async {
        final resp = await innerHandler(request, res);
        return resp;
      };
    };

    final router = MyRouter();

    router.get('/', (req, res) {
      res.statusCode = 200;
      res.write('angel');
    },middleware: myMiddleware);

    router.get('/administracao/permissoes/<numCgm>/<anoExercicio>', (RequestContext req, res) {
      print('req ${req.params}');
      res.statusCode = 200;
      res.write('angel2');
    });

    for (final sr in simulatedRoutes) {
      final method = sr.keys.first.toUpperCase();
      final path = sr.values.first;
      router.add(method, path, (req, res) => simulatedWork);
    }

    app.all('*', (req, res) => router.call(req, res));

    // app.optimizedRouter.chain([simulatedMiddleware]).group('/api/v1', (router) {
    //   for (final sr in simulatedRoutes) {
    //     final method = sr.keys.first.toUpperCase();
    //     final path = sr.values.first;
    //     router.addRoute(method, path, (req, res) => simulatedWork);
    //   }
    // });
  };
}

final simulatedRoutes = [
  {'get': '/administracao/paises'},
  {'get': '/administracao/ufs'},
  {'get': '/administracao/municipios'},
  {'get': '/administracao/modulos'},

  {'get': '/administracao/permissoes/:numCgm/:anoExercicio'},
  {'put': '/administracao/permissoes/:numCgm/:anoExercicio'},
  {'get': '/administracao/escolaridades'},
  {'get': '/administracao/tiposlogradouro'},
  {'get': '/administracao/orgaos'},
  {'get': '/administracao/unidades'},
  {'get': '/administracao/departamentos'},
  {'get': '/administracao/setores'},
  {'get': '/administracao/gestao'},
  {'get': '/administracao/usuarios'},
  {'get': '/administracao/usuarios/:numcgm'},
  {'post': '/administracao/usuarios'},
  {'put': '/administracao/usuarios'},
  {'get': '/administracao/cgm'},
  {'get': '/administracao/cgm/:cgm'},
  {'get': '/administracao/auditorias'},
  {'post': '/administracao/auditorias'},
  {'get': '/administracao/configuracao'},
  {'get': '/administracao/configuracao/by/filtro'},
  {'get': '/administracao/funcionalidades'},
  {'get': '/administracao/menu/:cgm'},
  {'get': '/administracao/organograma/hierarquia'},
  {'get': '/administracao/acoes'},
  //auth
  {'post': '/change/pass'},
  {'get': '/auth/check/permissao/:cgm'},
  {'post': '/auth/login'},
  {'post': '/auth/check'},
  {'get': '/auth/check/toke'},
  //cgm
  {'get': '/cgm/full'},
  {'get': '/cgm/full/:cgm'},
  {'delete': '/cgm'},
  {'post': '/cgm/full'},
  {'post': '/cgm/full/interno'},
  {'put': '/cgm/full'},
  {'get': '/cgm/atributos'},
  {'get': '/cgm/atributos/:cgm'},
  {'get': '/cgm/categoriashabilitacao'},
  {'get': '/cgm/tiposlogradouro'},
  //
  {'get': '/estatistica/processos/ano'},
  {'get': '/estatistica/processos/periodo/setor/primero/tramite'},
  {'get': '/estatistica/processos/situacao'},
  {'get': '/estatistica/processos/classificacao'},
  {'get': '/estatistica/processos/assunto'},
  //
  {'get': '/norma/normas'},
  //
  {'get': '/protocolo/processos/favoritos/cgm/:cgm'},
  {'post': '/protocolo/processos/favoritos'},
  {'post': '/protocolo/processos/favoritos/:codProcesso/:anoExercicio'},
  {'put': '/protocolo/processos/favoritos'},
  {'delete': '/protocolo/processos/favoritos/:id'},
  {'delete': '/protocolo/processos/favoritos/:codProcesso/:anoExercicio'},
  {'get': '/protocolo/acoes/favoritas/cgm/:cgm'},
  {'post': '/protocolo/acoes/favoritas'},
  {'post': '/protocolo/acoes/favoritas/:codAcao'},
  {'put': '/protocolo/acoes/favoritas'},
  {'delete': '/protocolo/acoes/favoritas/:id'},
  {'delete': '/protocolo/acoes/favoritas/:codAcao'},
  {'get': '/protocolo/assuntos'},
  {'post': '/protocolo/assuntos'},
  {'put': '/protocolo/assuntos'},
  {'delete': '/protocolo/assuntos'},
  {'get': '/protocolo/assuntos/:codAssunto/:codClassificacao'},
  {'get': '/protocolo/classificacoes'},
  {'post': '/protocolo/classificacoes'},
  {'put': '/protocolo/classificacoes'},
  {'delete': '/protocolo/classificacoes'},
  {'get': '/protocolo/despachospadrao'},
  {'post': '/protocolo/despachospadrao'},
  {'put': '/protocolo/despachospadrao'},
  {'delete': '/protocolo/despachospadrao'},
  {'get': '/protocolo/tramites'},
  {'post': '/protocolo/tramites'},
  {
    'put':
        '/protocolo/tramites/:codClassiOld/:codAssuntoOld/:ordemOld/:exercicioOld'
  },
  {'delete': '/protocolo/tramites'},
  {'get': '/protocolo/processos/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/em/apenso/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/apenso/a/:anoExercicio/:codProcesso'},
  {'get': '/protocolo/processos/andamentos/:anoExercicio/:codProcesso'},
  {
    'get':
        '/protocolo/processos/despachos/:anoExercicio/:codProcesso/:codAndamento/:codUsuario/:timestamp'
  },
  {'get': '/protocolo/processos'},
  {'get': '/protocolo/processos/areceber'},
  {'get': '/protocolo/processos/aemcaminhar'},
  {'get': '/protocolo/processos/byfiltros'},
  {'get': '/protocolo/processos/aapensara'},
  {'get': '/protocolo/processos/adesapensar'},
  {'get': '/protocolo/processos/adespachar'},
  {'get': '/protocolo/processos/aalterar'},
  {'get': '/protocolo/processos/acancelar'},
  {'get': '/protocolo/processos/aarquivar'},
  {'get': '/protocolo/processos/adesarquivar'},
  {'post': '/protocolo/processos'},
  {'post': '/protocolo/processos/implantar'},
  {'put': '/protocolo/processos'},
  {'post': '/protocolo/processos/receber/lote'},
  {'post': '/protocolo/processos/despachar/lote'},
  {'post': '/protocolo/processos/encaminhar/lote'},
  {'post': '/protocolo/processos/cancelarencaminhamento/lote'},
  {'post': '/protocolo/processos/apensar/lote'},
  {'post': '/protocolo/processos/desapensar/lote'},
  {'post': '/protocolo/processos/arquivar/lote'},
  {'post': '/protocolo/processos/desarquivar/lote'},
  {'post': '/protocolo/processos/anexos'},
  {'get': '/protocolo/processos/anexos/:codProcesso/:anoExercicio'},
  {'get': '/protocolo/situacoes'},
  {'get': '/protocolo/historicoarquivamento'},
  {'post': '/protocolo/historicoarquivamento'},
  {'put': '/protocolo/historicoarquivamento'},
  {'delete': '/protocolo/historicoarquivamento'},
  {'get': '/protocolo/listagemprocessos'},
  {'post': '/protocolo/listagemprocessos'},
  {'get': '/protocolo/documentos'},
  {'post': '/protocolo/documentos'},
  {'put': '/protocolo/documentos'},
  {'delete': '/protocolo/documentos'},
  {'get': '/protocolo/atributosprotocolo'},
  {'post': '/protocolo/atributosprotocolo'},
  {'put': '/protocolo/atributosprotocolo'},
  {'delete': '/protocolo/atributosprotocolo'},
  {'get': '/protocolo/processos/public/site/:anoExercicio/:codProcesso'},
];

Future<dynamic> simulatedWork(RequestContext req, ResponseContext res) async {
  try {
    // ignore: unused_local_variable
    final filters = req.queryParameters;
    final listItems = List.generate(150, (int index) => {'name': 'Jon_$index'});
    res.statusCode = 200;
    res.headers['Content-Type'] = 'application/json;charset=utf-8';
    res.headers['total-records'] = '150';
    res.write(jsonEncode(listItems));
  } catch (e, s) {
    print('simulatedWork@all $e $s');
    var v = jsonEncode({
      'is_error': true,
      'status_code': 400,
      'message': 'Error',
      'exception': e.toString(),
      'stackTrace': s.toString()
    });
    res.statusCode = 400;
    res.headers['Content-Type'] = 'application/json;charset=utf-8';
    res.write(v);
  }
}

experimental custom Router

import 'package:angel3_framework/angel3_framework.dart';
import 'package:http_methods/http_methods.dart';
import 'package:meta/meta.dart' show sealed;
import 'dart:async';
import 'package:angel3_framework/angel3_framework.dart';

/// Check if the [regexp] is non-capturing.
bool _isNoCapture(String regexp) {
  // Construct a new regular expression matching anything containing regexp,
  // then match with empty-string and count number of groups.
  return RegExp('^(?:$regexp)|.*\$').firstMatch('')!.groupCount == 0;
}

typedef Handler = FutureOr<dynamic> Function(
    RequestContext req, ResponseContext res);
typedef MyMiddleware = Handler Function(Handler innerHandler);

/// Entry in the router.
///
/// This class implements the logic for matching the path pattern.
class RouterEntry {
  /// Pattern for parsing the route pattern
  static final RegExp _parser = RegExp(r'([^<]*)(?:<([^>|]+)(?:\|([^>]*))?>)?');

  final String verb, route;
  final Function _handler;
  final MyMiddleware? _middleware;

  /// Expression that the request path must match.
  ///
  /// This also captures any parameters in the route pattern.
  final RegExp _routePattern;

  /// Names for the parameters in the route pattern.
  final List<String> _params;

  /// List of parameter names in the route pattern.
  List<String> get params => _params.toList(); // exposed for using generator.

  RouterEntry._(this.verb, this.route, this._handler, this._middleware,
      this._routePattern, this._params);

  factory RouterEntry(
    String verb,
    String route,
    Function handler, {
    MyMiddleware? middleware,
  }) {
    if (!route.startsWith('/')) {
      throw ArgumentError.value(
          route, 'route', 'expected route to start with a slash');
    }

    final params = <String>[];
    var pattern = '';
    for (var m in _parser.allMatches(route)) {
      pattern += RegExp.escape(m[1]!);
      if (m[2] != null) {
        params.add(m[2]!);
        if (m[3] != null && !_isNoCapture(m[3]!)) {
          throw ArgumentError.value(
              route, 'route', 'expression for "${m[2]}" is capturing');
        }
        pattern += '(${m[3] ?? r'[^/]+'})';
      }
    }
    final routePattern = RegExp('^$pattern\$');

    return RouterEntry._(
        verb, route, handler, middleware, routePattern, params);
  }

  /// Returns a map from parameter name to value, if the path matches the
  /// route pattern. Otherwise returns null.
  Map<String, String>? match(String path) {
    // Check if path matches the route pattern
    var m = _routePattern.firstMatch(path);
    if (m == null) {
      return null;
    }
    // Construct map from parameter name to matched value
    var params = <String, String>{};
    for (var i = 0; i < _params.length; i++) {
      // first group is always the full match, we ignore this group.
      params[_params[i]] = m[i + 1]!;
    }
    return params;
  }

  // invoke handler with given request and params
  Future<void> invoke(RequestContext request, ResponseContext response,
      Map<String, String> params) async {

        request.params.addAll(params);

    if (_middleware != null) {
      await _middleware!((request, response) async {
        await _handler(request, response);
      });
    } else {
      await _handler(request, response);
    }
  }
}

@sealed
class MyRouter {
  final List<RouterEntry> _routes = [];

  MyRouter();

  /// Add [handler] for [verb] requests to [route].
  ///
  /// If [verb] is `GET` the [handler] will also be called for `HEAD` requests
  /// matching [route]. This is because handling `GET` requests without handling
  /// `HEAD` is always wrong. To explicitely implement a `HEAD` handler it must
  /// be registered before the `GET` handler.
  void add(
    String verb,
    String route,
    Function handler, {
    MyMiddleware? middleware,
  }) {
    if (!isHttpMethod(verb)) {
      throw ArgumentError.value(verb, 'verb', 'expected a valid HTTP method');
    }
    verb = verb.toUpperCase();

    if (verb == 'GET') {
      // Handling in a 'GET' request without handling a 'HEAD' request is always
      // wrong, thus, we add a default implementation that discards the body.
      _routes.add(RouterEntry(
        'HEAD',
        route,
        handler,
        middleware: middleware,
      ));
    }
    _routes.add(RouterEntry(verb, route, handler));
  }

  /// Handle all request to [route] using [handler].
  void all(String route, Function handler) {
    _routes.add(RouterEntry('ALL', route, handler));
  }

  /// Route incoming requests to registered handlers.
  ///
  /// This method allows a Router instance to be a [Handler].
  Future call(RequestContext request, ResponseContext resp) async {
    // Note: this is a great place to optimize the implementation by building
    //       a trie for faster matching... left as an exercise for the reader :)

    for (var route in _routes) {
      if (route.verb != request.method.toUpperCase() && route.verb != 'ALL') {
        continue;
      }
      final path =
          request.path.startsWith('/') ? request.path : '/${request.path}';

      var params = route.match(path);

      if (params != null) {
        await route.invoke(request, resp, params);
      }
    }
  }

  // Handlers for all methods

  /// Handle `GET` request to [route] using [handler].
  ///
  /// If no matching handler for `HEAD` requests is registered, such requests
  /// will also be routed to the [handler] registered here.
  void get(String route, Function handler, {MyMiddleware? middleware}) =>
      add('GET', route, handler, middleware: middleware);

  /// Handle `HEAD` request to [route] using [handler].
  void head(String route, Function handler) => add('HEAD', route, handler);

  /// Handle `POST` request to [route] using [handler].
  void post(String route, Function handler) => add('POST', route, handler);

  /// Handle `PUT` request to [route] using [handler].
  void put(String route, Function handler) => add('PUT', route, handler);

  /// Handle `DELETE` request to [route] using [handler].
  void delete(String route, Function handler) => add('DELETE', route, handler);

  /// Handle `CONNECT` request to [route] using [handler].
  void connect(String route, Function handler) =>
      add('CONNECT', route, handler);

  /// Handle `OPTIONS` request to [route] using [handler].
  void options(String route, Function handler) =>
      add('OPTIONS', route, handler);

  /// Handle `TRACE` request to [route] using [handler].
  void trace(String route, Function handler) => add('TRACE', route, handler);

  /// Handle `PATCH` request to [route] using [handler].
  void patch(String route, Function handler) => add('PATCH', route, handler);
}
 dart ./bin/main.dart -p 3350 -a 0.0.0.0 -j 16

PS C:\MyDartProjects\dart_segment_fault> bombardier.exe  -c400 -d30s http://192.168.66.123:3350
Bombarding http://192.168.66.123:3350 for 30s using 400 connection(s)
[==================================================================================================================================================] 30s
Done!
Statistics        Avg      Stdev        Max
  Reqs/sec     22038.05   10444.21   58836.56
  Latency       18.41ms    13.21ms   658.06ms
  HTTP codes:
    1xx - 0, 2xx - 650939, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:     6.33MB/s
dukefirehawk commented 7 months ago

This is very helpful benchmark for tuning Angel3 performance.