Twisted getPage(): паметта на процеса нараства при заявка на много страници

Пиша скрипт за постоянно (всеки 30-120 секунди) грабване на информация, търсеща голям набор от URL адреси (страници за състояние на Icecast/Shoutcast сървъри), около 500 URL адреса. Работи добре, но размерът на резидентния процес на Python непрекъснато нараства. Сигурен съм, че има безкраен растеж, тъй като го оставих да работи няколко часа и отне 1,2 Gb RES от първоначалните 30 Mb.

Опростих скрипта за лесно разбиране до следното:

from twisted.internet import reactor
from twisted.web.client import getPage
from twisted.enterprise import adbapi

def ok(res, url):
    print "OK: " + str(url)
    reactor.callLater(30, load, url)

def error(res, url):
    print "FAIL: " + str(url)
    reactor.callLater(30, load, url)

def db_ok(res):
    for item in res:
        if item[1]:
            print "ADDED: " + str(item[1])
            reactor.callLater(30, load, item[1])

def db_error(res):
    print "Database error: " + str(res)
    reactor.stop()

def load(url):
    d = getPage(url,
                headers={"Accept": "text/html"},
                timeout=30)
    d.addCallback(ok, url)
    d.addErrback(error, url)


dbpool = adbapi.ConnectionPool("MySQLdb", "host", "user", "passwd", db="db")
q = dbpool.runQuery("SELECT id, url FROM stations")
q.addCallback(db_ok).addErrback(db_error)

reactor.run()

Той расте по същия начин като оригиналния демон и по този начин локализирах проблема. Мисля, че е свързано по някакъв начин с twisted.web.client.getPage(). В оригиналния демон използвах twisted.manhole за оценки на купчини с meliae по време на изпълнение, но не виждам нищо неприятно.

Първо изхвърляне на meliae, направено веднага след завършване на само 1 или 2 цикъла на заявка:

Total 84313 objects, 188 types, Total size = 15.9MiB (16647235 bytes)
 Index   Count   %      Size   % Cum     Max Kind
     0    5806   6   4142800  24  24  786712 dict
     1   28070  33   2223457  13  38    4874 str
     2     612   0   1636992   9  48    3424 HTTPClientFactory
     3   19599  23   1585720   9  57     608 tuple
     4     643   0    720160   4  61    1120 DelayedCall
     5     642   0    713904   4  66    1112 Client
     6     617   0    691040   4  70    1120 Connector
     7     639   0    577656   3  73     904 type
     8     691   0    556576   3  77    1120 Deferred
     9    3962   4    475440   2  80     120 function
    10    3857   4    462840   2  82     120 code
    11    3017   3    308192   1  84    4856 list
    12     240   0    266880   1  86    1112 Method
    13    2968   3    237440   1  87      80 instancemethod
    14     612   0    215424   1  88     352 InsensitiveDict
    15     217   0    211128   1  90   12624 module
    16    2185   2    157320   0  91      72 builtin_function_or_method
    17     107   0    119840   0  91    1120 HTTPPageGetter
    18     343   0    117992   0  92     344 IcecastRadioStation
    19     343   0    117992   0  93     344 HTTPExtractor

И горе около това време:

VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
248m  27m 4152 R   92  1.6   0:09.21 python

Сега изчакваме известно време и проверяваме отново, това е картината след 20 минути работа (около 40 цикъла на заявка):

Total 67428 objects, 188 types, Total size = 11.9MiB (12463799 bytes)
 Index   Count   %      Size   % Cum     Max Kind
     0    3865   5   3601624  28  28  786712 dict
     1   23762  35   2002029  16  44    4874 str
     2   16382  24   1346208  10  55     608 tuple
     3     644   0    582176   4  60     904 type
     4     174   0    554304   4  64    3424 HTTPClientFactory
     5     456   0    510720   4  68    1120 DelayedCall
     6    3963   5    475560   3  72     120 function
     7    3857   5    462840   3  76     120 code
     8     240   0    266880   2  78    1112 Method
     9     237   0    263544   2  80    1112 Client
    10     217   0    211128   1  82   12624 module
    11     187   0    209440   1  84    1120 Connector
    12     182   0    194624   1  85    1120 Deferred
    13    1648   2    179696   1  87    3768 list
    14    1530   2    122400   0  88      80 instancemethod
    15     343   0    117992   0  89     344 IcecastRadioStation
    16     343   0    117992   0  90     344 HTTPExtractor
    17    1175   1    103400   0  90      88 weakref
    18    1109   1     88720   0  91      80 wrapper_descriptor
    19      75   0     83400   0  92    1112 InterfaceClass

И отгоре:

VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
532m 240m 4152 S   54 13.7   4:02.64 python

Според meliae нито броят на обектите нараства, нито общият размер. Но процесът изяжда 200Mb резидентна памет през тези 20 минути.

Използвах и valgrind на python, но не бяха открити течове. някакви мисли?

Използвам Python версия 2.6.6, усукана версия 10.2.0


