TurboManage

David Chandler's Journal of Java Web and Mobile Development

  • David M. Chandler


    Web app developer since 1994 and former Developer Advocate with Google now residing in Colorado. Besides tech, I enjoy landscape photography and share my work at ColoradoPhoto.gallery.

  • Subscribe

  • Enter your email address to subscribe to this blog and receive notifications of new posts by email.

    Join 241 other followers

  • Sleepless Nights…

    March 2010
    S M T W T F S
    « Feb   Apr »
     123456
    78910111213
    14151617181920
    21222324252627
    28293031  
  • Blog Stats

    • 857,849 hits

A few words on AppEngine logging (production)

Posted by David Chandler on March 5, 2010

The AppEngine production log viewer is the envy of most development and sysadmin teams I’ve ever worked with. It offers a a near real-time view into your application’s doings in a powerful Web-based interface. In addition to filtering on the standard JDK log levels, you can search a particular time period, filter any regex, and use labels to filter on

  • day,
  • month,
  • year,
  • hour,
  • minute,
  • second,
  • tzone,
  • remotehost,
  • identd_user,
  • user,
  • status,
  • bytes,
  • referrer,
  • useragent,
  • method,
  • path,
  • querystring,
  • protocol

The request log shows every request, even images and CSS, so you can see why you need to turn on expiration headers for static files 🙂 RPC calls, cron jobs, task servlets–they’re all there. Furthermore, if your app is enabled for Google account authentication, every request is tagged with the Google user id. This is a poor man’s “fish tag” and is extremely helpful for real-time customer support with your mother-in-law (“Mom! You’re using IE 5!”).

If you’re using gwt-dispatch, you’ll notice that all requests to the dispatcher are logged alike (which also causes the Dashboard CPU meter to aggregate all requests to your dispatch servlet). With this in mind, I’m thinking of having the dispatch servlet log the Action class being invoked so I can put together something akin to a click trail. In addition, I wonder if there’s a way for the GWT dispatcher to append the action name as extra path info or query string? This way, the Dashboard might be able to break out which Actions are consuming the most CPU.

The only unpleasantness I’ve found is that AppEngine clutters up the logs with a bunch of harmless warnings about FinalizableReferenceQueue. You can easily get rid of them, however, by putting these lines to your WEB-INF/logging.properties:

# Hide harmless
com.google.inject.internal.FinalizableReferenceQueue=WARNING
com.google.inject.internal.FinalizableReferenceQueue$SystemLoader=WARNING
com.google.appengine.repackaged.com.google.common.base.FinalizableReferenceQueue.level=WARNING

Actually, there is one more unpleasantness: the much-discussed cold start problem. If your app is not yet world-famous, AppEngine will cycle it out after only a few minutes of non-use. This issue has been beat to death on the forums, but suffice it to say it’s easy to spot: just look for the requests with CPU time in red that took 8 seconds after a period of inactivity. Lots of folks have said they’d be willing to stay “hot,” which seems like a good idea. For my part, I like the platform enough that I’m willing to bet Google will take this seriously.

Advertisements

4 Responses to “A few words on AppEngine logging (production)”

  1. Sven Tiffe said

    Thank you for your blog post on GAE logging. When I access the logs section of my application, I can filter on level of severity, but for some reasons I cannot manage to filter on labels. Also I do not find any referrer information when browsing the unfiltered list of logs (GAE running a Java service).

    Do I need to activate such kind of logging separately, e.g. in logging.properties? I did not found much on the web or in the GAE group regarding referrer logging.

    Thanks!

    • AFAIK, you don’t have to enable anything special to filter on label. In the admin console under Logs, just click on Options, then select the Labels radio button. Is that not working for you?

      • Sven Tiffe said

        When I enter “referrer” as label, I get an error “There were errors: * Filter”. When I select “All requests”, I cannot see any entries which look like referrer logs to me. Strange…

      • Sven Tiffe said

        Edit: sorry, in unfiltered mode, I can see the referrer in log entries for “/”. Also, I can filter them by “path:/”

        My mistake was that I thought filtering on “referrer” is possible and returns automatically all referrers. Thanks!

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

 
%d bloggers like this: