"gcloud app logs tail" shows week old data

Question

I'm trying to stream logs for my Google Cloud Platform application. The first thing I notice is that Google sends about 10 healthchecks per second, at a minimum, so I have to grep -v /health to get any useful info. Is that standard?

The second thing is that it streams old logs. I'm running gcloud app logs tail -s default and getting logs from April 11 (a week old at this point). Newer logs (from 4, 3, and 2 days ago) are slowly streaming in over a matter of hours. I just hit refresh on my app (which triggers a log message) and saw no new logs.

Is there any way to get a close-to-realtime (within minutes or hours) view of new log messages?

Answer 1

For the healthchecks, you don't need to rely in grep. The SDK has included filters, so you could just filter the output. However, you would just be hiding them on the terminal, but the SDK would still get them from the API (just like using grep). A more optimal way would be using gcloud logging read 'resource.type="gae_app" AND logName:"logs/appengine.googleapis.com%2Frequest_log" AND protoPayload.resource!="/health"' --order desc, as you would be requesting only the logs matching a custom filter. This gives quite a verbose log, so you can format the output directly on the SDK to make it as similar to gcloud app logs tailas you want.

Since gcloud logging does not have a "tail" mode, you can just wrap it in watch like:

watch 'gcloud logging read "resource.type=\"gae_app\" AND logName:\"logs/appengine.googleapis.com%2Frequest_log\" AND protoPayload.resource!=\"/health\"" --order desc --limit 1'

You should add the --format flag to make the output fit your needs, and the --limit flag to something that make sense to you (the larger the limit, the slower the response).

Regarding the time where the logs start, if you run gcloud app logs tail -s default --log-http and compare the request done by the SDK with the filters available on the API, you'll see why it starts showing one week old logs.

I think that the best option in your case would be making the call directly to the API, wrapped in watch.

A direct API call would also allow you to add a custom filter and use a field mask, returning only the relevant log entries and fields, making it less straining to the network and having faster responses.

First you have to create a log filter that will return only the logs you want (no healthcheck or monitoring spam). The best way to do this is by testing in the console itself until you're satisfied with the logs displayed.

Then you check the fields you're interested in. For GAE logs, most likely you'll want only the protoPayload (and only some fields of the payload at that, but those can be filtered later).

So we construct our API call loop in the following way (warning: quote escaping hell):

watch -tcn 0.5 'curl  -H"Authorization: Bearer $(gcloud auth print-access-token)" \
   -H"Content-Type: application/json" \
   "https://logging.googleapis.com/v2/entries:list?fields=entries%2FprotoPayload" \
   -d"{
   \"filter\":\"resource.type=\\\"gae_app\\\"
                logName=\\\"projects/$(gcloud config get-value project)/logs/appengine.googleapis.com%2Frequest_log\\\"\",
   \"pageSize\":$(tput lines),
   \"orderBy\":\"timestamp desc\",
   \"resourceNames\": [
      \"projects/$(gcloud config get-value project)\"
   ]
 }" 2>\dev\null |jq -cC ".entries[].protoPayload | { timestamp: .startTime, method, status, latency, URL: (.host + .resource) }"'

As a quick test, I'm piping the response through jq to format the output and limiting the response size to the screen size, but you should adapt this to the fields and output that makes it easier for you to read.