React Storefront
|

Debugging Performance

All requests served by the Moovweb XDN contain a response header called x-moov-t, which contains the time the request took at every layer of the Moovweb stack. This can be extremely helpful when diagnosing performance issues.

x-moov-t

Order is important: Values are prepended at response time. So reading them left to right goes from the outermost edge (e.g. Fastly) to innermost component (e.g. moovworker.)

The format is x-moov-t: <id>=<time>[,<id2>=<time2>...

Components

What are the components involved?

  • Outer Edge = o
  • Outer Edge Shield = s
  • Inner Edge Worker = e
  • Inner Edge NGINX = n
  • Inner Edge Varnish = v
  • MPS = m
  • MoovWorker = w

Keys

All times are in milliseconds.

Here is an example of the header:

x-moov-t: ot=180,oc=miss,st=170,sc=miss,nt=168,ep=5,et=165,vt=160,vc=miss,vf=144,mt=143,mu=133,wt=127,wu=113,wp=12,wc=2

If there is a cache hit, we do not report the remaining metrics

x-moov-t: ot=10,oc=hit
x-moov-t: ot=12,oc=miss,st=2,sc=hit
x-moov-t: ot=14,oc=miss,st=12,sc=miss,nt=2,vc=hit

Moovworker

  • wt = Total time (including wp)
  • wm = Time of longest upstream request that was completed
  • wp = Time executing JavaScript code in user request and response
  • wc = Count of upstream requests that completed (Note: This is not a time, but a count)

To get the total time spent waiting for upstream requests to complete, subtract wp from wt.

MPS

  • mt = Total time (including mu)
  • mu = Time waiting for upstream (not included if upstream is skipped)
  • mp = Time executing user Tritium project code time (not included if Tritium is not executed)
  • mb = Time waiting for associated BLOB to be fetched (not included if there is no associated BLOB)

Inner Edge Varnish

  • vt = Total time (including vf)
  • vf = Time waiting for upstream
  • vc = Cache action - hit, cached, miss or pass

Inner Edge NGINX

  • nt = Total time waiting for upstream (in seconds)

Outer Edge Varnish

  • ot = Total time (including of)
  • of = Total time waiting for upstream
  • oc = Cache action - hit, cached, miss or pass
  • bd = Time spent on bot detection

Shield Outer Edge Varnish

  • st = Total time (including sf)
  • sf = Total time waiting for upstream
  • sc = Cache action - hit, cached, miss or pass

Common Outer Edge Varnish

  • bf = Total time waiting for inner edge upstream (stands for "backend fetch")

Cache Action

Cache action can be one of the following values:

  • hit - The request checked the cache and found the page. The response was served from the cache.
  • cached - The request checked the cache and did not find the page. The response was served from the upstream and stored in the cache.
  • miss - The request checked the cache and did not find the page. The response was served from the upstream and not stored in the cache. E.g. set-cookie found in response.
  • pass - The request did not check the cache. The response was served from the upstream. e.g. ?moov_debug found in request or POST request.

Additional Notes

The timing stats from Fastly are a .vcl variable %{time.elapsed.usec}V are in microseconds. For cache hits we should not log the metrics at all as they would just skew the data (we would have to exclude all such metrics from composite metrics) and add unnecessary cost to our logging space.