--- a/bin/effecteval	Tue May 27 05:48:25 2014 +0000
+++ b/bin/effecteval	Tue May 27 06:29:00 2014 +0000
@@ -1,13 +1,13 @@
 #!bin/python
 from run_local import log
-from twisted.internet import reactor
+from twisted.internet import reactor, task
 from twisted.internet.defer import inlineCallbacks
 import cyclone.web, cyclone.websocket, cyclone.httpclient
-import sys, optparse, logging, subprocess, json, re
+import sys, optparse, logging, subprocess, json, re, time
 from rdflib import URIRef, RDF
 
 sys.path.append(".")
-from light9 import networking, showconfig, Submaster
+from light9 import networking, showconfig, Submaster, dmxclient
 from light9.rdfdb.syncedgraph import SyncedGraph
 from light9.curvecalc.curve import Curve
 from light9.namespaces import L9, DCTERMS
@@ -55,60 +55,83 @@
 class EffectNode(object):
     def __init__(self, graph, uri):
         self.graph, self.uri = graph, uri
-    
-    def eval(self, songTime):
-        with self.graph.currentState(tripleFilter=(self.uri, L9['code'], None)) as g:
-            code = g.value(self.uri, L9['code'])
-        # consider http://waxeye.org/ for a parser that can be used in py and js
-        m = re.match(r'^out = sub\((.*?), intensity=(.*?)\)', code)
+        self.graph.addHandler(self.prepare)
+
+    def prepare(self):
+        self.code = self.graph.value(self.uri, L9['code'])
+        m = re.match(r'^out = sub\((.*?), intensity=(.*?)\)', self.code)
         if not m:
             raise NotImplementedError
-        sub = uriFromCurie(m.group(1))
-        intensityCurve = uriFromCurie(m.group(2))
-
-        print vars()
+        subUri = uriFromCode(m.group(1))
+        subs = Submaster.get_global_submasters(self.graph)
+        self.sub = subs.get_sub_by_uri(subUri)
         
-def effectDmxDict(graph, effect, songTime):
-    subs = Submaster.get_global_submasters(graph)
-
-    curve = URIRef("http://ex/effect/song1/opening")
-    c = Curve()
-    with graph.currentState(tripleFilter=(curve, None, None)) as g:
-        c.set_from_string(g.value(curve, L9['points']))
-
-    with graph.currentState(tripleFilter=(effect, None, None)) as g:
-        print 'got code', g.value(effect, L9['code'])
-        en = EffectNode(graph, effect)
-
-        en.eval(songTime)
-        
-        sub = subs.get_sub_by_uri(URIRef("http://light9.bigasterisk.com/show/dance2014/sub/stageleft"))
-        level = c.eval(songTime)
-        scaledSubs = [sub * level]
-
-        out = Submaster.sub_maxes(*scaledSubs)
-        levels_dict = out.get_levels()
-        dmx = out.get_dmx_list()
-        return json.dumps(dmx)
+        intensityCurve = uriFromCode(m.group(2))
+        self.curve = Curve()
+        self.curve.set_from_string(self.graph.value(intensityCurve, L9['points']))
+                
+    def eval(self, songTime):
+        # consider http://waxeye.org/ for a parser that can be used in py and js
+        level = self.curve.eval(songTime)
+        scaledSubs = self.sub * level
+        return scaledSubs
 
         
 class EffectEval(PrettyErrorHandler, cyclone.web.RequestHandler):
     @inlineCallbacks
     def get(self):
-        # return dmx dict for that effect
+        # return dmx list for that effect
         uri = URIRef(self.get_argument('uri'))
         response = yield cyclone.httpclient.fetch(
             networking.musicPlayer.path('time'))
         songTime = json.loads(response.body)['t']
-        self.write(effectDmxDict(self.settings.graph, uri, songTime))
-        
+
+        node = EffectNode(self.settings.graph, uri)
+        outSub = node.eval(songTime)
+        self.write(json.dumps(outSub.get_dmx_list()))
+
+
+# Completely not sure where the effect background loop should
+# go. Another process could own it, and get this request repeatedly:
 class SongEffectsEval(PrettyErrorHandler, cyclone.web.RequestHandler):
     def get(self):
         song = URIRef(self.get_argument('song'))
         effects = effectsForSong(self.settings.graph, song)
+        raise NotImplementedError
         self.write(maxDict(effectDmxDict(e) for e in effects))
         # return dmx dict for all effects in the song, already combined
