comparison service/mqtt_to_rdf/inference.py @ 1597:387a9cb66517

logging adjustments
author drewp@bigasterisk.com
date Sun, 05 Sep 2021 22:39:38 -0700
parents 4e795ed3a693
children 9e6a593180b6
comparison
equal deleted inserted replaced
1596:4e795ed3a693 1597:387a9cb66517
95 if stmt in boundUsedByFuncs: 95 if stmt in boundUsedByFuncs:
96 pass 96 pass
97 elif stmt in workingSet: 97 elif stmt in workingSet:
98 pass 98 pass
99 else: 99 else:
100 log.debug(f'{INDENT*5} binding was invalid because {stmt}) is not known to be true') 100 log.debug(f'{INDENT*5} stmt not known to be true')
101 return False 101 return False
102 log.debug(f"{INDENT*5} this rule's lhs can work under this binding")
103 return True 102 return True
104 103
105 def logVerifyBanner(self, boundLhs, workingSet: ReadOnlyWorkingSet, boundUsedByFuncs): 104 def logVerifyBanner(self, boundLhs, workingSet: ReadOnlyWorkingSet, boundUsedByFuncs):
106 if not log.isEnabledFor(logging.DEBUG): 105 if not log.isEnabledFor(logging.DEBUG):
107 return 106 return
108 log.debug(f'{INDENT*4}/ verify all bindings against this lhs:') 107 log.debug(f'{INDENT*4}/ verify all bindings against this boundLhs:')
109 for stmt in sorted(boundLhs): 108 for stmt in sorted(boundLhs):
110 log.debug(f'{INDENT*4}|{INDENT} {stmt}') 109 log.debug(f'{INDENT*4}|{INDENT} {stmt}')
111 110
112 log.debug(f'{INDENT*4}| and against this workingSet:') 111 # log.debug(f'{INDENT*4}| and against this workingSet:')
113 for stmt in sorted(workingSet): 112 # for stmt in sorted(workingSet):
114 log.debug(f'{INDENT*4}|{INDENT} {stmt}') 113 # log.debug(f'{INDENT*4}|{INDENT} {stmt}')
115 114
116 log.debug(f'{INDENT*4}| while ignoring these usedByFuncs:') 115 stmts = sorted(boundUsedByFuncs)
117 for stmt in sorted(boundUsedByFuncs): 116 if stmts:
118 log.debug(f'{INDENT*4}|{INDENT} {stmt}') 117 log.debug(f'{INDENT*4}| while ignoring these usedByFuncs:')
118 for stmt in stmts:
119 log.debug(f'{INDENT*4}|{INDENT} {stmt}')
119 log.debug(f'{INDENT*4}\\') 120 log.debug(f'{INDENT*4}\\')
120 121
121 122
122 @dataclass 123 @dataclass
123 class Lhs: 124 class Lhs:
136 self.staticRuleStmts.add(ruleStmt) 137 self.staticRuleStmts.add(ruleStmt)
137 138
138 def findCandidateBindings(self, workingSet: ReadOnlyWorkingSet) -> Iterator[CandidateBinding]: 139 def findCandidateBindings(self, workingSet: ReadOnlyWorkingSet) -> Iterator[CandidateBinding]:
139 """bindings that fit the LHS of a rule, using statements from workingSet and functions 140 """bindings that fit the LHS of a rule, using statements from workingSet and functions
140 from LHS""" 141 from LHS"""
141 log.debug(f'{INDENT*2} nodesToBind: {self.lhsBindables}') 142 log.debug(f'{INDENT*3} nodesToBind: {self.lhsBindables}')
142 143
143 if not self.allStaticStatementsMatch(workingSet): 144 if not self.allStaticStatementsMatch(workingSet):
144 return 145 return
145 146
146 candidateTermMatches: Dict[BindableTerm, Set[Node]] = self.allCandidateTermMatches(workingSet) 147 candidateTermMatches: Dict[BindableTerm, Set[Node]] = self.allCandidateTermMatches(workingSet)
147 148
148 orderedVars, orderedValueSets = organize(candidateTermMatches) 149 orderedVars, orderedValueSets = organize(candidateTermMatches)
149 150
150 self.logCandidates(orderedVars, orderedValueSets) 151 self.logCandidates(orderedVars, orderedValueSets)
151 152
152 log.debug(f'{INDENT*2} trying all permutations:') 153 log.debug(f'{INDENT*3} trying all permutations:')
153 154
154 for perm in itertools.product(*orderedValueSets): 155 for perm in itertools.product(*orderedValueSets):
155 binding = CandidateBinding(dict(zip(orderedVars, perm))) 156 binding = CandidateBinding(dict(zip(orderedVars, perm)))
156 log.debug('') 157 log.debug('')
157 log.debug(f'{INDENT*3}*trying {binding}') 158 log.debug(f'{INDENT*4}*trying {binding}')
158 159
159 try: 160 try:
160 usedByFuncs = binding.applyFunctions(self) 161 usedByFuncs = binding.applyFunctions(self)
161 except EvaluationFailed: 162 except EvaluationFailed:
162 continue 163 continue
163 164
164 if not binding.verify(self, workingSet, usedByFuncs): 165 if not binding.verify(self, workingSet, usedByFuncs):
165 log.debug(f'{INDENT*3} this binding did not verify') 166 log.debug(f'{INDENT*4} this binding did not verify')
166 continue 167 continue
167 yield binding 168 yield binding
168 169
169 def allStaticStatementsMatch(self, workingSet: ReadOnlyWorkingSet) -> bool: 170 def allStaticStatementsMatch(self, workingSet: ReadOnlyWorkingSet) -> bool:
170 for ruleStmt in self.staticRuleStmts: 171 for ruleStmt in self.staticRuleStmts:
176 def allCandidateTermMatches(self, workingSet: ReadOnlyWorkingSet) -> Dict[BindableTerm, Set[Node]]: 177 def allCandidateTermMatches(self, workingSet: ReadOnlyWorkingSet) -> Dict[BindableTerm, Set[Node]]:
177 """the total set of terms each variable could possibly match""" 178 """the total set of terms each variable could possibly match"""
178 179
179 candidateTermMatches: Dict[BindableTerm, Set[Node]] = defaultdict(set) 180 candidateTermMatches: Dict[BindableTerm, Set[Node]] = defaultdict(set)
180 for lhsStmt in self.graph: 181 for lhsStmt in self.graph:
181 log.debug(f'{INDENT*3} possibles for this lhs stmt: {lhsStmt}') 182 log.debug(f'{INDENT*4} possibles for this lhs stmt: {lhsStmt}')
182 for i, trueStmt in enumerate(sorted(workingSet)): 183 for i, trueStmt in enumerate(sorted(workingSet)):
183 log.debug(f'{INDENT*4} consider this true stmt ({i}): {trueStmt}') 184 # log.debug(f'{INDENT*5} consider this true stmt ({i}): {trueStmt}')
184 185
185 for v, vals in self._bindingsFromStatement(lhsStmt, trueStmt): 186 for v, vals in self._bindingsFromStatement(lhsStmt, trueStmt):
186 candidateTermMatches[v].update(vals) 187 candidateTermMatches[v].update(vals)
187 188
188 for trueStmt in itertools.chain(workingSet, self.graph): 189 for trueStmt in itertools.chain(workingSet, self.graph):
205 bindingsFromStatement.setdefault(term1, set()).add(term2) 206 bindingsFromStatement.setdefault(term1, set()).add(term2)
206 elif term1 != term2: 207 elif term1 != term2:
207 break 208 break
208 else: 209 else:
209 for v, vals in bindingsFromStatement.items(): 210 for v, vals in bindingsFromStatement.items():
211 log.debug(f'{INDENT*5} {v=} {vals=}')
210 yield v, vals 212 yield v, vals
211 213
212 def graphWithoutEvals(self, binding: CandidateBinding) -> Graph: 214 def graphWithoutEvals(self, binding: CandidateBinding) -> Graph:
213 g = Graph() 215 g = Graph()
214 usedByFuncs = binding.applyFunctions(self) 216 usedByFuncs = binding.applyFunctions(self)
219 return g 221 return g
220 222
221 def logCandidates(self, orderedVars, orderedValueSets): 223 def logCandidates(self, orderedVars, orderedValueSets):
222 if not log.isEnabledFor(logging.DEBUG): 224 if not log.isEnabledFor(logging.DEBUG):
223 return 225 return
224 log.debug(f'{INDENT*2} resulting candidate terms:') 226 log.debug(f'{INDENT*3} resulting candidate terms:')
225 for v, vals in zip(orderedVars, orderedValueSets): 227 for v, vals in zip(orderedVars, orderedValueSets):
226 log.debug(f'{INDENT*3} {v} could be:') 228 log.debug(f'{INDENT*4} {v!r} could be:')
227 for val in vals: 229 for val in vals:
228 log.debug(f'{INDENT*4}{val}') 230 log.debug(f'{INDENT*5}{val!r}')
229 231
230 232
231 class Evaluation: 233 class Evaluation:
232 """some lhs statements need to be evaluated with a special function 234 """some lhs statements need to be evaluated with a special function
233 (e.g. math) and then not considered for the rest of the rule-firing 235 (e.g. math) and then not considered for the rest of the rule-firing
312 314
313 def infer(self, graph: Graph): 315 def infer(self, graph: Graph):
314 """ 316 """
315 returns new graph of inferred statements. 317 returns new graph of inferred statements.
316 """ 318 """
317 log.debug(f'{INDENT*0} Begin inference of graph len={graph.__len__()} with rules len={len(self.rules)}:') 319 log.info(f'{INDENT*0} Begin inference of graph len={graph.__len__()} with rules len={len(self.rules)}:')
318 320
319 # everything that is true: the input graph, plus every rule conclusion we can make 321 # everything that is true: the input graph, plus every rule conclusion we can make
320 workingSet = Graph() 322 workingSet = Graph()
321 workingSet += graph 323 workingSet += graph
322 324
324 implied = ConjunctiveGraph() 326 implied = ConjunctiveGraph()
325 327
326 bailout_iterations = 100 328 bailout_iterations = 100
327 delta = 1 329 delta = 1
328 while delta > 0 and bailout_iterations > 0: 330 while delta > 0 and bailout_iterations > 0:
329 log.debug(f'{INDENT*1}*iteration ({bailout_iterations} left)') 331 log.info(f'{INDENT*1}*iteration ({bailout_iterations} left)')
330 bailout_iterations -= 1 332 bailout_iterations -= 1
331 delta = -len(implied) 333 delta = -len(implied)
332 self._iterateAllRules(workingSet, implied) 334 self._iterateAllRules(workingSet, implied)
333 delta += len(implied) 335 delta += len(implied)
334 log.info(f'{INDENT*1} this inference round added {delta} more implied stmts') 336 log.info(f'{INDENT*2} this inference iteration added {delta} more implied stmts')
335 log.info(f'{INDENT*0} {len(implied)} stmts implied:') 337 log.info(f'{INDENT*0} Inference done; {len(implied)} stmts implied:')
336 for st in implied: 338 for st in implied:
337 log.info(f'{INDENT*2} {st}') 339 log.info(f'{INDENT*1} {st}')
338 return implied 340 return implied
339 341
340 def _iterateAllRules(self, workingSet: Graph, implied: Graph): 342 def _iterateAllRules(self, workingSet: Graph, implied: Graph):
341 for i, r in enumerate(self.rules): 343 for i, r in enumerate(self.rules):
342 self.logRuleApplicationHeader(workingSet, i, r) 344 self.logRuleApplicationHeader(workingSet, i, r)
349 if not log.isEnabledFor(logging.DEBUG): 351 if not log.isEnabledFor(logging.DEBUG):
350 return 352 return
351 353
352 log.debug('') 354 log.debug('')
353 log.debug(f'{INDENT*2} workingSet:') 355 log.debug(f'{INDENT*2} workingSet:')
354 for i, stmt in enumerate(sorted(workingSet)): 356 for j, stmt in enumerate(sorted(workingSet)):
355 log.debug(f'{INDENT*3} ({i}) {stmt}') 357 log.debug(f'{INDENT*3} ({j}) {stmt}')
356 358
357 log.debug('') 359 log.debug('')
358 log.debug(f'{INDENT*2}-applying rule {i}') 360 log.debug(f'{INDENT*2}-applying rule {i}')
359 log.debug(f'{INDENT*3} rule def lhs: {graphDump(r[0])}') 361 log.debug(f'{INDENT*3} rule def lhs: {graphDump(r[0])}')
360 log.debug(f'{INDENT*3} rule def rhs: {graphDump(r[2])}') 362 log.debug(f'{INDENT*3} rule def rhs: {graphDump(r[2])}')
361 363
362 364
363 def applyRule(lhs: Lhs, rhs: Graph, workingSet: Graph, implied: Graph): 365 def applyRule(lhs: Lhs, rhs: Graph, workingSet: Graph, implied: Graph):
364 for binding in lhs.findCandidateBindings(ReadOnlyGraphAggregate([workingSet])): 366 for binding in lhs.findCandidateBindings(ReadOnlyGraphAggregate([workingSet])):
367 log.debug(f'{INDENT*3} rule has a working binding:')
368
365 for lhsBoundStmt in binding.apply(lhs.graphWithoutEvals(binding)): 369 for lhsBoundStmt in binding.apply(lhs.graphWithoutEvals(binding)):
370 log.debug(f'{INDENT*5} adding {lhsBoundStmt=}')
366 workingSet.add(lhsBoundStmt) 371 workingSet.add(lhsBoundStmt)
367 for newStmt in binding.apply(rhs): 372 for newStmt in binding.apply(rhs):
373 log.debug(f'{INDENT*5} adding {newStmt=}')
368 workingSet.add(newStmt) 374 workingSet.add(newStmt)
369 implied.add(newStmt) 375 implied.add(newStmt)
370 376
371 377
372 def parseList(graph, subj) -> Tuple[List[Node], Set[Triple]]: 378 def parseList(graph, subj) -> Tuple[List[Node], Set[Triple]]: