changeset 2337:c1fa4f7fe5d1

log & metrics
author drewp@bigasterisk.com
date Fri, 02 Jun 2023 16:16:06 -0700
parents 47f7f5ac81e8
children 709c3d6dccf4
files light9/effect/effecteval2.py light9/effect/sequencer/eval_faders.py light9/effect/sequencer/service.py
diffstat 3 files changed, 12 insertions(+), 4 deletions(-) [+]
line wrap: on
line diff
--- a/light9/effect/effecteval2.py	Fri Jun 02 16:15:20 2023 -0700
+++ b/light9/effect/effecteval2.py	Fri Jun 02 16:16:06 2023 -0700
@@ -102,7 +102,9 @@
                 v = self._getEffectAttrValue(eaForName, inputs)
 
             kw[arg.name] = v
-        log.debug('calling %s with %s', c.func, kw)
+
+        if False and log.isEnabledFor(logging.DEBUG):
+            log.debug('calling %s with %s', c.func, kw)
         return c.func(**kw)
 
     def _getEffectAttrValue(self, attr: EffectAttr, inputs: EffectSettings) -> VTUnion:
--- a/light9/effect/sequencer/eval_faders.py	Fri Jun 02 16:15:20 2023 -0700
+++ b/light9/effect/sequencer/eval_faders.py	Fri Jun 02 16:16:06 2023 -0700
@@ -1,3 +1,4 @@
+import traceback
 import logging
 import time
 from dataclasses import dataclass
@@ -18,7 +19,7 @@
 log = logging.getLogger('seq.fader')
 
 COMPILE = Summary('compile_graph_fader', '')
-
+COMPUTE_ALL_FADERS = Summary('compute_all_faders', '')
 
 @dataclass
 class Fader:
@@ -72,6 +73,7 @@
         setAttr = typedValue(EffectAttr, self.graph, setting, L9['effectAttr'])
         return (Fader(self.graph, self.lib, cast(URIRef, fader), effect, setAttr))
 
+    @COMPUTE_ALL_FADERS.time()
     def computeOutput(self) -> DeviceSettings:
         faderEffectOutputs: List[DeviceSettings] = []
         now = UnixTime(time.time())
@@ -89,3 +91,7 @@
                 raise
 
         return DeviceSettings.merge(self.graph, faderEffectOutputs)
+        merged = DeviceSettings.merge(self.graph, faderEffectOutputs)
+        # please remove (after fixing stats display to show it)
+        log.debug("computed %s faders in %.1fms", len(self.faders), (time.time()-now)*1000)
+        return merged
--- a/light9/effect/sequencer/service.py	Fri Jun 02 16:15:20 2023 -0700
+++ b/light9/effect/sequencer/service.py	Fri Jun 02 16:16:06 2023 -0700
@@ -51,9 +51,9 @@
 def main():
     graph = SyncedGraph(networking.rdfdb.url, "effectSequencer")
     logging.getLogger('autodepgraphapi').setLevel(logging.INFO)
-    logging.getLogger('syncedgraph').setLevel(logging.DEBUG)
+    logging.getLogger('syncedgraph').setLevel(logging.INFO)
     logging.getLogger('sse_starlette.sse').setLevel(logging.INFO)
-    logging.getLogger('effecteval').setLevel(logging.INFO)
+    logging.getLogger('effecteval').setLevel(logging.DEBUG)
 
     # seq = Sequencer(graph, send)  # per-song timed notes
     lib = EffectFunctionLibrary(graph)