Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

@Blocking on a standard grpc service run on a single thread #40155

Closed
nahguam opened this issue Apr 19, 2024 · 12 comments · Fixed by #40173
Closed

@Blocking on a standard grpc service run on a single thread #40155

nahguam opened this issue Apr 19, 2024 · 12 comments · Fixed by #40173
Labels
area/grpc gRPC kind/bug Something isn't working
Milestone

Comments

@nahguam
Copy link
Contributor

nahguam commented Apr 19, 2024

Describe the bug

If I implement a standard grpc service (not mutiny) and annotate it with @Blocking then requests are correctly dispatched to the core thread pool instead of the event loop. However, requests are always dispatched to the same core thread. This results in effectively only being able to process 1 request at a time.

I've tried increasing quarkus.thread-pool.core-threads but it is having no effect.

Expected behavior

Requests are dispatched to a new/free threads.

Actual behavior

Requests are dispatched to the same thread and queued.

How to Reproduce?

Create grpc starter app

Add proto:

syntax = "proto3";

option java_multiple_files = true;
option java_package = "org.acme";

package hello;

service StandardBlockingGrpcService {
  rpc Invoke (Request) returns (Response) {}
}

message Request {
  int32 id = 1;
}

message Response {
  int32 id = 1;
}

Add service implementation:

class GrpcServices {
  private static final Logger logger = LoggerFactory.getLogger(GrpcServices.class);

  @GrpcService
  @Blocking
  static class StandardBlocking extends StandardBlockingGrpcServiceImplBase {
    @Override
    public void invoke(Request request, StreamObserver<Response> responseObserver) {
      logger.info("start: {}", request.getId());
      try {
        Thread.sleep(Duration.ofSeconds(2).toMillis());
      } catch (InterruptedException e) {
        Thread.currentThread().interrupt();
        throw new RuntimeException(e);
      }
      responseObserver.onNext(Response.newBuilder().setId(request.getId()).build());
      responseObserver.onCompleted();
      logger.info("end: {}", request.getId());
    }
  }
}

Add test:

@QuarkusTest
class GrpcServicesTest {
  private static final Logger logger = LoggerFactory.getLogger(GrpcServicesTest.class);

  @GrpcClient
  StandardBlockingGrpcServiceBlockingStub standardBlocking;

  ExecutorService executor = Executors.newCachedThreadPool();

  @Test
  void standardBlockingTest() {
    var futures = IntStream.range(0, 5)
        .mapToObj(i -> CompletableFuture.runAsync(() -> standardBlocking(i), executor))
        .toArray(CompletableFuture[]::new);
    CompletableFuture.allOf(futures).join();
  }

  void standardBlocking(int id) {
    logger.info("start: {}", id);
    standardBlocking.invoke(Request.newBuilder().setId(id).build());
    logger.info("end: {}", id);
  }
}

Log output:

