snowdrop-zen / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
1 stars 0 forks source link

MP RestClient timeouts not honoured in Quarkus 1.6 #141

Closed snowdrop-bot closed 4 years ago

snowdrop-bot commented 4 years ago

Describe the bug

I am using the MP RestClient for some remote calls

I have set timeouts in application.properties for connection and then the remote read:

rbac/mp-rest/connectTimeout=1000
rbac/mp-rest/readTimeout=1000

With Quarkus 1.5.1.Final, those are (more or less) honored:

2020-07-20 11:24:06,426 INFO  [RbacFilter] (executor-thread-1) Timeout calling RBAC
2020-07-20 11:24:06,434 WARNING [RbacFilter] (executor-thread-1) Call to RBAC took 1977ms

Quarkus 1.6 does not abort the call after the expected 2s (2*1000ms) as 1.5 does, but seems to have a different timeout impl:

2020-07-20 11:29:14,294 INFO  [RbacFilter] (executor-thread-1) Timeout calling RBAC
2020-07-20 11:29:14,300 WARNING [RbacFilter] (executor-thread-1) Call to RBAC took 4998ms

Code is like in #10804

  @Inject
  @RestClient
  RbacServer rbac;

  [...]

    long t1 = System.currentTimeMillis();
    try {
      result = getRbacInfo(user.getRawRhIdHeader());
    } catch (Throwable e) {
      if (e.getCause()!= null && e.getCause() instanceof SocketTimeoutException) {
        log.info("Timeout calling RBAC");
      }
      requestContext.abortWith(Response.status(Response.Status.FORBIDDEN).build());
      return;
    } finally {
      long t2 = System.currentTimeMillis();
      if (warnSlowRbac.get() && (t2 - t1) > 500) {
        log.warning("Call to RBAC took " + (t2 - t1) + "ms");
      }
    }

//  @CacheResult(cacheName = "rbac-cache")   // <<-- disabled on purpose
  RbacRaw getRbacInfo(String xrhidHeader)  {
    RbacRaw result;
    result = rbac.getRbacInfo("policies", xrhidHeader);
    return result;
  }

Expected behaviour

Configured timeouts are honored like in Quarkus 1.5 and earlier


https://github.com/quarkusio/quarkus/issues/10846


$upstream:10846$