0

I'm using an open source Django app that logs all requests to a model. It stores things like path, ip, user, queryset, etc. However, I'm interested in see which paths take the longest, so I can optimize them, yet the app doesn't store the explicit start and end time it takes to process the request, so I want to extend this model to seamlessly support this without adding any new models.

The maintainer of the Django app doesn't want to add this functionality, and I don't want to fork it, extend it, and maintain a completely separate app. So I've decided to implement just these new features by dynamically adding a couple fields using Django's class_prepared signal, and a custom save process to update these field values using Django's post_save signal.

My code looks like:

from django.db.models.signals import class_prepared, post_save

def add_request_fields(sender, **kwargs):
    """
    class_prepared signal handler that checks for the model named
    MyModel as the sender, and adds a CharField
    to it.
    """
    if sender.__name__ == 'Request':
        # Create a field to record when we first receive the request.
        field = DateTimeField(_('start time'), default=None, db_index=True, blank=True, null=True, editable=False)
        field.contribute_to_class(sender, 'start_time')
        # Create a field to record to total seconds it takes to process a request.
        field = FloatField(_('total seconds'), default=None, db_index=True, blank=True, null=True, editable=False)
        field.contribute_to_class(sender, 'total_seconds')
        # Re-name default time field with a more accurate label.
        sender._meta.get_field('time').verbose_name = 'end time'

class_prepared.connect(add_request_fields)


def post_request_save(sender, instance, **kwargs):
    """
    When the request instance is created, update its timestamp to calculate the total seconds taken to process the request.
    """
    if sender.__name__ == 'Request':
        # Request has to be imported here, instead of at the file's top-level, otherwise it breaks the custom field additions.
        from request.models import Request
        start_time = get_current_request_start() # Custom method that uses its own middleware to record the start time of each request.
        total_seconds = None
        if start_time and instance.time:
            total_seconds = (instance.time - start_time).total_seconds()
        Request.objects.filter(id=instance.id).update(start_time=start_time, total_seconds=total_seconds)

post_save.connect(post_request_save)

This seems to work well when manually testing with the dev server, but now when I run my unittest suite, Python is crashing due to a segmentation fault at random points. The only thing I've changed is the addition of this code, so presumably this is somehow causing. Why would this be?

Is there some potential memory leak in my implementation or any other concerns? Is there a better way to implement this functionality?

Edit: If I run my tests inside gdb and capture a backtrace, this is the output:

