JsonLogFormatter unexpectedly squelches message(s) from Django?

[groovecoder]

See https://github.com/mozilla/fx-private-relay/pull/82/files#r395097199 ... not sure why this code:

https://github.com/mozilla-services/python-dockerflow/blob/6cc06627fa69e653f1fc321d43df4c29f98f7e52/src/dockerflow/logging.py#L122-L123

is skipping log records where messages are already json-like? This means code like the following:

     logger.info({
         'event_type': 'email_relay',
         'relay_address_id': relay_address.id,
         'relay_address': sha256(local_portion.encode('utf-8')).hexdigest(),
         'real_address': sha256(
             relay_address.user.email.encode('utf-8')
         ).hexdigest(),
     })

Omits the dictionary from the output. So this outputs:

{"Timestamp": 1584647678788551936, "Type": "events", "Logger": "fx-private-relay", "Hostname": "groovetop", "EnvVersion": "2.0", "Severity": 6, "Pid": 4031, "Fields": {}}

?

Which makes no sense to me. Is there a different way I should be logging JSON-like objects via dockerflow.

[diox]

I don't know either: it has always been like this, ever since the first version of https://github.com/mozilla/mozilla-cloud-services-logger which this logger is imported from. I implemented is_value_jsonlike() to give a possibility to consumers to cheat and use their own logger inheriting from the one the lib provides if they want to log json data directly.

[groovecoder]

Can we tell if/which other projects or sites use this library? It doesn't make sense to me to squelch the msg value like this. But I don't want to break some other site.

[diox]

https://github.com/mozilla-services/python-dockerflow/network/dependents should be pretty accurate. I don't know which of those use the logger, though.

[jwhitlock]

@groovecoder, it looks like you were able to fix this issue: https://github.com/mozilla/fx-private-relay/pull/82#discussion_r395740768

Okay, learned I can pass extra={} in the logger.info call to make the dictionary values show up in Fields ... {"Timestamp": 1584720542840398080, "Type": "events", "Logger": "fx-private-relay", "Hostname": "groovetop", "EnvVersion": "2.0", "Severity": 6, "Pid": 9438, "Fields": {"relay_address_id": 18, "relay_address": "cf80cd8aed482d5d1527d7dc72fceff84e6326592848447d2dc0b0e87dfc9a90", "real_address": "f46fbc15047cae1e3b8f098d125372f713e99d974f57d7c0e7d8a1de691c1733", "msg": "email_relay"}}

Is this issue and the PR still relevant? Does the docker flow documentation need your solution?

[groovecoder]

May not need the PR. But it would be nice if the docs made it clear(er) to pass JSON into extra= ?

[jwhitlock]

I've opened issue #45 to track documenting the "right way" to do this, which I think is the extra parameter.

[leplatrem]

I propose to close this and #41 in favor of #45 then... Re-open if I'm wrong