958690 - [traceback] ValueError: 'Jan 10 08:46:54 web4.mktweb.services.phx1.mozilla.com CEF:0|Mozilla|marketplace ... google.protobuf.internal.type_checkers in CheckValue

Status: RESOLVED FIXED

(Marketplace Graveyard :: Payments/Refunds, defect, P1)

Description

[Christopher Van Wiemeersch [:cvan]]

ValueError: 'Jan 10 08:46:54 web4.mktweb.services.phx1.mozilla.com CEF:0|Mozilla|marketplace|0|RECEIPTSIGN|Receipt sign|5|cs1Label=requestClientApplication cs1=Mozilla/5.0 (Mobile; rv:18.1) Gecko/18.1 Firefox/18.1 requestMethod=POST request=/reviewers/receipt/issue/canada-podcast src=46.54.226.50 dhost=marketplace.firefox.com suser=Nino Vrane\xc5\xa1i\xc4\x8d cs2=461386 suid=5691904 cs2Label=Recei

Stacktrace (most recent call last):

  File "django/core/handlers/base.py", line 111, in get_response
    response = callback(request, *callback_args, **callback_kwargs)
  File "newrelic/hooks/framework_django.py", line 485, in wrapper
    return wrapped(*args, **kwargs)
  File "addons/decorators.py", line 34, in wrapper
    return f(request, addon, *args, **kw)
  File "amo/decorators.py", line 128, in wrapper
    response = func(*args, **kw)
  File "amo/decorators.py", line 51, in wrapper
    return f(request, *args, **kw)
  File "mkt/receipts/views.py", line 183, in issue
    receipt_cef.log(request, addon, 'sign', 'Receipt signing for %s' % flavour)
  File "lib/cef_loggers.py", line 80, in log
    environ, **kwargs)
  File "heka_cef/cef_plugin.py", line 84, in log_cef
    self.heka(type='cef', payload=msg, fields={'cef_meta': cef_meta})
  File "heka/client.py", line 263, in heka
    msg.payload = payload
  File "/data/mkt.prod/www/marketplace.firefox.com/current/venv/lib/python2.6/site-packages/google/protobuf/internal/python_message.py", line 454, in setter
    type_checker.CheckValue(new_value)
  File "/data/mkt.prod/www/marketplace.firefox.com/current/venv/lib/python2.6/site-packages/google/protobuf/internal/type_checkers.py", line 128, in CheckValue
    (proposed_value))

Comment 1

[Andy McKay]

This looks like an issue in heka, did we pass something heka didn't like in there?

Comment 2

[Rob Miller [:rmiller]]

Vic and I are looking at this. The problem seems to be that the cef library automatically converts all unicode to UTF8 encoded strings (see https://github.com/mozilla/cef/blob/master/cef.py#L211), but the protobuf library expects all strings to be 7-bit ASCII, and wants unicode otherwise (see http://code.google.com/p/protobuf/source/browse/trunk/python/google/protobuf/internal/type_checkers.py#113).

We *could* have the Heka client explicitly convert the string back to unicode, but it seems likely that we're doing a bunch of extra work in that case, converting from unicode to string and then back again. Digging deeper to see if there's a better solution.

Comment 3

[Rob Miller [:rmiller]]

I implemented a band-aid fix that resolves the issue by catching the ValueError and then forcibly converting the string to unicode before passing it in to the protobuf lib. This means we're ultimately converting the data from unicode to utf-8 string back to unicode and then again to utf-8. This could be resolved by adding a 'give me unicode' option to the CEF library so it won't do the unnecessary conversion before it gets to heka-py.

The temporary fix is in heka-py-cef 0.3.1, which has been pushed and tagged and uploaded to the zamboni pyrepo index and will soon be uploaded to pypi.

Comment 4

[Andy McKay]

Put 0.3.1 on -dev and couldn't reproduce the issue.

https://github.com/mozilla/zamboni/commit/ceee2cc96c14fcfdd969acc097a0591b4484ba1d

Thank Rob.