I am making gRPC calls from a java service, and using withDeadlineAfter(1000, TimeUnit.MILLISECONDS).callApi()
This call times out in most cases (DEADLINE_EXCEEDED). When I checked the logs, it looks as follows
2019-06-14 06:30:09.153 +0000 - [DEBUG] - from io.grpc.internal.ClientCallImpl - Call timeout set to '999861860' ns, due to context deadline. Explicit call timeout was not set.
2019-06-14 06:30:09.909 +0000 - [ERROR] - from application - [ epoch=1560493809909 req=1560493808679.df7ns.10.0.3.96 ] - EVENT_MIGRATION:Failed to create channel: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: deadline exceeded after 999695013ns
If I understand correctly, deadline was set at time 06:30:09.153 for the 1 second after 09.153, effectively meaning that the call with the stub should fail after 10.153. The Exception was thrown way before this registered time.
Can someone please explain the behavior?