我正在尝试更好地了解Google的 Cloud 控制台堆栈驱动程序跟踪显示调用详细信息的方式,并调试我的应用程序的一些性能问题 . 大多数请求都与memcache set / get操作有很大关系,我在这里遇到了一些问题,但我不明白为什么调用之间存在很长时间的差距 . 我上传了2个截图 .
所以,正如你所看到的,@ 1025ms的呼叫耗时2ms,但它和urlfetch呼叫@ 5235ms之间的距离超过4秒 .
首先,我的代码在那时并不密集(并且完整请求显示大约9000ms的未跟踪时间),第二,运行相同代码的大多数类似请求没有这些间隙(即,重复请求不会有相同的行为) . 但我也在其他请求中也看到了这个问题,我无法重现它们 .
请指教!
EDIT:
我已经从appstats上传了另一个截图 . 这是一个“正常”请求,通常需要几百毫秒才能运行(最多1秒),也需要在localhost(开发)中 . 我无法找到任何进一步调试的东西 . 我觉得我遗漏了一些简单的东西,基础层面的东西,关于app引擎的DO和DO NOTs .
2 回答
我知道这些差距的以下常见原因(“未跟踪时间”):
要检查此问题,请转至日志查看器并查看受影响的传入HTTP请求的详细信息 . 请注意,从跟踪详细信息到日志条目还有一个方便的直接链接 . 在请求日志条目中,查找 cpu_ms 字段,该字段指出
该指标也可在 protoPayload.megaCycles 中找到 .
这是一个具有大量未跟踪时间的慢速请求的示例日志条目:
此示例请求的 cpu_ms 字段异常高( 11927 ),表示大部分未跟踪时间都花费在应用程序本身(或运行时)中 .
为什么请求处理程序使用那么多CPU?通常,几乎不可能确切地告诉CPU时间花费在哪里,但如果您知道在给定请求中应该发生什么,则可以更轻松地缩小范围 . 两个常见原因是:
Protip,如果您想在日志查看器中将调查过滤器集中在这样的 loading requests ,请应用此高级过滤器:
如果问题在dev appserver中可以在本地重现,则可以使用分析器(或者可能只是jstack)来缩小范围 . 在其他一些情况下,我确实必须逐步将应用程序代码二等分,添加更多日志语句,重新部署等,直到识别出有问题的代码 .
App Engine标准环境中的Stackdriver Trace实际上没有开箱即用的后端调用 . 到目前为止我唯一知道的例子是Cloud SQL . 考虑使用Google Cloud Trace for JDBC来跟踪与Cloud SQL的交互 .
该应用程序是多线程的(太棒了!)并且遇到了一些自我造成的同步问题 . 我在野外看过的例子:
特定于应用程序的同步强制对存储后端的所有请求进行序列化(对于给定的App Engine实例) . 除了那些神秘的空隙之外,没有任何东西在痕迹中突出......
应用程序使用数据库连接池 . 并行请求数超过了容量池(对于给定的App Engine实例),某些请求必须等到连接可用 . 这是前一项的更复杂的变体 .
鉴于这种情况很少发生并且实际处理时间(由 Span 长度表示)很短,我怀疑是某种App Engine缩放操作正在后台发生 . 例如,减速可能是由添加到应用程序的新实例引起的 . 您可以通过查看App Engine仪表板上的活动图或使用AppStats(参见this SO帖子)进一步深入研究 .
在跟踪时间线视图中显示App Engine事件是我们一直希望做的事情,因为它会大大缩短这种情况下的分析过程 .