First call to grpc server is very slow

[btxlittle]

I just write a demo to use grpc with worker pool, the first call was very slow, it almost need couple seconds to get the response

version: "3"
server:
  command: "php roadrunner.php"
grpc:
  listen: "tcp://:50051"
  proto:
    - "grpc.proto"
  pool:
    debug: false
    num_workers: 2
    max_jobs: 10
    allocate_timeout: 60s
    reset_timeout: 60s
    destroy_timeout: 60s
reload:
  interval: 10s
  patterns: [ ".php" ]
logs:
  level: debug
  mode: production

<?php
require_once  __DIR__ . '/vendor/autoload.php';
use GameGrpcServer\Processor\GrpcProcessorInterface;
use GameGrpcServer\Processor\Request;
use GameGrpcServer\Processor\Response;
use Spiral\RoadRunner\GRPC\Invoker;
use Spiral\RoadRunner\GRPC\Server;
use Spiral\RoadRunner\Worker;
final class Processor implements GrpcProcessorInterface
{
    public function Process(\Spiral\RoadRunner\GRPC\ContextInterface $ctx, Request $in): Response
    {
        echo "Processing request: " . $in->getParams() . PHP_EOL;
        return new Response(['message' => $in->getParams()]);
    }
}
$server = new Server(new Invoker(), [
    'debug' => false, // optional (default: false)
]);

$server->registerService(GrpcProcessorInterface::class, new Processor());

$server->serve(Worker::create());

debug logs

{"level":"info","ts":1772431497627411683,"logger":"server","msg":"Processing request: consequat minim\n"}

{"level":"debug","ts":1772431497827983961,"logger":"server","msg":"req-resp mode","pid":1333}

{"level":"debug","ts":1772431497828040874,"logger":"grpc","msg":"method was called successfully","method":"/GrpcProcessor.GrpcProcessor/Process","start":1772431497136599571,"elapsed":691}

{"level":"info","ts":1772431504569466455,"logger":"server","msg":"Processing request: consequat minim\n"}

{"level":"debug","ts":1772431504628993430,"logger":"server","msg":"req-resp mode","pid":1332}

{"level":"debug","ts":1772431504629113674,"logger":"grpc","msg":"method was called successfully","method":"/GrpcProcessor.GrpcProcessor/Process","start":1772431502118976206,"elapsed":2510}

{"level":"info","ts":1772431507564701077,"logger":"server","msg":"Processing request: consequat minim\n"}

{"level":"debug","ts":1772431507564814947,"logger":"server","msg":"req-resp mode","pid":1333}

{"level":"debug","ts":1772431507564851978,"logger":"grpc","msg":"method was called successfully","method":"/GrpcProcessor.GrpcProcessor/Process","start":1772431507564264103,"elapsed":0}

{"level":"info","ts":1772431509468753749,"logger":"server","msg":"Processing request: consequat minim\n"}

{"level":"debug","ts":1772431509468854273,"logger":"server","msg":"req-resp mode","pid":1332}

{"level":"debug","ts":1772431509468885075,"logger":"grpc","msg":"method was called successfully","method":"/GrpcProcessor.GrpcProcessor/Process","start":1772431509468472962,"elapsed":0}

[rustatian]

Hey @btxlittle 👋🏻
There is no reload plugin. If that is not something custom, where did you get that configuration? Also, what is your RR version?

Related to the performance, try to use a simple sample worker without any of your code, simply some string response, and then check the timings. Because RR simply passes requests to the worker. All these lags are likely related to something in your PHP code. Try to debug/profile it.

[rauanmayemir]

@btxlittle This has to be php app.php warming up (tokenizer, cycle schema warm up).
Try to warm up PHP cache before booting roadrunner. Use something like:

TOKENIZER_CACHE_TARGETS=true
CYCLE_SCHEMA_WARMUP=true
TOKENIZER_LOAD_INTERFACES=true
TOKENIZER_LOAD_ENUMS=true

[btxlittle]

When i installed the protobuf extension, the first call turned to 20ms