[Geoserver-devel] Request logging

Andrea_Aime3 · February 7, 2007, 4:05pm

Hi,
I'm not very satisfied with current geoserver request logging:

[INFO] org.vfny.geoserver.servlets.AbstractService - handling request: org.vfny.geoserver.wms.requests.GetMapRequest@anonymised.com [INFO] org.vfny.geoserver.servlets.AbstractService - Service handled

Hum, not very informative. I'd prefer to see the actual request.
Now, since the actual request may be (very) long, we could limit
logging to the first, say, 1024 or 2048 characters in it
Would you like it?

Cheers
Andrea

Chris_Holmes1 · February 7, 2007, 4:16pm

I'm +1. I think some code may already be there at FINE, but yeah, I agree it should be more prominent.

One way to do it might be to just make a .toString() method for GetMapRequest - I think when WFS comes in it gives you a nicely formatted summary of the request.

Chris

Andrea Aime wrote:

Hi,
I'm not very satisfied with current geoserver request logging:

[INFO] org.vfny.geoserver.servlets.AbstractService - handling request: org.vfny.geoserver.wms.requests.GetMapRequest@anonymised.com [INFO] org.vfny.geoserver.servlets.AbstractService - Service handled

Hum, not very informative. I'd prefer to see the actual request.
Now, since the actual request may be (very) long, we could limit
logging to the first, say, 1024 or 2048 characters in it
Would you like it?

Cheers
Andrea

-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier.
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
_______________________________________________
Geoserver-devel mailing list
Geoserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/geoserver-devel

!DSPAM:1003,45c9fbce309101804284693!

--
Chris Holmes
The Open Planning Project
http://topp.openplans.org

Farber_Saul_EEA · February 7, 2007, 4:25pm

Andrea,

Short answer: yeah. +1 from me.

Long answer:

Logging means different things to different people. For example, when developing I would really like the first 1024 (or 2048) characters of a request, but I know that when thinking about production deployment issues, I'd really like an apache common log formatted log with things broken down by request type, featurestores requested/referenced, source IP, time, bytes, time-to-respond, etc.

So at the minimum, it seems like there's two different meanings of "logging" here. One is for developers who are looking to try and fix bugs/keep an eye on things. The other is for production support folks who want to determine usage rates, request breakdowns and traffic consumption. And there may be a few more meanings of "logging" that I'm not thinking of.

I am in favor of you making the mentioned changes to the logger, but what I'd REALLY like is to have some sort of guidelines about what goes at which logging level (warn, info, config, fine, finer, finest), including a target amount of output expected at each level (warn = lines only if there are problems, info = 4 lines/request, config = 20 lines/request, fine = 100 lines/request, finer = 200 lines/request, finest = unlimited).

Separately from this, I'm a little unclear about what technical logging systems we're using at different levels. For example, the spring container supports a bunch of different logging outputs, and auto-configures itself based on the JVM setup...so what percentage of our logging output is just spring yakking through our logging mechanism? What percentage is debugging stuff left over from when someone fixed GEOS-XXX, and what percentage is actually useful? Is there any clear thought to what levels are logged at which code-points and why?

--saul

Now, since the actual request may be (very) long, we could limit
logging to the first, say, 1024 or 2048 characters in it
Would you like it?

Justin_Deoliveira · February 7, 2007, 4:27pm

What I have done for wfs on trunk is essentially what Chris suggests. The result is a decently formatted summary of the properties of the request object. Example:

