1

I use mapserver to generate one single tile per request. The mapfile contains several layers and I would like to know which of them is the bottleneck that needs too much time to render. WIth shp2img I can get a rough idea but as we also use mapscript it would be better to get these debug information directly from mapserver. Is this possible?

shp2img -m alk.map -o ~/tmp/test.png -map_debug 3

[Tue Jun  4 11:13:34 2019].577359 msDrawRasterLayerLow(relief): entering.
[Tue Jun  4 11:13:34 2019].618554 msDrawMap(): Layer 0 (relief), 0.044s
[Tue Jun  4 11:13:34 2019].619952 msDrawRasterLayerLow(osm_ab_4000_sichtbar): entering.
[Tue Jun  4 11:13:34 2019].638350 msDrawMap(): Layer 2 (osm_ab_4000_sichtbar), 0.020s
  • If debug level is high enough you should get timings into your MS_ERRORFILE. – user30184 Jun 6 at 11:40
  • @user30184: For vectorlayer this seems to work but not for wms layer... – markgraeflerland Jun 6 at 13:19
  • You mean cascaded layer from external WMS? – user30184 Jun 6 at 13:26
1

The debug info can be forwarded into file that is defined with MS_ERRORFILE configuration option https://mapserver.org/mapfile/map.html

CONFIG "MS_ERRORFILE" "/path/to/errorfile.log"

Debug level 2 or higher is needed for including timings from msDrawMap(). Debug can be set at MAP level when it affects all the layers, of individually at LAYER level. Layer level debug value overrides the map level debug setting.

For testing if timigs are available also for cascaded WMS layers I created a layer as

LAYER
  NAME "states"
  TYPE RASTER
  STATUS ON
  debug 5
  CONNECTION "http://localhost:8080/geoserver/wms?"
  CONNECTIONTYPE WMS
  METADATA
    "wms_srs"             "EPSG:4326"
    "wms_name"            "states"
    "wms_server_version"  "1.1.1"
    "wms_format"          "image/png"
  END
END

This is what I get into MS_ERRORFILE (the bbox of the request does not make sense but that's now important now).

[Thu Jun  6 16:33:07 2019].250000 HTTP: Starting to prepare HTTP requests.
[Thu Jun  6 16:33:07 2019].250000 Using CURL_CA_BUNDLE=/ms4w/Apache/conf/ca-bundle/cacert.pem
[Thu Jun  6 16:33:07 2019].250000 HTTP request: id=2, http://localhost:8080/geoserver/wms?LAYERS=states&REQUEST=GetMap&SERVICE=WMS&FORMAT=image/png&STYLES=&HEIGHT=681&VERSION=1.1.1&SRS=EPSG:4326&WIDTH=1395&BBOX=-56083.1360024968,6928975.24790378,519065.155268358,7577950.64783149&TRANSPARENT=TRUE&EXCEPTIONS=application/vnd.ogc.se_inimage
[Thu Jun  6 16:33:07 2019].250000 HTTP: Before download loop
[Thu Jun  6 16:33:07 2019].403000 msHTTPWriteFct(id=2, 14119 bytes)
[Thu Jun  6 16:33:07 2019].403000 msHTTPWriteFct(id=2, 7164 bytes)
[Thu Jun  6 16:33:07 2019].403000 HTTP: After download loop
[Thu Jun  6 16:33:07 2019].403000 msHTTPExecuteRequests() timing summary per layer (connect_time + time_to_first_packet + download_time = total_time in seconds)
[Thu Jun  6 16:33:07 2019].403000 Layer 2: 0.047 + 0.125 + 0.047 = 0.219s
[Thu Jun  6 16:33:07 2019].404000 msDrawRasterLayerLow(states): entering.
[Thu Jun  6 16:33:07 2019].410000 msResampleGDALToMap(): LOAD_WHOLE_IMAGE set, loading whole image.
[Thu Jun  6 16:33:07 2019].410000 msResampleGDALToMap in effect: cellsize = 412.588444
[Thu Jun  6 16:33:07 2019].412000 msDrawGDAL(states): using RAW_WINDOW=0 0 1395 681, dst=0,0,1395,681
[Thu Jun  6 16:33:07 2019].412000 msDrawRasterLayerGDAL(): red,green,blue,alpha bands = 1,2,3,4
[Thu Jun  6 16:33:07 2019].488000 msDrawMap(): Layer 2 (states), 0.084s
[Thu Jun  6 16:33:07 2019].514000 freeLayer(): freeing layer at 00715528.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.