1340674 - Update Sync to use the latest mozlog format for application logs.

Status: RESOLVED INACTIVE

(Cloud Services Graveyard :: Server: Sync, defect)

Description

[Bob Micheletto [:bobm]]

Sync application logs are not in the latest mozlog format.  This format is required for Logging 2.0.

Comment 1

[Bob Micheletto [:bobm]]

Attachment: The mozlog schema definition.

Comment 2

[Bob Micheletto [:bobm]]

(In reply to Bob Micheletto [:bobm] from comment #1)
Note that the time stamp field should be in nanoseconds from the epoch.

Comment 3

[Bob Micheletto [:bobm]]

Example of the present logging format: 

{
    "agent": "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX",
    "code": XXX,
    "device_id": "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX",
    "fxa_uid": "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX",
    "hostname": "XXXXXXXXXXXX",
    "method": "POST",
    "name": "mozsvc.metrics",
    "op": "mozsvc.metrics",
    "path": "https://sync-XXX-XX-XXXX-X.sync.services.mozilla.com/1.5/XXXXXXXX/storage/tabs",
    "pid": XXXX,
    "remoteAddressChain": [
        "A.B.C.D",
        "W.X.Y.Z"
    ],
    "request_time": X.XXXXXXXXXXXXXXXXX,
    "time": "XXXX-XX-XXTXX:XX:XX.XXXXXXZ",
    "v": 1
}

Comment 4

[Ryan Kelly [:rfkelly]]

:mostlygeek, is this something we might be able to wrangle the Python devs on you team to help out with?

Comment 5

[Rémy Hubscher (:natim)]

We have something here that we could probably reuse https://github.com/Kinto/kinto/blob/master/kinto/core/logs.py#L67-L125

There is also this lib that can be useful: https://pypi.python.org/pypi/mozlog

Comment 6

[Mathieu Leplatre [:leplatrem]]

I suggest that we contribute a new formater to mozsvc so that projects like Sync or Shavar could leverage it with just a lib upgrade and a configuration change:
E.g. https://github.com/mozilla-services/shavar/blob/master/shavar.ini#L52

Let's figure out if it's feasible with the logging context data that we currently receive...

Comment 7

[Benson Wong [:mostlygeek]]

A while back :lorchard wrote a python mozlog formatter[1] for TestPilot.

:lorchard 
Did you ever spin the formatter out into a PyPi module? 

[1] https://github.com/mozilla/testpilot/blob/2016-03-16/testpilot/base/logging.py

Comment 8

[Benson Wong [:mostlygeek]]

We should also include Tokenserver in the list of servers that should log in mozlog.

Comment 9

[Les Orchard [:lorchard]]

I did, though it's pretty much abandonware now that we don't have a Django server on Test Pilot any more:

https://pypi.python.org/pypi/mozilla-cloud-services-logger/

Comment 10

[Mathieu Leplatre [:leplatrem]]

Oh cool thanks!

Then I guess there is no development needed for switching Sync, Shavar and Tokenserver.

Just install that package and plug the provided formatter in the application settings:

- https://github.com/mozilla-services/server-syncstorage/blob/1071431e723d149a2d7c222719593fa38fe5b5b4/example.ini#L38
- https://github.com/mozilla-services/tokenserver/blob/v1.2.15/etc/production.ini#L95
- https://github.com/mozilla-services/shavar/blob/0.9/shavar.ini#L52

Comment 11

[Benson Wong [:mostlygeek]]

(In reply to Mathieu Leplatre (:leplatrem) from comment #10)
> Oh cool thanks!
> 
> Then I guess there is no development needed for switching Sync, Shavar and
> Tokenserver.
> 

I suppose the question is if sync, shavar and tokenserver sends the Fields to the actual logger. mozlog expects specific data[1] when type is request.summary. 

[1]https://wiki.mozilla.org/Firefox/Services/Logging#Application_Request_Summary_.28Type:.22request.summary.22.29

Comment 12

[Bob Micheletto [:bobm]]

(In reply to Mathieu Leplatre (:leplatrem) from comment #10)
> Oh cool thanks!
> 
> Then I guess there is no development needed for switching Sync, Shavar and
> Tokenserver.
> 
> Just install that package and plug the provided formatter in the application
> settings:

Running into some trace backs trying that.  I tried an equivalent of this: https://github.com/Micheletto/server-syncstorage/pull/1

Getting this:
Traceback (most recent call last):
  File "/data/server-syncstorage/bin/gunicorn", line 14, in <module>
    sys.exit(run())
  File "/media/ephemeral0/server-syncstorage/lib/python2.6/site-packages/gunicorn/app/wsgiapp.py", line 74, in run
    WSGIApplication("%(prog)s [OPTIONS] [APP_MODULE]").run()
  File "/media/ephemeral0/server-syncstorage/lib/python2.6/site-packages/gunicorn/app/base.py", line 189, in run
    super(Application, self).run()
  File "/media/ephemeral0/server-syncstorage/lib/python2.6/site-packages/gunicorn/app/base.py", line 72, in run
    Arbiter(self).run()
  File "/media/ephemeral0/server-syncstorage/lib/python2.6/site-packages/gunicorn/arbiter.py", line 58, in __init__
    self.setup(app)
  File "/media/ephemeral0/server-syncstorage/lib/python2.6/site-packages/gunicorn/arbiter.py", line 89, in setup
    self.log = self.cfg.logger_class(app.cfg)
  File "/media/ephemeral0/server-syncstorage/lib/python2.6/site-packages/gunicorn/glogging.py", line 176, in __init__
    self.setup(cfg)
  File "/media/ephemeral0/server-syncstorage/lib/python2.6/site-packages/gunicorn/glogging.py", line 207, in setup
    disable_existing_loggers=False)
  File "/usr/lib64/python2.6/logging/config.py", line 76, in fileConfig
    formatters = _create_formatters(cp)
  File "/usr/lib64/python2.6/logging/config.py", line 134, in _create_formatters
    f = c(fs, dfs)
  File "/usr/lib/python2.6/site-packages/mozilla_cloud_services_logger/formatters.py", line 42, in __init__
    super(JsonLogFormatter, self).__init__(format, datefmt)
TypeError: super() argument 1 must be type, not classobj

Comment 13

[Ryan Kelly [:rfkelly]]

> TypeError: super() argument 1 must be type, not classobj

Are we running python2.6 in production?  According to this similar bug report [1], the inheritance chain for logging.Formatter changed between python2.6 and python2.7, and you can't use super() for Formatter objects in python2.6.

If that's the problem, we'll either have to fix this in mozilla_cloud_services_logger, or update the servers to python2.7.

[1] https://github.com/rspivak/logsna/issues/2

Comment 14

[Bob Micheletto [:bobm]]

(In reply to Ryan Kelly [:rfkelly] from comment #13)
 
> If that's the problem, we'll either have to fix this in
> mozilla_cloud_services_logger, or update the servers to python2.7.

I suppose a third option would be to change the current formatter.

We are using Python 2.6 and will switch to Python 2.7 when we make a move from our present Linux distribution.  Any guess on what kind of effort would be involved in modifying this to work with Python 2.6?

Comment 15

[Ryan Kelly [:rfkelly]]

> Any guess on what kind of effort would be involved in modifying this to work with Python 2.6?

It's likely a fairly trivial change to the mozilla_cloud_services_logger package, just to use old-style parent method calling convention instead of super().