java - GAE 日志字段中时间值的确切含义是什么？

Question

我在标准的 Google 应用引擎日志中看到一些神秘的时间字段，这让我很好奇:

2011-05-09 21:56:00.577 /whatever 200 211ms 775cpu_ms 589api_cpu_ms 
0.1.0.1 - - [09/May/2011:21:56:00 -0700] "GET /whatever HTTP/1.1"
200 34 - "AppEngine-Google; (+http://code.google.com/appengine)"
"****.appspot.com" ms=212 cpu_ms=776 api_cpu_ms=589 cpm_usd=0.021713
queue_name=__cron task_name=dc4d411120bc75ea8bbea773d23eaecc

特别是:ms、cpu_ms、api_cpu_ms，它们各两次，值略有不同。

此外，当我自己使用下面的简单结构为 GET 请求记录计时信息时，它会打印出一个稍低的值。在这种情况下，特别是 182 毫秒，而官方的 775。

protected void doGet(HttpServletRequest req, HttpServletResponse resp) {
  long t0 = System.currentTimeMillis();
  //Do the stuff
  long t1 = System.currentTimeMillis();
  log.info("Completed in " + (t1-t0) + " msecs.\n");
}

所以，我的问题是:为什么我测量的时间结果与 cpu_ms 值之间存在差异，我该如何降低它？ GAE 日志字段中时间值的确切含义是什么？

我想优化我的代码，并且根据上述事实我意识到，大部分时间(将近 600 毫秒!)并没有直接花在 doGet 请求期间。 (我使用 JPA、URLFetch，这是一个 cron 任务。)

Answer 1

211ms:这是响应时间，因为它会被请求页面的用户感知。您将尝试减少它，以提高您网站的速度。

775cpu_ms:根据App Engine documentation , “CPU 时间以“秒”为单位报​​告，这相当于 1.2 GHz Intel x86 处理器在该时间段内可以执行的 CPU 周期数。实际花费的 CPU 周期数差异很大，具体取决于在 App Engine 内部的条件下，因此使用此处理器作为引用测量来调整此数字以用于报告目的。“

然后，没有“实时”时间是正常的:它应该与您使用 System.currentTimeMillis() 测量的时间不同，因为它已经过调整。相反，您应该使用 Quota API 来监控 CPU 使用情况:请参阅文档 here . CPU 时间是收费的(免费配额是每天 6.5 个 CPU 小时，您可以为更多的 CPU 时间付费)。然后，您将尝试减少它，以减少支付。

589api_cpu_ms:这是 API 使用(数据存储、用户 API 等)花费的调整后的 CPU 时间