[Thu Apr 25 14:30:24 2013].964000 CGI Request 1 on process 13664
[Thu Apr 25 14:30:24 2013].965000 msDrawMap(): rendering using outputformat named png (AGG/PNG).
[Thu Apr 25 14:30:24 2013].970000 HTTP: Starting to prepare HTTP requests.
[Thu Apr 25 14:30:24 2013].970000 Using CURL_CA_BUNDLE=/ms4w/Apache/conf/ca-bundle/cacert.pem
[Thu Apr 25 14:30:24 2013].970000 HTTP request: id=1, https://...&FORMAT=image/jpeg&STYLES=&HEIGHT=353&VERSION=1.1.1&SRS=EPSG:3067&WIDTH=459&BBOX=406810.908602495,7216210.70370872,407078.361045337,7216416.39153513&TRANSPARENT=TRUE&EXCEPTIONS=application/vnd.ogc.se_inimage
[Thu Apr 25 14:30:24 2013].970000 HTTP: Before download loop
[Thu Apr 25 14:30:26 2013].950000 msHTTPWriteFct(id=1, 4070 bytes)
[Thu Apr 25 14:30:27 2013].22000 msHTTPWriteFct(id=1, 4096 bytes)
[Thu Apr 25 14:30:27 2013].96000 msHTTPWriteFct(id=1, 4096 bytes)
[Thu Apr 25 14:30:27 2013].221000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:30:27 2013].345000 msHTTPWriteFct(id=1, 7201 bytes)
[Thu Apr 25 14:30:27 2013].345000 HTTP: After download loop
[Thu Apr 25 14:30:27 2013].345000 msHTTPExecuteRequests() timing summary per layer (connect_time + time_to_first_packet + download_time = total_time in seconds)
[Thu Apr 25 14:30:27 2013].345000 Layer 1: 0.140 + 1.841 + 0.546 = 2.527s
[Thu Apr 25 14:30:27 2013].350000 msDrawMap(): WMS/WFS set-up and query, 2.385s
[Thu Apr 25 14:30:27 2013].353000 msDrawRasterLayerLow(test): entering.
[Thu Apr 25 14:30:27 2013].354000 msDrawRasterLayerGDAL(): red,green,blue,alpha bands = 1,2,3,0
[Thu Apr 25 14:30:27 2013].372000 msDrawMap(): Layer 1 (test), 0.022s
[Thu Apr 25 14:30:27 2013].372000 msDrawMap(): Drawing Label Cache, 0.000s
[Thu Apr 25 14:30:27 2013].372000 msDrawMap() total time: 2.408s
[Thu Apr 25 14:30:27 2013].590000 msSaveImage(stdout) total time: 0.218s
[Thu Apr 25 14:30:27 2013].592000 mapserv request processing time (msLoadMap not incl.): 2.629s
[Thu Apr 25 14:30:27 2013].592000 msFreeMap(): freeing map at 038E2420.
[Thu Apr 25 14:30:27 2013].592000 freeLayer(): freeing layer at 038EAAA8.
[Thu Apr 25 14:30:27 2013].592000 freeLayer(): freeing layer at 038EB608.
[Thu Apr 25 14:30:27 2013].592000 freeLayer(): freeing layer at 038EC500.
[Thu Apr 25 14:31:13 2013].909000 CGI Request 1 on process 19476
[Thu Apr 25 14:31:13 2013].910000 msDrawMap(): rendering using outputformat named png (AGG/PNG).
[Thu Apr 25 14:31:13 2013].914000 HTTP: Starting to prepare HTTP requests.
[Thu Apr 25 14:31:13 2013].914000 Using CURL_CA_BUNDLE=/ms4w/Apache/conf/ca-bundle/cacert.pem
[Thu Apr 25 14:31:13 2013].915000 HTTP request: id=1, https://...&FORMAT=image/png&STYLES=&HEIGHT=353&VERSION=1.1.1&SRS=EPSG:3067&WIDTH=459&BBOX=406508.434778249,7215858.43375314,407593.615379665,7216693.00619824&TRANSPARENT=TRUE&EXCEPTIONS=application/vnd.ogc.se_inimage
[Thu Apr 25 14:31:13 2013].915000 HTTP: Before download loop
[Thu Apr 25 14:31:16 2013].62000 msHTTPWriteFct(id=1, 4071 bytes)
[Thu Apr 25 14:31:16 2013].251000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:16 2013].413000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:16 2013].463000 msHTTPWriteFct(id=1, 4480 bytes)
[Thu Apr 25 14:31:16 2013].652000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:16 2013].786000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:17 2013].111000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:17 2013].286000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:17 2013].413000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:17 2013].509000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:17 2013].714000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:17 2013].945000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:18 2013].85000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:18 2013].261000 msHTTPWriteFct(id=1, 8000 bytes)
[Thu Apr 25 14:31:18 2013].293000 msHTTPWriteFct(id=1, 1920 bytes)
[Thu Apr 25 14:31:18 2013].335000 msHTTPWriteFct(id=1, 2825 bytes)
[Thu Apr 25 14:31:18 2013].336000 HTTP: After download loop
[Thu Apr 25 14:31:18 2013].336000 msHTTPExecuteRequests() timing summary per layer (connect_time + time_to_first_packet + download_time = total_time in seconds)
[Thu Apr 25 14:31:18 2013].336000 Layer 1: 0.047 + 2.106 + 2.309 = 4.462s
[Thu Apr 25 14:31:18 2013].343000 msDrawMap(): WMS/WFS set-up and query, 4.433s
[Thu Apr 25 14:31:18 2013].348000 msDrawRasterLayerLow(test): entering.
[Thu Apr 25 14:31:18 2013].349000 msDrawRasterLayerGDAL(): red,green,blue,alpha bands = 1,0,0,0
[Thu Apr 25 14:31:18 2013].349000 drawGDAL(): Unable to access file. GDALDatasetRasterIO() failed: GetBlockRef failed at X block offset 0, Y block offset 0
[Thu Apr 25 14:31:18 2013].349000 msDrawMap(): WMS connection error. Failed to draw WMS layer named 'test'. This most likely happened because the remote WMS server returned an invalid image, and XML exception or another unexpected result in response to the GetMap request. Also check and make sure that the layer's connection URL is valid.
[Thu Apr 25 14:31:18 2013].349000 mapserv request processing time (msLoadMap not incl.): 4.441s
[Thu Apr 25 14:31:18 2013].349000 msFreeMap(): freeing map at 03892428.
[Thu Apr 25 14:31:18 2013].349000 freeLayer(): freeing layer at 0389AAB0.
[Thu Apr 25 14:31:18 2013].349000 freeLayer(): freeing layer at 0389B610.
[Thu Apr 25 14:31:18 2013].349000 freeLayer(): freeing layer at 0389C508.