How to use and interpret DEBUG?

[Rahkonen Jukka]

Hi again,
 
Now I have got some reasonable numbers to Apache log files, but there is still one thing confusing me. For each browser request I am getting two new blocks of data into the logfile. They look otherwise exactly alike, but timing values are not the same. Why do these blocks appear twise and should I add these values together to get the overall response time? For example in the case below, is the total time for GeoTiff thus (total time 1) + (total time 2) = 0.040 + 0.040 s = 0.080 seconds, and for JPEG 2000 0.240 + 0.240 = 0.480 seconds? The times for these two blocks are not always the same even in this case they are.
 
Short explanation about this very first test. I set the map extents in a mapfile to 100 by 100 meters and image size to 200 by 200 pixels that equals to image pixels in my test image with 0.50 metre pixel size. The requested area was somewhere in the middle of the original image of size 10000 by 10000 pixels. The source was in the first case in Geotiff format and in the other case in lossless JPEG 2000.  I made the request by browser with mode=map.
Please do not look too closely at the numbers yet (well, I guess that now you for sure will...). This case with corresponding number of image screen pixels seems to be extremely favourable for GeoTiff.  It might be correct to say that Mapserver in extreme case, which is when source image pixels correspond directly to screen pixels, can perform 6 times better with GeoTiff format than with JPEG 2000 but this has to be verified.
 
Regards,
 
-Jukka-
 
Below is the excerpt of the log file
 
Case geotiff:
msDrawRasterLayerLow(Geotiff): entering.\r
msDrawGDAL(): src=99,9699,201,201, dst=0,0,200,200\r
msDrawGDAL(): red,green,blue,alpha bands = 1,2,3,0\r
msDrawMap(): Layer 0 (Geotiff), 0.040s\r
msDrawMap(): Drawing Label Cache, 0.000s\r
msDrawMap() total time: 0.040s\r
msDrawRasterLayerLow(Geotiff): entering.\r
msDrawGDAL(): src=99,9699,201,201, dst=0,0,200,200\r
msDrawGDAL(): red,green,blue,alpha bands = 1,2,3,0\r
msDrawMap(): Layer 0 (Geotiff), 0.040s\r
msDrawMap(): Drawing Label Cache, 0.000s\r
msDrawMap() total time: 0.040s\r

Case JPEG 2000:
msDrawRasterLayerLow(jp2): entering.\r
msDrawGDAL(): src=99,9699,201,201, dst=0,0,200,200\r
msDrawGDAL(): red,green,blue,alpha bands = 1,2,3,0\r
msDrawMap(): Layer 2 (jp2), 0.240s\r
msDrawMap(): Drawing Label Cache, 0.000s\r
msDrawMap() total time: 0.240s\r
msDrawRasterLayerLow(jp2): entering.\r
msDrawGDAL(): src=99,9699,201,201, dst=0,0,200,200\r
msDrawGDAL(): red,green,blue,alpha bands = 1,2,3,0\r
msDrawMap(): Layer 2 (jp2), 0.240s\r
msDrawMap(): Drawing Label Cache, 0.000s\r
msDrawMap() total time: 0.240s\r