[mapserver-users] Can't stop Mapserver 6.2.1 from gathering too much log into MS_ERRORFILE

Wed Jun 5 15:36:57 PDT 2013

Hi,

The reason for the trouble was simple: the MS_DEBUGLEVEL was set to value 3 in the Apache configuration.  I spent some hours with trying to find the reason myself until Daniel Morissette told where to look for this configuration element.  I copy my comment from the Github issue page https://github.com/mapserver/mapserver/issues/4662 here because I think that Mapserver users and developers should continue to use also this list instead of using Github issue page as a discussion forum. I was too busy with creating a new issue myself and I am sorry for that.

Taken from the Github forum for invalid issues:

" The very reason was that Linux server admin without experience on Mapserver copied httpd.conf from MS4W installation and removed a comment from here
# uncomment the following lines to log MapServer errors to a file
#SetEnv MS_DEBUGLEVEL 3

Logging errors to a file feels like a good idea and not dangerous at all. However the comment is misleading and debug level 3 collects much more info than just errors. I believe that this setting it is unsuitable for most production system and I will write a note for Jeff McKenna and suggest to add another comment line for warning.

Mapserver documentation deals with debug in 4 places:
[1] Mapfile MAP http://www.mapserver.org/mapfile/map.html
[2] Mapfile LAYER http://www.mapserver.org/mapfile/layer.html
[3] Special debugging page http://www.mapserver.org/optimization/debugging.html
[4] RFC 28 page http://www.mapserver.org/development/rfc/ms-rfc-28.html#rfc28

After carefully reading the documentation I feel only moderately ashamed for not finding that the reason for my trouble was in MS_DEBUGLEVEL environment variable. Both [1] and [2] are telling about this only
"You can also set the debug level by using the “MS_DEBUGLEVEL” environment variable."
However, they have links for getting more info about debug mechanism. [1] has a link to [3] while [2] has a link to [4].

Documents [3] and [4] contain the same text about having set both MS_DEBUGLEVEL and DEBUG
" If a DEBUG value is also specified in the mapfile in some map or layer objects then the local value (in the mapfile) takes precedence over the value of the environment variable."

That is not totally true and it it also somehow documented that DEBUG will not always override MS_DEBUGLEVEL totally because
"This option also sets the debug level for any msDebug() call located outside of the context of a map or layer object, for instance for debug statements relating to initialization before a map is loaded. "

Conclusions:

-    Ticket can be closed as invalid
-    Link in document [2] could be changed to point to [3] instead of [4]
-    [3] might be edited a bit "..takes precedence over the value of the environment variable for those objects..Debug info coming from outside of the context of a map or layer object cannot be turned off by having DEBUG OFF in the mapfile "
-    There is a comment in the RFC [4] which would be useful to have also in the main debugging page "This option [setting MS_DEBUGLEVEL] is mostly useful when tuning applications by enabling timing/debug output before the map is loaded, to capture the full process initialization and map loading time, for instance."

>From my experience the debugging document should strongly encourage to use layer or map level DEBUG for all regular needs instead of MS_DEBUGLEVEL."

-Jukka Rahkonen-

________________________________________
Lähettäjä: mapserver-users-bounces at lists.osgeo.org [mapserver-users-bounces at lists.osgeo.org] käyttäjän Rahkonen Jukka [jukka.rahkonen at mmmtike.fi] puolesta
Lähetetty: 3. kesäkuuta 2013 17:20
Vastaanottaja: 'mapserver-users at lists.osgeo.org'
Aihe: Re: [mapserver-users] Can't stop Mapserver 6.2.1 from gathering too much log into MS_ERRORFILE

Hi,

Quoting myself "I have added DEBUG 0 on both MAP level and in each LAYER definition". Based on documentation I believe this means the same as DEBUG OFF but I made another trial with that now and it did not change anything. I was also adding some new layers from vector data and I can see that some debug into gets written into MS_ERRORFILE for those too.

I usually wait until someone confirms that what looks like a bug really is such a thing before writing a report, especially if I am on a foreign land as I am now with Linux. However, this one looks so much like a bug that I believe that I will file an issue soon.

