Hi Jim,
How where you creating the session object in requestobject.c ? If you
were using PythonObject_New, then this may explain the memory leak.
Objects that must be managed by the garbage collector have to be
created with PyObject_GC_New.
Regards,
Nicolas
2005/6/12, Jim Gallacher <[EMAIL PROTECTED]>:
> Replying to my own email,
>
> It looks like there was problem with a circular reference in
> req->session->req. This resulted in a memory leak which I had
> mis-interpreted as a reference count problem in req_get_session.
>
> As a result, I was not doing a Py_INCREF(self->session) in
> req_get_session(). This resulted in the intermittent segfault. (I just
> *knew* I was going to screw up the reference counting. :) )
>
> Refactoring TestSession to remove saved reference to the request object
> fixed the memory leak problem. Adding Py_INCREF(self->session) in
> req_get_session() fixed the segfault problem.
>
> I still don't understand why the memory lead only occurs when the
> session object is created in requestobject.c and not when created
> directly in a python script, but there you go.
>
> Jim
>
> Jim Gallacher wrote:
> > Hi All,
> >
> > Sorry for the long post, but I think I have a nice contribution to the
> > session handling mechanism, but I've got a bug I just can't track down.
> > Make yourself a cup of coffee, sit down and have a read.
> >
> > In an effort to make session handling more transparent and less error
> > prone, I've added a new method called get_session to the request object.
> >
> > (As an aside, I've also created a new apache config directive
> > PythonSessionOptions, a req.get_session_options() to read the directive,
> > and a small internal change to req.internal_redirect() to pass a session
> > to a redirected request).
> >
> > req.get_session() returns the session instance if it exists or creates a
> > new one. Internally it calls some python code,
> > mod_python.Session.create_session(), which does the actual work. The
> > user will only use get_session() to access their session, and so all our
> > deadlocking issues are gone forever.
> >
> > It mostly works, but I've found that approx 1 in 10000 requests will
> > segfault. Calling mod_python.Session.create_session directly does not
> > segfault (tested for 2000000 requests) so that is not the issue.
> >
> > I really hope someone can spot where the problem is. I've reduced
> > everything to the simplest possible case. The unlock method in
> > TestSession very rarely segfault or raise an exception and then
> > segfault, but very rarely. It only fails 0.004% of the time based on
> > 500000 requests. I suspect some kind of garbage collection issue, maybe
> > a circular reference caused by req->session->_req, but I don't
> > understand why it works 99.996 % of the time.
> >
> > I've included the full error.log for 5000000 requests at the end of this
> > message, but the ones that caught my eye as unusual are:
> >
> > [Tue Jun 07 17:52:02 2005] [notice] child pid 15066 exit signal
> > Segmentation fault (11)
> > Fatal Python error: deletion of interned string failed
> >
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: Traceback (most recent call last):
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File "/usr/lib/python2.3/site-packages/mod_python/apache.py",
> > line 299, in HandlerDispatch\n result = object(req)
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File "/var/www/mp/mptest.py", line 19, in handler\n sess =
> > req.get_session()
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File
> > "/usr/lib/python2.3/site-packages/mod_python/TestSession.py", line 46,
> > in create_session\n return TestSession(req,sid)
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File
> > "/usr/lib/python2.3/site-packages/mod_python/TestSession.py", line 40,
> > in unlock\n if self._lock and self._locked:
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: AttributeError: 'TestSession' object has no attribute '_lock'
> >
> > [Tue Jun 07 18:04:03 2005] [notice] child pid 16170 exit signal
> > Segmentation fault (11)
> > Fatal Python error: GC object already tracked
> >
> >
> > I hope someone can give me some insight to the problem. Note that I'm
> > using mpm-worker.
> >
> > Regards,
> > Jim
> >
> > ------------------------------------------------------------------------
> > mptest.py
> > # the test handler
> >
> > from mod_python import apache
> > from mod_python import TestSession
> >
> > def handler(req):
> > req.content_type = 'text/plain'
> > req.write('mptest.py')
> >
> > if req.path_info:
> > test_case = req.path_info[1:]
> > else:
> > test_case = '1'
> >
> > if test_case == '1':
> > # the good case - always works
> > sess = TestSession.create_session(req,None)
> > elif test_case == '2':
> > # the bad case - sometimes segfaults
> > sess = req.get_session()
> > else:
> > req.write('no test specified')
> >
> > return apache.OK
> >
> > ---------------------------------------------------------------------------------------------------
> >
> > mod_python/TestSession.py
> > # emulate a simple test session
> > import _apache
> > from Session import _new_sid
> >
> > class TestSession(object):
> >
> > def __init__(self, req, sid=0, secret=None, timeout=0, lock=1):
> > req.log_error("TestSession.__init__")
>
> ### CIRCULAR REFERENCE self._req = req
> ### causes memory leak
> > self._req = req
> ###
>
> > self._lock = 1
> > self._locked = 0
> > self._sid = _new_sid(req)
> > self.lock()
> > self.unlock()
> >
> > def lock(self):
> > if self._lock:
> > _apache._global_lock(self._req.server, self._sid)
> > self._locked = 1
> >
> > def unlock(self):
> > # unlock will ocassionally segfault
> > if self._lock and self._locked:
> > _apache._global_unlock(self._req.server, self._sid)
> > self._locked = 0
> >
> > def create_session(req,sid):
> > return TestSession(req,sid)
> >
> > -------------------------------------------------------------------------------------------------
> >
> > src/requestobject.c
> > In the following code session is a PyObject* defined in the the
> > requestobject struct.
> >
> > static PyObject *req_get_session(requestobject *self, PyObject *args)
> > {
> > PyObject *m;
> > PyObject *sid;
> >
> > if (!self->session) {
> > m = PyImport_ImportModule("mod_python.TestSession");
> > /* is this redirected request with an existing session? */
> > sid = PyObject_CallMethod(self->subprocess_env, "get",
> > "(ss)","REDIRECT_PYSID", "");
> >
> > self->session = PyObject_CallMethod(m, "create_session", "(OO)",
> > self, sid);
> > Py_DECREF(m);
> > Py_DECREF(sid);
> > if (self->session == NULL)
> > return NULL;
> > }
>
> // increase ref count to fix segfault problem
> Py_INCREF(self->session);
>
> > return self->session;
> > }
> >
> > --------------------------------------------------------------------------------------------------------
> >
> > /var/log/apache2/error.log
> >
> > The full error log for approx 500000 requests (generated using grep -v
> > "TestSession.__init" error.log).
> >
> > [Tue Jun 07 16:35:32 2005] [notice] mod_python: Creating 32 session
> > mutexes based on 6 max processes and 25 max threads.
> > [Tue Jun 07 16:35:32 2005] [notice] Apache/2.0.54 (Debian GNU/Linux)
> > mod_python/3.2.0-dev-20050519 Python/2.3.5 configured -- resuming normal
> > operations
> > [Tue Jun 07 16:35:49 2005] [notice] child pid 11540 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 16:35:49 2005] [notice] child pid 11545 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 16:36:05 2005] [notice] child pid 11601 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 16:46:21 2005] [notice] child pid 11629 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 16:46:35 2005] [notice] child pid 11949 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:04:07 2005] [notice] child pid 12454 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:11:47 2005] [notice] child pid 12351 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:18:08 2005] [notice] child pid 12342 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:18:20 2005] [notice] child pid 13057 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:34:48 2005] [notice] child pid 12859 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:36:35 2005] [notice] child pid 13599 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:38:10 2005] [notice] child pid 13698 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:39:02 2005] [notice] child pid 13764 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:39:13 2005] [notice] child pid 13819 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:39:15 2005] [notice] child pid 13810 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:40:02 2005] [notice] child pid 13917 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:41:03 2005] [notice] child pid 13048 exit signal
> > Segmentation fault (11)
> > Fatal Python error: GC object already tracked
> > [Tue Jun 07 17:42:41 2005] [notice] child pid 14016 exit signal Aborted (6)
> > Fatal Python error: GC object already tracked
> > [Tue Jun 07 17:45:10 2005] [notice] child pid 14321 exit signal Aborted (6)
> > [Tue Jun 07 17:48:01 2005] [notice] child pid 14439 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:48:49 2005] [notice] child pid 14508 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:50:03 2005] [notice] child pid 14615 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:50:03 2005] [notice] child pid 14672 exit signal
> > Segmentation fault (11)
> > Fatal Python error: GC object already tracked
> > [Tue Jun 07 17:50:53 2005] [notice] child pid 14665 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:50:53 2005] [notice] child pid 14758 exit signal Aborted (6)
> > [Tue Jun 07 17:51:18 2005] [notice] child pid 14800 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:51:18 2005] [notice] child pid 14832 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:51:18 2005] [notice] child pid 14864 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:51:20 2005] [notice] child pid 14893 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:51:21 2005] [notice] child pid 14921 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:51:21 2005] [notice] child pid 14928 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:51:23 2005] [notice] child pid 14977 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:51:24 2005] [notice] child pid 15006 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:52:02 2005] [notice] child pid 15066 exit signal
> > Segmentation fault (11)
> > Fatal Python error: deletion of interned string failed
> > [Tue Jun 07 17:53:06 2005] [notice] child pid 15109 exit signal Aborted (6)
> > Fatal Python error: deletion of interned string failed
> > [Tue Jun 07 17:53:55 2005] [notice] child pid 15210 exit signal Aborted (6)
> > [Tue Jun 07 17:54:03 2005] [notice] child pid 15104 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:54:05 2005] [notice] child pid 15312 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:54:17 2005] [notice] child pid 15405 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:55:04 2005] [notice] child pid 15437 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:55:04 2005] [notice] child pid 15483 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:55:17 2005] [notice] child pid 15563 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:55:54 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: Traceback (most recent call last):
> > [Tue Jun 07 17:55:54 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File "/usr/lib/python2.3/site-packages/mod_python/apache.py",
> > line 287, in HandlerDispatch\n log=debug)
> > [Tue Jun 07 17:55:54 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File "/usr/lib/python2.3/site-packages/mod_python/apache.py",
> > line 422, in import_module\n module = sys.modules[module_name]
> > [Tue Jun 07 17:55:54 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: KeyError: 'mptest'
> > [Tue Jun 07 17:55:58 2005] [notice] child pid 15474 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:56:08 2005] [notice] child pid 15600 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:56:08 2005] [notice] child pid 15644 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:57:08 2005] [notice] child pid 15730 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:57:10 2005] [notice] child pid 15778 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:57:44 2005] [notice] child pid 15772 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:58:11 2005] [notice] child pid 15902 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:58:21 2005] [notice] child pid 15945 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: Traceback (most recent call last):
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File "/usr/lib/python2.3/site-packages/mod_python/apache.py",
> > line 299, in HandlerDispatch\n result = object(req)
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File "/var/www/mp/mptest.py", line 19, in handler\n sess =
> > req.get_session()
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File
> > "/usr/lib/python2.3/site-packages/mod_python/TestSession.py", line 46,
> > in create_session\n return TestSession(req,sid)
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: File
> > "/usr/lib/python2.3/site-packages/mod_python/TestSession.py", line 40,
> > in unlock\n if self._lock and self._locked:
> > [Tue Jun 07 17:58:57 2005] [error] [client 192.168.1.12] PythonHandler
> > mptest: AttributeError: 'TestSession' object has no attribute '_lock'
> > [Tue Jun 07 17:59:38 2005] [notice] child pid 15939 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 18:02:59 2005] [notice] child pid 15865 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 18:02:59 2005] [notice] child pid 16051 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 18:03:02 2005] [notice] child pid 16142 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 18:04:03 2005] [notice] child pid 16170 exit signal
> > Segmentation fault (11)
> > Fatal Python error: GC object already tracked
> > [Tue Jun 07 18:04:16 2005] [notice] child pid 16248 exit signal Aborted (6)
> > [Tue Jun 07 18:04:40 2005] [notice] child pid 16285 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 18:05:15 2005] [notice] child pid 16318 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 18:16:49 2005] [notice] child pid 16573 exit signal
> > Segmentation fault (11)
> > [Tue Jun 07 18:17:50 2005] [notice] child pid 16924 exit signal
> > Segmentation fault (11)
> >
>
>