2024-04-19 12:53:53,209 WARN  [io.qua.grp.run.GrpcServerRecorder] (main) Using legacy gRPC support, with separate new HTTP server instance. Switch to single HTTP server instance usage with quarkus.grpc.server.use-separate-server=false property
2024-04-19 12:53:53,236 WARN  [io.qua.virtual-threads] (vert.x-eventloop-thread-0) You weren't able to create an executor that spawns virtual threads, the default blocking executor will be used, please check that your JDK is compatible with virtual threads
2024-04-19 12:53:53,273 INFO  [io.qua.grp.run.GrpcServerRecorder] (vert.x-eventloop-thread-1) Started gRPC server on 0.0.0.0:9001 [TLS enabled: false]
2024-04-19 12:53:53,294 INFO  [io.quarkus] (main) code-with-quarkus 1.0.0-SNAPSHOT on JVM (powered by Quarkus 3.6.9) started in 0.826s. Listening on: http://localhost:8081
2024-04-19 12:53:53,295 INFO  [io.quarkus] (main) Profile test activated. 
2024-04-19 12:53:53,295 INFO  [io.quarkus] (main) Installed features: [cdi, grpc-client, grpc-server, smallrye-context-propagation, vertx]
2024-04-19 12:53:53,300 INFO  [io.qua.grp.run.sup.Channels] (main) gRPC client standardBlocking created without configuration. We are assuming that it's created to test your gRPC services.
2024-04-19 12:53:53,304 INFO  [io.qua.grp.run.sup.Channels] (main) Creating Netty gRPC channel ...
2024-04-19 12:53:53,319 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-5) start: 4
2024-04-19 12:53:53,319 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-2) start: 1
2024-04-19 12:53:53,319 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-3) start: 2
2024-04-19 12:53:53,319 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-4) start: 3
2024-04-19 12:53:53,319 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-1) start: 0
2024-04-19 12:53:53,389 INFO  [org.acm.GrpcServices] (executor-thread-4) start: 4
2024-04-19 12:53:55,396 INFO  [org.acm.GrpcServices] (executor-thread-4) end: 4
2024-04-19 12:53:55,397 INFO  [org.acm.GrpcServices] (executor-thread-4) start: 1
2024-04-19 12:53:55,400 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-5) end: 4
2024-04-19 12:53:57,400 INFO  [org.acm.GrpcServices] (executor-thread-4) end: 1
2024-04-19 12:53:57,400 INFO  [org.acm.GrpcServices] (executor-thread-4) start: 3
2024-04-19 12:53:57,403 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-2) end: 1
2024-04-19 12:53:59,404 INFO  [org.acm.GrpcServices] (executor-thread-4) end: 3
2024-04-19 12:53:59,405 INFO  [org.acm.GrpcServices] (executor-thread-4) start: 0
2024-04-19 12:53:59,407 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-4) end: 3
2024-04-19 12:54:01,409 INFO  [org.acm.GrpcServices] (executor-thread-4) end: 0
2024-04-19 12:54:01,409 INFO  [org.acm.GrpcServices] (executor-thread-4) start: 2
2024-04-19 12:54:01,410 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-1) end: 0
2024-04-19 12:54:03,413 INFO  [org.acm.GrpcServices] (executor-thread-4) end: 2
2024-04-19 12:54:03,415 INFO  [org.acm.GrpcServicesTest] (pool-8-thread-3) end: 2
2024-04-19 12:54:03,438 INFO  [io.qua.grp.run.sup.Channels] (main) Shutting down gRPC channel ManagedChannelOrphanWrapper{delegate=ManagedChannelImpl{logId=4, target=dns:///0.0.0.0:9001}}
2024-04-19 12:54:03,446 INFO  [io.quarkus] (main) code-with-quarkus stopped in 0.019s

Output of uname -a or ver

Darwin -MacBook-Pro-16-inch-2023- 22.6.0 Darwin Kernel Version 22.6.0: Fri Sep 15 13:41:28 PDT 2023; root:xnu-8796.141.3.700.8~1/RELEASE_ARM64_T6020 arm64

Output of java -version

openjdk version "11.0.19" 2023-04-18 OpenJDK Runtime Environment Temurin-11.0.19+7 (build 11.0.19+7) OpenJDK 64-Bit Server VM Temurin-11.0.19+7 (build 11.0.19+7, mixed mode)

Quarkus version or git rev

3.6.9

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.9.6 (bc0240f3c744dd6b6ec2920b3cd08dcc295161ae) Maven home: /opt/homebrew/Cellar/maven/3.9.6/libexec Java version: 11.0.19, vendor: Eclipse Adoptium, runtime: /Library/Java/JavaVirtualMachines/temurin-11.jdk/Contents/Home Default locale: en_GB, platform encoding: UTF-8 OS name: "mac os x", version: "13.6", arch: "aarch64", family: "mac"

Additional information

No response

@nahguam nahguam added the kind/bug Something isn't working label Apr 19, 2024
@quarkus-bot quarkus-bot bot added the area/grpc gRPC label Apr 19, 2024
@quarkus-bot
Copy link

quarkus-bot bot commented Apr 19, 2024

/cc @alesj (grpc), @cescoffier (grpc)

cescoffier added a commit to cescoffier/quarkus that referenced this issue Apr 21, 2024
…bal ordering

Fix quarkusio#40155

Previously, the code utilized `executeBlocking` with `ordered=true` to maintain event order. However, this approach enforced global order instead of per-call order. This commit corrects the behavior, ensuring per-call order preservation using the BlockingExecutionHandler lock.
@cescoffier
Copy link
Member

Thanks for reporting. I've implemented a fix in #40173

@nahguam
Copy link
Contributor Author

nahguam commented Apr 22, 2024

Thanks, will this be backported to 3.6? (We're stuck on Java 11)

@jbonofre
Copy link

I think it should be backported to 3.6 as it's impactful issue. @cescoffier thoughts ?

@cescoffier
Copy link
Member

A bit of hardening time is needed before being considered for a backport.

There are workarounds (using a reactive messaging and dealing with the blocking part yourself)

@jbonofre
Copy link

@cescoffier do you want us to do a new pass on this ?

@nahguam
Copy link
Contributor Author

nahguam commented Apr 23, 2024

Thanka @cescoffier . Yes, this what we have done for now.

@gsmet
Copy link
Member

gsmet commented Apr 23, 2024

I think it should be backported to 3.6 as it's impactful issue. @cescoffier thoughts ?

3.6 is not a supported version. We won't publish any new 3.6 (we announced it quite some time ago already).

@gsmet
Copy link
Member

gsmet commented Apr 23, 2024

And while this particular issue might affect you, I would be more worried about the security fixes: 3.6 doesn't have any security fix applied.

You can either use 3.2 LTS, 3.8 LTS or latest.
I'm not entirely sure we would take the risk to backport this patch on 3.2 though. Definitely not without sufficient bake time as mentioned by @cescoffier .

@jbonofre
Copy link

@gsmet yeah, that's ok, thanks. I'm just wondering which LTS supports Java11 (that's why we are using Quarkus 3.6.x). We can't upgrade to 3.8.x as we are not Java17 ready yet.

@cescoffier
Copy link
Member

It's 3.2, and no, I don't believe we will backport this to 3.2. Lots of things have changed internally, I'm not sure it can be backported as it is.

@jbonofre
Copy link

Yeah, 3.2 is not an option for us as we need others fixes and improvements.

@quarkus-bot quarkus-bot bot added this to the 3.11 - main milestone Apr 24, 2024
zZHorizonZz added a commit to zZHorizonZz/quarkus-grpc-transcode that referenced this issue Apr 24, 2024
commit 4bfd3cc
Merge: 76744d6 cfcd5a3
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Wed Apr 24 14:31:22 2024 +0200

    Merge branch 'quarkusio:main' into grpc-transcoding

commit 76744d6
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Wed Apr 24 14:17:07 2024 +0200

    chore(transcoding): moved some generic methods to util classes

commit cfcd5a3
Merge: 4945eaa 288a54d
Author: Guillaume Smet <guillaume.smet@gmail.com>
Date:   Wed Apr 24 13:31:10 2024 +0200

    Merge pull request quarkusio#40218 from gastaldi/bump_http

    Bump Quarkus HTTP to 5.2.2.Final

commit 4945eaa
Merge: ea41b08 7d56d5d
Author: Sergey Beryozkin <sberyozkin@gmail.com>
Date:   Wed Apr 24 12:28:39 2024 +0100

    Merge pull request quarkusio#40211 from sberyozkin/bc_fips_test

    Add another BouncyCastle FIPS test

commit ea41b08
Merge: fae267b d3db508
Author: Yoann Rodière <yoann@hibernate.org>
Date:   Wed Apr 24 13:13:49 2024 +0200

    Merge pull request quarkusio#40238 from gsmet/run-if-wip

    Run CI when title starts with WIP

commit 82bde60
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Wed Apr 24 12:47:33 2024 +0200

    feat(transcoding): added http method check and code refactor

commit 44ac07c
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Wed Apr 24 12:01:25 2024 +0200

    feat(transcoding): added support for path parameter and query parameters

commit fae267b
Merge: 20ed823 618fbbd
Author: Yoann Rodière <yoann@hibernate.org>
Date:   Wed Apr 24 11:49:06 2024 +0200

    Merge pull request quarkusio#40235 from yrodiere/image-metrics-return

    When verifying image metrics, return all failures instead of just the first one

commit 3fe1e11
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Wed Apr 24 11:48:34 2024 +0200

    feat(transcoding): added support for path parameter and query parameters

commit 20ed823
Merge: fb4963a 6625d56
Author: Martin Kouba <mkouba@redhat.com>
Date:   Wed Apr 24 10:04:40 2024 +0200

    Merge pull request quarkusio#39233 from radcortez/mp-config-3.1

    Update MicroProfile Config to 3.1

commit d3db508
Author: Guillaume Smet <guillaume.smet@gmail.com>
Date:   Tue Apr 23 16:26:16 2024 +0200

    Run CI when title starts with WIP

    We introduced this check when draft PRs weren't a thing but nowadays,
    it's nice to be able to convey the fact that we don't want the PR to get
    merged but still want main CI to run.

commit 618fbbd
Author: Yoann Rodière <yoann@hibernate.org>
Date:   Wed Apr 24 08:58:41 2024 +0200

    When verifying image metrics, return all failures instead of just the first one

    Building a native image takes a lot of time, so it's quite frustrating to iterate on this and solve errors one by one. Better have all the information upfront.

commit fb4963a
Merge: eddc31b 4411438
Author: Yoann Rodière <yoann@hibernate.org>
Date:   Wed Apr 24 08:41:13 2024 +0200

    Merge pull request quarkusio#40230 from quarkusio/dependabot/maven/hibernate-orm.version-6.4.5.Final

    Bump hibernate-orm.version from 6.4.4.Final to 6.4.5.Final

commit eddc31b
Merge: 648de87 2a2bb84
Author: Clement Escoffier <clement@apache.org>
Date:   Wed Apr 24 08:32:59 2024 +0200

    Merge pull request quarkusio#40173 from cescoffier/grpc-concurrent-blocking-call

    Allow concurrent invocation of blocking gRPC services by removing global ordering

commit 648de87
Merge: 0efd81a c97b545
Author: Phillip Krüger <phillip.kruger@gmail.com>
Date:   Wed Apr 24 11:34:33 2024 +1000

    Merge pull request quarkusio#40228 from dgf/main

    Fixed order for default OpenAPI security responses

commit 4411438
Author: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Date:   Tue Apr 23 21:40:24 2024 +0000

    Bump hibernate-orm.version from 6.4.4.Final to 6.4.5.Final

    Bumps `hibernate-orm.version` from 6.4.4.Final to 6.4.5.Final.

    Updates `org.hibernate.orm:hibernate-core` from 6.4.4.Final to 6.4.5.Final
    - [Release notes](https://github.com/hibernate/hibernate-orm/releases)
    - [Changelog](https://github.com/hibernate/hibernate-orm/blob/6.4.5/changelog.txt)
    - [Commits](hibernate/hibernate-orm@6.4.4...6.4.5)

    Updates `org.hibernate.orm:hibernate-graalvm` from 6.4.4.Final to 6.4.5.Final
    - [Release notes](https://github.com/hibernate/hibernate-orm/releases)
    - [Changelog](https://github.com/hibernate/hibernate-orm/blob/6.4.5/changelog.txt)
    - [Commits](hibernate/hibernate-orm@6.4.4...6.4.5)

    Updates `org.hibernate.orm:hibernate-envers` from 6.4.4.Final to 6.4.5.Final
    - [Release notes](https://github.com/hibernate/hibernate-orm/releases)
    - [Changelog](https://github.com/hibernate/hibernate-orm/blob/6.4.5/changelog.txt)
    - [Commits](hibernate/hibernate-orm@6.4.4...6.4.5)

    Updates `org.hibernate.orm:hibernate-jpamodelgen` from 6.4.4.Final to 6.4.5.Final
    - [Release notes](https://github.com/hibernate/hibernate-orm/releases)
    - [Changelog](https://github.com/hibernate/hibernate-orm/blob/6.4.5/changelog.txt)
    - [Commits](hibernate/hibernate-orm@6.4.4...6.4.5)

    Updates `org.hibernate:hibernate-jpamodelgen` from 6.4.4.Final to 6.4.5.Final
    - [Release notes](https://github.com/hibernate/hibernate-orm/releases)
    - [Changelog](https://github.com/hibernate/hibernate-orm/blob/6.4.5/changelog.txt)
    - [Commits](hibernate/hibernate-orm@6.4.4...6.4.5)

    Updates `org.hibernate.orm:hibernate-community-dialects` from 6.4.4.Final to 6.4.5.Final
    - [Release notes](https://github.com/hibernate/hibernate-orm/releases)
    - [Changelog](https://github.com/hibernate/hibernate-orm/blob/6.4.5/changelog.txt)
    - [Commits](hibernate/hibernate-orm@6.4.4...6.4.5)

    ---
    updated-dependencies:
    - dependency-name: org.hibernate.orm:hibernate-core
      dependency-type: direct:production
      update-type: version-update:semver-patch
    - dependency-name: org.hibernate.orm:hibernate-graalvm
      dependency-type: direct:production
      update-type: version-update:semver-patch
    - dependency-name: org.hibernate.orm:hibernate-envers
      dependency-type: direct:production
      update-type: version-update:semver-patch
    - dependency-name: org.hibernate.orm:hibernate-jpamodelgen
      dependency-type: direct:production
      update-type: version-update:semver-patch
    - dependency-name: org.hibernate:hibernate-jpamodelgen
      dependency-type: direct:production
      update-type: version-update:semver-patch
    - dependency-name: org.hibernate.orm:hibernate-community-dialects
      dependency-type: direct:production
      update-type: version-update:semver-patch
    ...

    Signed-off-by: dependabot[bot] <support@github.com>

commit c97b545
Author: Danny Gräf <deep@dagnu.de>
Date:   Tue Apr 23 13:00:05 2024 +0100

    Fixed order for default OpenAPI security responses

commit 6625d56
Author: Roberto Cortez <radcortez@yahoo.com>
Date:   Wed Mar 6 16:53:16 2024 +0000

    Update MicroProfile Config to 3.1

commit 7d56d5d
Author: Sergey Beryozkin <sberyozkin@gmail.com>
Date:   Tue Apr 23 11:18:23 2024 +0100

    Add another BouncyCastle FIPS test

commit 288a54d
Author: George Gastaldi <gegastaldi@gmail.com>
Date:   Tue Apr 23 11:06:25 2024 -0300

    Bump Quarkus HTTP to 5.2.2.Final

commit 0efd81a
Merge: b09853f 8d8dc6e
Author: Yoann Rodière <yoann@hibernate.org>
Date:   Tue Apr 23 18:27:22 2024 +0200

    Merge pull request quarkusio#40214 from zakkak/2024-04-23-fix-webjar-locator-it

    Use new webjars-locator name in integration test

commit b09853f
Merge: af955bd 9e05bd9
Author: George Gastaldi <gegastaldi@gmail.com>
Date:   Tue Apr 23 12:48:55 2024 -0300

    Merge pull request quarkusio#40157 from Dairdevil/feature/fabric8-split-package-resolved

    Remove explicitly ignored split packages

commit 320a63f
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Tue Apr 23 14:30:51 2024 +0200

    feat(transcoding): initial version of complex paths

commit af955bd
Merge: a3d1568 469fd3a
Author: Sanne Grinovero <sanne@hibernate.org>
Date:   Tue Apr 23 13:16:39 2024 +0100

    Merge pull request quarkusio#40203 from stuartwdouglas/eager-classes

    Deprecate 'eager transformers'

commit 8d8dc6e
Author: Foivos Zakkak <fzakkak@redhat.com>
Date:   Tue Apr 23 14:33:39 2024 +0300

    Use new webjars-locator name in integration test

    Closes quarkusio#40213

commit f77df97
Merge: 2af788d a3d1568
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Tue Apr 23 12:49:53 2024 +0200

    Merge branch 'quarkusio:main' into grpc-transcoding

commit 469fd3a
Author: Stuart Douglas <stuart.w.douglas@gmail.com>
Date:   Tue Apr 23 17:29:37 2024 +1000

    Deprecate 'eager transformers'

    They have not done anything for a while and no longer make sense.

commit 2af788d
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Sun Apr 21 22:42:11 2024 +0200

    feat(transcoding): removed unnecessary code

commit 2a2bb84
Author: Clement Escoffier <clement.escoffier@gmail.com>
Date:   Sun Apr 21 16:17:25 2024 +0200

    Allow concurrent invocation of blocking gRPC services by removing global ordering

    Fix quarkusio#40155

    Previously, the code utilized `executeBlocking` with `ordered=true` to maintain event order. However, this approach enforced global order instead of per-call order. This commit corrects the behavior, ensuring per-call order preservation using the BlockingExecutionHandler lock.

commit 3e9ce41
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Sat Apr 20 12:56:40 2024 +0200

    feat(transcoding): removed unnecessary encoding

commit 817d9a0
Merge: 89fdbd5 914ae38
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Sat Apr 20 12:16:22 2024 +0200

    Merge branch 'refs/heads/main' into grpc-transcoding

commit 9e05bd9
Author: Alasdair Preston <apreston@redhat.com>
Date:   Fri Apr 19 14:35:59 2024 +0100

    Remove split package ignored list as no entries remain

commit 89fdbd5
Author: Daniel Fiala <danfiala23@gmail.com>
Date:   Fri Apr 19 09:48:15 2024 +0200

    chore(transcoding): cleanup
zZHorizonZz pushed a commit to zZHorizonZz/quarkus-grpc-transcode that referenced this issue Apr 24, 2024
…bal ordering

Fix quarkusio#40155

Previously, the code utilized `executeBlocking` with `ordered=true` to maintain event order. However, this approach enforced global order instead of per-call order. This commit corrects the behavior, ensuring per-call order preservation using the BlockingExecutionHandler lock.
poldinik pushed a commit to poldinik/quarkus that referenced this issue Apr 29, 2024
…bal ordering

Fix quarkusio#40155

Previously, the code utilized `executeBlocking` with `ordered=true` to maintain event order. However, this approach enforced global order instead of per-call order. This commit corrects the behavior, ensuring per-call order preservation using the BlockingExecutionHandler lock.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/grpc gRPC kind/bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants