Missing protobuf descriptor: google.appengine.logging.v1.RequestLog

[Fkawala]

Hello,

To send a protobuf RequestLog entry through the stackdriver logging facility fails with the error stack below.

Traceback (most recent call last):
  File "do_log.py", line 28, in <module>
    logger.log_proto(Struct(fields=pb_fields), labels=labels)
  File "/usr/local/lib/python2.7/dist-packages/google/cloud/logging/logger.py", line 260, in log_proto
    client.logging_api.write_entries([entry_resource])
  File "/usr/local/lib/python2.7/dist-packages/google/cloud/logging/_gax.py", line 110, in write_entries
    entry_pbs = [_log_entry_mapping_to_pb(entry) for entry in entries]
  File "/usr/local/lib/python2.7/dist-packages/google/cloud/logging/_gax.py", line 612, in _log_entry_mapping_to_pb
    Parse(json.dumps(mapping['protoPayload']), entry_pb.proto_payload)
  File "/usr/local/lib/python2.7/dist-packages/google/protobuf/json_format.py", line 369, in Parse
    return ParseDict(js, message, ignore_unknown_fields)
  File "/usr/local/lib/python2.7/dist-packages/google/protobuf/json_format.py", line 384, in ParseDict
    parser.ConvertMessage(js_dict, message)
  File "/usr/local/lib/python2.7/dist-packages/google/protobuf/json_format.py", line 413, in ConvertMessage
    methodcaller(_WKTJSONMETHODS[full_name][1], value, message)(self)
  File "/usr/local/lib/python2.7/dist-packages/google/protobuf/json_format.py", line 518, in _ConvertAnyMessage
    sub_message = _CreateMessageFromTypeUrl(type_url)
  File "/usr/local/lib/python2.7/dist-packages/google/protobuf/json_format.py", line 341, in _CreateMessageFromTypeUrl
    'Can not find message descriptor by type_url: {0}.'.format(type_url))
TypeError: Can not find message descriptor by type_url: type.googleapis.com/google.appengine.logging.v1.RequestLog.

The protobuf is created / sent as follows:

from google.cloud import logging
from google.protobuf.struct_pb2 import Struct, Value, ListValue
client = logging.Client()
logger = client.logger('test')

line = Struct(fields={'time': Value(string_value='2016-09-04T13:00:08.139759Z'), 
                      'severity': Value(string_value='INFO'),
                      'logMessage': Value(string_value='Simply testing')})
lines = ListValue()
lines.values.add(struct_value=line)

pb_fields = {'@type': Value(string_value='type.googleapis.com/google.appengine.logging.v1.RequestLog'),
             'startTime':Value(string_value='2016-09-04T13:00:08.117102Z'),
             'endTime':Value(string_value='2016-09-04T13:00:08.117102Z'),
             'latency':Value(string_value='0s'),
             'responseSize':Value(string_value='349'),
             'userAgent': Value(string_value='agent'),
             'resource': Value(string_value='test resource'),
             'line': Value(list_value=lines)}

labels =  {'serviceName': 'custom.googleapis.com',
           'custom.googleapis.com/primary_key': 'fake_module',
           'custom.googleapis.com/secondary_key': 'fake_version',
           'zone': 'us6'}

logger.log_proto(Struct(fields=pb_fields), labels=labels)

This gist provides a docker test environment.

Is this a bug or am I missing something ?
François.

[dhermes]

@bjwatson Is there some kind of automated conversion for Any messages (i.e. with a type url)?

[bjwatson]

@dhermes Looks like there is, but it doesn't recognize type.googleapis.com/google.appengine.logging.v1.RequestLog. The relevant code seems to be here and here.

[dhermes]

@bjwatson Do you know how types get registered with symbol_database.Default()? Do any of the GAPIC / gRPC generated libraries register types (UPDATE: I confirmed that they do register lots of types, probably the generated _pb2 files do it)?

The GAE protos don't have the google.appengine.logging.v1 namespace. The docs seem to refer to the v1beta3 version of this proto, but not v1.

/cc @waprin @jonparrott

[bjwatson]

Hi @pherl. I was referred to you by @geigerj. Do you have any thoughts on this issue involving protobuf/json_format.py?

[dhermes]

@Fkawala Sorry I missed this and focused on the wrong thing. Why are you manually specifying the contents of the protobuf? The implementation expects usage of "registered" types, and the failure is due to the fact that the type URL you used is not in the registry in google.protobuf.

[Fkawala]

@dhermes I got the idea here. How could I list the URL in the registry? This PB type is rendered in a particularly convenient way in the Google cloud log browser.

[dhermes]

@Fkawala It's probably not something you want to do. Seems AddDescriptor is what you want, but that requires an actual protobuf type, and those are not usually written by hand (e.g.).

Why do you want to add logs that you copy-pasted from a browser?

[dhermes]

@bjwatson What do you think is the right answer here? The message is essentially an Any type if it doesn't have a registered type URL but parser.ConvertMessage(js_dict, message) doesn't really have a way to convert to a native Any.

[Fkawala]

@dhermes A side note, the code I provided works with gcloud-python 0.18.3. I wonder where I could find the actual descriptor for this PB type, any hints ?

[dhermes]

Whoa, that's surprising. Let me check it out!

[dhermes]

I confirmed this. Differences in deps are:

                        | 0.18.3   | 0.20.0
------------------------+----------+-------
                 grpcio | 1.0.1rc1 | 1.0.0
             google-gax | 0.12.5   | 0.14.1
gapic-google-logging-v2 | (NA)     | 0.10.1
  gax-google-logging-v2 | 0.8.3    | (NA)
 grpc-google-logging-v2 | 0.8.1    | 0.10.1

Both use: protobuf==3.1.0.post1, googleapis-common-protos==1.3.5,

[dhermes]

@bjwatson This is really crazy, do you think somehow the gapic / gax deps are registering extra types?

[bjwatson]

@dhermes Like you said earlier, it looks like only the gRPC-generated code (grpc-google-* packages and googleapis-common-protos) register any extra types. I don't see the GAPIC or GAX code doing this.

@Fkawala Looks like we need to add google.appengine.logging.v1.RequestLog (and google.appengine.logging.v1.LogLine) to googleapis-common-protos. I'll look into this.

I don't know why this worked for you in an earlier version of gcloud-python; it seems like it shouldn't have.

[bjwatson]

@Fkawala This is almost fixed. Once googleapis/api-client-staging#89 is approved by @geigerj, I will publish a new version of https://pypi.python.org/pypi/googleapis-common-protos containing the RequestLog class definition. Thanks for your patience.

[bjwatson]

@Fkawala This should now be fixed by the 1.4.0 release of https://pypi.python.org/pypi/googleapis-common-protos. Please re-open this issue if the problem still exists for you.

[bjwatson]

@dhermes Please see the discussion in googleapis/packman#147. I am wondering why Logger.log_proto(...) is converting the message to JSON, just to parse it back into a message again?

Note that these links point at the 0.20.0 version of the code, not HEAD.

[dhermes]

@bjwatson The two lines you linked don't always follow one another. The conversion to JSON is nominally for sending an HTTP request, but may be repurposed in the gRPC code as well. It may end up parsed back to protobuf in the gRPC case because @tseaver was trying to minimize the parsing code, so at times was converting PBs as JSON resources to avoid repeating code.

Also

I'm not yet convinced this needs to be in a common protos

I and @jonparrott have said it doesn't belong there. A true "fix" could be for MessageToDict to just punt when it can't find the type and just cast it to an Any?

[bjwatson]

@dhermes Thanks. I better understand the design of log_proto now.

I'm surprised by your objection to putting RequestLog in googleapis-common-protos. I posted my plan to do that six days ago, and I never saw an objection from you or @jonparrott. I just double-checked my email to make sure I'm not missing anything.

I published googleapis-common-protos 1.4.0 with the google/appengine/logging message types yesterday.

[dhermes]

@bjwatson It's not a problem that it's in there, it just isn't a "common" proto, that's all.

[bjwatson]

@dhermes and I discussed offline. I see his point that these messages could be in their own separate package, like grpc-google-appengine-logging-v1. We're currently committed to them being in googleapis-common-protos, but can fix this later with a 2.0 release. (see https://github.com/googleapis/api-client-staging/issues/90)

[Fkawala]

@bjwatson thanks !

[theacodes]

@bjwatson @dhermes this is just caused all sorts of problems. oauth2client now thinks that all environments are app engine because now google.appengine exists. Also, it seems google.appengine isn't a proper namespace package.

[theacodes]

googleapis/packman#147 (comment)

[jaitaiwan]

Just been hit by this myself for the past few days when trying to use the cloud logging api

[geigerj]

@lukesneeringer @bjwatson I can update googleapis/googleapis#226 and googleapis/api-client-staging#144 and have a new logging-extra-types package pretty quickly. Does that sound reasonable?

[lukesneeringer]

Just discussed with @geigerj offline, and based on #2572 (comment), I am pretty sure we should not do that. It would just move the problem, because as soon as you installed that package, oauth2client would think you were on GAE.

[bjwatson]

@lukesneeringer @geigerj This seems like a P1 issue given the user impact. I assigned to Luke; feel free to re-assign to Jacob if you prefer.

[geigerj]

@jonparrott Do you have thoughts on the right way to handle this?

[theacodes]

@bjwatson good news and bad news:

1. We no longer depend on oauth2client. The new library does a narrow check and wouldn't be triggered by the presence of that package.
2. If we installed that package, we'll break any app engine users. This library already has tenuous support for App Engine, so let's try not to do anything more to rock the boat.

If the extra types library can have an import path that doesn't start with google.appengine then we're in the clear. But, as far as I can tell google.appengine should only be used by the GAE SDK.

[dhermes]

The fix is to loosen the way we parse Any protobufs here. (We had discussed this before and I let it fall through the cracks, my bad.) No need for any new generated libraries

[dhermes]

Duplicate of #2674

[mikelambert]

Thanks for investigating and pushing for this @Fkawala, I see dhermes has added support for Any protobufs now.

But François I was curious how you accumulate your application logs? If you've already built that, I'd love to take a peek (if possible!), to save me the trouble of digging into the complexity of python loggers, handlers, exclusions, etc. Thanks!

[dhermes]

@mikelambert Have you seen the "getting started" doc for logging? https://googlecloudplatform.github.io/google-cloud-python/stable/logging-usage.html

[mikelambert]

Yup, it's quite helpful, but didn't quite answer the above for me. My confusion was more about python's logging system.

If I dig into google/cloud/logging/handlers/handlers.py for inspiration, and make a best-guess about how python's logging works (and ignore stuff like propagate and sub-loggers), then my test code would be something like this:

import logging
import google.cloud.logging

client = google.cloud.logging.Client()

class AggregatingHandler(logging.StreamHandler):
  def __init__(self):
    super(AggregatingHandler, self).__init__()
    self.logs = []
  def emit(self, record):
    self.logs.append(record)

def build_request_proto(logs):
  pass # ...

def aggregated_logging_middleware(app):
  def wsgi_app(environ, start_response):
    logger = logging.getLogger()
    handler = AggregatingHandler()
    logger.addHandler(handler)
    try:
      return app(environ, start_response)
    finally:
      cloud_logger = client.logger('aggregated_logs')
      cloud_logger.log_proto(build_request_proto(handler.logs))
      logger.removeHandler(handler)
  return wsgi_app    

I was just hoping to save the time of writing and testing this, if Francois had already done it, since it looks like he's trying to do the same thing I am. I'm already spending enough time reimplementing GAE Standard features, so I can migrate off the now-deprecated Managed VMs onto Flexible VMs, trying to leverage work where I can. :)

[dhermes]

Ah I see, maybe @waprin can give some pointers there.

[Fkawala]

Hi @mikelambert, for some reason I missed the notifications from this thread. Sorry. I doubt that you still need help on this topic, but just in case here is some information.

My current solution (which I wrote when the PB issue wasn't solved) does not rely on the log_proto method, but instead uses log_struct. The logName field is set to : projects/<project-name>/logs/<module-name> so that the log viewer puts my logs in a nicely usable way (section: Global, subsection ).

More precisely, I use logging.StreamHandler, logging.handlers.QueueListener (in case of multiprocessing) and google.cloud.logging.Batch. If you don't use multiprocessing the solution boils down to a subclass of logging.StreamHandler that processes log records to extract input parameters for the log_struct method. This logging.StreamHandler also do periodic commit of the google.cloud.logging.Batch that actually sends logs.

If you need it I might be able to share the source, but I'll I have to check with my company first, let me know.

[eyalev]

One of my motivations for working with log_proto is to be able to get multiple line elements per log entry, similar to that in GAE Standard.

@Fkawala by looking at your example I guess this was also your motivation. Have you succeeded with multiple line elements that are collapsible in the Cloud Console Logging UI (with log_struct)?

In any case I would love if could share your working source code. Thanks.

[Fkawala]

@eyalev I was digging into PB logging for the exact same reason :) From what I understood back then PB logging was the only way to achieve that. Note that the google cloud support team kindly suggested me not to spent to much time on that because it is hackish and the log viewer might change without notice.

Also, when I opened the issue I was quite short on time so I moved to struct_log and prefixed my logs with [host_uuid:process_uuid:task_uuid] that is a lame (but working) solution. It allows me to extract a sequence of related log lines quite effectively.

[eyalev]

Even if this solution will work for a few months I'm ok with it. If/when it will break I will update to a new solution or fallback to the current setup.

From my experience with GCP timelines I'm guessing I have at least a year :)

BTW, currently when using log_proto I get en error, but if I set the env var GOOGLE_CLOUD_DISABLE_GRPC to true it works. I have no idea why :)

[snarfed]

hi! i've hit this recently too, with google-cloud-logging 1.14.0 and googleapis-common-protos 1.6.0:

>>> from google.cloud.logging import Client
>>> c = Client()
>>> entries = c.list_entries(('brid-gy',), filter_='resource.type="gae_app" AND protoPayload.@type="type.googleapis.com/google.appengine.logging.v1.RequestLog"', order_by='timestamp desc')
>>> next(iter(entries)).to_api_repr()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File ".../google/cloud/logging/entries.py", line 357, in to_api_repr
    info["protoPayload"] = MessageToDict(self.payload)
  File ".../google/protobuf/json_format.py", line 168, in MessageToDict
    return printer._MessageToJsonObject(message)
  File ".../google/protobuf/json_format.py", line 202, in _MessageToJsonObject
    return methodcaller(_WKTJSONMETHODS[full_name][0], message)(self)
  File ".../google/protobuf/json_format.py", line 314, in _AnyMessageToJsonObject
    sub_message = _CreateMessageFromTypeUrl(type_url, self.descriptor_pool)
  File ".../google/protobuf/json_format.py", line 389, in _CreateMessageFromTypeUrl
    'Can not find message descriptor by type_url: {0}.'.format(type_url))
TypeError: Can not find message descriptor by type_url: type.googleapis.com/google.appengine.logging.v1.RequestLog.

we've been discussing this on the google-appengine group and StackOverflow. i've tried to follow the discussions here and in #2674, but i can't tell what the conclusion is. anyone know how i can fix this?

[snarfed]

i ended up generating my own request_log_pb2.py file based on request_log.proto, and it parses google.appengine.logging.v1.RequestLog serialized protobufs great! details in https://stackoverflow.com/a/59414384/186123.

obviously not ideal, i'd rather use an official version of that file maintained by Google instead, but this is an ok workaround in the meantime.