GAE日志字段中时间值的确切含义是什么？ [英] What are the exact meaning of time values in GAE log fields?

问题描述

我在标准的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.comms = 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 msecs与官方 775 。

> protected void doGet（HttpServletRequest req，HttpServletResponse resp）{
long t0 = System.currentTimeMillis（）;
//做这些东西
long t1 = System.currentTimeMillis（）;
log.info（Completed in+（t1-t0）+msecs.\\\
）;





$ b因此，我的问题是：为什么我的测量时间结果与cpu_ms的价值，我怎么能降低它？ GAE日志字段中时间值的确切含义是什么？

我想优化我的代码，并且基于上述事实我意识到，大部分时间（近600毫秒！）不会在 doGet 请求期间直接使用。 （我使用JPA，URLFetch，这是一个cron任务。） ：这是响应的时间，因为它会被请求该页面的用户感知。你会尽量减少它，以提高你的网站的速度。

775cpu_ms ：根据 App Engine文档，CPU时间以秒为单位进行报告这相当于在这段时间内可以通过1.2 GHz Intel x86处理器执行的CPU周期数。实际使用的CPU周期数根据App Engine内部条件的不同而有很大差异，因此将根据报告进行调整目的是使用这个处理器作为参考测量。

然后，通常不会有真实时间：它应该与您测量的不同与 System.currentTimeMillis（），因为它已被调整。相反，您应该使用 Quota API 来监控CPU使用情况：请参阅文档这里。 CPU时间是可计费的（免费配额为每天6.5个CPU小时，并且您可以支付更多的CPU时间）。然后，您将尝试减少它，以便支付更少。

589api_cpu_ms ：这是API使用所花费的仲裁CPU时间（数据存储，用户API等）。

I see some enigmatic time fields in the standard Google app-engine logs which make me curious:

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

Particularly: ms, cpu_ms, api_cpu_ms, each of them two times with slightly different values.

Additionally, when I log timing information myself with a simple structure below for the GET request, it prints a somewhat lower value. In this case, particulary 182 msecs, against the official 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");
}

So, my questions are: Why the difference between my measured time result and the cpu_ms value and how could I lower it? What are the exact meaning of time values in GAE log fields?

I want to optimize my code and I realized based on the aforementioned facts, that most time (nearly 600 msecs!) doesn't spent directly during doGet request. (I use JPA, URLFetch and this is a cron task.)

解决方案

211ms: It's the response's time, as it will be perceived by the user who requested the page. You will try to decrease it, in order to improve the speed of your website.

775cpu_ms: According to the App Engine documentation, "CPU time is reported in "seconds," which is equivalent to the number of CPU cycles that can be performed by a 1.2 GHz Intel x86 processor in that amount of time. The actual number of CPU cycles spent varies greatly depending on conditions internal to App Engine, so this number is adjusted for reporting purposes using this processor as a reference measurement."

Then, it's normal not to have the "real" time: it should be different from what you measured with System.currentTimeMillis() because it's adjusted. Instead, you should use the Quota API to monitor the CPU usage: see documentation here. CPU time is billable (the free quota is 6.5 CPU-hours per day, and you can pay for more CPU time). Then, you will try to decrease it, in order to pay less.

589api_cpu_ms: It's the adjuested CPU time spent by the API usage (Datastore, User API, etc.)

这篇关于GAE日志字段中时间值的确切含义是什么？的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！