search

grpc / grpc-java

The Java gRPC implementation. HTTP/2 based RPC
https://grpc.io/docs/languages/java/
Apache License 2.0
11.46k stars 3.85k forks source link

Spring boot with GRPC server blocking GRPC client request #10940

Closed ValeriyDolgov closed 8 months ago

ValeriyDolgov commented 8 months ago

I have Spring boot app v.3.2.1 and GRPC server and client in one app. Initially, when I wrote the service, I only had a GRPC client. Everything worked well until the moment when I added a GRPC server to the same service. After adding it, requests to the GRPC server are successful, but when trying to make a request through the GRPC client, the request simply freezes.

Dependencies i have in pom.xml

<dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-data-jpa</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>

        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
            <optional>true</optional>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-validation</artifactId>
        </dependency>
        <dependency>
            <groupId>org.flywaydb</groupId>
            <artifactId>flyway-core</artifactId>
            <version>9.22.0</version>
        </dependency>
        <dependency>
            <groupId>org.postgresql</groupId>
            <artifactId>postgresql</artifactId>
            <version>42.7.1</version>
        </dependency>
        <dependency>
            <groupId>org.springdoc</groupId>
            <artifactId>springdoc-openapi-starter-webmvc-ui</artifactId>
            <version>2.2.0</version>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-security</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.security</groupId>
            <artifactId>spring-security-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>net.devh</groupId>
            <artifactId>grpc-client-spring-boot-starter</artifactId>
            <version>2.15.0.RELEASE</version>
        </dependency>
        <dependency>
            <groupId>net.devh</groupId>
            <artifactId>grpc-server-spring-boot-starter</artifactId>
            <version>2.15.0.RELEASE</version>
        </dependency>
        <dependency>
            <groupId>io.grpc</groupId>
            <artifactId>grpc-stub</artifactId>
            <version>${grpc.version}</version>
        </dependency>
        <dependency>
            <groupId>io.grpc</groupId>
            <artifactId>grpc-protobuf</artifactId>
            <version>${grpc.version}</version>
        </dependency>
        <dependency>
            <groupId>io.grpc</groupId>
            <artifactId>grpc-netty</artifactId>
            <version>${grpc.version}</version>
        </dependency>
        <dependency>
            <groupId>javax.annotation</groupId>
            <artifactId>javax.annotation-api</artifactId>
            <version>1.3.1</version>
        </dependency>
        <dependency>
            <groupId>org.mapstruct</groupId>
            <artifactId>mapstruct</artifactId>
            <version>${mapstruct.version}</version>
        </dependency>
        <dependency>
            <groupId>org.testcontainers</groupId>
            <artifactId>postgresql</artifactId>
            <version>${testcontainers.version}</version>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.testcontainers</groupId>
            <artifactId>junit-jupiter</artifactId>
            <version>${testcontainers.version}</version>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>io.grpc</groupId>
            <artifactId>grpc-testing</artifactId>
            <version>1.61.0</version>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.hibernate.orm</groupId>
            <artifactId>hibernate-jpamodelgen</artifactId>
            <version>${jpamodelgen.version}</version>
            <scope>provided</scope>
        </dependency>
    </dependencies>

    <build>
        <extensions>
            <extension>
                <groupId>kr.motd.maven</groupId>
                <artifactId>os-maven-plugin</artifactId>
                <version>1.7.0</version>
            </extension>
        </extensions>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
                <configuration>
                    <excludes>
                        <exclude>
                            <groupId>org.projectlombok</groupId>
                            <artifactId>lombok</artifactId>
                        </exclude>
                    </excludes>
                </configuration>
            </plugin>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <configuration>
                    <annotationProcessorPaths>
                        <path>
                            <groupId>org.projectlombok</groupId>
                            <artifactId>lombok</artifactId>
                            <version>${lombok.version}</version>
                        </path>
                        <path>
                            <groupId>org.mapstruct</groupId>
                            <artifactId>mapstruct-processor</artifactId>
                            <version>${mapstruct.version}</version>
                        </path>
                        <path>
                            <groupId>org.hibernate</groupId>
                            <artifactId>hibernate-jpamodelgen</artifactId>
                            <version>${jpamodelgen.version}</version>
                        </path>
                    </annotationProcessorPaths>
                </configuration>
            </plugin>
            <plugin>
                <groupId>org.xolstice.maven.plugins</groupId>
                <artifactId>protobuf-maven-plugin</artifactId>
                <version>0.6.1</version>
                <configuration>
                    <protocArtifact>com.google.protobuf:protoc:${protobuf.version}:exe:${os.detected.classifier}</protocArtifact>
                    <pluginId>grpc-java</pluginId>
                    <pluginArtifact>io.grpc:protoc-gen-grpc-java:${grpc.version}:exe:${os.detected.classifier}</pluginArtifact>
                </configuration>
                <executions>
                    <execution>
                        <goals>
                            <goal>compile</goal>
                            <goal>compile-custom</goal>
                        </goals>
                    </execution>
                </executions>
            </plugin>
        </plugins>
    </build>

