#32970: Investigate feasibility of improving WhereNode clone performance
-------------------------------------+-------------------------------------
Reporter: Keryn Knight | Owner: Keryn
Type: | Knight
Cleanup/optimization | Status: assigned
Component: Database layer | Version: dev
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Description changed by Keryn Knight:
Old description:
> This relates to #32948 insofar as it's about figuring out how shallow or
> deep a copy is necessary for cloning `Node` instances/subclasses. And a
> bit to #28455 which acknowledges the need to avoid cloning sometimes due
> to it being costly.
>
> The PR I made for optimising Q combining/inverting
> (https://github.com/django/django/pull/14673) wants to introduce a
> `__copy__` method onto `Q` objects to indicate what level of operation is
> needed. Unlike that PR, it's decidedly not possible to take the same
> approach with WhereNode and just do `clone.__dict__ =
> self.__dict__.copy()` (things broke horribly) because of attributes like
> `contains_aggregate` and `output_field` which are cached properties on
> the WhereNode instance. Also `resolved` gets set after the fact by
> `resolve_expression`. But, as far as I can tell, the
> looping/testing/child cloning ''may be removable''. Perhaps once upon a
> time they were required and other components changed such that it's now
> safe to consider. I can't readily say, but initial experimentation
> suggests it's OK to look at, at least in theory.
>
> There is a PR already for this, here:
> https://github.com/django/django/pull/14709 which is currently marked
> draft/WIP because I couldn't easily run the whole test suite locally and
> needed to see if the more exotic parts caused problems. They didn't,
> which was unexpected, so here I am. The PR currently replaces the
> `WhereNode.clone` method like so:
> {{{
> clone = self.__class__._new_instance(children=[],
> connector=self.connector, negated=self.negated)
> for child in self.children:
> if hasattr(child, 'clone'):
> clone.children.append(child.clone())
> else:
> clone.children.append(child)
> }}}
> with:
> {{{
> clone = self.__class__._new_instance(children=None,
> connector=self.connector, negated=self.negated)
> clone.children = self.children[:]
> }}}
>
> But I ''think'' that Q and WhereNode ''can'' both just return a shallow
> copy by only aliasing the children property, at which point I think the
> `__copy__` method could be implemented on `Node` directly and mirror the
> existing `__deepcopy__` method. By preferring those stdlib names it draws
> a line in the sand over what level of copy should be expected. The
> existing `clone` and `copy` methods can become aliases to same.
>
> === Before any changes
>
> If we now begin to examine the before and after with as much data as I
> can easily gather. First a bit of prelude:
>
> {{{
> In [1]: from django.db.models.sql.where import WhereNode
> In [2]: from django.db.models import QuerySet
> In [3]: from django.db.models.sql import Query
> In [4]: from django.contrib.auth.models import User
> In [5]: x = User.objects.all()
> In [6]: y = User.objects.filter(username='test',
> email='t...@test.test').exclude(username='test').filter(email='nottest')
> In [7]: %load_ext line_profiler
> }}}
>
> Now let's establish a ballpark for how much time is spent where, I've
> stripped the line profiling down to just the relevant bits for clarity.
>
> ==== Queryset with no clauses (`x`)
>
> {{{
> In [8]: %lprun -f QuerySet._chain -f QuerySet._clone -f Query.chain -f
> Query.clone -f WhereNode.clone for _ in range(1000): x._chain()
>
> Function: QuerySet._chain
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 1325 def _chain(self,
> **kwargs):
> ...
> 1330 1000 88169.0 88.2 97.8 obj =
> self._clone()
>
> Function: QuerySet._clone
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 1337 def _clone(self):
> ...
> 1342 1000 80796.0 80.8 86.3 chained =
> self.query.chain()
> 1343 1000 7240.0 7.2 7.7 c =
> self.__class__(model=self.model, query=chained, using=self._db,
> hints=self._hints))
>
> Function: Query.chain
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 341 def chain(self,
> klass=None):
> ...
> 346 2000 116961.0 58.5 94.8 obj =
> self.clone()
>
> Function: Query.clone
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 290 def clone(self):
> ...
> 304 2000 18294.0 9.1 27.0 obj.where =
> self.where.clone()
>
> Function: WhereNode.clone
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 142 def clone(self):
> ...
> 148 4000 6227.0 1.6 63.7 clone =
> self.__class__._new_instance(
> 149 2000 1170.0 0.6 12.0 children=[],
> connector=self.connector, negated=self.negated)
> 150 2000 1407.0 0.7 14.4 for child in
> self.children:
> 151 if
> hasattr(child, 'clone'):
> 152
> clone.children.append(child.clone())
> 153 else:
> 154
> clone.children.append(child)
> 155 2000 969.0 0.5 9.9 return clone
> }}}
>
> ==== Queryset with where clauses (`y`)
>
> Youu can see the cost begin to go up:
> {{{
> In [9]: %lprun -f QuerySet._chain -f QuerySet._clone -f Query.chain -f
> Query.clone -f WhereNode.clone for _ in range(1000): y._chain()
>
> Function: Query.clone
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 290 def clone(self):
> ...
> 304 2000 60065.0 30.0 59.1 obj.where =
> self.where.clone()
>
> Function: WhereNode.clone
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 142 def clone(self):
> 148 8000 11473.0 1.4 33.1 clone =
> self.__class__._new_instance(
> 149 4000 2379.0 0.6 6.9 children=[],
> connector=self.connector, negated=self.negated)
> 150 14000 7241.0 0.5 20.9 for child in
> self.children:
> 151 10000 5553.0 0.6 16.0 if
> hasattr(child, 'clone'):
> 152 2000 1255.0 0.6 3.6
> clone.children.append(child.clone())
> 153 else:
> 154 8000 5069.0 0.6 14.6
> clone.children.append(child)
> 155 4000 1715.0 0.4 4.9 return clone
>
> }}}
>
> and the timings for those 2 (`x` and `y`) querysets, plus an example of
> prefetching related data:
>
> {{{
> In [10]: %timeit x._chain()
> 6.43 µs ± 52 ns per loop (mean ± std. dev. of 7 runs, 100000 loops each)
> In [11]: %timeit y._chain()
> 8.24 µs ± 35.3 ns per loop (mean ± std. dev. of 7 runs, 100000 loops
> each))
> In [12]: %timeit y.query.where.clone()
> 2.79 µs ± 38.2 ns per loop (mean ± std. dev. of 7 runs, 100000 loops
> each)
> In [13]: %prun for _ in range(100000): y._chain()
> 3400003 function calls (3300003 primitive calls) in 1.506 seconds
> ncalls tottime percall cumtime percall
> filename:lineno(function)
> 100000 0.357 0.000 1.007 0.000 query.py:290(clone)
> 200000/100000 0.301 0.000 0.539 0.000 where.py:142(clone) <--
> WhereNode
> 100000 0.172 0.000 1.344 0.000 query.py:1337(_clone)
> 100000 0.068 0.000 1.086 0.000 query.py:341(chain)
> 100000 0.058 0.000 1.415 0.000 query.py:1325(_chain)
> In [14]: %timeit
> tuple(User.objects.prefetch_related('groups__permissions',
> 'user_permissions'))
> 18.2 ms ± 117 µs per loop (mean ± std. dev. of 7 runs, 100 loops each))
> }}}
>
> === After replacing the clone method
>
> Given those data points, here are the same bits of line profiling,
> showing only those where the needle has moved:
>
> ==== Queryset with no clauses (`x`)
>
> {{{
> Function: Query.clone
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 290 def clone(self):
> ...
> 304 2000 14134.0 7.1 22.8 obj.where =
> self.where.clone()
>
> Function: WhereNode.clone
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 142 def clone(self):
> ...
> 148 2000 5586.0 2.8 71.0 clone =
> self.__class__._new_instance(children=None, connector=self.connector,
> negated=self.negated)
> 149 2000 1412.0 0.7 18.0 clone.children =
> self.children[:]
> 150 2000 865.0 0.4 11.0 return clone
> }}}
>
> ==== Queryset with where clauses (`y`)
>
> {{{
> Function: Query.clone at line 290
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 290 def clone(self):
> ...
> 304 2000 13730.0 6.9 24.7 obj.where =
> self.where.clone()
>
> Function: WhereNode.clone
> Line # Hits Time Per Hit % Time Line Contents
> ==============================================================
> 142 def clone(self):
> ...
> 148 2000 5273.0 2.6 69.0 clone =
> self.__class__._new_instance(children=None, connector=self.connector,
> negated=self.negated)
> 149 2000 1498.0 0.7 19.6 clone.children =
> self.children[:]
> 150 2000 871.0 0.4 11.4 return clone
> }}}
>
> And the timings; in the empty case (`x`), it's ''basically'' just paying
> the cost of class creation, but where there are clauses it is more
> consistent (ie: ''nearer'' a constant time vs linear growth).
> {{{
> In [10]: %timeit x._chain()
> 6.51 µs ± 47.6 ns per loop (mean ± std. dev. of 7 runs, 100000 loops
> each))
> In [11]: %timeit y._chain()
> 6.25 µs ± 36.4 ns per loop (mean ± std. dev. of 7 runs, 100000 loops
> each)
> In [12]: %timeit y.query.where.clone()
> 1.16 µs ± 9.09 ns per loop (mean ± std. dev. of 7 runs, 1000000 loops
> each)
> In [13]: %prun for _ in range(100000): y._chain()
> 3800003 function calls in 1.926 seconds
> ncalls tottime percall cumtime percall filename:lineno(function)
> 100000 0.355 0.000 0.606 0.000 query.py:290(clone)
> 100000 0.169 0.000 0.939 0.000 query.py:1337(_clone)
> 100000 0.068 0.000 0.139 0.000 where.py:142(clone) <---
> WhereNode
> 100000 0.067 0.000 0.683 0.000 query.py:341(chain)
> 100000 0.058 0.000 1.009 0.000 query.py:1325(_chain)
> In [14]: %timeit
> tuple(User.objects.prefetch_related('groups__permissions',
> 'user_permissions'))
> 17.9 ms ± 345 µs per loop (mean ± std. dev. of 7 runs, 10 loops each)
> }}}
>
> Gut feeling says the "final" implementation could be something like the
> following, directly on the `Node` class.
> {{{
> def __copy__(self):
> clone = self._new_instance(children=None, connector=self.connector,
> negated=self.negated)
> clone.children = self.children[:]
> return clone
>
> copy = __copy__
> clone = __copy__
>
> def __deepcopy__(self, memo):
> ...
> clone.children = copy.deepcopy(self.children, memo)
> ...
> }}}
>
> which would remove the need for methods on either subclass. Note also
> that aliasing the methods that way rather than doing `def copy(): return
> self.clone()` as `WhereNode` currently does is also ''slightly'' quicker.
> We're talking `0.10µs` - small potatoes, but it doesn't hurt to have +
> it's 1 fewer stack frame.
>
> A final note then: if this properly shallow clone is done, I suspect
> `resolve_expression` can be altered too, to avoid calling `_resolve_node`
> if it's already been done on `self` - the shallow copy would ensure that
> anything which had previously been resolved is kept around and doesn't
> need doing again, I think.
>
> Other stats: Of the 14,000 tests I can run easily, only 1 time was
> `resolved` in `self.__dict__` when `clone` was called (the value was
> `True`). `contains_aggregate` turned up 209 times (207 with a value of
> `False`, 2 with `True`), and `output_field` only appeared 2 times (both
> `BooleanField`). Those are the only extra attribute I spotted.
New description:
This relates to #32948 insofar as it's about figuring out how shallow or
deep a copy is necessary for cloning `Node` instances/subclasses. And a
bit to #28455 which acknowledges the need to avoid cloning sometimes due
to it being costly.
The PR I made for optimising Q combining/inverting
(https://github.com/django/django/pull/14673) wants to introduce a
`__copy__` method onto `Q` objects to indicate what level of operation is
needed. Unlike that PR, it's decidedly not possible to take the same
approach with WhereNode and just do `clone.__dict__ =
self.__dict__.copy()` (things broke horribly) because of attributes like
`contains_aggregate` and `output_field` which are cached properties on the
WhereNode instance. Also `resolved` gets set after the fact by
`resolve_expression`. But, as far as I can tell, the looping/testing/child
cloning ''may be removable''. Perhaps once upon a time they were required
and other components changed such that it's now safe to consider. I can't
readily say, but initial experimentation suggests it's OK to look at, at
least in theory.
There is a PR already for this, here:
https://github.com/django/django/pull/14709 which is currently marked
draft/WIP because I couldn't easily run the whole test suite locally and
needed to see if the more exotic parts caused problems. They didn't, which
was unexpected, so here I am. The PR currently replaces the
`WhereNode.clone` method like so:
{{{
clone = self.__class__._new_instance(children=[],
connector=self.connector, negated=self.negated)
for child in self.children:
if hasattr(child, 'clone'):
clone.children.append(child.clone())
else:
clone.children.append(child)
}}}
with:
{{{
clone = self.__class__._new_instance(children=None,
connector=self.connector, negated=self.negated)
clone.children = self.children[:]
}}}
But I ''think'' that Q and WhereNode ''can'' both just return a shallow
copy by only aliasing the children property, at which point I think the
`__copy__` method could be implemented on `Node` directly and mirror the
existing `__deepcopy__` method. By preferring those stdlib names it draws
a line in the sand over what level of copy should be expected. The
existing `clone` and `copy` methods can become aliases to same.
=== Before any changes
If we now begin to examine the before and after with as much data as I can
easily gather. First a bit of prelude:
{{{
In [1]: from django.db.models.sql.where import WhereNode
In [2]: from django.db.models import QuerySet
In [3]: from django.db.models.sql import Query
In [4]: from django.contrib.auth.models import User
In [5]: x = User.objects.all()
In [6]: y = User.objects.filter(username='test',
email='t...@test.test').exclude(username='test').filter(email='nottest')
In [7]: %load_ext line_profiler
}}}
Now let's establish a ballpark for how much time is spent where, I've
stripped the line profiling down to just the relevant bits for clarity.
==== Queryset with no clauses (`x`)
{{{
In [8]: %lprun -f QuerySet._chain -f QuerySet._clone -f Query.chain -f
Query.clone -f WhereNode.clone for _ in range(1000): x._chain()
Function: QuerySet._chain
Line # Hits Time Per Hit % Time Line Contents
==============================================================
1325 def _chain(self,
**kwargs):
...
1330 1000 88169.0 88.2 97.8 obj =
self._clone()
Function: QuerySet._clone
Line # Hits Time Per Hit % Time Line Contents
==============================================================
1337 def _clone(self):
...
1342 1000 80796.0 80.8 86.3 chained =
self.query.chain()
1343 1000 7240.0 7.2 7.7 c =
self.__class__(model=self.model, query=chained, using=self._db,
hints=self._hints))
Function: Query.chain
Line # Hits Time Per Hit % Time Line Contents
==============================================================
341 def chain(self,
klass=None):
...
346 2000 116961.0 58.5 94.8 obj =
self.clone()
Function: Query.clone
Line # Hits Time Per Hit % Time Line Contents
==============================================================
290 def clone(self):
...
304 2000 18294.0 9.1 27.0 obj.where =
self.where.clone()
Function: WhereNode.clone
Line # Hits Time Per Hit % Time Line Contents
==============================================================
142 def clone(self):
...
148 4000 6227.0 1.6 63.7 clone =
self.__class__._new_instance(
149 2000 1170.0 0.6 12.0 children=[],
connector=self.connector, negated=self.negated)
150 2000 1407.0 0.7 14.4 for child in
self.children:
151 if
hasattr(child, 'clone'):
152
clone.children.append(child.clone())
153 else:
154
clone.children.append(child)
155 2000 969.0 0.5 9.9 return clone
}}}
==== Queryset with where clauses (`y`)
Youu can see the cost begin to go up:
{{{
In [9]: %lprun -f QuerySet._chain -f QuerySet._clone -f Query.chain -f
Query.clone -f WhereNode.clone for _ in range(1000): y._chain()
Function: Query.clone
Line # Hits Time Per Hit % Time Line Contents
==============================================================
290 def clone(self):
...
304 2000 60065.0 30.0 59.1 obj.where =
self.where.clone()
Function: WhereNode.clone
Line # Hits Time Per Hit % Time Line Contents
==============================================================
142 def clone(self):
148 8000 11473.0 1.4 33.1 clone =
self.__class__._new_instance(
149 4000 2379.0 0.6 6.9 children=[],
connector=self.connector, negated=self.negated)
150 14000 7241.0 0.5 20.9 for child in
self.children:
151 10000 5553.0 0.6 16.0 if
hasattr(child, 'clone'):
152 2000 1255.0 0.6 3.6
clone.children.append(child.clone())
153 else:
154 8000 5069.0 0.6 14.6
clone.children.append(child)
155 4000 1715.0 0.4 4.9 return clone
}}}
and the timings for those 2 (`x` and `y`) querysets, plus an example of
prefetching related data:
{{{
In [10]: %timeit x._chain()
6.43 µs ± 52 ns per loop (mean ± std. dev. of 7 runs, 100000 loops each)
In [11]: %timeit y._chain()
8.24 µs ± 35.3 ns per loop (mean ± std. dev. of 7 runs, 100000 loops
each))
In [12]: %timeit y.query.where.clone()
2.79 µs ± 38.2 ns per loop (mean ± std. dev. of 7 runs, 100000 loops each)
In [13]: %prun for _ in range(100000): y._chain()
3400003 function calls (3300003 primitive calls) in 1.506 seconds
ncalls tottime percall cumtime percall
filename:lineno(function)
100000 0.357 0.000 1.007 0.000 query.py:290(clone)
200000/100000 0.301 0.000 0.539 0.000 where.py:142(clone) <--
WhereNode
100000 0.172 0.000 1.344 0.000 query.py:1337(_clone)
100000 0.068 0.000 1.086 0.000 query.py:341(chain)
100000 0.058 0.000 1.415 0.000 query.py:1325(_chain)
In [14]: %timeit
tuple(User.objects.prefetch_related('groups__permissions',
'user_permissions'))
18.2 ms ± 117 µs per loop (mean ± std. dev. of 7 runs, 100 loops each))
}}}
=== After replacing the clone method
Given those data points, here are the same bits of line profiling, showing
only those where the needle has moved:
==== Queryset with no clauses (`x`)
{{{
Function: Query.clone
Line # Hits Time Per Hit % Time Line Contents
==============================================================
290 def clone(self):
...
304 2000 14134.0 7.1 22.8 obj.where =
self.where.clone()
Function: WhereNode.clone
Line # Hits Time Per Hit % Time Line Contents
==============================================================
142 def clone(self):
...
148 2000 5586.0 2.8 71.0 clone =
self.__class__._new_instance(children=None, connector=self.connector,
negated=self.negated)
149 2000 1412.0 0.7 18.0 clone.children =
self.children[:]
150 2000 865.0 0.4 11.0 return clone
}}}
==== Queryset with where clauses (`y`)
{{{
Function: Query.clone at line 290
Line # Hits Time Per Hit % Time Line Contents
==============================================================
290 def clone(self):
...
304 2000 13730.0 6.9 24.7 obj.where =
self.where.clone()
Function: WhereNode.clone
Line # Hits Time Per Hit % Time Line Contents
==============================================================
142 def clone(self):
...
148 2000 5273.0 2.6 69.0 clone =
self.__class__._new_instance(children=None, connector=self.connector,
negated=self.negated)
149 2000 1498.0 0.7 19.6 clone.children =
self.children[:]
150 2000 871.0 0.4 11.4 return clone
}}}
And the timings; in the empty case (`x`), it's ''basically'' just paying
the cost of class creation, but where there are clauses it is more
consistent (ie: ''nearer'' a constant time vs linear growth).
{{{
In [10]: %timeit x._chain()
6.51 µs ± 47.6 ns per loop (mean ± std. dev. of 7 runs, 100000 loops
each))
In [11]: %timeit y._chain()
6.25 µs ± 36.4 ns per loop (mean ± std. dev. of 7 runs, 100000 loops each)
In [12]: %timeit y.query.where.clone()
1.16 µs ± 9.09 ns per loop (mean ± std. dev. of 7 runs, 1000000 loops
each)
In [13]: %prun for _ in range(100000): y._chain()
2100003 function calls in 1.087 seconds
ncalls tottime percall cumtime percall filename:lineno(function)
100000 0.355 0.000 0.606 0.000 query.py:290(clone)
100000 0.169 0.000 0.939 0.000 query.py:1337(_clone)
100000 0.068 0.000 0.139 0.000 where.py:142(clone) <---
WhereNode
100000 0.067 0.000 0.683 0.000 query.py:341(chain)
100000 0.058 0.000 1.009 0.000 query.py:1325(_chain)
In [14]: %timeit
tuple(User.objects.prefetch_related('groups__permissions',
'user_permissions'))
17.9 ms ± 345 µs per loop (mean ± std. dev. of 7 runs, 10 loops each)
}}}
Gut feeling says the "final" implementation could be something like the
following, directly on the `Node` class.
{{{
def __copy__(self):
clone = self._new_instance(children=None, connector=self.connector,
negated=self.negated)
clone.children = self.children[:]
return clone
copy = __copy__
clone = __copy__
def __deepcopy__(self, memo):
...
clone.children = copy.deepcopy(self.children, memo)
...
}}}
which would remove the need for methods on either subclass. Note also that
aliasing the methods that way rather than doing `def copy(): return
self.clone()` as `WhereNode` currently does is also ''slightly'' quicker.
We're talking `0.10µs` - small potatoes, but it doesn't hurt to have +
it's 1 fewer stack frame.
A final note then: if this properly shallow clone is done, I suspect
`resolve_expression` can be altered too, to avoid calling `_resolve_node`
if it's already been done on `self` - the shallow copy would ensure that
anything which had previously been resolved is kept around and doesn't
need doing again, I think.
Other stats: Of the 14,000 tests I can run easily, only 1 time was
`resolved` in `self.__dict__` when `clone` was called (the value was
`True`). `contains_aggregate` turned up 209 times (207 with a value of
`False`, 2 with `True`), and `output_field` only appeared 2 times (both
`BooleanField`). Those are the only extra attribute I spotted.
--
--
Ticket URL: <https://code.djangoproject.com/ticket/32970#comment:1>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
--
You received this message because you are subscribed to the Google Groups
"Django updates" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to django-updates+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/django-updates/067.4f35f237231bb0fd703218e785e40672%40djangoproject.com.
