[mapserver-dev] Shapefile goes from 1 sec to 90+ sec just adding a labels!

[Stephen Woodbridge]

Hi all,

I have run into a very bazaar problem with a shapefile going from 1 
second render times to ~50 second render times just for the geometry, 
not the label cache when I add labels to the layer.

I can reproduce this with just one layer and one shapefile.

Has anyone else run into anything like this?

-Steve

MapServer version 5.4.0 OUTPUT=GIF OUTPUT=PNG OUTPUT=JPEG OUTPUT=WBMP 
OUTPUT=SVG SUPPORTS=PROJ SUPPORTS=AGG SUPPORTS=FREETYPE SUPPORTS=ICONV 
SUPPORTS=FRIBIDI SUPPORTS=WMS_SERVER SUPPORTS=WMS_CLIENT 
SUPPORTS=WFS_SERVER INPUT=EPPL7 INPUT=POSTGIS INPUT=OGR INPUT=GDAL 
INPUT=SHAPEFILE


MAP
   MAXSIZE 4000
   SIZE 800 800
   SHAPEPATH "/u/data/data/Jamaica-900913"
   SYMBOLSET "/u/data/data/Jamaica-900913/symbols/symbols.sym"
   FONTSET "/u/data/data/Jamaica-900913/symbols/fontset.txt"
   IMAGECOLOR "#80B1D3"
   IMAGETYPE agg
   EXTENT -20037508.34 -20037508.34 20037508.34 20037508.34
   UNITS METERS
   DEBUG 10
   CONFIG MS_ERRORFILE "stderr"
   OUTPUTFORMAT
     NAME agg
     DRIVER "AGG/PNG"
     EXTENSION "png"
     MIMETYPE "image/png"
     IMAGEMODE RGB
     FORMATOPTION "INTERLACE=false"
     FORMATOPTION "QUANTIZE_FORCE=ON"
     FORMATOPTION "QUANTIZE_DITHER=OFF"
     FORMATOPTION "QUANTIZE_COLORS=256"
   END
   WEB
     METADATA
       wms_srs "epsg:900913"
       labelcache_map_edge_buffer "-10"
       wms_title "jamaica data"
     END
   END
   LAYER
     NAME "World"
     GROUP "cb"
     STATUS DEFAULT
     TYPE POLYGON
     DATA "world/world"
     CLASSITEM "COLOR"
     LABELITEM "NAME"
     CLASS
       EXPRESSION "1"
       STYLE
         COLOR "#99B3FF"
         OUTLINECOLOR "#888888"
       END
       LABEL
         TYPE TRUETYPE FONT "arial" SIZE 7 COLOR "#010101" PARTIALS 
FALSE OUTLINEWIDTH 3
         PRIORITY 8
         BUFFER 4 POSITION CC MINDISTANCE 250 MINFEATURESIZE 10
       END
     END
     CLASS
       EXPRESSION "2"
       STYLE
         COLOR "#B3FF99"
         OUTLINECOLOR "#888888"
       END
       LABEL
         TYPE TRUETYPE FONT "arial" SIZE 7 COLOR "#010101" PARTIALS 
FALSE OUTLINEWIDTH 3
         PRIORITY 8
         BUFFER 4 POSITION CC MINDISTANCE 250 MINFEATURESIZE 10
       END
     END
     CLASS
       EXPRESSION "3"
       STYLE
         COLOR "#FFE699"
         OUTLINECOLOR "#888888"
       END
       LABEL
         TYPE TRUETYPE FONT "arial" SIZE 7 COLOR "#010101" PARTIALS 
FALSE OUTLINEWIDTH 3
         PRIORITY 8
         BUFFER 4 POSITION CC MINDISTANCE 250 MINFEATURESIZE 10
       END
     END
     CLASS
       EXPRESSION "4"
       STYLE
         COLOR "#FFB399"
         OUTLINECOLOR "#888888"
       END
       LABEL
         TYPE TRUETYPE FONT "arial" SIZE 7 COLOR "#010101" PARTIALS 
FALSE OUTLINEWIDTH 3
         PRIORITY 8
         BUFFER 4 POSITION CC MINDISTANCE 250 MINFEATURESIZE 10
       END
     END
     CLASS
       EXPRESSION "5"
       STYLE
         COLOR "#99FFB3"
         OUTLINECOLOR "#888888"
       END
       LABEL
         TYPE TRUETYPE FONT "arial" SIZE 7 COLOR "#010101" PARTIALS 