Актуализация #1: Използвах също valgrind масив за профилиране на използването на паметта на CPython, ето дърво за разпределение за 99,93% от разпределената памет:

99.93% (578,647,287B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->94.69% (548,309,283B) 0x550819: O_cwrite (cStringIO.c:406)
| ->94.69% (548,309,283B) 0x55096F: O_write (cStringIO.c:436)
|   ->94.69% (548,309,283B) 0x5A17F9: PyCFunction_Call (methodobject.c:81)
|     ->94.69% (548,309,283B) 0x4D1373: call_function (ceval.c:3750)
|       ->94.69% (548,309,283B) 0x4CC2A2: PyEval_EvalFrameEx (ceval.c:2412)
|         ->94.69% (548,309,283B) 0x4D1868: fast_function (ceval.c:3836)
|           ->94.69% (548,309,283B) 0x4D1549: call_function (ceval.c:3771)
|             ->94.69% (548,309,283B) 0x4CC2A2: PyEval_EvalFrameEx (ceval.c:2412)
|               ->94.69% (548,309,283B) 0x4D1868: fast_function (ceval.c:3836)
|                 ->94.69% (548,309,283B) 0x4D1549: call_function (ceval.c:3771)
|                   ->94.69% (548,309,283B) 0x4CC2A2: PyEval_EvalFrameEx (ceval.c:2412)
|                     ->94.69% (548,309,283B) 0x4D1868: fast_function (ceval.c:3836)
|                       ->94.69% (548,309,283B) 0x4D1549: call_function (ceval.c:3771)
|                         ->94.69% (548,309,283B) 0x4CC2A2: PyEval_EvalFrameEx    (ceval.c:2412)
|                           ->94.69% (548,309,283B) 0x4D1868: fast_function (ceval.c:3836)
|                             ->94.69% (548,309,283B) 0x4D1549: call_function (ceval.c:3771)
|                               ->94.69% (548,309,283B) 0x4CC2A2: PyEval_EvalFrameEx (ceval.c:2412)
|                                 ->94.69% (548,309,283B) 0x4CEBB3: PyEval_EvalCodeEx (ceval.c:3000)
|                                   ->94.69% (548,309,283B) 0x5A0DC6: function_call (funcobject.c:524)
|                                     ->94.69% (548,309,283B) 0x4261E8: PyObject_Call (abstract.c:2492)
|                                       ->94.69% (548,309,283B) 0x4D2870: ext_do_call (ceval.c:4063)
|                                         ->94.69% (548,309,283B) 0x4CC4E3: PyEval_EvalFrameEx (ceval.c:2452)
|                                           ->94.69% (548,309,283B) 0x4CEBB3: PyEval_EvalCodeEx (ceval.c:3000)
|                                             ->94.69% (548,309,283B) 0x5A0DC6: function_call (funcobject.c:524)
|                                               ->94.69% (548,309,283B) 0x4261E8: PyObject_Call (abstract.c:2492)
|                                                 ->94.69% (548,309,283B) 0x4D2870: ext_do_call (ceval.c:4063)
|                                                   ->94.69% (548,309,283B) 0x4CC4E3: PyEval_EvalFrameEx (ceval.c:2452)
|                                                     ->94.69% (548,309,283B) 0x4CEBB3: PyEval_EvalCodeEx (ceval.c:3000)
|                                                       ->94.69% (548,309,283B) 0x5A0DC6: function_call (funcobject.c:524)
|                                                         ->94.69% (548,309,283B) 0x4261E8: PyObject_Call (abstract.c:2492)

person Anton Martchukov    schedule 25.03.2011    source източник
comment
Това е добър въпрос. Интересно ми е да видя каква е причината за нарастването на паметта. За целите на тестването оставихте ли го да работи наистина дълго време, за да видите дали разширяването на паметта продължава?   -  person jathanism    schedule 25.03.2011
comment
Два пъти го оставих да работи дълго време. Веднъж го прекратих, след като достигна 1,2 Gb резидентен размер и втори път, не знам колко е отишъл, имам 2 GB RAM и трябваше да рестартирам лаптопа си поради твърда смяна.   -  person Anton Martchukov    schedule 25.03.2011


Отговори (1)


Предполагам, че планирате тези извличания на страници въз основа на фиксиран таймер и не обръщате внимание къде всъщност завършват извличанията. Представете си, че извличането на всяка страница отнема 60 секунди. Имате огромна купчина извличания, планирани за 30 секунди, а след това отново за 30 секунди, като се натрупват все повече и повече, докато изпълнявате по-ранни заявки. Това обаче е само предположение, тъй като дори този опростен пример не е напълно самостоятелен. (Можете ли да го възпроизведете, без да имате включена база данни, само с фиксиран списък от URL адреси?)

Това проследяване на стека също не е особено полезно; ефективно, той просто казва, че паметта е разпределена чрез извикване на функция на python, което трябва да е очевидно. Може да опитате специфичен за Python инструмент за профилиране на паметта, като Heapy или Dowser, за да видите накъде отиват вашите Python обекти.

person Glyph    schedule 27.03.2011