summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--README28
-rw-r--r--docs/changelog.rst1
-rw-r--r--factory/base.py18
-rw-r--r--factory/containers.py21
-rw-r--r--factory/declarations.py35
-rw-r--r--factory/utils.py7
-rwxr-xr-xsetup.py11
7 files changed, 112 insertions, 9 deletions
diff --git a/README b/README
index 06f3393..8586e1d 100644
--- a/README
+++ b/README
@@ -184,6 +184,34 @@ The associated object's strategy will be used:
True
+Debugging factory_boy
+"""""""""""""""""""""
+
+Debugging factory_boy can be rather complex due to the long chains of calls.
+Detailed logging is available through the ``factory`` logger:
+
+.. code-block:: python
+
+ import logging
+ logger = logging.getLogger('factory')
+ logger.addHandler(logging.StreamHandler())
+ logger.setLevel(logging.DEBUG)
+
+This will yield messages similar to those (artificial indentation):
+
+.. code-block:: ini
+
+ BaseFactory: Preparing tests.test_using.TestModel2Factory(extra={})
+ LazyStub: Computing values for tests.test_using.TestModel2Factory(two=<OrderedDeclarationWrapper for <factory.declarations.SubFactory object at 0x1e15610>>)
+ SubFactory: Instantiating tests.test_using.TestModelFactory(__containers=(<LazyStub for tests.test_using.TestModel2Factory>,), one=4), create=True
+ BaseFactory: Preparing tests.test_using.TestModelFactory(extra={'__containers': (<LazyStub for tests.test_using.TestModel2Factory>,), 'one': 4})
+ LazyStub: Computing values for tests.test_using.TestModelFactory(one=4)
+ LazyStub: Computed values, got tests.test_using.TestModelFactory(one=4)
+ BaseFactory: Generating tests.test_using.TestModelFactory(one=4)
+ LazyStub: Computed values, got tests.test_using.TestModel2Factory(two=<tests.test_using.TestModel object at 0x1e15410>)
+ BaseFactory: Generating tests.test_using.TestModel2Factory(two=<tests.test_using.TestModel object at 0x1e15410>)
+
+
ORM Support
"""""""""""
diff --git a/docs/changelog.rst b/docs/changelog.rst
index 5d6c4bf..a08330f 100644
--- a/docs/changelog.rst
+++ b/docs/changelog.rst
@@ -15,6 +15,7 @@ ChangeLog
to their own modules (:mod:`factory.django` and :mod:`factory.mogo`)
- Add the :meth:`~factory.Factory.reset_sequence` classmethod to :class:`~factory.Factory`
to ease resetting the sequence counter for a given factory.
+ - Add debug messages to ``factory`` logger.
*Bugfix*
diff --git a/factory/base.py b/factory/base.py
index ff5404f..60aa218 100644
--- a/factory/base.py
+++ b/factory/base.py
@@ -20,7 +20,12 @@
# OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
# THE SOFTWARE.
+import logging
+
from . import containers
+from . import utils
+
+logger = logging.getLogger('factory.generate')
# Strategies
BUILD_STRATEGY = 'build'
@@ -300,7 +305,13 @@ class BaseFactory(object):
force_sequence = None
if extra:
force_sequence = extra.pop('__sequence', None)
- return containers.AttributeBuilder(cls, extra).build(
+ log_ctx = '%s.%s' % (cls.__module__, cls.__name__)
+ logger.debug('BaseFactory: Preparing %s.%s(extra=%r)',
+ cls.__module__,
+ cls.__name__,
+ extra,
+ )
+ return containers.AttributeBuilder(cls, extra, log_ctx=log_ctx).build(
create=create,
force_sequence=force_sequence,
)
@@ -338,6 +349,11 @@ class BaseFactory(object):
# Extract *args from **kwargs
args = tuple(kwargs.pop(key) for key in cls.FACTORY_ARG_PARAMETERS)
+ logger.debug('BaseFactory: Generating %s.%s(%s)',
+ cls.__module__,
+ cls.__name__,
+ utils.log_pprint(args, kwargs),
+ )
if create:
return cls._create(target_class, *args, **kwargs)
else:
diff --git a/factory/containers.py b/factory/containers.py
index b3b003e..4975036 100644
--- a/factory/containers.py
+++ b/factory/containers.py
@@ -20,6 +20,9 @@
# OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
# THE SOFTWARE.
+import logging
+
+logger = logging.getLogger(__name__)
from . import declarations
from . import utils
@@ -49,17 +52,18 @@ class LazyStub(object):
__initialized = False
- def __init__(self, attrs, containers=(), target_class=object):
+ def __init__(self, attrs, containers=(), target_class=object, log_ctx=None):
self.__attrs = attrs
self.__values = {}
self.__pending = []
self.__containers = containers
self.__target_class = target_class
+ self.__log_ctx = log_ctx or '%s.%s' % (target_class.__module__, target_class.__name__)
self.factory_parent = containers[0] if containers else None
self.__initialized = True
def __repr__(self):
- return '<LazyStub for %s>' % self.__target_class.__name__
+ return '<LazyStub for %s.%s>' % (self.__target_class.__module__, self.__target_class.__name__)
def __str__(self):
return '<LazyStub for %s with %s>' % (
@@ -72,8 +76,14 @@ class LazyStub(object):
dict: map of attribute name => computed value
"""
res = {}
+ logger.debug("LazyStub: Computing values for %s(%s)",
+ self.__log_ctx, utils.log_pprint(kwargs=self.__attrs),
+ )
for attr in self.__attrs:
res[attr] = getattr(self, attr)
+ logger.debug("LazyStub: Computed values, got %s(%s)",
+ self.__log_ctx, utils.log_pprint(kwargs=res),
+ )
return res
def __getattr__(self, name):
@@ -219,8 +229,8 @@ class AttributeBuilder(object):
overridden default values for the related SubFactory.
"""
- def __init__(self, factory, extra=None, *args, **kwargs):
- super(AttributeBuilder, self).__init__(*args, **kwargs)
+ def __init__(self, factory, extra=None, log_ctx=None, **kwargs):
+ super(AttributeBuilder, self).__init__(**kwargs)
if not extra:
extra = {}
@@ -228,6 +238,7 @@ class AttributeBuilder(object):
self.factory = factory
self._containers = extra.pop('__containers', ())
self._attrs = factory.declarations(extra)
+ self._log_ctx = log_ctx
attrs_with_subfields = [
k for k, v in self._attrs.items()
@@ -266,7 +277,7 @@ class AttributeBuilder(object):
wrapped_attrs[k] = v
stub = LazyStub(wrapped_attrs, containers=self._containers,
- target_class=self.factory)
+ target_class=self.factory, log_ctx=self._log_ctx)
return stub.__fill__()
diff --git a/factory/declarations.py b/factory/declarations.py
index abd384e..dbade97 100644
--- a/factory/declarations.py
+++ b/factory/declarations.py
@@ -23,11 +23,15 @@
import itertools
import warnings
+import logging
from . import compat
from . import utils
+logger = logging.getLogger('factory.generate')
+
+
class OrderedDeclaration(object):
"""A factory declaration.
@@ -67,6 +71,7 @@ class LazyAttribute(OrderedDeclaration):
self.function = function
def evaluate(self, sequence, obj, create, extra=None, containers=()):
+ logger.debug("LazyAttribute: Evaluating %r on %r", self.function, obj)
return self.function(obj)
@@ -131,6 +136,8 @@ class SelfAttribute(OrderedDeclaration):
target = containers[self.depth - 2]
else:
target = obj
+
+ logger.debug("SelfAttribute: Picking attribute %r on %r", self.attribute_name, target)
return deepgetattr(target, self.attribute_name, self.default)
def __repr__(self):
@@ -161,6 +168,7 @@ class Iterator(OrderedDeclaration):
self.iterator = iter(iterator)
def evaluate(self, sequence, obj, create, extra=None, containers=()):
+ logger.debug("Iterator: Fetching next value from %r", self.iterator)
value = next(self.iterator)
if self.getter is None:
return value
@@ -184,6 +192,7 @@ class Sequence(OrderedDeclaration):
self.type = type
def evaluate(self, sequence, obj, create, extra=None, containers=()):
+ logger.debug("Sequence: Computing next value of %r for seq=%d", self.function, sequence)
return self.function(self.type(sequence))
@@ -197,6 +206,8 @@ class LazyAttributeSequence(Sequence):
of counter for the 'function' attribute.
"""
def evaluate(self, sequence, obj, create, extra=None, containers=()):
+ logger.debug("LazyAttributeSequence: Computing next value of %r for seq=%d, obj=%r",
+ self.function, sequence, obj)
return self.function(obj, self.type(sequence))
@@ -364,6 +375,11 @@ class SubFactory(ParameteredAttribute):
override the wrapped factory's defaults
"""
subfactory = self.get_factory()
+ logger.debug("SubFactory: Instantiating %s.%s(%s), create=%r",
+ subfactory.__module__, subfactory.__name__,
+ utils.log_pprint(kwargs=params),
+ create,
+ )
return subfactory.simple_generate(create, **params)
@@ -375,6 +391,7 @@ class Dict(SubFactory):
def generate(self, sequence, obj, create, params):
dict_factory = self.get_factory()
+ logger.debug("Dict: Building dict(%s)", utils.log_pprint(kwargs=params))
return dict_factory.simple_generate(create,
__sequence=sequence,
**params)
@@ -389,6 +406,9 @@ class List(SubFactory):
def generate(self, sequence, obj, create, params):
list_factory = self.get_factory()
+ logger.debug('List: Building list(%s)',
+ utils.log_pprint(args=[v for _i, v in sorted(params.items())]),
+ )
return list_factory.simple_generate(create,
__sequence=sequence,
**params)
@@ -435,6 +455,11 @@ class PostGeneration(PostGenerationDeclaration):
self.function = function
def call(self, obj, create, extracted=None, **kwargs):
+ logger.debug('PostGeneration: Calling %s.%s(%s)',
+ self.function.__module__,
+ self.function.__name__,
+ utils.log_pprint((obj, create, extracted), kwargs),
+ )
return self.function(obj, create, extracted, **kwargs)
@@ -474,6 +499,11 @@ class RelatedFactory(PostGenerationDeclaration):
passed_kwargs[self.name] = obj
factory = self.get_factory()
+ logger.debug('RelatedFactory: Generating %s.%s(%s)',
+ factory.__module__,
+ factory.__name__,
+ utils.log_pprint((create,), passed_kwargs),
+ )
factory.simple_generate(create, **passed_kwargs)
@@ -509,4 +539,9 @@ class PostGenerationMethodCall(PostGenerationDeclaration):
passed_kwargs = dict(self.method_kwargs)
passed_kwargs.update(kwargs)
method = getattr(obj, self.method_name)
+ logger.debug('PostGenerationMethodCall: Calling %r.%s(%s)',
+ obj,
+ self.method_name,
+ utils.log_pprint(passed_args, passed_kwargs),
+ )
method(*passed_args, **passed_kwargs)
diff --git a/factory/utils.py b/factory/utils.py
index fb8cfef..e1b265f 100644
--- a/factory/utils.py
+++ b/factory/utils.py
@@ -94,3 +94,10 @@ def import_object(module_name, attribute_name):
module = __import__(module_name, {}, {}, [attribute_name], 0)
return getattr(module, attribute_name)
+
+def log_pprint(args=(), kwargs=None):
+ kwargs = kwargs or {}
+ return ', '.join(
+ [str(arg) for arg in args] +
+ ['%s=%r' % item for item in kwargs.items()]
+ )
diff --git a/setup.py b/setup.py
index 050e43b..42519ce 100755
--- a/setup.py
+++ b/setup.py
@@ -46,10 +46,15 @@ class test(cmd.Command):
except ImportError:
import unittest
- if self.verbose:
- verbosity=1
+ import logging
+ logger = logging.getLogger('factory')
+ logger.addHandler(logging.StreamHandler())
+
+ verbosity = self.verbose
+ if verbosity >= 2:
+ logger.setLevel(logging.DEBUG)
else:
- verbosity=0
+ logger.setLevel(logging.INFO)
loader = unittest.TestLoader()
suite = unittest.TestSuite()