FALSE OUTLINEWIDTH 3
         PRIORITY 8
         BUFFER 4 POSITION CC MINDISTANCE 250 MINFEATURESIZE 10
       END
     END
   END
END

Here is the log of just zooming out:

[Wed Jun 10 12:53:35 2009].323025 msDrawMap(): Layer 0 (World), 0.422s
[Wed Jun 10 12:53:35 2009].323329 msDrawLabelCache(): 
labelcache_map_edge_buffer = -10
[Wed Jun 10 12:53:35 2009].336325 msDrawMap(): Drawing Label Cache, 0.013s
[Wed Jun 10 12:53:35 2009].336355 msDrawMap() total time: 0.438s
[Wed Jun 10 12:53:35 2009].357835 msSaveImage() total time: 0.021s
[Wed Jun 10 12:53:35 2009].358140 mapserv request processing time 
(loadmap not incl.): 0.460s
[Wed Jun 10 12:53:35 2009].358160 msFreeMap(): freeing map at 0x63aa00.
[Wed Jun 10 12:53:36 2009].994979 msDrawMap(): Layer 0 (World), 0.786s
[Wed Jun 10 12:53:36 2009].995292 msDrawLabelCache(): 
labelcache_map_edge_buffer = -10
[Wed Jun 10 12:53:37 2009].7982 msDrawMap(): Drawing Label Cache, 0.013s
[Wed Jun 10 12:53:37 2009].8014 msDrawMap() total time: 0.801s
[Wed Jun 10 12:53:37 2009].29497 msSaveImage() total time: 0.021s
[Wed Jun 10 12:53:37 2009].29769 mapserv request processing time 
(loadmap not incl.): 0.823s
[Wed Jun 10 12:53:37 2009].29789 msFreeMap(): freeing map at 0x63aa00.
[Wed Jun 10 12:53:41 2009].780255 msDrawMap(): Layer 0 (World), 3.827s
[Wed Jun 10 12:53:41 2009].780566 msDrawLabelCache(): 
labelcache_map_edge_buffer = -10
[Wed Jun 10 12:53:41 2009].795910 msDrawMap(): Drawing Label Cache, 0.015s
[Wed Jun 10 12:53:41 2009].795941 msDrawMap() total time: 3.845s
[Wed Jun 10 12:53:41 2009].818499 msSaveImage() total time: 0.023s
[Wed Jun 10 12:53:41 2009].818785 mapserv request processing time 
(loadmap not incl.): 3.868s
[Wed Jun 10 12:53:41 2009].818805 msFreeMap(): freeing map at 0x63aa10.
[Wed Jun 10 12:54:40 2009].258306 msDrawMap(): Layer 0 (World), 56.436s
[Wed Jun 10 12:54:40 2009].258634 msDrawLabelCache(): 
labelcache_map_edge_buffer = -10
[Wed Jun 10 12:54:40 2009].293897 msDrawMap(): Drawing Label Cache, 0.035s
[Wed Jun 10 12:54:40 2009].293931 msDrawMap() total time: 56.474s
[Wed Jun 10 12:54:40 2009].320803 msSaveImage() total time: 0.027s
[Wed Jun 10 12:54:40 2009].321088 mapserv request processing time 
(loadmap not incl.): 56.501s
[Wed Jun 10 12:54:40 2009].321110 msFreeMap(): freeing map at 0x63aa00.
[Wed Jun 10 12:56:10 2009].600928 msDrawMap(): Layer 0 (World), 49.215s
[Wed Jun 10 12:56:10 2009].601264 msDrawLabelCache(): 
labelcache_map_edge_buffer = -10
[Wed Jun 10 12:56:10 2009].629768 msDrawMap(): Drawing Label Cache, 0.029s
[Wed Jun 10 12:56:10 2009].629802 msDrawMap() total time: 49.246s
[Wed Jun 10 12:56:10 2009].655105 msSaveImage() total time: 0.025s
[Wed Jun 10 12:56:10 2009].655601 mapserv request processing time 
(loadmap not incl.): 49.272s
[Wed Jun 10 12:56:10 2009].655623 msFreeMap(): freeing map at 0x63aa10.