I'm trying to inject tracing context into log statements for a sample flask application using LoggingInstrumentor and FlaskInstrumentor.
from flask import Flask
import logging
from opentelemetry import trace
from opentelemetry.sdk.resources import Resource
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor, ConsoleSpanExporter
from opentelemetry.instrumentation.flask import FlaskInstrumentor
from opentelemetry.instrumentation.logging import LoggingInstrumentor
logger = logging.getLogger(__name__)
resource = Resource.create({"service.name": "basic_service"})
provider = TracerProvider(resource=resource)
processor = BatchSpanProcessor(ConsoleSpanExporter())
provider.add_span_processor(processor)
trace.set_tracer_provider(provider)
app = Flask(__name__)
FlaskInstrumentor().instrument_app(app)
LoggingInstrumentor().instrument(set_logging_format=True)
@app.route("/")
def hello_world():
logger.info('----test----')
return "<p>Hello, World!</p>"
app.run()
I'm using the following requirements.txt file and Python 3.8.5.
opentelemetry-api==1.9.1
opentelemetry-sdk==1.9.1
opentelemetry-instrumentation-flask==0.28b1
opentelemetry-instrumentation-logging==0.28b1
flask==2.0.2
I notice that some logs display the trace_id and span_id with correct values such as:
2022-02-09 15:49:11,554 INFO [__main__] [tutorial.py:27] [trace_id=8f2ad7d81da12aca044e4c070db75917 span_id=647f7b36e0d46cf8 resource.service.name=basic_service] - ----test----
Other logs don't have valid trace_id and span_id such as:
2022-02-09 15:49:11,557 INFO [werkzeug] [_internal.py:225] [trace_id=0 span_id=0 resource.service.name=basic_service] - 127.0.0.1 - - [09/Feb/2022 15:49:11] "GET / HTTP/1.1" 200 -
We can also see the following trace being sent to stdout. Notice the trace_id and span_id correspond to the first log statement where we see ----test---- in the message.
{
"name": "/",
"context": {
"trace_id": "0x8f2ad7d81da12aca044e4c070db75917",
"span_id": "0x647f7b36e0d46cf8",
"trace_state": "[]"
},
"kind": "SpanKind.SERVER",
"parent_id": null,
"start_time": "2022-02-09T20:49:11.548435Z",
"end_time": "2022-02-09T20:49:11.555767Z",
"status": {
"status_code": "UNSET"
},
"attributes": {
"http.method": "GET",
"http.server_name": "127.0.0.1",
"http.scheme": "http",
"net.host.port": 5000,
"http.host": "127.0.0.1:5000",
"http.target": "/",
"net.peer.ip": "127.0.0.1",
"http.user_agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/98.0.4758.82 Safari/537.36",
"net.peer.port": 51770,
"http.flavor": "1.1",
"http.route": "/",
"http.status_code": 200
},
"events": [],
"links": [],
"resource": {
"telemetry.sdk.language": "python",
"telemetry.sdk.name": "opentelemetry",
"telemetry.sdk.version": "1.9.1",
"service.name": "basic_service"
}
}
I would like to see correct values in my logs statements but can't seem to get it working correctly. Any help is appreciated.