-        
+
+# Or, we could own that loop, like this:
+@inlineCallbacks
+def effectLoop(graph):
+    t1 = time.time()
+    response = json.loads((yield cyclone.httpclient.fetch(
+        networking.musicPlayer.path('time'))).body)
+    song = URIRef(response['song'])
+    songTime = response['t']
+    # Possibilities to make this shut up about graph copies:
+    # - implement the cheap readonly currentState response
+    # - do multiple little currentState calls (in this code) over just
+    #   the required triples
+    # - use addHandler instead and only fire dmx when there is a data
+    #   change (and also somehow call it when there is a time change)
+
+    outSubs = []
+    with graph.currentState(tripleFilter=(song, L9['effect'], None)) as g:
+        for effectUri in g.objects(song, L9['effect']):
+            node = EffectNode(graph, effectUri)
+            outSubs.append(node.eval(songTime))
+        out = Submaster.sub_maxes(*outSubs)
+        # out.get_levels() for a more readable view
+        dmx = out.get_dmx_list()
+
+        if log.isEnabledFor(logging.DEBUG):
+            log.debug("send dmx: %r", out.get_levels())
+        yield dmxclient.outputlevels(dmx, twisted=True)
+
+    loopTime = time.time() - t1
+    log.debug('loopTime %.1f ms', 1000 * loopTime)
+    
 class App(object):
     def __init__(self, show):
         self.show = show
@@ -126,9 +149,10 @@
             (r'/effect/eval', EffectEval),
             (r'/songEffects/eval', SongEffectsEval),
         ], debug=True, graph=self.graph)
-        #graph.initiallySynced.addCallback(
+        self.graph.initiallySynced.addCallback(self.launch)
 
-        # see bin/subserver
+    def launch(self, *args):
+        task.LoopingCall(effectLoop, self.graph).start(1)    
 
 class StaticCoffee(PrettyErrorHandler, cyclone.web.RequestHandler):
     def initialize(self, src):

--- a/light9/Submaster.py	Tue May 27 05:48:25 2014 +0000
+++ b/light9/Submaster.py	Tue May 27 06:29:00 2014 +0000
@@ -334,7 +334,11 @@
 _submasters = None
 
 def get_global_submasters(graph):
-    """Get (and make on demand) the global instance of Submasters."""
+    """
+    Get (and make on demand) the global instance of
+    Submasters. Cached, but the cache is not correctly using the graph
+    argument. The first graph you pass will stick in the cache.
+    """
     global _submasters
     if _submasters is None:
         _submasters = Submasters(graph)

--- a/light9/dmxclient.py	Tue May 27 05:48:25 2014 +0000
+++ b/light9/dmxclient.py	Tue May 27 06:29:00 2014 +0000
@@ -47,6 +47,7 @@
             time.sleep(1)
         d = _dmx.callRemote('outputlevels', clientid, levellist)
         d.addErrback(err)
+        return d
 
 dummy = os.getenv('DMXDUMMY')
 if dummy:

--- a/light9/rdfdb/currentstategraphapi.py	Tue May 27 05:48:25 2014 +0000
+++ b/light9/rdfdb/currentstategraphapi.py	Tue May 27 06:29:00 2014 +0000
@@ -1,4 +1,4 @@
-import logging, traceback
+import logging, traceback, time
 from rdflib import ConjunctiveGraph
 from light9.rdfdb.rdflibpatch import contextsForStatement as rp_contextsForStatement
 log = logging.getLogger("currentstate")
@@ -25,18 +25,20 @@
                 # done. Typical usage will do some reads on this graph
                 # before moving on to writes.
 
+                t1 = time.time()
                 g = ConjunctiveGraph()
                 for s,p,o,c in self._graph.quads(tripleFilter):
                     g.store.add((s,p,o), c)
 
                 if tripleFilter == (None, None, None):
-                    self2.logThisCopy(g)
+                    self2.logThisCopy(g, time.time() - t1)
                     
                 g.contextsForStatement = lambda t: contextsForStatementNoWildcards(g, t)
                 return g
 
-            def logThisCopy(self, g):
-                log.info("copied graph %s statements because of this:" % len(g))
+            def logThisCopy(self, g, sec):
+                log.info("copied graph %s statements (%.1f ms) "
+                         "because of this:" % (len(g), sec * 1000))
                 for frame in traceback.format_stack(limit=4)[:-2]:
                     for line in frame.splitlines():
                         log.info("  "+line)

--- a/show/dance2014/demo.n3	Tue May 27 05:48:25 2014 +0000
+++ b/show/dance2014/demo.n3	Tue May 27 06:29:00 2014 +0000
@@ -34,7 +34,13 @@
   # going to parse it anyway. but, sometimes it will have a syntax
   # error. Can code with errors just parse to a bogus AST that saves
   # the string with errors (and also the uri links found inside)?
-  # Still missing: multiple lines of code with multiple outputs. What's an output?
+  #
+  # Another option- separate just the uri chunks:
+  #   :code ("out = sub(" sub:stageleft ", intensity=" song1:opening ")")
+  # so at least the links are visible in this file.
+  #
+  # Still missing: multiple lines of code with multiple outputs. What's
+  # an output?
   :dep <http://ex/effect/song1/opening>, <http://light9.bigasterisk.com/show/dance2014/sub/stageleft>
   .