Add HTTP tracing

kaidisn · Mar 25, 2021 · 7847e52 · 7847e52
1 parent 00e2a65
commit 7847e52
Show file tree

Hide file tree

Showing 16 changed files with 730 additions and 167 deletions.
diff --git a/cli/cmd/encore/db.go b/cli/cmd/encore/db.go
@@ -208,13 +208,13 @@ func init() {
 	dbResetCmd.Flags().BoolVar(&resetAll, "all", false, "Reset all services in the application")
 	dbCmd.AddCommand(dbResetCmd)
 
-	dbShellCmd.Flags().StringVarP(&dbEnv, "env", "e", "", "Environment name to connect to (such as \"production\")")
+	dbShellCmd.Flags().StringVarP(&dbEnv, "env", "e", "local", "Environment name to connect to (such as \"prod\")")
 	dbCmd.AddCommand(dbShellCmd)
 
-	dbProxyCmd.Flags().StringVarP(&dbEnv, "env", "e", "", "Environment name to connect to (such as \"production\")")
+	dbProxyCmd.Flags().StringVarP(&dbEnv, "env", "e", "local", "Environment name to connect to (such as \"prod\")")
 	dbProxyCmd.Flags().Int32VarP(&dbProxyPort, "port", "p", 0, "Port to listen on (defaults to a random port)")
 	dbCmd.AddCommand(dbProxyCmd)
 
-	dbConnURICmd.Flags().StringVarP(&dbEnv, "env", "e", "", "Environment name to connect to (such as \"production\")")
+	dbConnURICmd.Flags().StringVarP(&dbEnv, "env", "e", "local", "Environment name to connect to (such as \"prod\")")
 	dbCmd.AddCommand(dbConnURICmd)
 }
diff --git a/cli/daemon/daemon.go b/cli/daemon/daemon.go
@@ -36,7 +36,7 @@ type Server struct {
 	streams  map[string]daemonpb.Daemon_RunServer // run id -> stream
 	appRoots map[string]string                    // cache of app id -> app root
 
-	daemonpb.UnsafeDaemonServer
+	daemonpb.UnimplementedDaemonServer
 }
 
 // New creates a new Server.

diff --git a/cli/daemon/dash/dashapp/src/components/trace/SpanDetail.tsx b/cli/daemon/dash/dashapp/src/components/trace/SpanDetail.tsx
@@ -1,5 +1,5 @@
 import { FunctionComponent, useState, useRef, useEffect } from "react"
-import { Request, Trace, Event, DBTransaction, DBQuery, TraceExpr, RPCCall, AuthCall } from "./model"
+import { Request, Trace, Event, DBTransaction, DBQuery, TraceExpr, RPCCall, AuthCall, HTTPCall } from "./model"
 import { latencyStr, svcColor } from "./util"
 import * as icons from "~c/icons"
 import { decodeBase64, Base64EncodedBytes } from "~lib/base64"
@@ -248,6 +248,24 @@ const GoroutineDetail: FunctionComponent<{g: gdata, req: Request, trace: Trace}>
                 }}
               />
             </React.Fragment>
+          } else if (ev.type === "HTTPCall") {
+            const [color, highlightColor] = svcColor(ev.url)
+            return <React.Fragment key={i}>
+              <style>{`
+                .${clsid}       { background-color: ${highlightColor}; }
+                .${clsid}:hover { background-color: ${color}; }
+              `}</style>
+              <div className={`absolute ${clsid}`}
+                onMouseEnter={(e) => setHover(e, ev)}
+                onMouseLeave={(e) => setHover(e, null)}
+                style={{
+                  borderRadius: "3px",
+                  top: "3px", bottom: "3px",
+                  left: start+"%", right: (100-end)+"%",
+                  minWidth: "1px" // so it at least renders if start === stop
+                }}
+              />
+            </React.Fragment>
           }
         })}
       </div>
@@ -261,6 +279,7 @@ const GoroutineDetail: FunctionComponent<{g: gdata, req: Request, trace: Trace}>
           {hoverObj && "type" in hoverObj && (
             hoverObj.type === "DBQuery" ? <DBQueryTooltip q={hoverObj} trace={props.trace} /> :
             hoverObj.type === "RPCCall" ? <RPCCallTooltip call={hoverObj as RPCCall} req={req} trace={props.trace} /> :
+            hoverObj.type === "HTTPCall" ? <HTTPCallTooltip call={hoverObj as HTTPCall} req={req} trace={props.trace} /> :
             null)}
         </div>
       }
@@ -354,6 +373,42 @@ const RPCCallTooltip: FunctionComponent<{call: RPCCall, req: Request, trace: Tra
   </div>
 }
 
