Creating nested log entries in Cloud Logging Viewer from API?

Question

I'd like to publish logs from a custom app running on a compute engine to the cloud logging API.

However, I'd like to get nested logs (like AppEngine loglines). Is this possible through the api?

score 2 · Answer 1 · edited Mar 04 '18 at 21:38

This use-case is explained in the AppEngline Logs docs.

Make sure to also set the traceId fields to non-null values on the request and app logs which you are sending. Here's sample code in Scala:

import com.google.cloud.MonitoredResource
import com.google.cloud.logging.Payload._
import com.google.cloud.logging._
import collection.JavaConverters._
import org.threeten.bp.Duration

val logging = LoggingOptions.getDefaultInstance().getService()
val traceId = "keasdfwxcbrbntpoiuwehrtiojsadf";

var firstEntry = {
  LogEntry.newBuilder(StringPayload.of("string-payload-one"))
    .setSeverity(Severity.DEBUG)
    .setLogName("app")
    .setTimestamp(1519955138399L)
    .setResource(MonitoredResource.newBuilder("global").build())
    .setLabels(Map("environment" -> "testing").asJava)
    .setTrace(traceId)
    .build()
}

var midEntry = {
  LogEntry.newBuilder(StringPayload.of("string-payload-two"))
    .setSeverity(Severity.INFO)
    .setLogName("request")
    .setResource(MonitoredResource.newBuilder("global").build())
    .setHttpRequest(HttpRequest.newBuilder().setStatus(200).setRequestUrl("/about-us").setLatency(Duration.ofMillis(1234)).build())
    .setTimestamp(1519955137906L)
    .setLabels(Map("environment" -> "testing").asJava)
    .setTrace(traceId)
    .build()
}

var lastEntry = {
  LogEntry.newBuilder(StringPayload.of("string-payload-three"))
    .setSeverity(Severity.DEBUG)
    .setLogName("app")
    .setResource(MonitoredResource.newBuilder("global").build())
    .setTimestamp(1519955138523L)
    .setLabels(Map("environment" -> "testing").asJava)
    .setTrace(traceId)
    .build()
}

logging.write(List(firstEntry, midEntry, lastEntry).asJava)

At the end, the log entries should show up both in their individual logs and "cross-logged" as children of their requests, like this:

score 0 · Answer 2 · edited Mar 02 '18 at 01:50

This is not documented as it should be (per this answer circa 2016), but if you inspect a LogEntry from GAE, you should be able to reproduce it from elsewhere. Here's an example:

