views:

321

answers:

3

A very simple java code inside a doGet() servlet is getting more than a second of cpu time on GAE. I have read some quota related documentation and apparently I am not doing anything wrong.

//Request the user Agent info
String userAgent = req.getHeader("User-Agent");

I wanted to know what was using the CPU the most, I use a google help recommendation.

    //The two lines below will get the CPU before requesting User-Agent Information
    QuotaService qs = QuotaServiceFactory.getQuotaService();
    long start = qs.getCpuTimeInMegaCycles();

    //Request the user Agent info
    String userAgent = req.getHeader("User-Agent");

    //The three lines below will get the CPU after requesting User-Agent Information 
    // and informed it to the application log.
    long end = qs.getCpuTimeInMegaCycles();
    double cpuSeconds = qs.convertMegacyclesToCpuSeconds(end - start);
    log.warning("CPU Seconds on geting User Agent: " + cpuSeconds);

The only thing that the code above tells me is that inspecting the header will use more than a second (1000ms) of cpu time, which for Google is a warning on the log panel. That seems to be a very simple request and still is using more than a second of cpu.

What I am missing?


Below the image of the logs for everyone's entertainment.

logs for Google App Engine Slow Reports

I am posting the full code, for the benefit of all.

@SuppressWarnings("serial")
public class R2CComingSoonSiteServlet extends HttpServlet {

private static final Logger log = Logger.getLogger(R2CComingSoonSiteServlet.class.getName());

public void doGet(HttpServletRequest req, HttpServletResponse resp)
        throws IOException {
    //The two lines below will get the CPU before requesting User-Agent Information
    QuotaService qs = QuotaServiceFactory.getQuotaService();
    long start = qs.getCpuTimeInMegaCycles();

    //Request the user Agent info
    String userAgent = req.getHeader("User-Agent");

    //The three lines below will get the CPU after requesting User-Agent Information 
    // and informed it to the application log.
    long end = qs.getCpuTimeInMegaCycles();
    double cpuSeconds = qs.convertMegacyclesToCpuSeconds(end - start);
    log.warning("CPU Seconds on geting User Agent: " + cpuSeconds);

    userAgent = userAgent.toLowerCase();
    if(userAgent.contains("iphone"))
        resp.sendRedirect("/mobIndex.html");
    else
        resp.sendRedirect("/index.html");} }
A: 

The only thing that the code above tells me is that inspecting the header will use more than a second (1000ms) of cpu time, which for Google is a warning on the log panel. That seems to be a very simple request and still is using more than a second of cpu.

Does this also happen without the calls to the quota API?

Thilo
Yes, the calls to the quota api, were implemented for the sole purpose of finding the root cause. The initial reason of me investigating this issue was the log warning icons, informing me of my application using more than a second of processing on a given servlet.
Geo
yes, maybe just log the time, in and out with and without the calls to the quota code. i'd be very surprised if the call to `req.getHeader` is taking a second as it is (depending on container implementation) a lookup to a pre-initialised map.
pstanton
@Geo: How about for a Servlet that does nothing at all?
Thilo
A: 

Your logs show that it is only slow sometimes.

Is the construction of your servlet object really slow?

Stephen Denne
Hi Stephen, thanks for your post. I just added the full servlet code for you benefit. This is a single purpose servlet, nothing out of the extraordinary.
Geo
+4  A: 

There are no longer any per-minute quotas on App Engine. Any messages referring to them are out of date. If you want to do better profiling of your CPU usage, you may want to try out the newly released appstats for Java.

Nick Johnson
Hi Nick, Thanks for this tip of information.
Geo
Hey Nick, could you please send me the official google press release where the per minute quotas are removed?
Geo
I don't believe we issued any sort of press release - if we issued one for every new feature, we'd never do anything else! It's likely in the release notes, though.
Nick Johnson