X-Git-Url: https://git.arvados.org/arvados.git/blobdiff_plain/74d5bfb293b2acf76d639df12ff8769bc333a5f2..128b6c914e9ac66744e36b4428c5235f3bde7089:/services/ws/handler.go

diff --git a/services/ws/handler.go b/services/ws/handler.go
index 91a77022d6..d527c39ba1 100644
--- a/services/ws/handler.go
+++ b/services/ws/handler.go
@@ -1,18 +1,27 @@
+// Copyright (C) The Arvados Authors. All rights reserved.
+//
+// SPDX-License-Identifier: AGPL-3.0
+
 package main
 
 import (
 	"context"
 	"io"
+	"sync"
 	"time"
 
 	"git.curoverse.com/arvados.git/sdk/go/arvados"
+	"git.curoverse.com/arvados.git/sdk/go/stats"
 )
 
 type handler struct {
 	Client      arvados.Client
 	PingTimeout time.Duration
 	QueueSize   int
-	NewSession  func(wsConn, chan<- interface{}) (session, error)
+
+	mtx       sync.Mutex
+	lastDelay map[chan interface{}]stats.Duration
+	setupOnce sync.Once
 }
 
 type handlerStats struct {
@@ -22,17 +31,36 @@ type handlerStats struct {
 	EventCount   uint64
 }
 
-func (h *handler) Handle(ws wsConn, incoming <-chan *event) (stats handlerStats) {
+func (h *handler) Handle(ws wsConn, eventSource eventSource, newSession func(wsConn, chan<- interface{}) (session, error)) (hStats handlerStats) {
+	h.setupOnce.Do(h.setup)
+
 	ctx, cancel := context.WithCancel(ws.Request().Context())
+	defer cancel()
 	log := logger(ctx)
+
+	incoming := eventSource.NewSink()
+	defer incoming.Stop()
+
 	queue := make(chan interface{}, h.QueueSize)
-	sess, err := h.NewSession(ws, queue)
+	h.mtx.Lock()
+	h.lastDelay[queue] = 0
+	h.mtx.Unlock()
+	defer func() {
+		h.mtx.Lock()
+		delete(h.lastDelay, queue)
+		h.mtx.Unlock()
+	}()
+
+	sess, err := newSession(ws, queue)
 	if err != nil {
-		log.WithError(err).Error("NewSession failed")
+		log.WithError(err).Error("newSession failed")
 		return
 	}
 
+	// Receive websocket frames from the client and pass them to
+	// sess.Receive().
 	go func() {
+		defer cancel()
 		buf := make([]byte, 2<<20)
 		for {
 			select {
@@ -48,22 +76,24 @@ func (h *handler) Handle(ws wsConn, incoming <-chan *event) (stats handlerStats)
 				err = errFrameTooBig
 			}
 			if err != nil {
-				if err != io.EOF {
+				if err != io.EOF && ctx.Err() == nil {
 					log.WithError(err).Info("read error")
 				}
-				cancel()
 				return
 			}
 			err = sess.Receive(buf)
 			if err != nil {
 				log.WithError(err).Error("sess.Receive() failed")
-				cancel()
 				return
 			}
 		}
 	}()
 
+	// Take items from the outgoing queue, serialize them using
+	// sess.EventMessage() as needed, and send them to the client
+	// as websocket frames.
 	go func() {
+		defer cancel()
 		for {
 			var ok bool
 			var data interface{}
@@ -89,8 +119,7 @@ func (h *handler) Handle(ws wsConn, incoming <-chan *event) (stats handlerStats)
 				buf, err = sess.EventMessage(e)
 				if err != nil {
 					log.WithError(err).Error("EventMessage failed")
-					cancel()
-					break
+					return
 				} else if len(buf) == 0 {
 					log.Debug("skip")
 					continue
@@ -105,18 +134,22 @@ func (h *handler) Handle(ws wsConn, incoming <-chan *event) (stats handlerStats)
 			t0 := time.Now()
 			_, err = ws.Write(buf)
 			if err != nil {
-				log.WithError(err).Error("write failed")
-				cancel()
-				break
+				if ctx.Err() == nil {
+					log.WithError(err).Error("write failed")
+				}
+				return
 			}
 			log.Debug("sent")
 
 			if e != nil {
-				stats.QueueDelayNs += t0.Sub(e.Received)
+				hStats.QueueDelayNs += t0.Sub(e.Ready)
+				h.mtx.Lock()
+				h.lastDelay[queue] = stats.Duration(time.Since(e.Ready))
+				h.mtx.Unlock()
 			}
-			stats.WriteDelayNs += time.Since(t0)
-			stats.EventBytes += uint64(len(buf))
-			stats.EventCount++
+			hStats.WriteDelayNs += time.Since(t0)
+			hStats.EventBytes += uint64(len(buf))
+			hStats.EventCount++
 		}
 	}()
 
@@ -126,6 +159,7 @@ func (h *handler) Handle(ws wsConn, incoming <-chan *event) (stats handlerStats)
 	// is done/cancelled or the incoming event stream ends. Shut
 	// down the handler if the outgoing queue fills up.
 	go func() {
+		defer cancel()
 		ticker := time.NewTicker(h.PingTimeout)
 		defer ticker.Stop()
 
@@ -145,10 +179,8 @@ func (h *handler) Handle(ws wsConn, incoming <-chan *event) (stats handlerStats)
 					default:
 					}
 				}
-				continue
-			case e, ok := <-incoming:
+			case e, ok := <-incoming.Channel():
 				if !ok {
-					cancel()
 					return
 				}
 				if !sess.Filter(e) {
@@ -158,7 +190,6 @@ func (h *handler) Handle(ws wsConn, incoming <-chan *event) (stats handlerStats)
 				case queue <- e:
 				default:
 					log.WithError(errQueueFull).Error("terminate")
-					cancel()
 					return
 				}
 			}
@@ -168,3 +199,39 @@ func (h *handler) Handle(ws wsConn, incoming <-chan *event) (stats handlerStats)
 	<-ctx.Done()
 	return
 }
+
+func (h *handler) DebugStatus() interface{} {
+	h.mtx.Lock()
+	defer h.mtx.Unlock()
+
+	var s struct {
+		QueueCount    int
+		QueueMin      int
+		QueueMax      int
+		QueueTotal    uint64
+		QueueDelayMin stats.Duration
+		QueueDelayMax stats.Duration
+	}
+	for q, lastDelay := range h.lastDelay {
+		s.QueueCount++
+		n := len(q)
+		s.QueueTotal += uint64(n)
+		if s.QueueMax < n {
+			s.QueueMax = n
+		}
+		if s.QueueMin > n || s.QueueCount == 1 {
+			s.QueueMin = n
+		}
+		if (s.QueueDelayMin > lastDelay || s.QueueDelayMin == 0) && lastDelay > 0 {
+			s.QueueDelayMin = lastDelay
+		}
+		if s.QueueDelayMax < lastDelay {
+			s.QueueDelayMax = lastDelay
+		}
+	}
+	return &s
+}
+
+func (h *handler) setup() {
+	h.lastDelay = make(map[chan interface{}]stats.Duration)
+}