[mapserver-dev] Found a strange performance issue

[Stephen Woodbridge]

I am developing a new mapfile file and have run into a very strange 
performance issue.

I have created a skeleton mapfile with all/most the layers like:

     LAYER
         NAME "linear_water"
         METADATA
             "ows_title"     "Streams and Rivers"
             "ows_srs"       "EPSG:4269 EPSG:4326"
             "ows_abstract"  "Streams and Rivers from the U.S. Census 
LINEARWATER data layer."
         END
         TYPE LINE
         TILEINDEX "tidx-LINEARWATER"
         PROJECTION
             "+proj=longlat +ellps=GRS80 +datum=NAD83" #EPSG: 4269
         END
         INCLUDE "map-LINEARWATER.inc"
     END

Where the INCLUDE is just an empty file. So in effect, a layer with data 
source and projection defined and no CLASS definitions. My plan is to 
populate these one at a time as I develop the mapfile.

So, if I run shp2img -m mymap.map -o junk it runs quickly and returns 
the expected image. In OL, I make a WMS request in spherical mercator 
projection. And the request times out.

Running from the command line with the same WMS request is below. I 
think the code is reading all the data and re-projecting it only to do 
nothing with it because there are no CLASS or STYLE definitions.

OK, I realize this is a corner case, but it seems that we should be 
smart enough to realize that there is not styling so it should skip over 
it. I can probably mitigate this by adding a huge MINSCALEDENOM until 
I'm ready to play with it.

My concern is that this seems like a hidden gotcha from a performance 
point of view.

Thoughts?

-Steve W

MapServer version 5.6.8 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 SUPPORTS=RGBA_PNG INPUT=EPPL7 INPUT=POSTGIS 
INPUT=OGR INPUT=GDAL INPUT=SHAPEFILE


woodbri at mappy:/u/data/tgr2011-maps$ /u/www/cgi-bin/mapserv 
QUERY_STRING="MAP=%2Fu%2Fdata%2Ftgr2011-maps%2Ftiger2011-tmp.map&FORMAT=image%2Fpng&MAP_IMAGETYPE=agg_qn&LAYERS=Tiger_2011&SERVICE=WMS&VERSION=1.1.1&REQUEST=GetMap&STYLES=&EXCEPTIONS=application%2Fvnd.ogc.se_inimage&SRS=EPSG%3A900913&BBOX=-17444764.183944,-498980.7376244,-3747249.058944,10263352.574876&WIDTH=700&HEIGHT=550" 
 > junk.png
[Mon Feb 20 18:52:09 2012].983341 msDrawMap(): WMS/WFS set-up and query, 
0.000s
[Mon Feb 20 18:52:10 2012].25715 msDrawMap(): Layer 1 (World Z1), 0.042s
[Mon Feb 20 18:52:10 2012].30751 msDrawMap(): Layer 3 (World Boundaries 
Z1), 0.005s
[Mon Feb 20 18:52:10 2012].36963 msDrawMap(): Layer 6 (World Names Z0), 
0.006s
[Mon Feb 20 18:52:10 2012].37661 msDrawMap(): Layer 9 (Equator), 0.001s
[Mon Feb 20 18:52:10 2012].56812 msDrawMap(): Layer 10 (state), 0.019s
[Mon Feb 20 18:52:10 2012].198219 msDrawMap(): Layer 11 (county), 0.141s
[Mon Feb 20 18:52:10 2012].848536 msDrawMap(): Layer 12 (cousub), 0.650s
[Mon Feb 20 18:52:11 2012].180890 msDrawMap(): Layer 13 (place), 0.332s
[Mon Feb 20 18:52:11 2012].963980 msDrawMap(): Layer 14 
(area_landmarks), 0.783s
[Mon Feb 20 18:52:11 2012].972431 msDrawMap(): Layer 15 (military), 0.008s
[Mon Feb 20 18:52:46 2012].969970 msDrawMap(): Layer 16 (area_water), 
34.997s
[Mon Feb 20 18:55:28 2012].560355 msDrawMap(): Layer 17 (linear_water), 
161.590s
[Mon Feb 20 18:55:29 2012].742523 msDrawMap(): Layer 18 (primary_roads), 
1.182s
[Mon Feb 20 18:55:44 2012].193565 msDrawMap(): Layer 19 (pri_sec_roads), 
14.451s
[Mon Feb 20 18:55:45 2012].820018 msDrawMap(): Layer 20 (rails), 1.626s
[Mon Feb 20 18:59:17 2012].81059 msDrawMap(): Layer 21 (roads), 211.261s
[Mon Feb 20 18:59:30 2012].812374 msDrawMap(): Layer 22 
(point_landmarks), 13.731s
[Mon Feb 20 18:59:30 2012].812444 msDrawLabelCache(): 
labelcache_map_edge_buffer = -10
[Mon Feb 20 18:59:30 2012].821460 msDrawMap(): Drawing Label Cache, 0.009s
[Mon Feb 20 18:59:30 2012].821492 msDrawMap() total time: 440.840s
[Mon Feb 20 18:59:30 2012].921310 msSaveImage() total time: 0.100s
[Mon Feb 20 18:59:30 2012].921672 mapserv request processing time 
(msLoadMap not incl.): 440.962s
[Mon Feb 20 18:59:30 2012].921698 msFreeMap(): freeing map at 0x1a8ba60.