# cmd/networktime #

networktime analyzes timings of a service with a particular eye
towards understanding time lost to the network (as opposed to time
spent servicing calls). It runs off of the live stream of data
provided by the Trace API and can be run to analyze calls involving
any Trace-instrumented service which calls other Trace-instrumented
services.

# usage #

networktime is a command-line application:

```
Usage of ./networktime:
	-sample float
		Sampling rate (default 0.1)
	-server string
		The hostport of the trace API server (default "trace-api.prod.us-west2.justin.tv:11143")
	-svc string
		The service to analyze (default "code.justin.tv/web/web")
	-t duration
	How long to capture data before returning a result (default 1s)
```

# output #

The ouput is a wall of text:
```
./networktime -server trace-api.prod.us-west2.justin.tv:11143 -svc code.justin.tv/web/web -sample 0.1 -t 60s
2015/09/30 14:02:00 turning on signal handling

		cross	within 	total
txs		9168	38370	47538
	client
	p50	79ms	16ms	24ms
	p75	127ms	37ms	58ms
	p90	235ms	99ms	136ms
	p95	343ms	170ms	215ms
	p99	779ms	493ms	583ms
	p999	1.222s	1.105s	1.196s

	service
	p50	230ms	61ms	79ms
	p75	371ms	107ms	164ms
	p90	542ms	201ms	325ms
	p95	722ms	329ms	476ms
	p99	1.035s	731ms	894ms
	p999	2.247s	1.775s	2.083s

	network
	p50	74ms	16ms	23ms
	p75	112ms	36ms	53ms
	p90	200ms	96ms	127ms
	p95	288ms	165ms	199ms
	p99	748ms	484ms	534ms
	p999	1.067s	1.081s	1.165s

calls		9302	259330	268632
	client
	p50	30ms	3ms	4ms
	p75	33ms	7ms	8ms
	p90	58ms	16ms	22ms
	p95	82ms	28ms	32ms
	p99	179ms	97ms	106ms
	p999	364ms	416ms	414ms

	service
	p50	2ms	0	0
	p75	3ms	1ms	0
	p90	4ms	121ms	68ms
	p95	5ms	205ms	145ms
	p99	141ms	41ms	436ms
	p999	162ms	505ms	1.005s

	network
	p50	28ms	3ms	3ms
	p75	29ms	7ms	8ms
	p90	52ms	15ms	21ms
	p95	65ms	28ms	30ms
	p99	121ms	100ms	96ms
	p999	317ms	424ms	415ms

roots		9168	38370	47538
	total service time
	p50	223ms	62ms	78ms
	p75	335ms	105ms	164ms
	p90	538ms	201ms	312ms
	p95	706ms	337ms	470ms
	p99	995ms	744ms	881ms
	p999	1.863s	1.452s	1.62s

services touched:
	code.justin.tv/chat/tmi/clue
	code.justin.tv/chat/tmi/irc
	code.justin.tv/chat/tmi/pubsub
	code.justin.tv/video/usher/api/usher
	code.justin.tv/web/cohesion/cmd/cohesion
	code.justin.tv/web/discovery
	code.justin.tv/web/jax/core
	code.justin.tv/web/web

datacenters touched:
	sfo01
	unknown
	us-west2

cross-dc services:
	code.justin.tv/web/cohesion/cmd/cohesion
	code.justin.tv/web/discovery
```

Let's break this down:

## header and counts ##
```
		cross	within 	total
txs		9168	38370	47538

```

This is showing information on full Transactions ('txs' in Trace
jargon) which involved code.justin.tv/web/web. Results are split into 3 columns:

 - `cross` describes cross-datacenter transactions: ones which
   originated in one cluster, then had a call anywhere along the way
   that was in a different datacenter.
 - `within` describes transactions that stayed within the same
   datacenter the whole time.
 - `total` describes all transactions observed over the time window
   (here, a 20s slice).

The first row of data shows counts: there were 9,168 cross-datacenter
transactions, 38,370 within-datacenter transactions, which makes
47,538 total.

## timings ##

