Stackdriver 日志对于应用引擎后台线程具有相同的时间戳

Question

我在应用引擎标准应用程序中使用来自 google.appengine.api 的 background_thread 创建一个线程，该线程每 30 秒轮询一次拉取任务队列以查找新任务。 应用引擎将每次运行的日志分组到堆栈驱动程序上的 /_ah/background 条目中，应用程序记录的所有内容都分组在该条目中。

问题是所有 /_ah/background 记录的时间戳都与创建的第一个条目的时间戳相同，但分组在其下的应用程序日志显示正确的时间戳。这也导致堆栈驱动程序在一天的运行后没有记录日志，因为它达到了限制（可能是因为所有条目都使用相同的时间戳记录）。

关于为什么 /_ah/background 条目具有相同时间戳的任何想法？

Answer 1

每当启动后台线程时，都会向 /_ah/background 发出特殊请求。也就是说，后台线程的工作方式就像它正在向 /_ah/background 提供请求一样。来自后台线程的所有日志都记录到该特定请求。在后台线程运行时，将记录诸如“active start=2013-08-21,11:15:17.586”之类的标签，而不是记录 HTTP 响应代码和经过的时间。如果终止，日志会显示响应代码和实际经过的时间。

但是，在同一线程中运行的每个操作都将具有与主操作相同的时间戳。因此，对于在相同后台主操作下运行的所有后台操作，将看到相同的时间戳。 深入了解 Stackdriver 中每个操作的日志将提供有关确切时间戳的更多详细信息以及有关任务的其他详细信息。

考虑到这一点，请注意 entries.write API 调用 limit 是每个项目每秒 1000 次写入。因此，这可能不一定是停止日志记录的原因。