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

【问题标题】：What are the exact meaning of time values in GAE log fields?GAE 日志字段中时间值的确切含义是什么？
【发布时间】：2011-08-22 04:17:32
【问题描述】：

我在标准的 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 任务。）

【问题讨论】：

标签： java google-app-engine logging

【解决方案1】：

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

775cpu_ms：根据App Engine documentation，“CPU时间以“秒”为单位报告，这相当于1.2 GHz Intel可以执行的CPU周期数x86 处理器。实际花费的 CPU 周期数根据 App Engine 内部条件的不同而有很大差异，因此为了报告的目的，使用此处理器作为参考测量来调整此数字。"

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

589api_cpu_ms：这是 API 使用（Datastore、User API 等）花费的调整后的 CPU 时间

【讨论】：