INFO:
Request: getFeature
  handle = null
  service = WFS
  version = 1.1.0
  query = [net.opengis.wfs.impl.QueryTypeImpl@anonymised.com (group: null, propertyName: null, function: null, filter: null, sortBy: null, featureVersion: null, handle: null, srsName: null, typeName: [{http://www.opengeospatial.net/cite\}RoadSegments])]
  maxFeatures = null
  outputFormat = GML2
  resultType = results
  traverseXlinkDepth = null
  traverseXlinkExpiry = null

Result:
  lockId = null
  timeStamp = java.util.GregorianCalendar[time=1170865498792,areFieldsSet=true,areAllFieldsSet=true,lenient=true,zone=sun.util.calendar.ZoneInfo[id="Canada/Pacific",offset=-28800000,dstSavings=3600000,useDaylight=true,transitions=189,lastRule=java.util.SimpleTimeZone[id=Canada/Pacific,offset=-28800000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=3,startMonth=3,startDay=1,startDayOfWeek=1,startTime=7200000,startTimeMode=0,endMode=2,endMonth=9,endDay=-1,endDayOfWeek=1,endTime=7200000,endTimeMode=0]],firstDayOfWeek=1,minimalDaysInFirstWeek=1,ERA=1,YEAR=2007,MONTH=1,WEEK_OF_YEAR=6,WEEK_OF_MONTH=2,DAY_OF_MONTH=7,DAY_OF_YEAR=38,DAY_OF_WEEK=4,DAY_OF_WEEK_IN_MONTH=1,AM_PM=0,HOUR=8,HOUR_OF_DAY=8,MINUTE=24,SECOND=58,MILLISECOND=792,ZONE_OFFSET=-28800000,DST_OFFSET=0]
  numberOfFeatures = 5
  feature = [org.geotools.data.DefaultFeatureResults@anonymised.com]

I also did it in an aspect so I didn't have to mess up the dispatcher or the wfs service with messy logging code.

Chris Holmes wrote:

I'm +1. I think some code may already be there at FINE, but yeah, I agree it should be more prominent.

One way to do it might be to just make a .toString() method for GetMapRequest - I think when WFS comes in it gives you a nicely formatted summary of the request.

Chris

Andrea Aime wrote:

Hi,
I'm not very satisfied with current geoserver request logging:

[INFO] org.vfny.geoserver.servlets.AbstractService - handling request: org.vfny.geoserver.wms.requests.GetMapRequest@anonymised.com [INFO] org.vfny.geoserver.servlets.AbstractService - Service handled

Hum, not very informative. I'd prefer to see the actual request.
Now, since the actual request may be (very) long, we could limit
logging to the first, say, 1024 or 2048 characters in it
Would you like it?

Cheers
Andrea

-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier.
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
_______________________________________________
Geoserver-devel mailing list
Geoserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/geoserver-devel

-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier.
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642

!DSPAM:1004,45c9fe24312261527717022!

------------------------------------------------------------------------

_______________________________________________
Geoserver-devel mailing list
Geoserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/geoserver-devel

!DSPAM:1004,45c9fe24312261527717022!

--
Justin Deoliveira
jdeolive@anonymised.com
The Open Planning Project
http://topp.openplans.org

Brent_Owens1 · February 7, 2007, 4:54pm

I would be up for it. Even if it is just the name of the type of request (getMap, getCapabilities, getFeature).

Brent Owens
(The Open Planning Project)

Andrea Aime wrote:

Hi,
I'm not very satisfied with current geoserver request logging:

[INFO] org.vfny.geoserver.servlets.AbstractService - handling request: org.vfny.geoserver.wms.requests.GetMapRequest@anonymised.com [INFO] org.vfny.geoserver.servlets.AbstractService - Service handled

Hum, not very informative. I'd prefer to see the actual request.
Now, since the actual request may be (very) long, we could limit
logging to the first, say, 1024 or 2048 characters in it
Would you like it?

Cheers
Andrea

-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier.
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
_______________________________________________
Geoserver-devel mailing list
Geoserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/geoserver-devel

Andrea_Aime3 · February 7, 2007, 6:24pm

Saul Farber ha scritto:

Andrea,

Short answer: yeah. +1 from me.

Long answer:

Separately from this, I'm a little unclear about what technical logging systems we're using at different levels. For example, the spring container supports a bunch of different logging outputs, and auto-configures itself based on the JVM setup...so what percentage of our logging output is just spring yakking through our logging mechanism? What percentage is debugging stuff left over from when someone fixed GEOS-XXX, and what percentage is actually useful? Is there any clear thought to what levels are logged at which code-points and why?

We do use Java logging, and Spring should use that.
Besides this, unfortunately we don't have any clear guideline about
how to write logs, and yes, it's a pity.
Willing to setup a document about that, and submit a GSIP?

Cheers
Andrea

Andrea_Aime3 · February 7, 2007, 6:25pm

Justin Deoliveira ha scritto:

What I have done for wfs on trunk is essentially what Chris suggests. The result is a decently formatted summary of the properties of the request object. Example:

INFO:
Request: getFeature
    handle = null
    service = WFS
    version = 1.1.0
    query = [net.opengis.wfs.impl.QueryTypeImpl@anonymised.com (group: null, propertyName: null, function: null, filter: null, sortBy: null, featureVersion: null, handle: null, srsName: null, typeName: [{http://www.opengeospatial.net/cite\}RoadSegments])]
    maxFeatures = null
    outputFormat = GML2
    resultType = results
    traverseXlinkDepth = null
    traverseXlinkExpiry = null

Result:
    lockId = null
    timeStamp = java.util.GregorianCalendar[time=1170865498792,areFieldsSet=true,areAllFieldsSet=true,lenient=true,zone=sun.util.calendar.ZoneInfo[id="Canada/Pacific",offset=-28800000,dstSavings=3600000,useDaylight=true,transitions=189,lastRule=java.util.SimpleTimeZone[id=Canada/Pacific,offset=-28800000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=3,startMonth=3,startDay=1,startDayOfWeek=1,startTime=7200000,startTimeMode=0,endMode=2,endMonth=9,endDay=-1,endDayOfWeek=1,endTime=7200000,endTimeMode=0]],firstDayOfWeek=1,minimalDaysInFirstWeek=1,ERA=1,YEAR=2007,MONTH=1,WEEK_OF_YEAR=6,WEEK_OF_MONTH=2,DAY_OF_MONTH=7,DAY_OF_YEAR=38,DAY_OF_WEEK=4,DAY_OF_WEEK_IN_MONTH=1,AM_PM=0,HOUR=8,HOUR_OF_DAY=8,MINUTE=24,SECOND=58,MILLISECOND=792,ZONE_OFFSET=-28800000,DST_OFFSET=0]

    numberOfFeatures = 5
    feature = [org.geotools.data.DefaultFeatureResults@anonymised.com]

Cool, is it possible to backport this to 1.5.x? guess not, right?
Cheers
Andrea

Andrea_Aime3 · February 7, 2007, 6:26pm

Chris Holmes ha scritto:

I'm +1. I think some code may already be there at FINE, but yeah, I agree it should be more prominent.

One way to do it might be to just make a .toString() method for GetMapRequest - I think when WFS comes in it gives you a nicely formatted summary of the request.

It would be nice, yeah. Thought, for debugging purposes it would
be nice to have a request we can paste into a browser for debugging...
Cheers
Andrea

Justin_Deoliveira · February 7, 2007, 6:27pm

Cool, is it possible to backport this to 1.5.x? guess not, right?
Cheers
Andrea

Hmmm, not without a substantial amount of work unfortunately.

!DSPAM:1004,45ca1ad116198365517736!

--
Justin Deoliveira
jdeolive@anonymised.com
The Open Planning Project
http://topp.openplans.org

jive · February 7, 2007, 6:34pm

Andrea Aime wrote:

Hi,
I'm not very satisfied with current geoserver request logging:

[INFO] org.vfny.geoserver.servlets.AbstractService - handling request: org.vfny.geoserver.wms.requests.GetMapRequest@anonymised.com [INFO] org.vfny.geoserver.servlets.AbstractService - Service handled

Hum, not very informative. I'd prefer to see the actual request.
Now, since the actual request may be (very) long, we could limit
logging to the first, say, 1024 or 2048 characters in it
Would you like it?

Yes However it would be nice to log the "leading edge" of the request (when it comes in); as noticed
in my last bug report sometimes requests do not make it to the "Service handled" line. To that end it would be nice
to stick a "name" on the request, and use the same "name" in the Service handled message so that failures based
on concurrent access can be untangled.

But first a question: some of that information should be in the logs for the application service - are you sure this would not be a duplication of effort?

Chris_Holmes1 · February 7, 2007, 8:38pm

Andrea Aime wrote:

Chris Holmes ha scritto:

I'm +1. I think some code may already be there at FINE, but yeah, I agree it should be more prominent.

One way to do it might be to just make a .toString() method for GetMapRequest - I think when WFS comes in it gives you a nicely formatted summary of the request.

It would be nice, yeah. Thought, for debugging purposes it would
be nice to have a request we can paste into a browser for debugging...

If it's for debugging purposes then I think it should go as 'fine', not as 'info'. I'd be happy to collaborate on the doc to for logging guidelines.

I don't think we need a GSIP for it though, as it's just an area that we haven't documented, it's not a big change.

The other request I've heard in the past from geoserver 'users' (those that are standing up GeoServers) is to put the request logging in a database. They want to know what is being asked for, and pretty much just that, they don't really care much about debugging information at all, and like it in a database where they can access it.

Chris

Cheers
Andrea

-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier.
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
_______________________________________________
Geoserver-devel mailing list
Geoserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/geoserver-devel

!DSPAM:1003,45ca1cb319821804284693!

--
Chris Holmes
The Open Planning Project
http://topp.openplans.org

Rob_Atkinson · February 7, 2007, 10:39pm

The other big thing I'd like to be able to do would be to turn on logging _per request_

i.e, I have a production system logging (in the usage logging sense) that experiences a problem. I then want to re-run a particular request with a flag saying that logging _for this request_ should be set to a level.

A short term and probably pretty simple compromise would be to allow the global logging level to be set by a request, or by the request handler, and reset at the end.

Also, I think that full stack traces for the typical exception reporting points, that capture deeper errors, suck. I want the stack trace of the nested error only. If I see a stack trace I want it to be important.

+1 for sorting it out

Rob

Chris Holmes wrote:

Andrea Aime wrote:

Chris Holmes ha scritto:

I'm +1. I think some code may already be there at FINE, but yeah, I agree it should be more prominent.

One way to do it might be to just make a .toString() method for GetMapRequest - I think when WFS comes in it gives you a nicely formatted summary of the request.

It would be nice, yeah. Thought, for debugging purposes it would
be nice to have a request we can paste into a browser for debugging...

If it's for debugging purposes then I think it should go as 'fine', not as 'info'. I'd be happy to collaborate on the doc to for logging guidelines.

I don't think we need a GSIP for it though, as it's just an area that we haven't documented, it's not a big change.

The other request I've heard in the past from geoserver 'users' (those that are standing up GeoServers) is to put the request logging in a database. They want to know what is being asked for, and pretty much just that, they don't really care much about debugging information at all, and like it in a database where they can access it.

Chris

Cheers
Andrea

-------------------------------------------------------------------------

Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier.
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
_______________________________________________
Geoserver-devel mailing list
Geoserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/geoserver-devel

!DSPAM:1003,45ca1cb319821804284693!

-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier.
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
------------------------------------------------------------------------

_______________________________________________
Geoserver-devel mailing list
Geoserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/geoserver-devel