veyron/tools/debug: Add vtrace support to the debug client command.
Change-Id: I47c89b02ac6e42c6e3329609fe2550c2a342fe96
diff --git a/runtimes/google/vtrace/store.go b/runtimes/google/vtrace/store.go
index f70dc2a..7ab0a0a 100644
--- a/runtimes/google/vtrace/store.go
+++ b/runtimes/google/vtrace/store.go
@@ -62,7 +62,7 @@
s.mu.Lock()
defer s.mu.Unlock()
- out := make([]vtrace.TraceRecord, s.size)
+ out := make([]vtrace.TraceRecord, len(s.traces))
i := 0
for _, ts := range s.traces {
ts.traceRecord(&out[i])
diff --git a/services/mgmt/debug/dispatcher_test.go b/services/mgmt/debug/dispatcher_test.go
index 2d9236b..f49afd2 100644
--- a/services/mgmt/debug/dispatcher_test.go
+++ b/services/mgmt/debug/dispatcher_test.go
@@ -13,13 +13,15 @@
"time"
"veyron.io/veyron/veyron2"
+ "veyron.io/veyron/veyron2/context"
"veyron.io/veyron/veyron2/ipc"
"veyron.io/veyron/veyron2/naming"
"veyron.io/veyron/veyron2/rt"
"veyron.io/veyron/veyron2/services/mgmt/logreader"
"veyron.io/veyron/veyron2/services/mgmt/stats"
- "veyron.io/veyron/veyron2/services/mgmt/vtrace"
+ vtracesvc "veyron.io/veyron/veyron2/services/mgmt/vtrace"
"veyron.io/veyron/veyron2/verror"
+ "veyron.io/veyron/veyron2/vtrace"
libstats "veyron.io/veyron/veyron/lib/stats"
"veyron.io/veyron/veyron/lib/testutil"
@@ -49,6 +51,11 @@
func TestDebugServer(t *testing.T) {
runtime := rt.Init()
+ tracedContext := func() context.T {
+ ctx := runtime.NewContext()
+ vtrace.FromContext(ctx).Trace().ForceCollect()
+ return ctx
+ }
rootName = "debug"
workdir, err := ioutil.TempDir("", "logreadertest")
@@ -91,7 +98,7 @@
// Access a log file that exists.
{
lf := logreader.LogFileClient(naming.JoinAddressName(endpoint, "debug/logs/test.INFO"))
- size, err := lf.Size(runtime.NewContext())
+ size, err := lf.Size(tracedContext())
if err != nil {
t.Errorf("Size failed: %v", err)
}
@@ -103,7 +110,7 @@
// Access a log file that doesn't exist.
{
lf := logreader.LogFileClient(naming.JoinAddressName(endpoint, "debug/logs/nosuchfile.INFO"))
- _, err = lf.Size(runtime.NewContext())
+ _, err = lf.Size(tracedContext())
if expected := verror.NoExist; !verror.Is(err, expected) {
t.Errorf("unexpected error value, got %v, want: %v", err, expected)
}
@@ -115,7 +122,7 @@
foo.Set(123)
st := stats.StatsClient(naming.JoinAddressName(endpoint, "debug/stats/testing/foo"))
- v, err := st.Value(runtime.NewContext())
+ v, err := st.Value(tracedContext())
if err != nil {
t.Errorf("Value failed: %v", err)
}
@@ -127,7 +134,7 @@
// Access a stats object that doesn't exists.
{
st := stats.StatsClient(naming.JoinAddressName(endpoint, "debug/stats/testing/nobodyhome"))
- _, err = st.Value(runtime.NewContext())
+ _, err = st.Value(tracedContext())
if expected := verror.NoExist; !verror.Is(err, expected) {
t.Errorf("unexpected error value, got %v, want: %v", err, expected)
}
@@ -135,7 +142,7 @@
// Access vtrace.
{
- vt := vtrace.StoreClient(naming.JoinAddressName(endpoint, "debug/vtrace"))
+ vt := vtracesvc.StoreClient(naming.JoinAddressName(endpoint, "debug/vtrace"))
call, err := vt.AllTraces(runtime.NewContext())
if err != nil {
t.Errorf("AllTraces failed: %v", err)
@@ -149,8 +156,8 @@
if err = stream.Err(); err != nil && err != io.EOF {
t.Fatalf("Unexpected error reading trace stream: %s", err)
}
- if ntraces < 1 {
- t.Errorf("We expected at least one trace, got: %d", ntraces)
+ if ntraces != 4 {
+ t.Errorf("We expected 4 traces, got: %d", ntraces)
}
}
diff --git a/services/mgmt/vtrace/impl/vtrace_test.go b/services/mgmt/vtrace/impl/vtrace_test.go
index 4e1d0c2..3600fd9 100644
--- a/services/mgmt/vtrace/impl/vtrace_test.go
+++ b/services/mgmt/vtrace/impl/vtrace_test.go
@@ -75,8 +75,8 @@
if err = stream.Err(); err != nil && err != io.EOF {
t.Fatalf("Unexpected error reading trace stream: %s", err)
}
- if ntraces < 2 {
- t.Fatalf("Expected at least 2 traces, got %#v", ntraces)
+ if ntraces != 1 {
+ t.Fatalf("Expected 1 trace, got %#v", ntraces)
}
if tr == nil {
t.Fatalf("Desired trace %x not found.", id)
diff --git a/tools/debug/impl.go b/tools/debug/impl.go
index f3dc121..f15adf3 100644
--- a/tools/debug/impl.go
+++ b/tools/debug/impl.go
@@ -24,9 +24,12 @@
logtypes "veyron.io/veyron/veyron2/services/mgmt/logreader/types"
"veyron.io/veyron/veyron2/services/mgmt/pprof"
"veyron.io/veyron/veyron2/services/mgmt/stats"
+ vtracesvc "veyron.io/veyron/veyron2/services/mgmt/vtrace"
"veyron.io/veyron/veyron2/services/watch"
watchtypes "veyron.io/veyron/veyron2/services/watch/types"
+ "veyron.io/veyron/veyron2/uniqueid"
"veyron.io/veyron/veyron2/vom"
+ "veyron.io/veyron/veyron2/vtrace"
)
var (
@@ -60,6 +63,81 @@
cmdPProfRun.Flags.StringVar(&pprofCmd, "pprofcmd", "veyron go tool pprof", "The pprof command to use.")
}
+var cmdVtrace = &cmdline.Command{
+ Run: runVtrace,
+ Name: "vtrace",
+ Short: "Returns vtrace traces.",
+ Long: "Returns matching vtrace traces (or all stored traces if no ids are given).",
+ ArgsName: "<name> [id ...]",
+ ArgsLong: `
+<name> is the name of a vtrace object.
+[id] is a vtrace trace id.
+`,
+}
+
+func doFetchTrace(ctx context.T, wg *sync.WaitGroup, client vtracesvc.StoreClientStub,
+ id uniqueid.ID, traces chan *vtrace.TraceRecord, errors chan error) {
+ defer wg.Done()
+
+ trace, err := client.Trace(ctx, id)
+ if err != nil {
+ errors <- err
+ } else {
+ traces <- &trace
+ }
+}
+
+func runVtrace(cmd *cmdline.Command, args []string) error {
+ ctx := rt.R().NewContext()
+ arglen := len(args)
+ if arglen == 0 {
+ return cmd.UsageErrorf("vtrace: incorrect number of arguments, got %d want >= 1", arglen)
+ }
+
+ name := args[0]
+ client := vtracesvc.StoreClient(name)
+ if arglen == 1 {
+ call, err := client.AllTraces(ctx)
+ if err != nil {
+ return err
+ }
+ stream := call.RecvStream()
+ for stream.Advance() {
+ trace := stream.Value()
+ vtrace.FormatTrace(os.Stdout, &trace, nil)
+ }
+ if err := stream.Err(); err != nil {
+ return err
+ }
+ return call.Finish()
+ }
+
+ ntraces := len(args) - 1
+ traces := make(chan *vtrace.TraceRecord, ntraces)
+ errors := make(chan error, ntraces)
+ var wg sync.WaitGroup
+ wg.Add(ntraces)
+ for _, arg := range args[1:] {
+ id, err := uniqueid.FromHexString(arg)
+ if err != nil {
+ return err
+ }
+ go doFetchTrace(ctx, &wg, client, id, traces, errors)
+ }
+ go func() {
+ wg.Wait()
+ close(traces)
+ close(errors)
+ }()
+
+ for trace := range traces {
+ vtrace.FormatTrace(os.Stdout, trace, nil)
+ }
+
+ // Just return one of the errors.
+ return <-errors
+}
+
var cmdGlob = &cmdline.Command{
Run: runGlob,
Name: "glob",
@@ -487,6 +565,7 @@
Long: "Command-line tool for interacting with the debug server.",
Children: []*cmdline.Command{
cmdGlob,
+ cmdVtrace,
&cmdline.Command{
Name: "logs",
Short: "Accesses log files",
diff --git a/tools/debug/test.sh b/tools/debug/test.sh
index 8c38207..c460c21 100755
--- a/tools/debug/test.sh
+++ b/tools/debug/test.sh
@@ -8,6 +8,7 @@
source "${VEYRON_ROOT}/scripts/lib/shell_test.sh"
readonly WORKDIR="${shell_test_WORK_DIR}"
+readonly DEBUG_FLAGS="--veyron.vtrace.sample_rate=1"
build() {
DEBUG_BIN="$(shell_test::build_go_binary 'veyron.io/veyron/veyron/tools/debug')"
@@ -35,7 +36,7 @@
# Test top level glob.
local -r DBGLOG="${WORKDIR}/debug.log"
- GOT=$("${DEBUG_BIN}" glob "${EP}/__debug/*" 2> "${DBGLOG}") \
+ GOT=$("${DEBUG_BIN}" "${DEBUG_FLAGS}" glob "${EP}/__debug/*" 2> "${DBGLOG}") \
|| (dumplogs "${DBGLOG}"; shell_test::fail "line ${LINENO}: failed to run debug")
WANT="${EP}/__debug/logs
${EP}/__debug/pprof
@@ -44,28 +45,39 @@
shell_test::assert_eq "${GOT}" "${WANT}" "${LINENO}"
# Test logs glob.
- GOT=$("${DEBUG_BIN}" glob "${EP}/__debug/logs/*" 2> "${DBGLOG}" | wc -l) \
+ GOT=$("${DEBUG_BIN}" "${DEBUG_FLAGS}" glob "${EP}/__debug/logs/*" 2> "${DBGLOG}" | wc -l) \
|| (dumplogs "${DBGLOG}"; shell_test::fail "line ${LINENO}: failed to run debug")
shell_test::assert_gt "${GOT}" "0" "${LINENO}"
# Test logs size.
echo "This is a log file" > "${TMPDIR}/my-test-log-file"
- GOT=$("${DEBUG_BIN}" logs size "${EP}/__debug/logs/my-test-log-file" 2> "${DBGLOG}") \
+ GOT=$("${DEBUG_BIN}" "${DEBUG_FLAGS}" logs size "${EP}/__debug/logs/my-test-log-file" 2> "${DBGLOG}") \
|| (dumplogs "${DBGLOG}"; shell_test::fail "line ${LINENO}: failed to run debug")
WANT=$(echo "This is a log file" | wc -c | tr -d ' ')
shell_test::assert_eq "${GOT}" "${WANT}" "${LINENO}"
# Test logs read.
- GOT=$("${DEBUG_BIN}" logs read "${EP}/__debug/logs/my-test-log-file" 2> "${DBGLOG}") \
+ GOT=$("${DEBUG_BIN}" "${DEBUG_FLAGS}" logs read "${EP}/__debug/logs/my-test-log-file" 2> "${DBGLOG}") \
|| (dumplogs "${DBGLOG}"; shell_test::fail "line ${LINENO}: failed to run debug")
WANT="This is a log file"
shell_test::assert_eq "${GOT}" "${WANT}" "${LINENO}"
# Test stats read.
- GOT=$("${DEBUG_BIN}" stats read "${EP}/__debug/stats/ipc/server/routing-id/*/methods/ReadLog/latency-ms" 2> "${DBGLOG}" | wc -l) \
+ GOT=$("${DEBUG_BIN}" "${DEBUG_FLAGS}" stats read "${EP}/__debug/stats/ipc/server/routing-id/*/methods/ReadLog/latency-ms" 2> "${DBGLOG}" | wc -l) \
|| (dumplogs "${DBGLOG}"; shell_test::fail "line ${LINENO}: failed to run debug")
shell_test::assert_gt "${GOT}" "0" "${LINENO}"
+ # Test fetching all vtrace traces.
+ GOT=$("${DEBUG_BIN}" "${DEBUG_FLAGS}" vtrace "${EP}/__debug/vtrace" 2> "${DBGLOG}" | egrep -o "^Trace - ([^ ]+)" | cut -b 9- | sort) \
+ || (dumplogs "${DBGLOG}"; shell_test::fail "line ${LINENO}: failed to run debug")
+ shell_test::assert_eq $(echo "${GOT}" | wc -l | tr -d ' ') "6" "${LINENO}"
+
+ # Test fetching individual traces.
+ IDS=$(echo "$GOT" | tr '\n' ' ')
+ GOT2=$("${DEBUG_BIN}" "${DEBUG_FLAGS}" vtrace "${EP}/__debug/vtrace" ${IDS} 2> "${DBGLOG}" | egrep -o "^Trace - ([^ ]+)" | cut -b 9- | sort) \
+ || (dumplogs "${DBGLOG}"; shell_test::fail "line ${LINENO}: failed to run debug")
+ shell_test::assert_eq "${GOT2}" "${GOT}" "${LINENO}"
+
# Test stats watch.
local TMP=$(shell::tmp_file)
touch "${TMP}"
