Here is a sample of GAE Console log record:

http://i.stack.imgur.com/M2iJX.png for readable high res version.

I would like to provide a breakdown of the fileds, displayed both in the collpased (summary) view and the expended (detail) view. I will fill the fields I know their meaning and would appreciate assistannce with dichipering the rest. This post will be updated once new information is available.

Thank you,
Maxim.

Open issues:

How to read timestamp? [...-prod/0-0-39.346862139187007139]
Why in summary it says request took 343ms but in details is says 344ms ?
If request spend 123ms on cpu and 30ms on API calls where did the rest of the time go? Why the total request time is 343/344ms ?

回答1:

Summary

12-14 : Date of the request. 12 is the month (December), 14 is the day of the month (Tuesday).
05:21AM : Time of the request, PST offset. 05 is the hour. 21 is the minute.
57.593 : Time of request, PST offset. 57 is the second. 593 is the millisecond.
/match/... : HTTP request path
200 : HTTP return code. (200 = OK)
343ms : The total time (in milliseconds) it took to calculate and return the response to the user
123cpu_ms : The time (in milliseconds) the request spend on CPU calculation
30api_cpu_ms : The time (in milliseconds) the request spend on API calls (Datastore get and co...)
1kb : The size (in kilobytes) of the response that was sent to the user
Mozilla/5.0 (X11; U; Linux x86_64; en-US) AppleWebKit/534.7 (KHTML, like Gecko) Chrome/7.0.517.44 Safari/534.7,gzip(gfe) : User Agent note that gzip(gfe) is added by AppEngine front end.

Details

IP yellow masked out : The IP address of the client initiating the request
HTTP Referrer : Note that it's empty on this request because it's a direct hit
[14/Dec/2010:05:21:57 -0800] : Date, including timestamp offset specification.
"GET /match/... HTTP/1.1" : The HTTP GET URI.
200 : HTTP return code. (200 = OK)
1036 : The size (in bytes) of the response that was sent to the user
Mozilla/5.0 (X11; U; Linux x86_64; en-US) AppleWebKit/534.7 (KHTML, like Gecko) Chrome/7.0.517.44 Safari/534.7,gzip(gfe) : User Agent note that gzip(gfe) is added by AppEngine front end.
ms=344 : The total time (in milliseconds) it took to calculate and return the response to the user
cpu_ms=123 : The time (in milliseconds) the request spend on CPU calculation
api_cpu_ms=30 : The time (in milliseconds) the request spend on API calls (Datastore get and co...)
cpm_usd=0.003648 : The amount (in us $) that 1000 requests such as this one would cost. ref

log record

12-14 : Date of this specific application emitted log entry. 12 is the month (December), 14 is the day of the month (Tuesday).
05:21AM : Time of this specific application emitted log entry, PST offset.
57.833 : Time of request, PST offset. 57 is the second. 833 is the millisecond.
[...-prod/0-0-39.346862139187007139] : The identifier of current version of the application that emitted this log message. Note: ...-prod is the application name. 0-0-39 is the deployed version name (app.yaml). .346862139187007139 is the time? (in what format?) when this version was deployed to appengine cloud.
stdout : The channel to which the application emitted this log message. Can be either stdout or stderr.
INFO ....Matcher - ... Id 208 matched. : Application level output. Can be done via either System.out.print or (as in this case) using a logging framework, logback

回答2:

Isn't 57.593 seconds.milliseconds? And cpm_usd represents an estimate of what 1,000 requests similar to this request would cost in US dollars.