Below that is a table of `client` timings:

```
	client
	p50	79ms	16ms	24ms
	p75	127ms	37ms	58ms
	p90	235ms	99ms	136ms
	p95	343ms	170ms	215ms
	p99	779ms	493ms	583ms
	p999	1.222s	1.105s	1.196s

```

These are the total amount of time clients spent waiting for
responses from servers. That's kind of a slippery concept, so just to
be clear: a transaction might fan out to 5 services in parallel, and
might have to wait 100ms for each response. While the wall-clock time
that this takes is 100ms (because they are in parallel), we'd show
`500ms` here.

The timings are in rows based on their percentile. The percentile is
slightly approximated.

Continuing down:

```
	service
	p50	230ms	61ms	79ms
	p75	371ms	107ms	164ms
	p90	542ms	201ms	325ms
	p95	722ms	329ms	476ms
	p99	1.035s	731ms	894ms
	p999	2.247s	1.775s	2.083s

	network
	p50	74ms	16ms	23ms
	p75	112ms	36ms	53ms
	p90	200ms	96ms	127ms
	p95	288ms	165ms	199ms
	p99	748ms	484ms	534ms
	p999	1.067s	1.081s	1.165s

```

Two more classes of timings are here: `service` timings, which so how
long services spent computing responses for clients, and `network`,
which shows the total _difference_ in service and client timings.

The network one is the main one this tool is focused on, but all the
timings may be useful. Looking here, it's pretty clear that the
cross-datacenter transactions have a dramatically higher median time
spent in network, but it flattens out as you hit the 99.9th
percentile.

## calls ##

```
calls		9302	259330	268632
	client
	p50	30ms	3ms	4ms
	p75	33ms	7ms	8ms
	p90	58ms	16ms	22ms
	p95	82ms	28ms	32ms
	p99	179ms	97ms	106ms
	p999	364ms	416ms	414ms

	service
	p50	2ms	0	0
	p75	3ms	1ms	0
	p90	4ms	121ms	68ms
	p95	5ms	205ms	145ms
	p99	141ms	41ms	436ms
	p999	162ms	505ms	1.005s

	network
	p50	28ms	3ms	3ms
	p75	29ms	7ms	8ms
	p90	52ms	15ms	21ms
	p95	65ms	28ms	30ms
	p99	121ms	100ms	96ms
	p999	317ms	424ms	415ms

```

The same information is repeated for `calls`, which are the individual
request/response RPCs that make up transactions. Looking at `calls`,
it becomes more clear what the single-request round-trip cost is - and
in this case, it becomes obvious that the network time is much larger
than the time to service the call for cross-datacenter calls.

## roots ##

```
roots		9168	38370	47538
	total service time
	p50	223ms	62ms	78ms
	p75	335ms	105ms	164ms
	p90	538ms	201ms	312ms
	p95	706ms	337ms	470ms
	p99	995ms	744ms	881ms
	p999	1.863s	1.452s	1.62s
    ```

The `roots` of the transactions are the base calls - the calls from
the end-user, typically, like landing on a channel page.

The timings here, then, show the total timing as it affects end users.

Be careful about interpreting this too strongly: in this case, it
looks like the cross-datacenter calls have a dramatic impact on
end-user performance, but the services which exist in other
datacenters might just be different and might have a harder workload.


## service and datacenter lists ##
```
services touched:
	code.justin.tv/chat/tmi/clue
	code.justin.tv/chat/tmi/irc
	code.justin.tv/chat/tmi/pubsub
	code.justin.tv/video/usher/api/usher
	code.justin.tv/web/cohesion/cmd/cohesion
	code.justin.tv/web/discovery
	code.justin.tv/web/jax/core
	code.justin.tv/web/web

datacenters touched:
	sfo01
	unknown
	us-west2

cross-dc services:
	code.justin.tv/web/cohesion/cmd/cohesion
	code.justin.tv/web/discovery
```

Finally, at the bottom, we've got a list of all services that the
input service is related to, a list of all datacenters that were
touched, and a list of the services which were involved in cross-dc
calls.