Thread 1 "python" received signal SIGSEGV, Segmentation fault.
0x00007fffe41dcad8 in ?? () from /usr/lib/x86_64-linux-gnu/libsqlite3.so.0
(gdb) backtrace
#0  0x00007fffe41dcad8 in ?? () from /usr/lib/x86_64-linux-gnu/libsqlite3.so.0
#1  0x00007fffe4216f0a in ?? () from /usr/lib/x86_64-linux-gnu/libsqlite3.so.0
#2  0x00007fffe42185f9 in ?? () from /usr/lib/x86_64-linux-gnu/libsqlite3.so.0
#3  0x00007fffe421ac24 in ?? () from /usr/lib/x86_64-linux-gnu/libsqlite3.so.0
#4  0x00007fffe423f2c1 in ?? () from /usr/lib/x86_64-linux-gnu/libsqlite3.so.0
#5  0x00007fffe42441a7 in sqlite3_step () from /usr/lib/x86_64-linux-gnu/libsqlite3.so.0
#6  0x00007fffcfff707e in pysqlite_step () from /home/chris/git/myproject/.env/lib/python2.7/lib-dynload/_sqlite3.x86_64-linux-gnu.so
#7  0x00007fffcfffa40d in _pysqlite_query_execute () from /home/chris/git/myproject/.env/lib/python2.7/lib-dynload/_sqlite3.x86_64-linux-gnu.so
#8  0x00000000004a577e in PyObject_Call ()
#9  0x00000000004c5e10 in PyEval_CallObjectWithKeywords ()
#10 0x0000000000537613 in ?? ()
#11 0x00000000004c15bf in PyEval_EvalFrameEx ()
#12 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#13 0x00000000004c16e7 in PyEval_EvalFrameEx ()
#14 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#15 0x00000000004c16e7 in PyEval_EvalFrameEx ()
#16 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#17 0x00000000004c16e7 in PyEval_EvalFrameEx ()
#18 0x00000000004c136f in PyEval_EvalFrameEx ()
#19 0x00000000004c136f in PyEval_EvalFrameEx ()
#20 0x00000000004c136f in PyEval_EvalFrameEx ()
#21 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#22 0x00000000004c1e6f in PyEval_EvalFrameEx ()
#23 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#24 0x00000000004c1e6f in PyEval_EvalFrameEx ()
#25 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#26 0x00000000004c1e6f in PyEval_EvalFrameEx ()
#27 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#28 0x00000000004d54b9 in ?? ()
#29 0x00000000004eebee in ?? ()
#30 0x00000000004a577e in PyObject_Call ()
#31 0x0000000000548253 in ?? ()
#32 0x00000000004c15bf in PyEval_EvalFrameEx ()
#33 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#34 0x00000000004d55f3 in ?? ()
#35 0x00000000004a577e in PyObject_Call ()
#36 0x00000000004bed3d in PyEval_EvalFrameEx ()
#37 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#38 0x00000000004d54b9 in ?? ()
#39 0x00000000004eebee in ?? ()
#40 0x00000000004a577e in PyObject_Call ()
#41 0x0000000000548253 in ?? ()
#42 0x00000000004c15bf in PyEval_EvalFrameEx ()
#43 0x00000000004c136f in PyEval_EvalFrameEx ()
#44 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#45 0x00000000004c1e6f in PyEval_EvalFrameEx ()
#46 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#47 0x00000000004c16e7 in PyEval_EvalFrameEx ()
#48 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#49 0x00000000004d55f3 in ?? ()
#50 0x00000000004a577e in PyObject_Call ()
#51 0x00000000004bed3d in PyEval_EvalFrameEx ()
#52 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#53 0x00000000004d55f3 in ?? ()
---Type <return> to continue, or q <return> to quit---
#54 0x00000000004a577e in PyObject_Call ()
#55 0x00000000004bed3d in PyEval_EvalFrameEx ()
#56 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#57 0x00000000004d55f3 in ?? ()
#58 0x00000000004a577e in PyObject_Call ()
#59 0x00000000004bed3d in PyEval_EvalFrameEx ()
#60 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#61 0x00000000004c1e6f in PyEval_EvalFrameEx ()
#62 0x00000000004c136f in PyEval_EvalFrameEx ()
#63 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#64 0x00000000004c1e6f in PyEval_EvalFrameEx ()
#65 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#66 0x00000000004c16e7 in PyEval_EvalFrameEx ()
#67 0x00000000004b9ab6 in PyEval_EvalCodeEx ()
#68 0x00000000004eb30f in ?? ()
#69 0x00000000004e5422 in PyRun_FileExFlags ()
#70 0x00000000004e3cd6 in PyRun_SimpleFileExFlags ()
#71 0x0000000000493ae2 in Py_Main ()
#72 0x00007ffff7810830 in __libc_start_main (main=0x4934c0 <main>, argc=6, argv=0x7fffffffdb88, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffffffdb78)
    at ../csu/libc-start.c:291
#73 0x00000000004933e9 in _start ()
Cerin
  • 60,957
  • 96
  • 316
  • 522
  • are you sure this is caused by this code? if you remove it everything works? That seems very strange. Can you provide the error you get or whatever happens? – Alexandr Tatarinov Jun 18 '18 at 18:16
  • @AlexandrTatarinov, Yes, when I remove this code, Python doesn't segfault. If I comment-in just the `class_prepared` code, that's enough to trigger the segfault. – Cerin Jun 18 '18 at 20:52

0 Answers0