Delta between DURATION and X-ENVOY-UPSTREAM-SERVICE-TIME for external calls

Networking
1

My team is using Istio 1.1.5. We noticed that there is a delta between the values for DURATION and the X-ENVOY-UPSTREAM-SERVICE-TIME header for calls to a mesh-external service, as logged by the application’s sidecar.

We have route rules in place to upgrade HTTP calls to the external service to HTTPS (with TLS origination):

apiVersion: networking.istio.io/v1alpha3
kind: ServiceEntry
metadata:
  name: service-with-tls-origination
  namespace: default
spec:
  hosts:
    - endpoint.service.com
  ports:
    - number: 30443
      name: http-port-for-tls-origination
      protocol: HTTP
  resolution: DNS
  location: MESH_EXTERNAL
  endpoints:
    - address: endpoint.service.com
      ports:
        https: 443
---
apiVersion: networking.istio.io/v1alpha3
kind: DestinationRule
metadata:
  name: originate-tls-for-service
  namespace: default
spec:
  host: endpoint.service.com
  subsets:
    - name: http-service-calls
      trafficPolicy:
        loadBalancer:
          simple: ROUND_ROBIN
        portLevelSettings:
          - port:
              number: 443
            tls:
              mode: SIMPLE 
  trafficPolicy:
    loadBalancer:
      simple: ROUND_ROBIN
    portLevelSettings:
      - connectionPool:
          tcp:
            connectTimeout: 500ms
        port:
          number: 443
---
apiVersion: networking.istio.io/v1alpha3
kind: ServiceEntry
metadata:
  name: service
  namespace: default
spec:
  hosts:
    - endpoint.service.com
  ports:
    - number: 443
      name: https
      protocol: HTTPS
  resolution: DNS
  location: MESH_EXTERNAL
---
apiVersion: networking.istio.io/v1alpha3
kind: VirtualService
metadata:
  name: tls-for-service
spec:
  hosts:
    - endpoint.service.com
  http:
    - match:
        - port: 30443
      route:
        - destination:
            subset: http-service-calls
            host: endpoint.service.com
            port:
              number: 443
          weight: 100

Here is a sample access log:

[2019-12-02T20:49:46.044Z] "POST / HTTP/1.1" 200 - "-" 300 900 33 29 "-" "node-fetch/1.0 (+https://github.com/bitinn/node-fetch)" "51f3541a-c9da-43a2-b899-ffff4523cfab" "endpoint.service.com:30443" "10.0.61.83:443" outbound|443|http-service-calls|endpoint.service.com - 10.0.40.84:30443 10.0.86.185:50154 -

As seen in the above sample log, the value for DURATION is 33ms and X-ENVOY-UPSTREAM-SERVICE-TIME is 29ms. Can we get some insight into why these values are different, or where to look to find a source of the delta?

Thanks,
Collin

2

I am also interested in a more detailed description of how X-ENVOY-UPSTREAM-SERVICE-TIME is to be read in Istio context and compared to, for example, numbers found in Prometheus.