Applcation.yaml

spring:
  main:
    banner-mode: off
  datasource:
    driverClassName: org.postgresql.Driver
    url: jdbc:postgresql://localhost:5432/postgres?prepareThreshold=0
    username: user
    password: postgres
  jpa:
    generate-ddl: false
    hibernate:
      ddl-auto: none
  flyway:
    enabled: true

server:
  port: 8081

grpc:
  client:
    account-grpc-server:
      address: static://localhost:8080
      enableKeepAlive: true
      keepAliveWithoutCalls: true
      negotiationType: plaintext
  server:
    port: 8082

logging:
  level:
    root: trace
    grpc: trace

In logs due request i have

2024-02-20T21:39:08.645+06:00 DEBUG 22556 --- [nio-8081-exec-1] io.grpc.ChannelLogger                    : [Channel<1>: (static://localhost:8080)] Exiting idle mode
2024-02-20T21:39:08.651+06:00 DEBUG 22556 --- [nio-8081-exec-1] io.grpc.util.MultiChildLoadBalancer      : Created
2024-02-20T21:39:08.652+06:00 TRACE 22556 --- [nio-8081-exec-1] io.grpc.ChannelLogger                    : [Channel<1>: (static://localhost:8080)] Resolved address: [[[localhost/127.0.0.1:8080]/{}]], config={io.grpc.internal.RetryingNameResolver.RESOLUTION_RESULT_LISTENER_KEY=io.grpc.internal.RetryingNameResolver$ResolutionResultListener@4dd6799c}
2024-02-20T21:39:08.652+06:00 DEBUG 22556 --- [nio-8081-exec-1] io.grpc.ChannelLogger                    : [Channel<1>: (static://localhost:8080)] Address resolved: [[[localhost/127.0.0.1:8080]/{}]]
2024-02-20T21:39:08.658+06:00 DEBUG 22556 --- [nio-8081-exec-1] io.grpc.Context                          : Storage override doesn't exist. Using default

java.lang.ClassNotFoundException: io.grpc.override.ContextStorageOverride
    at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:641) ~[na:na]
    at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188) ~[na:na]
    at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:525) ~[na:na]
    at java.base/java.lang.Class.forName0(Native Method) ~[na:na]
    at java.base/java.lang.Class.forName(Class.java:375) ~[na:na]
    at io.grpc.Context$LazyStorage.createStorage(Context.java:129) ~[grpc-api-1.59.0.jar:1.59.0]
    at io.grpc.Context$LazyStorage.<clinit>(Context.java:118) ~[grpc-api-1.59.0.jar:1.59.0]
    at io.grpc.Context.storage(Context.java:106) ~[grpc-api-1.59.0.jar:1.59.0]
    at io.grpc.Context.current(Context.java:172) ~[grpc-api-1.59.0.jar:1.59.0]
    at io.grpc.internal.ClientCallImpl.<init>(ClientCallImpl.java:122) ~[grpc-core-1.59.0.jar:1.59.0]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-10.1.17.jar:10.1.17]
    at java.base/java.lang.Thread.run(Thread.java:840) ~[na:na]

2024-02-20T21:39:09.280+06:00 DEBUG 22556 --- [nio-8081-Poller] org.apache.tomcat.util.net.NioEndpoint   : timeout completed: keys processed=1; now=1708443549280; nextExpiration=1708443548904; keyCount=0; hasEvents=false; eval=false
2024-02-20T21:39:09.911+06:00 DEBUG 22556 --- [5)-172.20.10.14] sun.rmi.transport.tcp                    : RMI TCP Connection(5)-172.20.10.14: accepted socket from [172.20.10.14:62195]

I try to make requests locally, but i didn't help.

Update: I add deadline for this request:

try {
            return accountServiceBlockingStub.withDeadlineAfter(5, TimeUnit.SECONDS)
                                             .setAccountsForMerchant(getAccountBasicRequest(requestId, merchantId, contractFee));
        } catch (Exception e) {
            var message = String.format("Error when getting response from account-service: %s", e.getMessage());
            log.error(message, e);

            throw new AccountServiceResponseException(messageService.getMessage(ACCOUNT_SERVICE_NOT_AVAILABLE), 400);
        }

After passing 5 seconds I received the following logs after the ones I sent earlier. 

2024-02-21T09:04:51.670+06:00 DEBUG 1976 --- [nio-8099-Poller] org.apache.tomcat.util.net.NioEndpoint   : timeout completed: keys processed=1; now=1708484691669; nextExpiration=1708484691664; keyCount=0; hasEvents=false; eval=false
2024-02-21T09:04:52.684+06:00 DEBUG 1976 --- [nio-8099-Poller] org.apache.tomcat.util.net.NioEndpoint   : timeout completed: keys processed=1; now=1708484692684; nextExpiration=1708484692669; keyCount=0; hasEvents=false; eval=false
2024-02-21T09:04:53.699+06:00 DEBUG 1976 --- [nio-8099-Poller] org.apache.tomcat.util.net.NioEndpoint   : timeout completed: keys processed=1; now=1708484693699; nextExpiration=1708484693684; keyCount=0; hasEvents=false; eval=false
2024-02-21T09:04:54.709+06:00 DEBUG 1976 --- [nio-8099-Poller] org.apache.tomcat.util.net.NioEndpoint   : timeout completed: keys processed=1; now=1708484694709; nextExpiration=1708484694699; keyCount=0; hasEvents=false; eval=false
2024-02-21T09:04:55.721+06:00 DEBUG 1976 --- [nio-8099-Poller] org.apache.tomcat.util.net.NioEndpoint   : timeout completed: keys processed=1; now=1708484695721; nextExpiration=1708484695709; keyCount=0; hasEvents=false; eval=false
2024-02-21T09:04:55.872+06:00 ERROR 1976 --- [nio-8099-exec-8] k.p.m.service.grpc.AccountService        : Error when getting response from account-service: DEADLINE_EXCEEDED: deadline exceeded after 4.794824000s. Name resolution delay 0.000000000 seconds. [closed=[], open=[[buffered_nanos=4802324400, waiting_for_connection]]]

io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: deadline exceeded after 4.794824000s. Name resolution delay 0.000000000 seconds. [closed=[], open=[[buffered_nanos=4802324400, waiting_for_connection]]]
    at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:268) ~[grpc-stub-1.59.0.jar:1.59.0]
    at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:249) ~[grpc-stub-1.59.0.jar:1.59.0]
    at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:167) ~[grpc-stub-1.59.0.jar:1.59.0]
    at kz.paspay.paspayledgerservice.grpc.AccountServiceGrpc$AccountServiceBlockingStub.setAccountsForMerchant(AccountServiceGrpc.java:358) ~[classes/:na]
    at kz.paspay.merchantserviceinner.service.grpc.AccountService.setAccountsForMerchant(AccountService.java:30) ~[classes/:na]
    at kz.paspay.merchantserviceinner.service.MerchantService.createAccounts(MerchantService.java:185) ~[classes/:na]
    at kz.paspay.merchantserviceinner.service.MerchantService.createMerchant(MerchantService.java:69) ~[classes/:na]
    ...

2024-02-21T09:04:55.886+06:00 TRACE 1976 --- [nio-8099-exec-8] o.s.t.i.TransactionInterceptor           : Completing transaction for [kz.paspay.merchantserviceinner.service.MerchantService.createMerchant] after exception: AccountServiceResponseException(code=400)
2024-02-21T09:04:55.886+06:00 DEBUG 1976 --- [nio-8099-exec-8] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction rollback
ejona86 commented 8 months ago

Cross-linking: https://stackoverflow.com/questions/78028717/spring-boot-with-grpc-server-blocking-grpc-client-request