diff --git a/cmd/vidforward/main.go b/cmd/vidforward/main.go index 202463e4..5a5732d2 100644 --- a/cmd/vidforward/main.go +++ b/cmd/vidforward/main.go @@ -138,6 +138,7 @@ func terminationCallback(m *broadcastManager) func() { return } m.log.Info("successfully saved broadcast manager state on termination signal") + logTrace(m.log.Debug,m.log.Warning) } } @@ -163,7 +164,7 @@ func (m *broadcastManager) loadConfig() error { return fmt.Errorf("could not unmarshal config file: %w", err) } - m.log.Debug("logger config loaded","cfg",cfg) + m.log.Debug("logger config loaded", "cfg", cfg) m.log.(*logging.JSONLogger).SetLevel(map[string]int8{ "debug": logging.Debug, "info": logging.Info, @@ -265,7 +266,7 @@ func (m *broadcastManager) recv(w http.ResponseWriter, r *http.Request) { rv, err := m.getPipeline(ma) if err != nil { - m.errorLogWrite(m.log, w, "could not get revid pipeline","mac",ma,"error",err) + m.errorLogWrite(m.log, w, "could not get revid pipeline", "mac", ma, "error", err) return } @@ -386,7 +387,7 @@ func (m *broadcastManager) getPipeline(ma MAC) (*revid.Revid, error) { var err error b.rv, err = m.initOrStartPipeline(b.rv, b.urls) if err != nil { - return nil, fmt.Errorf("could not init or start pipeline: %v",err) + return nil, fmt.Errorf("could not init or start pipeline: %v", err) } return b.rv, nil @@ -394,18 +395,18 @@ func (m *broadcastManager) getPipeline(ma MAC) (*revid.Revid, error) { // initOrStartPipeline ensures that provided Revid pointer points to an // initialised and running revid pipeline. -func (m *broadcastManager) initOrStartPipeline(rv *revid.Revid, urls []string) (*revid.Revid, error){ +func (m *broadcastManager) initOrStartPipeline(rv *revid.Revid, urls []string) (*revid.Revid, error) { var err error if rv == nil { rv, err = newRevid(m.log, urls) if err != nil { - return nil, fmt.Errorf("could not create new revid: %v",err) + return nil, fmt.Errorf("could not create new revid: %v", err) } } if !rv.Running() { err = rv.Start() if err != nil { - return nil, fmt.Errorf("could not start revid pipeline: %v",err) + return nil, fmt.Errorf("could not start revid pipeline: %v", err) } } return rv, nil @@ -436,7 +437,7 @@ func (m *broadcastManager) isActive(ma MAC) bool { // status field of the broadcast i.e. whether we expect data from a source // or write the slate image. func (m *broadcastManager) createOrUpdate(broadcast Broadcast) error { - m.log.Debug("create or update","mac",broadcast.mac) + m.log.Debug("create or update", "mac", broadcast.mac) m.mu.Lock() defer m.mu.Unlock() @@ -459,7 +460,7 @@ func (m *broadcastManager) createOrUpdate(broadcast Broadcast) error { // If the URLS have changed, we need to update the revid pipeline. // We won't enter this if we've just created a new revid pipeline. if !reflect.DeepEqual(maybeOld.urls, broadcast.urls) { - m.log.Debug("RTMP URLs have changed, updating pipeline config","mac",broadcast.mac,"old",maybeOld.urls,"new",broadcast.urls) + m.log.Debug("RTMP URLs have changed, updating pipeline config", "mac", broadcast.mac, "old", maybeOld.urls, "new", broadcast.urls) urls := strings.Join(broadcast.urls, ",") err := maybeOld.rv.Update(map[string]string{"RTMPURL": urls}) if err != nil { @@ -472,7 +473,7 @@ func (m *broadcastManager) createOrUpdate(broadcast Broadcast) error { // i.e. if the status is slate, we need to start writing the slate image. // We won't enter this if we've just created a new revid pipeline. if maybeOld.status != broadcast.status { - m.log.Debug("status has changed, starting or stopping slate","mac",broadcast.mac,"old",maybeOld.status,"new",broadcast.status) + m.log.Debug("status has changed, starting or stopping slate", "mac", broadcast.mac, "old", maybeOld.status, "new", broadcast.status) switch broadcast.status { case statusActive, statusPlay, statusCreate: m.log.Info("updating configuration for mac", "mac", broadcast.mac) diff --git a/cmd/vidforward/notifier.go b/cmd/vidforward/notifier.go index e709c8a0..a3a15d3c 100644 --- a/cmd/vidforward/notifier.go +++ b/cmd/vidforward/notifier.go @@ -92,12 +92,20 @@ func (n *watchdogNotifier) notify() { n.termCallback() }() + var consecutiveUnhealthyStates int for { + const nUnhealthyStatesForTrace = 10 if n.handlersUnhealthy() { + consecutiveUnhealthyStates++ + if consecutiveUnhealthyStates >= nUnhealthyStatesForTrace { + logTrace(n.log.Debug,n.log.Warning) + consecutiveUnhealthyStates = 0 + } const unhealthyHandlerWait = 1 * time.Second time.Sleep(unhealthyHandlerWait) continue } + consecutiveUnhealthyStates = 0 <-notifyTicker.C diff --git a/cmd/vidforward/utils.go b/cmd/vidforward/utils.go index a93c5008..2d62acc6 100644 --- a/cmd/vidforward/utils.go +++ b/cmd/vidforward/utils.go @@ -28,6 +28,7 @@ import ( "fmt" "net/http" "strconv" + "runtime" "bitbucket.org/ausocean/av/codec/codecutil" "bitbucket.org/ausocean/av/revid" @@ -86,3 +87,18 @@ func isMac(m string) bool { } return true } + +type Log func(msg string, args ...interface{}) + +func logTrace(debug, warning Log){ + const ( + maxStackTraceSize = 100000 + allStacks = true + ) + buf := make([]byte, maxStackTraceSize) + n := runtime.Stack(buf, allStacks) + if n > maxStackTraceSize && warning != nil { + warning("stacktrace exceeded buffer size") + } + debug("got stacktrace at termination", "stacktrace", string(buf[:n])) +}