{
  "httpRequest": {
    "status": 500
  },
  "insertId": "5a93c0d800088625d8b7e45f",
  "labels": {
    "clone_id": "00c61b117c43aee4462ccf2cc75fa0a439d65d89992032719b9f34b7b4fa341bf0d3b7de"
  },
  "logName": "projects/matchmaker/logs/appengine.googleapis.com%2Frequest_log",
  "operation": {
    "id": "5a93be8000ff0e7e83cece7ced0001737e70726f6a656374736572656e6469700001323031373131323474313631353036000100",
    "last": true,
    "producer": "appengine.googleapis.com/request_id"
  },
  "protoPayload": {
    "@type": "type.googleapis.com/google.appengine.logging.v1.RequestLog",
    "appEngineRelease": "1.9.54",
    "appId": "s~matchmaker",
    "cost": 3.5092199999999997e-07,
    "endTime": "2018-02-26T08:10:00.558238Z",
    "finished": true,
    "host": "matchmaker.appspot.com",
    "httpVersion": "HTTP/1.1",
    "instanceId": "00c61b117c43aee4462ccf2cc75fa0a439d65d89992032719b9f34b7b4fa341bf0d3b7de",
    "instanceIndex": -1,
    "ip": "0.1.0.1",
    "latency": "599.608347s",
    "line": [
      {
        "logMessage": "mail_body: Hi X and Y,<br>\n<br>\nYou've been matched!<br>\n<br>\nGo forth and one-on-one, and may it be as awesome as a peregrine falcon soaring\nthrough the rays of a setting sun.<br>\n<br>\nCheers,<br>\nProject Lemma<br>\n<br>\nPS: I'm not a calendar (yet) so it's up to you two to find a time to meet.",
        "severity": "INFO",
        "sourceLocation": {
          "file": "/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/models/match.py",
          "functionName": "send_email_and_put",
          "line": "47"
        },
        "time": "2018-02-26T08:09:41.148490Z"
      },
      {
        "logMessage": "Traceback (most recent call last):\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/runtime/wsgi.py\", line 267, in Handle\n     result = handler(dict(self._environ), self._StartResponse)\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/lib/flask/app.py\", line 2000, in __call__\n     return self.wsgi_app(environ, start_response)\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/lib/flask/app.py\", line 1988, in wsgi_app\n     response = self.full_dispatch_request()\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/lib/flask/app.py\", line 1639, in full_dispatch_request\n     rv = self.dispatch_request()\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/lib/flask/app.py\", line 1625, in dispatch_request\n     return self.view_functions[rule.endpoint](**req.view_args)\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/cron/__init__.py\", line 11, in matches\n     for match in all_matches():\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/cron/matches.py\", line 21, in all_matches\n     possibilities = {u.key: u.possible_matches for u in avail}\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/cron/matches.py\", line 21, in <dictcomp>\n     possibilities = {u.key: u.possible_matches for u in avail}\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/models/user.py\", line 64, in possible_matches\n     return sorted(matches, reverse=True)\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/models/match.py\", line 19, in __cmp__\n     return cmp(self.score, other.score)\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/models/match.py\", line 71, in score\n     total_capacity = sum(f.get().cur_capacity for f in self.folks)\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/models/match.py\", line 71, in <genexpr>\n     total_capacity = sum(f.get().cur_capacity for f in self.folks)\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/models/user.py\", line 33, in cur_capacity\n     return int(self.settings['freq']) - len(self.cur_matches)\n   File \"/base/data/home/apps/s~matchmaker/20171124t161506.405758693491065379/models/user.py\", line 47, in cur_matches\n     ).fetch(1000)\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/ext/ndb/utils.py\", line 160, in positional_wrapper\n     return wrapped(*args, **kwds)\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/ext/ndb/query.py\", line 1218, in fetch\n     return self.fetch_async(limit, **q_options).get_result()\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/ext/ndb/tasklets.py\", line 383, in get_result\n     self.check_success()\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/ext/ndb/tasklets.py\", line 378, in check_success\n     self.wait()\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/ext/ndb/tasklets.py\", line 362, in wait\n     if not ev.run1():\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/ext/ndb/eventloop.py\", line 268, in run1\n     delay = self.run0()\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/ext/ndb/eventloop.py\", line 230, in run0\n     callback(*args, **kwds)\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/ext/ndb/tasklets.py\", line 433, in _help_tasklet_along\n     ns = namespace_manager.get_namespace()\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/api/namespace_manager/namespace_manager.py\", line 86, in get_namespace\n     name = os.environ.get(_ENV_CURRENT_NAMESPACE, None)\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_dist/lib/python2.7/_abcoll.py\", line 382, in get\n     return self[key]\n   File \"/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/runtime/request_environment.py\", line 125, in __getitem__\n     def __getitem__(self, key):\n DeadlineExceededError: The overall deadline for responding to the HTTP request was exceeded.",
        "severity": "ERROR",
        "sourceLocation": {
          "file": "/base/alloc/tmpfs/dynamic_runtimes/python27/a7637d5531ec9deb_unzipped/python27_lib/versions/1/google/appengine/runtime/wsgi.py",
          "functionName": "Handle",
          "line": "279"
        },
        "time": "2018-02-26T08:10:00.549690Z"
      }
    ],
    "megaCycles": "34946",
    "method": "GET",
    "requestId": "5a93be8000ff0e7e83cece7ced0001737e70726f6a656374736572656e6469700001323031373131323474313631353036000100",
    "resource": "/cron/matches",
    "startTime": "2018-02-26T08:00:00.949891Z",
    "status": 500,
    "taskName": "f5915e6b03b632b41d45204c6686840b",
    "taskQueueName": "__cron",
    "urlMapEntry": "cron.APP",
    "userAgent": "AppEngine-Google; (+http://code.google.com/appengine)",
    "versionId": "20171124t161506"
  },
  "receiveTimestamp": "2018-02-26T08:10:00.564188790Z",
  "resource": {
    "labels": {
      "module_id": "default",
      "project_id": "matchmaker",
      "version_id": "20171124t161506",
      "zone": "us2"
    },
    "type": "gae_app"
  },
  "severity": "ERROR",
  "timestamp": "2018-02-26T08:00:00.949891Z"
}

SO won't let me downvote it — it's the wrong direction, as far as I can tell. "line" is ignored regardless of what else I do, but the other answer I linked works — https://stackoverflow.com/a/49036936/10728 — Andrey Fedorov, Mar 02 '18 at 02:01
You might be able to get your bounty back possibly. Although that bounty really confuses me. — gsquaredxc, Mar 02 '18 at 02:07
I just really wanted the answer. It's still a bit confusing — the logs show up both nested and un-nested when I follow those directions. Getting it back would be nice, of course. — Andrey Fedorov, Mar 02 '18 at 02:09
Well that bounty is only 4 times my total rep XD! Quote of the year - "Getting [500 rep] back would be nice" — gsquaredxc, Mar 02 '18 at 02:12
Happy to give it to you if you want to comment with the link to the docs @GrantGarrison — Andrey Fedorov, Mar 04 '18 at 05:47
If you answer the question, yes. That’s how bounties work! >_ — Andrey Fedorov, Mar 04 '18 at 16:30
The link itself is a good answer and I can extend it with code and and a screenshot. — Andrey Fedorov, Mar 04 '18 at 16:34
It’s the other link but I’ll fix it in a min https://cloud.google.com/logging/docs/view/service/appengine-logs#linking_application_logs_and_requests — Andrey Fedorov, Mar 04 '18 at 16:53
Actually, I included some of the stuff from that link in my answer. — gsquaredxc, Mar 04 '18 at 16:55
All yours, thanks for helping out here & have a good Sunday! :-) — Andrey Fedorov, Mar 04 '18 at 17:07
You too! Thanks for the rep. I can’t thank you enough for 500 rep! Now to give back by going through the review queues! — gsquaredxc, Mar 04 '18 at 17:21

score -1 · Answer 3 · answered Jan 11 '18 at 17:45

3 years later and here we go....

That concept from app engine is grouping by long running operations

You just need to specify the paramether operation in the api call with the object LogentryOperation

Here is the reference for this object

https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#LogEntryOperation

Creating nested log entries in Cloud Logging Viewer from API?

3 Answers3