Could not retrieve correlation-id in Sanic app

[Sureya]

What am I trying to do?

When a JSON record is passed to API, add a column called _id which will be the correlation id from the json-logging module

What is the issue?

Even though the log record displays correlation-id when I try to access it as mentioned in the README with json_logging.get_correlation_id() it returns '-' instead of the id.

How to replicate the issue?

"""
Author: Sureya Sathiamoorthi
"""
# in-built
import logging
from sys import stdout

# 3rd party
import json_logging
from sanic import Sanic
from sanic_restful_api import Api, Resource


app = Sanic(__name__)
api = Api(app)

# JSON logging configuration
json_logging.ENABLE_JSON_LOGGING = True
json_logging.CREATE_CORRELATION_ID_IF_NOT_EXISTS = True
json_logging.init_sanic()
json_logging.init_request_instrument(app)
logger = logging.getLogger("extractor-app")
logger.setLevel(logging.INFO)
logger.addHandler(logging.StreamHandler(stdout))


class ParseData(Resource):
    async def post(self, request):
        input_record = request.json
        logger.info("Everything looks great, queuing record for ")
        input_record['_id'] = json_logging.get_correlation_id()
        logger.info("corelation parsed")
        return input_record, 200


api.add_resource(ParseData, '/review')

if __name__ == '__main__':
    app.run(host="0.0.0.0", port=9558, debug=True)

Log output

{"written_at": "2020-04-17T12:41:13.769Z", "written_ts": 1587127273769067000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "log", "logger": "extractor-app", "thread": "MainThread", "level": "INFO", "module": "extract", "line_no": 30, "msg": "Everything looks great, queuing record for ", "correlation_id": "b92b1640-80a8-11ea-956f-acde48001122"}
{"written_at": "2020-04-17T12:41:13.787Z", "written_ts": 1587127273787433000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "log", "logger": "extractor-app", "thread": "MainThread", "level": "INFO", "module": "extract", "line_no": 32, "msg": "corelation parsed", "correlation_id": "b92b1640-80a8-11ea-956f-acde48001122"}
{"written_at": "2020-04-17T12:41:13.788Z", "written_ts": 1587127273788014000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "request", "correlation_id": "b92b1640-80a8-11ea-956f-acde48001122", "remote_user": null, "request": "/review", "referer": "-", "x_forwarded_for": "-", "protocol": "-", "method": "POST", "remote_ip": "1", "request_size_b": -1, "remote_host": "1", "remote_port": "-", "request_received_at": "2020-04-17T12:41:13.768Z", "response_time_ms": 19, "response_status": 200, "response_size_b": "-", "response_content_type": "application/json", "response_sent_at": "2020-04-17T12:41:13.787Z"}
{"written_at": "2020-04-17T12:41:13.788Z", "written_ts": 1587127273788336000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "log", "logger": "sanic.access", "thread": "MainThread", "level": "INFO", "module": "server", "line_no": 465, "msg": "", "correlation_id": "b92b1640-80a8-11ea-956f-acde48001122"}
{"written_at": "2020-04-17T12:41:18.792Z", "written_ts": 1587127278792868000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "log", "logger": "sanic.root", "thread": "MainThread", "level": "DEBUG", "module": "server", "line_no": 250, "msg": "KeepAlive Timeout. Closing connection.", "correlation_id": "-"}
{"written_at": "2020-04-17T12:41:58.340Z", "written_ts": 1587127318340604000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "log", "logger": "extractor-app", "thread": "MainThread", "level": "INFO", "module": "extract", "line_no": 30, "msg": "Everything looks great, queuing record for ", "correlation_id": "d3bc29b8-80a8-11ea-867a-acde48001122"}
{"written_at": "2020-04-17T12:41:58.340Z", "written_ts": 1587127318340784000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "log", "logger": "extractor-app", "thread": "MainThread", "level": "INFO", "module": "extract", "line_no": 32, "msg": "corelation parsed", "correlation_id": "d3bc29b8-80a8-11ea-867a-acde48001122"}
{"written_at": "2020-04-17T12:41:58.341Z", "written_ts": 1587127318341005000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "request", "correlation_id": "d3bc29b8-80a8-11ea-867a-acde48001122", "remote_user": null, "request": "/review", "referer": "-", "x_forwarded_for": "-", "protocol": "-", "method": "POST", "remote_ip": "1", "request_size_b": -1, "remote_host": "1", "remote_port": "-", "request_received_at": "2020-04-17T12:41:58.339Z", "response_time_ms": 0, "response_status": 200, "response_size_b": "-", "response_content_type": "application/json", "response_sent_at": "2020-04-17T12:41:58.340Z"}
{"written_at": "2020-04-17T12:41:58.341Z", "written_ts": 1587127318341203000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "log", "logger": "sanic.access", "thread": "MainThread", "level": "INFO", "module": "server", "line_no": 465, "msg": "", "correlation_id": "d3bc29b8-80a8-11ea-867a-acde48001122"}
{"written_at": "2020-04-17T12:42:03.342Z", "written_ts": 1587127323342081000, "component_id": "-", "component_name": "-", "component_instance": 0, "type": "log", "logger": "sanic.root", "thread": "MainThread", "level": "DEBUG", "module": "server", "line_no": 250, "msg": "KeepAlive Timeout. Closing connection.", "correlation_id": "-"}

# Input 
{
   "company": "Starl Industry",
   "name": "Tony"
}

# Response
{
    "company": "Starl Industry",
    "name": "Tony",
    "_id": "-"
}

[bobbui]

will take a look

[Sureya]

@thangbn : hey , did you get a chance to take a look at it please ?

[bobbui]

fixed in 1.2.0