I have tried getting the pypy source and building my own version of pypy. I
have modified rpython/memory/gc/incminimark.py:major_collection_step() to
print out when it starts and when it stops. Apparently, the slow queries do
NOT occur during major_collection_step; at least, I have not observed major
step output during a query execution. So, apparently, something else is
blocking. This could be another aspect of the GC, but it could also be
anything else.
Just to be sure, I have tried running the same application in python with
garbage collection disabled. I don't see the problem there, so it is
somehow related to either GC or the runtime somehow.
Cheers,
/Martin
On Fri, Mar 14, 2014 at 4:19 PM, Martin Koch <m...@issuu.com> wrote:
> We have hacked up a small sample that seems to exhibit the same issue.
>
> We basically generate a linked list of objects. To increase connectedness,
> elements in the list hold references (dummy_links) to 10 randomly chosen
> previous elements in the list.
>
> We then time a function that traverses 50000 elements from the list from a
> random start point. If the traversal reaches the end of the list, we
> instead traverse one of the dummy links. Thus, exactly 50K elements are
> traversed every time. To generate some garbage, we build a list holding the
> traversed elements and a dummy list of characters.
>
> Timings for the last 100 runs are stored in a circular buffer. If the
> elapsed time for the last run is more than twice the average time, we print
> out a line with the elapsed time, the threshold, and the 90% runtime (we
> would like to see that the mean runtime does not increase with the number
> of elements in the list, but that the max time does increase (linearly with
> the number of object, i guess); traversing 50K elements should be
> independent of the memory size).
>
> We have tried monitoring memory consumption by external inspection, but
> cannot consistently verify that memory is deallocated at the same time that
> we see slow requests. Perhaps the pypy runtime doesn't always return freed
> pages back to the OS?
>
> Using top, we observe that 10M elements allocates around 17GB after
> building, 20M elements 26GB, 30M elements 28GB (and grows to 35GB shortly
> after building).
>
> Here is output from a few runs with different number of elements:
>
>
> *pypy mem.py 10000000*
> start build
> end build 84.142424
> that took a long time elapsed: 13.230586 slow_threshold: 1.495401
> 90th_quantile_runtime: 0.421558
> that took a long time elapsed: 13.016531 slow_threshold: 1.488160
> 90th_quantile_runtime: 0.423441
> that took a long time elapsed: 13.032537 slow_threshold: 1.474563
> 90th_quantile_runtime: 0.419817
>
> *pypy mem.py 20000000*
> start build
> end build 180.823105
> that took a long time elapsed: 27.346064 slow_threshold: 2.295146
> 90th_quantile_runtime: 0.434726
> that took a long time elapsed: 26.028852 slow_threshold: 2.283927
> 90th_quantile_runtime: 0.374190
> that took a long time elapsed: 25.432279 slow_threshold: 2.279631
> 90th_quantile_runtime: 0.371502
>
> *pypy mem.py 30000000*
> start build
> end build 276.217811
> that took a long time elapsed: 40.993855 slow_threshold: 3.188464
> 90th_quantile_runtime: 0.459891
> that took a long time elapsed: 41.693553 slow_threshold: 3.183003
> 90th_quantile_runtime: 0.393654
> that took a long time elapsed: 39.679769 slow_threshold: 3.190782
> 90th_quantile_runtime: 0.393677
> that took a long time elapsed: 43.573411 slow_threshold: 3.239637
> 90th_quantile_runtime: 0.393654
>
> *Code below*
> *--------------------------------------------------------------*
> import time
> from random import randint, choice
> import sys
>
>
> allElems = {}
>
> class Node:
> def __init__(self, v_):
> self.v = v_
> self.next = None
> self.dummy_data = [randint(0,100)
> for _ in xrange(randint(50,100))]
> allElems[self.v] = self
> if self.v > 0:
> self.dummy_links = [allElems[randint(0, self.v-1)] for _ in
> xrange(10)]
> else:
> self.dummy_links = [self]
>
> def set_next(self, l):
> self.next = l
>
>
> def follow(node):
> acc = []
> count = 0
> cur = node
> assert node.v is not None
> assert cur is not None
> while count < 50000:
> # return a value; generate some garbage
> acc.append((cur.v, [choice("abcdefghijklmnopqrstuvwxyz") for x in
> xrange(100)]))
>
> # if we have reached the end, chose a random link
> cur = choice(cur.dummy_links) if cur.next is None else cur.next
> count += 1
>
> return acc
>
>
> def build(num_elems):
> start = time.time()
> print "start build"
> root = Node(0)
> cur = root
> for x in xrange(1, num_elems):
> e = Node(x)
> cur.next = e
> cur = e
> print "end build %f" % (time.time() - start)
> return root
>
>
> num_timings = 100
> if __name__ == "__main__":
> num_elems = int(sys.argv[1])
> build(num_elems)
> total = 0
> timings = [0.0] * num_timings # run times for the last num_timings runs
> i = 0
> beginning = time.time()
> while time.time() - beginning < 600:
> start = time.time()
> elem = allElems[randint(0, num_elems - 1)]
> assert(elem is not None)
>
> lst = follow(elem)
>
> total += choice(lst)[0] # use the return value for something
>
> end = time.time()
>
> elapsed = end-start
> timings[i % num_timings] = elapsed
> if (i > num_timings):
> slow_time = 2 * sum(timings)/num_timings # slow defined as >
> 2*avg run time
> if (elapsed > slow_time):
> print "that took a long time elapsed: %f slow_threshold:
> %f 90th_quantile_runtime: %f" % \
> (elapsed, slow_time,
> sorted(timings)[int(num_timings*.9)])
> i += 1
> print total
>
>
>
>
>
> On Thu, Mar 13, 2014 at 7:45 PM, Maciej Fijalkowski <fij...@gmail.com>wrote:
>
>> On Thu, Mar 13, 2014 at 1:45 PM, Martin Koch <m...@issuu.com> wrote:
>> > Hi Armin, Maciej
>> >
>> > Thanks for responding.
>> >
>> > I'm in the process of trying to determine what (if any) of the code I'm
>> in a
>> > position to share, and I'll get back to you.
>> >
>> > Allowing hinting to the GC would be good. Even better would be a means
>> to
>> > allow me to (transparently) allocate objects in unmanaged memory, but I
>> > would expect that to be a tall order :)
>> >
>> > Thanks,
>> > /Martin
>>
>> Hi Martin.
>>
>> Note that in case you want us to do the work of isolating the problem,
>> we do offer paid support to do that (then we can sign NDAs and stuff).
>> Otherwise we would be more than happy to fix bugs once you isolate a
>> part you can share freely :)
>>
>
>
_______________________________________________
pypy-dev mailing list
pypy-dev@python.org
https://mail.python.org/mailman/listinfo/pypy-dev