-Jukka Rahkonen-

Stephen Woodbridge wrote:

> Do you have DEBUG turned on in your mapfile? Tuen this off and the messages
> should go away. If they do not them someone probably left some debug output
> in the code. And a bug report is needed.
>
> -Steve
>
> On 6/3/2013 9:23 AM, Rahkonen Jukka wrote:
> > Hi,
> >
> > We have compiled Mapserver 6.2.1 for Linux and the version info is as
> > follows
> >
> > MapServer version 6.2.1
> > OUTPUT=GIF OUTPUT=PNG OUTPUT=JPEG SUPPORTS=PROJ SUPPORTS=GD
> > SUPPORTS=AGG SUPPORTS=FREETYPE SUPPORTS=CAIRO SUPPORTS=ICONV
> > SUPPORTS=WMS_SERVER SUPPORTS=WMS_CLIENT SUPPORTS=WFS_SERVER
> > SUPPORTS=WFS_CLIENT SUPPORTS=WCS_SERVER SUPPORTS=SOS_SERVER
> > SUPPORTS=FASTCGI SUPPORTS=THREADS SUPPORTS=GEOS INPUT=JPEG
> INPUT=OGR
> > INPUT=GDAL INPUT=SHAPEFILE
> >
> > I do not understand why this version is printing whole lot of
> > information that I do not want into MS_ERRORFILE. I had originally no
> > DEBUG lines in my mapfiles and now I have added DEBUG 0 on both MAP
> > level and in each LAYER definition . Nothing helps and I keep on
> > getting new lines into the errorfile after each GetMap.  For example
> > with a GROUP layer which is combined from 11 scale dependent layers it
> > means 37 new lines after each request
> >
> > [Mon Jun  3 16:12:25 2013].799634 loadParams() QUERY_STRING:
> >
> map=/test.map&REQUEST=GetMap&SERVICE=WMS&VERSION=1.1.1&WIDTH=
> 1059&HEIG
> >
> HT=776&LAYERS=group&TRANSPARENT=TRUE&FORMAT=image%2Fpng&BBOX
> =-302742.3
> >
> 606628045,6634887.305484046,1741121.9462003412,8132563.133742593&SR
> S=E
> > PSG:3067&STYLES= [Mon Jun  3 16:12:25 2013].801140 msLoadMap(): 0.001s
> > [Mon Jun  3 16:12:25 2013].802506 msLayerIsVisible(): Skipping layer
> > (mml_taustakartta_2) because LAYER.MAXSCALE is too small for this MAP
> > scale [Mon Jun  3 16:12:25 2013].802522 msLayerIsVisible(): Skipping
> > layer (mml_taustakartta_3) because LAYER.MAXSCALE is too small for
> > this MAP scale [Mon Jun  3 16:12:25 2013].802528 msLayerIsVisible():
> > Skipping layer (mml_taustakartta_4) because LAYER.MAXSCALE is too
> > small for this MAP scale [Mon Jun  3 16:12:25 2013].802533
> > msLayerIsVisible(): Skipping layer (mml_taustakartta_5) because
> > LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> > 2013].802537 msLayerIsVisible(): Skipping layer (mml_taustakartta_6)
> > because LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3
> > 16:12:25 2013].802542 msLayerIsVisible(): Skipping layer
> > (mml_taustakartta_7) because LAYER.MAXSCALE is too small for this MAP
> > scale [Mon Jun  3 16:12:25 2013].802546 msLayerIsVisible(): Skipping
> > layer (mml_taustakartta_8) because LAYER.MAXSCALE is too small for
> > this MAP scale [Mon Jun  3 16:12:25 2013].802551 msLayerIsVisible():
> > Skipping layer (mml_taustakartta_9) because LAYER.MAXSCALE is too
> > small for this MAP scale [Mon Jun  3 16:12:25 2013].802555
> > msLayerIsVisible(): Skipping layer (mml_taustakartta_10) because
> > LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> > 2013].802560 msLayerIsVisible(): Skipping layer (mml_taustakartta_11)
> because LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802566 msLayerIsVisible(): Skipping layer (mml_taustakartta_2) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802571 msLayerIsVisible(): Skipping layer (mml_taustakartta_3) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802575 msLayerIsVisible(): Skipping layer (mml_taustakartta_4) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802580 msLayerIsVisible(): Skipping layer (mml_taustakartta_5) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802584 msLayerIsVisible(): Skipping layer (mml_taustakartta_6) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802589 msLayerIsVisible(): Skipping layer (mml_taustakartta_7) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802593 msLayerIsVisible(): Skipping layer (mml_taustakartta_8) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802598 msLayerIsVisible(): Skipping layer (mml_taustakartta_9) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802602 msLayerIsVisible(): Skipping layer (mml_taustakartta_10) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802607 msLayerIsVisible(): Skipping layer (mml_taustakartta_11) because
> LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> 2013].802616 msDrawRasterLayerLow(mml_taustakartta_1): entering.
> > [Mon Jun  3 16:12:25 2013].802815 msResampleGDALToMap in effect:
> > cellsize = 1932.163743 [Mon Jun  3 16:12:25 2013].803881
> > msDrawGDAL(mml_taustakartta_1): using RAW_WINDOW=76 93 1652 1501,
> > dst=0,0,855,777 [Mon Jun  3 16:12:25 2013].803915
> > msDrawRasterLayerGDAL(): red,green,blue,alpha bands = 1,2,3,0 [Mon Jun
> > 3 16:12:25 2013].847533 msDrawMap(): Layer 0 (mml_taustakartta_1),
> > 0.045s [Mon Jun  3 16:12:25 2013].847558 msLayerIsVisible(): Skipping
> > layer (mml_taustakartta_2) because LAYER.MAXSCALE is too small for
> > this MAP scale [Mon Jun  3 16:12:25 2013].847564 msLayerIsVisible():
> > Skipping layer (mml_taustakartta_3) because LAYER.MAXSCALE is too
> > small for this MAP scale [Mon Jun  3 16:12:25 2013].847710
> > msLayerIsVisible(): Skipping layer (mml_taustakartta_4) because
> > LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> > 2013].847722 msLayerIsVisible(): Skipping layer (mml_taustakartta_5)
> > because LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3
> > 16:12:25 2013].847727 msLayerIsVisible(): Skipping layer
> > (mml_taustakartta_6) because LAYER.MAXSCALE is too small for this MAP
> > scale [Mon Jun  3 16:12:25 2013].847732 msLayerIsVisible(): Skipping
> > layer (mml_taustakartta_7) because LAYER.MAXSCALE is too small for
> > this MAP scale [Mon Jun  3 16:12:25 2013].847737 msLayerIsVisible():
> > Skipping layer (mml_taustakartta_8) because LAYER.MAXSCALE is too
> > small for this MAP scale [Mon Jun  3 16:12:25 2013].847741
> > msLayerIsVisible(): Skipping layer (mml_taustakartta_9) because
> > LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3 16:12:25
> > 2013].847746 msLayerIsVisible(): Skipping layer (mml_taustakartta_10)
> > because LAYER.MAXSCALE is too small for this MAP scale [Mon Jun  3
> > 16:12:25 2013].847751 msLayerIsVisible(): Skipping layer
> > (mml_taustakartta_11) because LAYER.MAXSCALE is too small for this MAP
> > scale
> >
> > Does this have something to do with Linux and compile options or is it perhaps
> a bug? I have never experienced anything similar on Windows with MS4W.
> >
> > -Jukka Rahkonen-
> >
> >
> > _______________________________________________
> > mapserver-users mailing list
> > mapserver-users at lists.osgeo.org
> > http://lists.osgeo.org/mailman/listinfo/mapserver-users
> >
>
> _______________________________________________
> mapserver-users mailing list
> mapserver-users at lists.osgeo.org
> http://lists.osgeo.org/mailman/listinfo/mapserver-users
_______________________________________________
mapserver-users mailing list
mapserver-users at lists.osgeo.org
http://lists.osgeo.org/mailman/listinfo/mapserver-users