+const HTTPCallTooltip: FunctionComponent<{call: HTTPCall, req: Request, trace: Trace}> = ({call, req, trace}) => {
+  return <div>
+    <h3 className="flex items-center text-gray-800 font-bold text-lg">
+      {icons.logout("h-8 w-auto text-gray-400 mr-2")}
+      HTTP {call.method} {call.host}{call.path !== "" ? "/" + call.path : ""}
+      <div className="ml-auto text-sm font-normal text-gray-500">{latencyStr(call.end_time - call.start_time)}</div>
+    </h3>
+
+    <div className="mt-4">
+      <h4 className="text-xs font-semibold font-sans text-gray-300 leading-3 tracking-wider uppercase mb-2">URL</h4>
+      <pre className="rounded overflow-auto border border-gray-200 p-2 bg-gray-100 text-gray-800 text-sm">{call.url}</pre>
+    </div>
+
+    <div className="mt-4">
+      <h4 className="text-xs font-semibold font-sans text-gray-300 leading-3 tracking-wider uppercase mb-2">Response</h4>
+      {call.end_time !== -1 ? (
+        <div className="text-gray-700 text-sm">HTTP {call.status_code}</div>
+      ) : (
+        <div className="text-gray-700 text-sm">No response recorded.</div>
+      )}
+    </div>
+
+    <div className="mt-4">
+      <h4 className="text-xs font-semibold font-sans text-gray-300 leading-3 tracking-wider uppercase mb-2">Error</h4>
+      {call.err !== null ? (
+        <pre className="rounded overflow-auto border border-gray-200 p-2 bg-gray-100 text-gray-800 text-sm">
+          {decodeBase64(call.err)}
+        </pre>
+      ) : (
+        <div className="text-gray-700 text-sm">Completed successfully.</div>
+      )}
+    </div>
+
+  </div>
+}
+
 const renderData = (data: Base64EncodedBytes[]) => {
   const json = JSON.parse(decodeBase64(data[0]))
   return <pre className="rounded overflow-auto border border-gray-200 p-2 bg-gray-100 text-gray-800 text-sm">{JSON.stringify(json, undefined, "  ")}</pre>

diff --git a/cli/daemon/dash/dashapp/src/components/trace/model.ts b/cli/daemon/dash/dashapp/src/components/trace/model.ts
@@ -83,7 +83,23 @@ export interface AuthCall {
   err: Base64EncodedBytes | null;
 }
 
-export type Event = DBTransaction | DBQuery | RPCCall | Goroutine;
+export interface HTTPCall {
+  type: "HTTPCall";
+  goid: number;
+  req_id: string;
+  start_time: number;
+  end_time: number;
+  body_closed_time: number;
+  method: string;
+  host: string;
+  path: string;
+  url: string;
+  status_code: number;
+  err: Base64EncodedBytes | null;
+}
+
+
+export type Event = DBTransaction | DBQuery | RPCCall | HTTPCall | Goroutine;
 
 export type TraceExpr = RpcDefExpr | RpcCallExpr | StaticCallExpr | AuthHandlerDefExpr
 

diff --git a/cli/daemon/dash/trace.go b/cli/daemon/dash/trace.go
@@ -90,6 +90,23 @@ type RPCCall struct {
 	Err       []byte `json:"err"`
 }
 
+type HTTPCall struct {
+	Type       string `json:"type"`
+	Goid       uint32 `json:"goid"`
+	ReqID      string `json:"req_id"`
+	StartTime  int64  `json:"start_time"`
+	EndTime    int64  `json:"end_time"`
+	Method     string `json:"method"`
+	Host       string `json:"host"`
+	Path       string `json:"path"`
+	URL        string `json:"url"`
+	StatusCode int    `json:"status_code"`
+	Err        []byte `json:"err"`
+
+	// May be -1
+	BodyClosedTime int64 `json:"body_closed_time"`
+}
+
 type Event interface {
 	traceEvent()
 }
@@ -98,6 +115,7 @@ func (Goroutine) traceEvent()     {}
 func (DBTransaction) traceEvent() {}
 func (DBQuery) traceEvent()       {}
 func (RPCCall) traceEvent()       {}
+func (HTTPCall) traceEvent()      {}
 
 func TransformTrace(ct *trace.TraceMeta) (*Trace, error) {
 	traceID := traceUUID(ct.ID)
@@ -212,6 +230,9 @@ func (tp *traceParser) parseReq(req *tracepb.Request) (*Request, error) {
 		case *tracepb.Event_Rpc:
 			r.Events = append(r.Events, tp.parseCall(e.Rpc))
 
+		case *tracepb.Event_Http:
+			r.Events = append(r.Events, tp.parseHTTP(e.Http))
+
 		case *tracepb.Event_Goroutine:
 			r.Events = append(r.Events, tp.parseGoroutine(e.Goroutine))
 		}
@@ -298,7 +319,27 @@ func (tp *traceParser) parseCall(c *tracepb.RPCCall) *RPCCall {
 	}
 }
 
+func (tp *traceParser) parseHTTP(c *tracepb.HTTPCall) *HTTPCall {
+	return &HTTPCall{
+		Type:           "HTTPCall",
+		Goid:           c.Goid,
+		ReqID:          strconv.FormatUint(c.SpanId, 10),
+		Method:         c.Method,
+		Host:           c.Host,
+		Path:           c.Path,
+		URL:            c.Url,
+		StatusCode:     int(c.StatusCode),
+		StartTime:      tp.time(c.StartTime),
+		EndTime:        tp.time(c.EndTime),
+		BodyClosedTime: tp.time(c.BodyClosedTime),
+		Err:            nullBytes(c.Err),
+	}
+}
+
 func (tp *traceParser) time(ns uint64) int64 {
+	if ns == 0 {
+		return -1
+	}
 	return int64(ns/1000) - tp.startTime
 }
 

diff --git a/cli/daemon/runtime/trace/trace.go b/cli/daemon/runtime/trace/trace.go
@@ -82,6 +82,7 @@ func Parse(traceID ID, data []byte) ([]*tracepb.Request, error) {
 		queryMap:    make(map[uint64]*tracepb.DBQuery),
 		callMap:     make(map[uint64]interface{}),
 		goMap:       make(map[goKey]*tracepb.Goroutine),
+		httpMap:     make(map[uint64]*tracepb.HTTPCall),
 	}
 	if err := tp.Parse(); err != nil {
 		return nil, err
@@ -102,6 +103,7 @@ type traceParser struct {
 	txMap    map[uint64]*tracepb.DBTransaction
 	queryMap map[uint64]*tracepb.DBQuery
 	callMap  map[uint64]interface{} // *RPCCall or *AuthCall
+	httpMap  map[uint64]*tracepb.HTTPCall
 	goMap    map[goKey]*tracepb.Goroutine
 }
 
@@ -140,6 +142,13 @@ func (tp *traceParser) Parse() error {
 			// Skip these events for now
 			tp.Skip(size)
 
+		case 0x14:
+			err = tp.httpStart(ts)
+		case 0x15:
+			err = tp.httpEnd(ts)
+		case 0x16:
+			err = tp.httpBodyClosed(ts)
+
 		default:
 			log.Error().Int("idx", i).Hex("event", []byte{ev}).Msg("trace: unknown event type, skipping")
 			tp.Skip(size)
@@ -405,6 +414,56 @@ func (tp *traceParser) callEnd(ts uint64) error {
 	return nil
 }
 
+func (tp *traceParser) httpStart(ts uint64) error {
+	callID := tp.UVarint()
+	spanID := tp.Uint64()
+	childSpanID := tp.Uint64()
+	req, ok := tp.reqMap[spanID]
+	if !ok {
+		return fmt.Errorf("unknown request span: %v", spanID)
+	}
+	c := &tracepb.HTTPCall{
+		SpanId:    childSpanID,
+		Goid:      uint32(tp.UVarint()),
+		Method:    tp.String(),
+		Host:      tp.String(),
+		Path:      tp.String(),
+		Url:       tp.String(),
+		StartTime: ts,
+	}
+	tp.httpMap[callID] = c
+	req.Events = append(req.Events, &tracepb.Event{
+		Data: &tracepb.Event_Http{Http: c},
+	})
+	return nil
+}
+
+func (tp *traceParser) httpEnd(ts uint64) error {
+	callID := tp.UVarint()
+	errMsg := tp.ByteString()
+	status := tp.UVarint()
+	c, ok := tp.httpMap[callID]
+	if !ok {
+		return fmt.Errorf("unknown call: %v ", callID)
+	}
+	c.EndTime = ts
+	c.Err = errMsg
+	c.StatusCode = uint32(status)
+	return nil
+}
+
+func (tp *traceParser) httpBodyClosed(ts uint64) error {
+	callID := tp.UVarint()
+	_ = tp.ByteString() // close error
+	c, ok := tp.httpMap[callID]
+	if !ok {
+		return fmt.Errorf("unknown call: %v ", callID)
+	}
+	c.BodyClosedTime = ts
+	delete(tp.httpMap, callID)
+	return nil
+}
+
 var bin = binary.LittleEndian
 
 type traceReader struct {

diff --git a/cli/daemon/sqldb/proxy.go b/cli/daemon/sqldb/proxy.go
@@ -156,7 +156,7 @@ func (cm *ClusterManager) PreauthProxyConn(frontend net.Conn, clusterID string)
 	defer frontend.Close()
 	var proxy pgproxy.Proxy
 
-	data, err := proxy.FrontendAuth(frontend, nil, true)
+	data, err := proxy.FrontendAuth(frontend, nil, false)
 	if err != nil {
 		return err
 	}