Merged in non-active (pull request #507)

vidforward: improve non-active mechanism

Resolves issue #404

Approved-by: Trek Hopton
Approved-by: David Sutton

cmd/vidforward/main.go

@@ -106,11 +106,12 @@ func (b *Broadcast) equal(other Broadcast) bool {
 // and a recv handler which is invoked when a camera wishes to get its video
 // forwarded to youtube.
 type broadcastManager struct {
-	broadcasts       map[MAC]*Broadcast
-	slateExitSignals map[MAC]chan struct{} // Used to signal to stop writing slate image.
-	log              logging.Logger
-	dogNotifier      *watchdogNotifier
-	mu               sync.Mutex
+	broadcasts          map[MAC]*Broadcast
+	slateExitSignals    map[MAC]chan struct{} // Used to signal to stop writing slate image.
+	lastLoggedNonActive map[MAC]time.Time     // Used to log non-active MACs every minute.
+	log                 logging.Logger
+	dogNotifier         *watchdogNotifier
+	mu                  sync.Mutex
 }
 
 // newBroadcastManager returns a new broadcastManager with the provided logger.
@@ -196,17 +197,39 @@ func (m *broadcastManager) recv(w http.ResponseWriter, r *http.Request) {
 	q := r.URL.Query()
 	ma := MAC(q.Get("ma"))
 
-	if !m.isActive(ma) {
-		m.errorLogWrite(m.log, w, "forward request mac is not mapped, doing nothing", "mac", ma)
-		time.Sleep(recvErrorDelay)
-		return
-	}
+	// Check that we're not receiving video when we shouldn't be. There's
+	// two conditions when this can happen; when the MAC is not mapped to a
+	// broadcast, or when the broadcast is in slate mode.
+	// It's expected this might happen a little bit under normal operation.
+	// It's difficult to get the camera power timing right, so we might
+	// receive a request before the camera has been registered, or after
+	// we've transitioned into slate mode.
+	// If this happens too much however, it may indicate a problem.
+	var reason string
+	switch {
+	case !m.isActive(ma):
+		reason = "forward request mac is not mapped, doing nothing"
+		fallthrough
+	case m.getStatus(ma) == statusSlate:
+		if reason == "" {
+			reason = "cannot receive video for this mac, status is slate"
+		}
 
-	// We can't receive video if we're in slate mode.
-	if m.getStatus(ma) == statusSlate {
-		m.errorLogWrite(m.log, w, "cannot receive video for this mac, status is slate", "mac", ma)
+		// We don't want to clutter the logs so only log non-active MACs every
+		// minute.
+		const logNonActiveInternal = 1 * time.Minute
+		last, ok := m.lastLoggedNonActive[ma]
+		if !ok || ok && time.Now().Sub(last) > logNonActiveInternal {
+			m.errorLogWrite(m.log, w, reason, "mac", ma)
+			m.lastLoggedNonActive[ma] = time.Now()
+		}
+
+		// Stall the client with a delay to prevent spamming. Probably cause timeout
+		// on client.
 		time.Sleep(recvErrorDelay)
 		return
+
+	default: // Continue (seems like mac is active and we're not in slate.)
 	}
 
 	const videoPin = "V0"