changeset 120:3733efe1fd19

finesse logging
author drewp@bigasterisk.com
date Tue, 23 May 2023 19:57:31 -0700
parents 6443cb265a2f
children 8a0559bcbe7e
files rdfdb/service.py rdfdb/shared_graph.py rdfdb/watched_files.py rdfdb/watched_graphs.py
diffstat 4 files changed, 19 insertions(+), 19 deletions(-) [+]
line wrap: on
line diff
--- a/rdfdb/service.py	Tue May 23 19:57:11 2023 -0700
+++ b/rdfdb/service.py	Tue May 23 19:57:31 2023 -0700
@@ -17,7 +17,7 @@
 from rdfdb.patch import Patch
 from rdfdb.shared_graph import SharedGraph
 
-log = logging.getLogger('rdfdb')
+log = logging.getLogger('rdfdb.net')
 
 _wsClientSerial = itertools.count(0)
 
@@ -107,9 +107,6 @@
             'xsd': URIRef('http://www.w3.org/2001/XMLSchema#'),
         }
 
-    log.setLevel(logging.DEBUG if 1 else logging.INFO)
-
-    log.info('setup watches')
     db = SharedGraph(dirUriMap=dirUriMap, prefixes=prefixes)
 
     app = Starlette(
--- a/rdfdb/shared_graph.py	Tue May 23 19:57:11 2023 -0700
+++ b/rdfdb/shared_graph.py	Tue May 23 19:57:31 2023 -0700
@@ -15,8 +15,9 @@
 from rdfdb.patch import ALLSTMTS, EmptyPatch, Patch
 from rdfdb.watched_graphs import WatchedGraphs
 
-log = logging.getLogger('shared')
-log.info('hello shared')
+log = logging.getLogger('rdfdb.graph')
+netlog = logging.getLogger('rdfdb.net')
+
 STAT_CLIENTS = Gauge('clients', 'connected clients')
 STAT_SETATTR_CALLS = Summary('set_attr_calls', 'set_attr calls')
 STAT_GRAPH_STATEMENTS = Gauge('graph_statements', 'graph statements')
@@ -37,7 +38,6 @@
         STAT_GRAPH_STATEMENTS.set(len(self.graph))
         STAT_CLIENTS.set(len(self.clients))
 
-        log.info('setup watches')
         self.watchedGraphs = WatchedGraphs(dirUriMap, prefixes)
         self._graphEventsTask = asyncio.create_task(self._graphEvents())
 
@@ -56,7 +56,11 @@
         except EmptyPatch:
             return
         log.info("patching graph %s %s" % (ctx, patch.shortSummary()))
-
+        if log.isEnabledFor(logging.DEBUG):
+            for q in patch.delQuads:
+                log.debug(f'- {q}')
+            for q in patch.addQuads:
+                log.debug(f'+ {q}')
         # if hasattr(self, 'watchedFiles'):  # todo: eliminate this
         #     self.watchedFiles.aboutToPatch(ctx)
 
@@ -86,7 +90,7 @@
             if now - self.lastWriteFileToContext.get(ev.uri, 0) < .1:
                 # probably a change due to our own write. this should be handled in watched_files, not here!
                 continue
-            log.info(f'last wrote file for {ev.uri} {now-self.lastWriteFileToContext.get(ev.uri, 0)} sec ago')
+            # log.info(f'last wrote file for {ev.uri} {now-self.lastWriteFileToContext.get(ev.uri, 0)} sec ago')
             prev = self.graph.getSubgraph(ev.uri)
             new = list(ev.content)
             p = Patch.fromTriplesDiff(prev, new, ev.uri)
@@ -96,20 +100,20 @@
         for cid in self.clients:
             if sender is not None and cid == sender:
                 # this client has self-applied the patch already
-                log.debug("_syncPatchToOtherClients: don't resend to %r", cid)
+                netlog.debug("_syncPatchToOtherClients: don't resend to %r", cid)
                 continue
-            log.debug('_syncPatchToOtherClients: send to %r', cid)
+            netlog.debug('_syncPatchToOtherClients: send to %r', cid)
             await self.clients[cid](p)
 
     async def addClient(self, newClient: str, sendPatchToClient: Callable[[Patch], Awaitable]):
-        log.info(f"new connection: sending all graphs to {newClient}")
+        netlog.info(f"new connection: sending all graphs to {newClient}")
         # this may be too big!
         self.clients[newClient] = sendPatchToClient
         await sendPatchToClient(Patch(addQuads=self.graph.quads(ALLSTMTS), delQuads=[]))
         STAT_CLIENTS.set(len(self.clients))
 
     def clientDisconnected(self, cid: str) -> None:
-        log.info(f"dropping client {cid}")
+        netlog.info(f"dropping client {cid}")
         del self.clients[cid]
         STAT_CLIENTS.set(len(self.clients))
 
--- a/rdfdb/watched_files.py	Tue May 23 19:57:11 2023 -0700
+++ b/rdfdb/watched_files.py	Tue May 23 19:57:31 2023 -0700
@@ -7,7 +7,7 @@
 import asyncinotify
 from asyncinotify import Event, Inotify, Mask
 
-log = logging.getLogger('watchedfiles')
+log = logging.getLogger('rdfdb.file')
 
 
 class FileIsGone:
@@ -89,7 +89,7 @@
             raise
 
     def _watchFile(self, p: Path):
-        log.info(f'watchFile({p})')
+        log.debug(f'watchFile({p})')
         # old code said this:
         #     inFile = correctToTopdirPrefix(self.dirUriMap, inFile)
 
@@ -112,7 +112,7 @@
                 0))
 
     def _watchDir(self, p: Path):
-        log.info(f'watchDir({p})')
+        log.debug(f'watchDir({p})')
         assert p.is_dir()
         self._addWatch(
             p,
@@ -167,7 +167,7 @@
             raise TypeError
         if p.name.endswith('.rdfdb-temp'):
             return
-        log.info(f'ino callback path={str(p)[-30:]!s:30} watchpath={str(iev.path)[-30:]!s:30} {iev.mask!r}')
+        log.debug(f'ino callback path={str(p)[-30:]!s:30} watchpath={str(iev.path)[-30:]!s:30} {iev.mask!r}')
 
         if iev.mask == Mask.DELETE_SELF:
             self._genGoneEvent(p)
--- a/rdfdb/watched_graphs.py	Tue May 23 19:57:11 2023 -0700
+++ b/rdfdb/watched_graphs.py	Tue May 23 19:57:31 2023 -0700
@@ -14,7 +14,7 @@
 
 patchN3SerializerToUseLessWhitespace()
 
-log = logging.getLogger('watchedgraphs')
+log = logging.getLogger('rdfdb.edit')
 
 
 @dataclasses.dataclass
@@ -33,7 +33,6 @@
         self._dirUriMap = dirUriMap
         self.addlPrefixes = addlPrefixes
         self.graphEditEvents = asyncio.Queue()
-        log.info("setup watches")
         self._wf = WatchedFiles(dirsToWatch=dirUriMap.keys(), filenameFilter=self._filenameFilter)
         self._loopTask = asyncio.create_task(self._loop())