From 507c89d6afef9048f1c20c5b02a3cbe614659dc9 Mon Sep 17 00:00:00 2001 From: David Korczynski Date: Wed, 29 Mar 2023 06:52:58 -0700 Subject: [PATCH] Avoid iterating excessive definitions and comment out a log of debugging logging. Signed-off-by: David Korczynski --- pycg/machinery/callgraph.py | 2 +- pycg/machinery/definitions.py | 14 +++- pycg/processing/base.py | 138 +++++++++++++++---------------- pycg/processing/cgprocessor.py | 42 +++++----- pycg/processing/postprocessor.py | 42 +++++----- pycg/pycg.py | 1 + 6 files changed, 126 insertions(+), 113 deletions(-) diff --git a/pycg/machinery/callgraph.py b/pycg/machinery/callgraph.py index 1522004..9b3e7ba 100644 --- a/pycg/machinery/callgraph.py +++ b/pycg/machinery/callgraph.py @@ -79,7 +79,7 @@ def add_edge(self, src, dest, lineno=-1, mod="", ext_mod=""): "ext_mod" : ext_mod } ) - logger.debug(self.cg_extended[src]) + #logger.debug(self.cg_extended[src]) def get(self): return self.cg diff --git a/pycg/machinery/definitions.py b/pycg/machinery/definitions.py index 4ff74d7..7af3ed9 100644 --- a/pycg/machinery/definitions.py +++ b/pycg/machinery/definitions.py @@ -18,9 +18,14 @@ # specific language governing permissions and limitations # under the License. # +import logging + from pycg.machinery.pointers import NamePointer, LiteralPointer from pycg import utils +logger = logging.getLogger(__name__) + + class DefinitionManager(object): def __init__(self): self.defs = {} @@ -142,11 +147,19 @@ def update_pointsto_args(pointsto_args, arg, name): pointsto_arg_def.add(item) return changed_something + logger.info("Def-Iterating %d defs"%(len(self.defs))) + if len(self.defs) > 9000: + logger.info("The definition list is too large. This is likely to take forever. Avoid this step") + return + for i in range(len(self.defs)): + #logger.info("Def-idx-%d"%(i)) changed_something = False for ns, current_def in self.defs.items(): + #logger.info("Def-idx2-%d"%(idx2)) # the name pointer of the definition we're currently iterating current_name_pointer = current_def.get_name_pointer() + #print("Name point: %s"%(str(current_name_pointer))) # iterate the names the current definition points to items # for name in current_name_pointer.get(): for name in current_name_pointer.get().copy(): @@ -172,7 +185,6 @@ def update_pointsto_args(pointsto_args, arg, name): pointsto_name_pointer.add_arg(arg_name, arg) continue changed_something = changed_something or update_pointsto_args(pointsto_args, arg, current_def.get_ns()) - if not changed_something: break diff --git a/pycg/processing/base.py b/pycg/processing/base.py index 61e810e..4837cdb 100644 --- a/pycg/processing/base.py +++ b/pycg/processing/base.py @@ -261,17 +261,17 @@ def do_assign(decoded, target): def decode_node(self, node): global node_decoder_counter - logger.debug("Node counter: %d"%(node_decoder_counter)) + #logger.debug("Node counter: %d"%(node_decoder_counter)) node_decoder_counter += 1 - logger.debug("In ProcessingBase.decode_node") + #logger.debug("In ProcessingBase.decode_node") if isinstance(node, ast.Name): - logger.debug("DEC-1") - logger.debug("Exit ProcessingBase.decode_node: Node type: Name") + #logger.debug("DEC-1") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Name") node_decoder_counter -= 1 return [self.scope_manager.get_def(self.current_ns, node.id)] elif isinstance(node, ast.Call): - logger.debug("DEC-2") + #logger.debug("DEC-2") decoded = self.decode_node(node.func) return_defs = [] for called_def in decoded: @@ -291,93 +291,93 @@ def decode_node(self, node): if defi: return_defs.append(defi) - logger.debug("Exit ProcessingBase.decode_node: Node type: Call") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Call") node_decoder_counter -= 1 return return_defs elif isinstance(node, ast.Lambda): - logger.debug("DEC-3") + #logger.debug("DEC-3") lambda_counter = self.scope_manager.get_scope(self.current_ns).get_lambda_counter() lambda_name = utils.get_lambda_name(lambda_counter) - logger.debug("Exit ProcessingBase.decode_node: Node type: Lambda") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Lambda") node_decoder_counter -= 1 return [self.scope_manager.get_def(self.current_ns, lambda_name)] elif isinstance(node, ast.Tuple): - logger.debug("DEC-4") + #logger.debug("DEC-4") decoded = [] for elt in node.elts: decoded.append(self.decode_node(elt)) - logger.debug("Exit ProcessingBase.decode_node: Node type: Tuple") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Tuple") node_decoder_counter -= 1 return decoded elif isinstance(node, ast.BinOp): - logger.debug("DEC-5") + #logger.debug("DEC-5") decoded_left = self.decode_node(node.left) decoded_right = self.decode_node(node.right) # return the non definition types if we're talking about a binop # since we only care about the type of the return (num, str, etc) if not isinstance(decoded_left, Definition): - logger.debug("Exit ProcessingBase.decode_node: Node type: BinOp->Left") + #logger.debug("Exit ProcessingBase.decode_node: Node type: BinOp->Left") node_decoder_counter -= 1 return decoded_left if not isinstance(decoded_right, Definition): - logger.debug("Exit ProcessingBase.decode_node: Node type: BinOp->Right") + #logger.debug("Exit ProcessingBase.decode_node: Node type: BinOp->Right") node_decoder_counter -= 1 return decoded_right elif isinstance(node, ast.Attribute): - logger.debug("DEC-6") + #logger.debug("DEC-6") names = self._retrieve_attribute_names(node) defis = [] for name in names: defi = self.def_manager.get(name) if defi: defis.append(defi) - logger.debug("Exit ProcessingBase.decode_node: Node type: Attribute") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Attribute") node_decoder_counter -= 1 return defis elif isinstance(node, ast.Num): - logger.debug("DEC-7") - logger.debug("Exit ProcessingBase.decode_node: Node type: Num") + #logger.debug("DEC-7") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Num") node_decoder_counter -= 1 return [node.n] elif isinstance(node, ast.Str): - logger.debug("DEC-8") - logger.debug("Exit ProcessingBase.decode_node: Node type: Str") + #logger.debug("DEC-8") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Str") node_decoder_counter -= 1 return [node.s] elif self._is_literal(node): - logger.debug("DEC-9") - logger.debug("Exit ProcessingBase.decode_node: Node type: Literal Node") + #logger.debug("DEC-9") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Literal Node") node_decoder_counter -= 1 return [node] elif isinstance(node, ast.Dict): - logger.debug("DEC-10") + #logger.debug("DEC-10") dict_counter = self.scope_manager.get_scope(self.current_ns).get_dict_counter() dict_name = utils.get_dict_name(dict_counter) scope_def = self.scope_manager.get_def(self.current_ns, dict_name) - logger.debug("Exit ProcessingBase.decode_node: Node type: Dict") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Dict") node_decoder_counter -= 1 return [self.scope_manager.get_def(self.current_ns, dict_name)] elif isinstance(node, ast.List): - logger.debug("DEC-11") + #logger.debug("DEC-11") list_counter = self.scope_manager.get_scope(self.current_ns).get_list_counter() list_name = utils.get_list_name(list_counter) scope_def = self.scope_manager.get_def(self.current_ns, list_name) - logger.debug("Exit ProcessingBase.decode_node: Node type: List") + #logger.debug("Exit ProcessingBase.decode_node: Node type: List") node_decoder_counter -= 1 return [self.scope_manager.get_def(self.current_ns, list_name)] elif isinstance(node, ast.Subscript): - logger.debug("DEC-12") + #logger.debug("DEC-12") names = self.retrieve_subscript_names(node) defis = [] for name in names: defi = self.def_manager.get(name) if defi: defis.append(defi) - logger.debug("Exit ProcessingBase.decode_node: Node type: Subscript") + #logger.debug("Exit ProcessingBase.decode_node: Node type: Subscript") node_decoder_counter -= 1 return defis - logger.debug("Exit ProcessingBase.decode_node: Invalid node type") + #logger.debug("Exit ProcessingBase.decode_node: Invalid node type") node_decoder_counter -= 1 return [] @@ -386,17 +386,17 @@ def _is_literal(self, item): return isinstance(item, int) or isinstance(item, str) or isinstance(item, float) def _retrieve_base_names(self, node): - logger.debug("In ProcessingBase._retrieve_base_names") + #logger.debug("In ProcessingBase._retrieve_base_names") if not isinstance(node, ast.Attribute): raise Exception("The node is not an attribute") if not getattr(self, "closured", None): - logger.debug("Exit ProcessingBase._retrieve_base_names: Not closure") + #logger.debug("Exit ProcessingBase._retrieve_base_names: Not closure") return set() decoded = self.decode_node(node.value) if not decoded: - logger.debug("Exit ProcessingBase._retrieve_base_names: Fail to decode node value") + #logger.debug("Exit ProcessingBase._retrieve_base_names: Fail to decode node value") return set() names = set() @@ -411,17 +411,17 @@ def _retrieve_base_names(self, node): for item in cls.get_mro(): names.add(item) - logger.debug("Exit ProcessingBase._retrieve_base_names") + #logger.debug("Exit ProcessingBase._retrieve_base_names") return names def _retrieve_parent_names(self, node): - logger.debug("In ProcessingBase._retrieve_parent_names") + #logger.debug("In ProcessingBase._retrieve_parent_names") if not isinstance(node, ast.Attribute): raise Exception("The node is not an attribute") decoded = self.decode_node(node.value) if not decoded: - logger.debug("Exit ProcessingBase._retrieve_parent_names: Fail to decode node value") + #logger.debug("Exit ProcessingBase._retrieve_parent_names: Fail to decode node value") return set() names = set() @@ -432,56 +432,56 @@ def _retrieve_parent_names(self, node): names = names.union(self.closured.get(parent.get_ns())) else: names.add(parent.get_ns()) - logger.debug("Exit ProcessingBase._retrieve_parent_names") + #logger.debug("Exit ProcessingBase._retrieve_parent_names") return names def _retrieve_attribute_names(self, node): - logger.debug("In ProcessingBase._retrieve_attribute_names") + #logger.debug("In ProcessingBase._retrieve_attribute_names") if not getattr(self, "closured", None): - logger.debug("Exit ProcessingBase._retrieve_attribute_names: Not closure") + #logger.debug("Exit ProcessingBase._retrieve_attribute_names: Not closure") return set() - logger.debug("D-1") + #logger.debug("D-1") parent_names = self._retrieve_parent_names(node) names = set() for parent_name in parent_names: - logger.debug("D-2") + #logger.debug("D-2") for name in self.closured.get(parent_name, []): - logger.debug("D-3") + #logger.debug("D-3") defi = self.def_manager.get(name) if not defi: continue - logger.debug("D-3.1") + #logger.debug("D-3.1") if defi.is_class_def(): - logger.debug("D-3.1-1") + #logger.debug("D-3.1-1") cls_names = self.find_cls_fun_ns(defi.get_ns(), node.attr) if cls_names: - logger.debug("D-3.1-2") + #logger.debug("D-3.1-2") names = names.union(cls_names) - logger.debug("D-3.2") + #logger.debug("D-3.2") if defi.is_function_def() or defi.is_module_def(): - logger.debug("D-3.3") + #logger.debug("D-3.3") names.add(utils.join_ns(name, node.attr)) - logger.debug("D-3.4") + #logger.debug("D-3.4") if defi.is_ext_def(): - logger.debug("D-3.5") + #logger.debug("D-3.5") # HACK: extenral attributes can lead to infinite loops # Identify them here if node.attr in name: continue - logger.debug("D-3.6") + #logger.debug("D-3.6") ext_name = utils.join_ns(name, node.attr) if not self.def_manager.get(ext_name): - logger.debug("D-3.7") + #logger.debug("D-3.7") self.def_manager.create(ext_name, utils.constants.EXT_DEF) - logger.debug("D-3.8") + #logger.debug("D-3.8") names.add(ext_name) - logger.debug("D-10") - logger.debug("Exit ProcessingBase._retrieve_attribute_names") + #logger.debug("D-10") + #logger.debug("Exit ProcessingBase._retrieve_attribute_names") return names def iterate_call_args(self, defi, node): - logger.debug("In ProcessingBase.iterate_call_args") + #logger.debug("In ProcessingBase.iterate_call_args") for pos, arg in enumerate(node.args): self.visit(arg) decoded = self.decode_node(arg) @@ -528,15 +528,15 @@ def iterate_call_args(self, defi, node): defi.get_name_pointer().add_arg(keyword.arg, d.get_ns()) else: defi.get_name_pointer().add_lit_arg(keyword.arg, d) - logger.debug("Exit ProcessingBase.loiterate_call_args") + #logger.debug("Exit ProcessingBase.loiterate_call_args") def retrieve_subscript_names(self, node): - logger.debug("In ProcessingBase.retrieve_subscript_names") + #logger.debug("In ProcessingBase.retrieve_subscript_names") if not isinstance(node, ast.Subscript): raise Exception("The node is not an subcript") if not getattr(self, "closured", None): - logger.debug("Exit ProcessingBase.retrieve_subscript_names: Not Closure") + #logger.debug("Exit ProcessingBase.retrieve_subscript_names: Not Closure") return set() if getattr(node.slice, "value", None) and self._is_literal(node.slice.value): @@ -576,11 +576,11 @@ def retrieve_subscript_names(self, node): full_ns = utils.join_ns(d, str_key) full_names.add(full_ns) - logger.debug("Exit ProcessingBase.retrieve_subscript_names") + #logger.debug("Exit ProcessingBase.retrieve_subscript_names") return full_names def retrieve_call_names(self, node): - logger.debug("In ProcessingBase.retrieve_call_names") + #logger.debug("In ProcessingBase.retrieve_call_names") names = set() if isinstance(node.func, ast.Name): defi = self.scope_manager.get_def(self.current_ns, node.func.id) @@ -604,27 +604,27 @@ def retrieve_call_names(self, node): if self.closured.get(n, None): names |= self.closured.get(n) - logger.debug("Exit ProcessingBase.retrieve_call_names") + #logger.debug("Exit ProcessingBase.retrieve_call_names") return names def analyze_submodules(self, cls, *args, **kwargs): - logger.debug("In ProcessingBase.analyze_submodules") + #logger.debug("In ProcessingBase.analyze_submodules") imports = self.import_manager.get_imports(self.modname) for imp in imports: self.analyze_submodule(cls, imp, *args, **kwargs) - logger.debug("Exit ProcessingBase.analyze_submodules") + #logger.debug("Exit ProcessingBase.analyze_submodules") def analyze_submodule(self, cls, imp, *args, **kwargs): - logger.debug("In ProcessingBase.analyze_submodule") + #logger.debug("In ProcessingBase.analyze_submodule") if imp in self.get_modules_analyzed(): - logger.debug("Exit ProcessingBase.analyze_submodule: Skip analyzed module: %s" % imp) + #logger.debug("Exit ProcessingBase.analyze_submodule: Skip analyzed module: %s" % imp) return fname = self.import_manager.get_filepath(imp) if not fname or not self.import_manager.get_mod_dir() in fname: - logger.debug("Exit ProcessingBase.analyze_submodule: Fail to locate module source: %s" % imp) + #logger.debug("Exit ProcessingBase.analyze_submodule: Fail to locate module source: %s" % imp) return self.import_manager.set_current_mod(imp, fname) @@ -634,13 +634,13 @@ def analyze_submodule(self, cls, imp, *args, **kwargs): self.merge_modules_analyzed(visitor.get_modules_analyzed()) self.import_manager.set_current_mod(self.modname, self.filename) - logger.debug("Exit ProcessingBase.analyze_submodule") + #logger.debug("Exit ProcessingBase.analyze_submodule") def find_cls_fun_ns(self, cls_name, fn): #logger.debug("In ProcessingBase.find_cls_fun_ns") cls = self.class_manager.get(cls_name) if not cls: - logger.debug("Exit ProcessingBase.find_cls_fun_ns: No class manager found") + #logger.debug("Exit ProcessingBase.find_cls_fun_ns: No class manager found") return set() ext_names = set() @@ -653,7 +653,7 @@ def find_cls_fun_ns(self, cls_name, fn): names.add(ns) if self.def_manager.get(ns): - logger.debug("Exit ProcessingBase.find_cls_fun_ns: Found from definition manager") + #logger.debug("Exit ProcessingBase.find_cls_fun_ns: Found from definition manager") return names parent = self.def_manager.get(item) @@ -668,7 +668,7 @@ def find_cls_fun_ns(self, cls_name, fn): return ext_names def add_ext_mod_node(self, name): - logger.debug("In ProcessingBase.add_ext_mod_node") + #logger.debug("In ProcessingBase.add_ext_mod_node") ext_modname = name.split(".")[0] ext_mod = self.module_manager.get(ext_modname) if not ext_mod: @@ -676,4 +676,4 @@ def add_ext_mod_node(self, name): ext_mod.add_method(ext_modname) ext_mod.add_method(name) - logger.debug("Exit ProcessingBase.add_ext_mod_node") + #logger.debug("Exit ProcessingBase.add_ext_mod_node") diff --git a/pycg/processing/cgprocessor.py b/pycg/processing/cgprocessor.py index 3ba7e23..ec5f48f 100644 --- a/pycg/processing/cgprocessor.py +++ b/pycg/processing/cgprocessor.py @@ -68,7 +68,7 @@ def add_to_current_func(self, line_number): self.call_graph.function_line_numbers[self.current_method].add(line_number) def visit_For(self, node): - logger.debug("In CallGraphProcessor.visit_For line number: %d -- %s" % (node.lineno, self.current_method)) + #logger.debug("In CallGraphProcessor.visit_For line number: %d -- %s" % (node.lineno, self.current_method)) self.add_to_current_func(node.lineno) self.visit(node.iter) @@ -89,10 +89,10 @@ def visit_For(self, node): self.call_graph.add_edge(self.current_method, next_ns, mod=self.modname) super().visit_For(node) - logger.debug("Exit CallGraphProcessor.visit_For") + #logger.debug("Exit CallGraphProcessor.visit_For") def visit_Lambda(self, node): - logger.debug("In CallGraphProcessor.visit_Lambda line number: %d -- %s" % (node.lineno, self.current_method)) + #logger.debug("In CallGraphProcessor.visit_Lambda line number: %d -- %s" % (node.lineno, self.current_method)) self.add_to_current_func(node.lineno) counter = self.scope_manager.get_scope(self.current_ns).inc_lambda_counter() lambda_name = utils.get_lambda_name(counter) @@ -101,7 +101,7 @@ def visit_Lambda(self, node): self.call_graph.add_node(lambda_fullns, self.modname) super().visit_Lambda(node, lambda_name) - logger.debug("Exit CallGraphProcessor.visit_Lambda") + #logger.debug("Exit CallGraphProcessor.visit_Lambda") def visit_Raise(self, node): logger.debug("In CallGraphProcessor.visit_Raise line number: %d-- %s" % (node.lineno, self.current_method)) @@ -204,7 +204,7 @@ def visit_Raise(self, node): def visit_If(self, node): - logger.debug("In CallGraphProcessor.visit_If line number: %d -- %s" % (node.lineno, self.current_method)) + #logger.debug("In CallGraphProcessor.visit_If line number: %d -- %s" % (node.lineno, self.current_method)) self.add_to_current_func(node.lineno) FTS="%s"%(str(self.current_ns)) @@ -218,10 +218,10 @@ def visit_If(self, node): self.call_graph.cg_extended[FTS]['meta']['ifCount'] = 1 self.generic_visit(node) - logger.debug("Exit CallGraphProcessor.visit_If") + #logger.debug("Exit CallGraphProcessor.visit_If") def visit_Expr(self, node): - logger.debug("In CallGraphProcessor.visit_Expr line number: %d -- %s" % (node.lineno, self.current_method)) + #logger.debug("In CallGraphProcessor.visit_Expr line number: %d -- %s" % (node.lineno, self.current_method)) self.add_to_current_func(node.lineno) FTS="%s"%(str(self.current_ns)) if FTS in self.call_graph.cg_extended: @@ -231,21 +231,21 @@ def visit_Expr(self, node): self.call_graph.cg_extended[FTS]['meta']['exprCount'] = 1 self.generic_visit(node) # #super().visit_Expr(node) - logger.debug("Exit CallGraphProcessor.visit_Expr") + #logger.debug("Exit CallGraphProcessor.visit_Expr") def visit_Call(self, node): - logger.debug("In CallGraphProcessor.visit_Call line number: %d -- %s" % (node.lineno, self.current_method)) + #logger.debug("In CallGraphProcessor.visit_Call line number: %d -- %s" % (node.lineno, self.current_method)) self.add_to_current_func(node.lineno) def create_ext_edge(name, ext_modname, e_lineno=-1, mod=""): - logger.debug( - "In CallGraphProcessor.visit_Call.create_ext_edge: " - "name: %s; external_mod_name: %s; external_line_no: %s; mod: %s" - % (name, ext_modname, e_lineno, mod) - ) + #logger.debug( + # "In CallGraphProcessor.visit_Call.create_ext_edge: " + # "name: %s; external_mod_name: %s; external_line_no: %s; mod: %s" + # % (name, ext_modname, e_lineno, mod) + #) self.add_ext_mod_node(name) self.call_graph.add_node(name, ext_modname) self.call_graph.add_edge(self.current_method, name, lineno=e_lineno, mod=mod, ext_mod=ext_modname) - logger.debug("Exit CallGraphProcessor.visit_Call.create_ext_edge") + #logger.debug("Exit CallGraphProcessor.visit_Call.create_ext_edge") # First visit the child function so that on the case of # func()()() @@ -275,23 +275,23 @@ def create_ext_edge(name, ext_modname, e_lineno=-1, mod=""): except Exception as e: logger.warn("In CallGraphProcessor.visit_Call: Exception: %s" % str(e)) - logger.debug("In CallGraphProcessor.visit_Call: Main process of line number: %d" % node.lineno) + #logger.debug("In CallGraphProcessor.visit_Call: Main process of line number: %d" % node.lineno) if not names: - logger.debug("In CallGraphProcessor.visit_Call: No name definition found: Fail safe logic") + #logger.debug("In CallGraphProcessor.visit_Call: No name definition found: Fail safe logic") print(str(node)) if isinstance(node.func, ast.Attribute) and self.has_ext_parent(node.func): - logger.debug("I-1") + #logger.debug("I-1") # TODO: This doesn't work for cases where there is an assignment of an attribute # i.e. import os; lala = os.path; lala.dirname() for name in self.get_full_attr_names(node.func): ext_modname = name.split(".")[0] create_ext_edge(name, ext_modname, node.lineno, self.modname) elif getattr(node.func, "id", None) and self.is_builtin(node.func.id): - logger.debug("I-2") + #logger.debug("I-2") name = utils.join_ns(utils.constants.BUILTIN_NAME, node.func.id) create_ext_edge(name, utils.constants.BUILTIN_NAME, node.lineno, self.modname) elif isinstance(node.func, ast.Attribute): - logger.debug("I-3") + #logger.debug("I-3") logger.debug(ast.dump(node, indent=4)) try: lhs = "" @@ -318,7 +318,7 @@ def create_ext_edge(name, ext_modname, e_lineno=-1, mod=""): create_ext_edge(lhs, utils.constants.BUILTIN_NAME, node.lineno, self.modname) except Exception as e: logger.error("In CallGraphProcessor.visit_Call: Exception: %s" % str(e)) - logger.debug("I-4") + #logger.debug("I-4") logger.debug("Exit CallGraphProcessor.visit_Call: No name definition found: Fail safe logic") return diff --git a/pycg/processing/postprocessor.py b/pycg/processing/postprocessor.py index 4815738..8e0931e 100644 --- a/pycg/processing/postprocessor.py +++ b/pycg/processing/postprocessor.py @@ -58,7 +58,7 @@ def visit_Call(self, node): if not names: return for _name in names: - logger.debug("- %s"%(_name)) + #logger.debug("- %s"%(_name)) if "atheris.Setup" in _name: logger.info("We found the call to atheris") logger.info("%s"%(node.args)) @@ -199,58 +199,58 @@ def visit_ClassDef(self, node): # iterate bases to compute MRO for the class cls = self.class_manager.get(cls_def.get_ns()) if not cls: - logger.debug("CC-3") + #logger.debug("CC-3") cls = self.class_manager.create(cls_def.get_ns(), self.modname) - logger.debug("CC-4") + #logger.debug("CC-4") cls.clear_mro() - logger.debug("CC-5") + #logger.debug("CC-5") for base in node.bases: - logger.debug("CC-6") + #logger.debug("CC-6") # all bases are of the type ast.Name self.visit(base) bases = self.decode_node(base) - logger.debug("CC-7") + #logger.debug("CC-7") for base_def in bases: - logger.debug("CC-8") + #logger.debug("CC-8") if not isinstance(base_def, Definition): continue - logger.debug("CC-9") + #logger.debug("CC-9") names = set() if base_def.get_name_pointer().get(): - logger.debug("CC-10") + #logger.debug("CC-10") names = base_def.get_name_pointer().get() - logger.debug("CC-11") + #logger.debug("CC-11") else: - logger.debug("CC-12") + #logger.debug("CC-12") names.add(base_def.get_ns()) - logger.debug("CC-13") + #logger.debug("CC-13") logger.debug("CC-14") for name in names: # add the base as a parent - logger.debug("CC-15") + #logger.debug("CC-15") cls.add_parent(name) - logger.debug("CC-16") + #logger.debug("CC-16") # add the base's parents parent_cls = self.class_manager.get(name) - logger.debug("CC-17") + #logger.debug("CC-17") if parent_cls: - logger.debug("CC-18") + #logger.debug("CC-18") parent_cls_mro = parent_cls.get_mro() - logger.debug("CC-18.1") + #logger.debug("CC-18.1") if parent_cls_mro == cls.mro: continue cls.add_parent(parent_cls_mro) - logger.debug("CC-19") + #logger.debug("CC-19") - logger.debug("CC-20") + #logger.debug("CC-20") cls.compute_mro() - logger.debug("CC-21") + #logger.debug("CC-21") super().visit_ClassDef(node) - logger.debug("CC-22") + #logger.debug("CC-22") logger.debug("Exit PreProcessor.visit_ClassDef") def visit_List(self, node): diff --git a/pycg/pycg.py b/pycg/pycg.py index ef04972..0d013ca 100644 --- a/pycg/pycg.py +++ b/pycg/pycg.py @@ -153,6 +153,7 @@ def do_pass(self, cls, install_hooks=False, *args, **kwargs): self.import_manager.install_hooks() else: logger.info("Not installing hooks") + logger.info("Creating processing class") processor = cls(input_file, input_mod, modules_analyzed=modules_analyzed, *args, **kwargs) logger.info("Done analysis: %s"%(input_file))