Stack trace from timing out PHP MapScript CGI

[Doug]

Interesting - it turns out that at least a significant part of our performance
problems was that MapServer wasn't using the QIX index files for the
shapefiles.  I surprised it took this long to stumble across, so maybe some
documentation can be added to warn about this situation.  Here's what we
finally found:

<http://mapserver.gis.umn.edu/data2/wilma/mapserver-users/0404/msg00677.html>

Doug wrote:
> I posted here a couple of weeks ago asking about our CGI PHP MapScript
> application that appears to quit responding periodically.
> <http://lists.umn.edu/cgi-bin/wa?A2=ind0410&L=mapserver-users&T=0&F=&S=&X=30762F284AB96B2313&P=50619>
>
> Context refresher:
>
> MapServer/MapScript 4.2.5, PHP 4.3.8 (cgi), PostgreSQL 7.4.3, PostGIS
> 0.8.2,
> Apache 2.0.51, Fedora Core 2 SMP (Dual CPU 2GHz P4).
>
> Application posts to PHP file, which does a map->draw() (of shapefile
> layers),
> followed by a couple of queryByRect() on non-shown (PostGIS) layers, manual
> point->draw()s with custom, numbered labels, then a map->save().
>
> I had observed that regularly the PHP processes seem to hang or stall, so
> somebody on #Mapserver suggested that I compile with debug options and
> try to
> obtain a stack trace when this happens.
>
> Unfortunately, I've been unable to duplicate the exact situation, but I
> have
> seen some similar ones where client requests to the PHP CGIs stack up
> and time
> out.  In fact, I can force that to happen simply by getting several
> clients to
> make a simultaneous request of the server.  Today, I forced 7 such
> simultaneous requests, and every single one of them timed out.
> Normally, when
> this kind of condition occurs, the MapServer stderr also reports:
>
> [Mon Nov 15 21:17:39 2004] [error] [client 32.83.226.185] PHP Fatal error:
> Maximum execution time of 30 seconds exceeded in
> var/www/html/offender/map.php
> on line 87
>
> But this didn't happen in my forced test today.  i.e. my clients timed out,
> but the PHP CGIs didn't seem to.  Obviously, I need to play with either my
> client or server timeouts, but can anything useful be determined by these
> stack traces?:
>
>  From last night's "natural" slowdown (which was so bad that most/all
> requests
> during a 30 minute period timed out):
>
> #0  0x00ac8402 in ?? ()
> #1  0x005e11ea in lseek64 () from /lib/tls/libc.so.6
> #2  0x00581a37 in _IO_file_seek_internal () from /lib/tls/libc.so.6
> #3  0x0058175a in _IO_new_file_seekoff () from /lib/tls/libc.so.6
> #4  0x00578a2a in _IO_seekoff_unlocked () from /lib/tls/libc.so.6
> #5  0x0057e08d in fseek () from /lib/tls/libc.so.6
> #6  0x0030b5c2 in msSHPReadBounds (psSHP=0x8f0d858, hEntity=36339712,
> padBounds=0xfef2dd70) at mapshape.c:1163
> #7  0x0030bb32 in msSHPWhichShapes (shpfile=0x8fcebc0, rect= {minx =
> 511572.85125965299, miny = 3562542.8004036499, maxx =
> 513272.85125965299, maxy
> = 3563562.8004036499}, debug=0) at mapshape.c:1338
> #8  0x0032e14a in msLayerWhichShapes (layer=0x8d92198, rect= {minx =
> 511572.85125965299, miny = 3562542.8004036499, maxx =
> 513272.85125965299, maxy
> = 3563562.8004036499}) at maplayer.c:198
> #9  0x00330a02 in msDrawVectorLayer (map=0xf6ff3008, layer=0x8d92198,
> image=0x8f0e7e0) at mapdraw.c:751
> #10 0x00330711 in msDrawLayer (map=0xf6ff3008, layer=0x8d92198,
> image=0x8f0e7e0) at mapdraw.c:639
> #11 0x00330028 in msDrawMap (map=0xf6ff3008) at mapdraw.c:317
> #12 0x0030006f in mapObj_draw (self=0xf6ff3008) at mapscript_i.c:419
> #13 0x002f2279 in php3_ms_map_draw (ht=0, return_value=0x8d550ac,
> this_ptr=0x8d5502c, return_value_used=1) at php_mapscript.c:3311
> #14 0x0811dcfa in execute (op_array=0x8d650d4) at
> /usr/src/php-4.3.8/Zend/zend_execute.c:1635
> #15 0x0811dac9 in execute (op_array=0x8d425dc) at
> /usr/src/php-4.3.8/Zend/zend_execute.c:1679
> #16 0x0811dac9 in execute (op_array=0x8d3ef8c) at
> /usr/src/php-4.3.8/Zend/zend_execute.c:1679
> #17 0x08112fd3 in zend_execute_scripts (type=8, retval=0x0,
> file_count=3) at
> /usr/src/php-4.3.8/Zend/zend.c:891
> #18 0x080f089c in php_execute_script (primary_file=0xfef30780)at
> /usr/src/php-4.3.8/main/main.c:1734
> #19 0x081220b2 in main (argc=1, argv=0xfef30844) at
> /usr/src/php-4.3.8/sapi/cgi/cgi_main.c:1592
>
>  From today's artificial one (which lasted less than a minute after the
> simultaneous requests were finished):
>
> #0  0x005fc7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
> #1  0x0050f85a in lseek64 () from /lib/tls/libc.so.6
> #2  0x004afbf7 in _IO_file_seek_internal () from /lib/tls/libc.so.6
> #3  0x004af91a in _IO_new_file_seekoff () from /lib/tls/libc.so.6
> #4  0x004a6bea in _IO_seekoff_unlocked () from /lib/tls/libc.so.6
> #5  0x004ac24d in fseek () from /lib/tls/libc.so.6
> #6  0x0080c5c2 in msSHPReadBounds (psSHP=0x9d5e190, hEntity=63127552,
> padBounds=0xfeebf8a0) at mapshape.c:1163
> #7  0x0080cb32 in msSHPWhichShapes (shpfile=0x9e1f860, rect={minx =
> 400998.78413511597, miny = 3697149.2200513999, maxx =
> 402698.78413511597, maxy
> = 3698169.2200513999}, debug=0) at mapshape.c:1338
> #8  0x0082f14a in msLayerWhichShapes (layer=0x9be1d60, rect={minx =
> 400998.78413511597, miny = 3697149.2200513999, maxx =
> 402698.78413511597, maxy
> = 3698169.2200513999}) at maplayer.c:198
> #9  0x00831a02 in msDrawVectorLayer (map=0xf6fc4008, layer=0x9be1d60,
> image=0x9d5e388) at mapdraw.c:751
> #10 0x00831711 in msDrawLayer (map=0xf6fc4008, layer=0x9be1d60,
> image=0x9d5e388) at mapdraw.c:639
> #11 0x00831028 in msDrawMap (map=0xf6fc4008) at mapdraw.c:317
> #12 0x0080106f in mapObj_draw (self=0xf6fc4008) at mapscript_i.c:419
> #13 0x007f3279 in php3_ms_map_draw (ht=0, return_value=0x9ba4254,
>     this_ptr=0x9ba41d4, return_value_used=1) at php_mapscript.c:3311
> #14 0x0811dcfa in execute (op_array=0x9bb4c84)  at
> /usr/src/php-4.3.8/Zend/zend_execute.c:1635
> #15 0x0811dac9 in execute (op_array=0x9b917dc)  at
> /usr/src/php-4.3.8/Zend/zend_execute.c:1679
> #16 0x0811dac9 in execute (op_array=0x9b8deec) at
> /usr/src/php-4.3.8/Zend/zend_execute.c:1679
> #17 0x08112fd3 in zend_execute_scripts (type=8, retval=0x0,
> file_count=3) at
> /usr/src/php-4.3.8/Zend/zend.c:891
> #18 0x080f089c in php_execute_script (primary_file=0xfeec22b0) at
> /usr/src/php-4.3.8/main/main.c:1734
> #19 0x081220b2 in main (argc=1, argv=0xfeec2374) at
> /usr/src/php-4.3.8/sapi/cgi/cgi_main.c:1592
>
> Basically, it seems that it takes very few simultaneous requests for our
> system to fall behind.  If it gets even more requests than that minimum, it
> seems to be unable to recover for sometimes half an hour or more.
>
> I've seen people claiming very good performance of similar applications on
> slower systems, so I'm trying to understand what could be causing this
> behaviour.
>
> Here's hoping the stack traces will at least help us pinpoint the likely
> cuplrit(s).
>
> Doug
>
>