Missing spans in case of multi library auto-instrumented project #832
Assignees
Labels
bug
Something isn't working
Comments
|
For the spans that you believe are missing:
|
|
@lzchen I made a mistake in description, I'm sorry. Missing spans
IMHO it looks like the instrumentation only generates spans for the library which was encountered as first. |
|
Hello @mat-rumian I am trying to reproduce your issue. I may have found something similar to what has happened to you. Can you please share the complete code of your application (if possible to you)? |
|
Hi @ocelotl |
Perfect, thanks! |
|
Ok, here it is: #852 This was a very tricky issue because the root cause was hidden in closures in the instrumentors. Please give it a try with these changes, @mat-rumian and also run this in all consoles before running any of the scripts that make up this example:
{
"data": [
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spans": [
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "ccacbd04ecaafd7a",
"flags": 1,
"operationName": "postgresql.account",
"references": [
{
"refType": "CHILD_OF",
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "f1c79533d108b518"
}
],
"startTime": 1592969641809192,
"duration": 5071,
"tags": [
{
"key": "component",
"type": "string",
"value": "postgresql"
},
{
"key": "db.type",
"type": "string",
"value": "sql"
},
{
"key": "db.instance",
"type": "string",
"value": "account"
},
{
"key": "db.statement",
"type": "string",
"value": "SELECT product, items_sold FROM account WHERE product = 'espresso'"
},
{
"key": "db.user",
"type": "string",
"value": "account"
},
{
"key": "net.peer.name",
"type": "string",
"value": "localhost"
},
{
"key": "net.peer.port",
"type": "int64",
"value": 5432
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "CLIENT"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p1",
"warnings": null
},
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "f1c79533d108b518",
"flags": 1,
"operationName": "pay_in",
"references": [
{
"refType": "CHILD_OF",
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "d362dff07011a56f"
}
],
"startTime": 1592969641766514,
"duration": 79572,
"tags": [
{
"key": "component",
"type": "string",
"value": "http"
},
{
"key": "http.method",
"type": "string",
"value": "POST"
},
{
"key": "http.server_name",
"type": "string",
"value": "127.0.0.1"
},
{
"key": "http.scheme",
"type": "string",
"value": "http"
},
{
"key": "host.port",
"type": "int64",
"value": 8084
},
{
"key": "http.host",
"type": "string",
"value": "localhost:8084"
},
{
"key": "http.target",
"type": "string",
"value": "/pay_in"
},
{
"key": "net.peer.ip",
"type": "string",
"value": "127.0.0.1"
},
{
"key": "net.peer.port",
"type": "int64",
"value": 35636
},
{
"key": "http.flavor",
"type": "string",
"value": "1.1"
},
{
"key": "http.route",
"type": "string",
"value": "/pay_in"
},
{
"key": "http.status_text",
"type": "string",
"value": "OK"
},
{
"key": "http.status_code",
"type": "int64",
"value": 200
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "SERVER"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p1",
"warnings": null
},
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "db60d891bf23662c",
"flags": 1,
"operationName": "postgresql.account",
"references": [
{
"refType": "CHILD_OF",
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "f1c79533d108b518"
}
],
"startTime": 1592969641786570,
"duration": 4131,
"tags": [
{
"key": "component",
"type": "string",
"value": "postgresql"
},
{
"key": "db.type",
"type": "string",
"value": "sql"
},
{
"key": "db.instance",
"type": "string",
"value": "account"
},
{
"key": "db.statement",
"type": "string",
"value": "SELECT product, price FROM account WHERE product = 'espresso'"
},
{
"key": "db.user",
"type": "string",
"value": "account"
},
{
"key": "net.peer.name",
"type": "string",
"value": "localhost"
},
{
"key": "net.peer.port",
"type": "int64",
"value": 5432
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "CLIENT"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p1",
"warnings": null
},
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "523b98d89568f29f",
"flags": 1,
"operationName": "postgresql.account",
"references": [
{
"refType": "CHILD_OF",
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "f1c79533d108b518"
}
],
"startTime": 1592969641833905,
"duration": 4260,
"tags": [
{
"key": "component",
"type": "string",
"value": "postgresql"
},
{
"key": "db.type",
"type": "string",
"value": "sql"
},
{
"key": "db.instance",
"type": "string",
"value": "account"
},
{
"key": "db.statement",
"type": "string",
"value": "UPDATE account SET items_sold = %s WHERE product = %s"
},
{
"key": "db.user",
"type": "string",
"value": "account"
},
{
"key": "net.peer.name",
"type": "string",
"value": "localhost"
},
{
"key": "net.peer.port",
"type": "int64",
"value": 5432
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "CLIENT"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p1",
"warnings": null
},
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "d362dff07011a56f",
"flags": 1,
"operationName": "/pay_in",
"references": [
{
"refType": "CHILD_OF",
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "c3eba4eae4a758b3"
}
],
"startTime": 1592969641758087,
"duration": 90405,
"tags": [
{
"key": "component",
"type": "string",
"value": "http"
},
{
"key": "http.method",
"type": "string",
"value": "POST"
},
{
"key": "http.url",
"type": "string",
"value": "http://localhost:8084/pay_in"
},
{
"key": "http.status_code",
"type": "int64",
"value": 200
},
{
"key": "http.status_text",
"type": "string",
"value": "OK"
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "CLIENT"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p2",
"warnings": null
},
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "c3eba4eae4a758b3",
"flags": 1,
"operationName": "do_espresso",
"references": [
{
"refType": "CHILD_OF",
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "7d361a6ee4495aea"
}
],
"startTime": 1592969640229366,
"duration": 1620113,
"tags": [
{
"key": "component",
"type": "string",
"value": "http"
},
{
"key": "http.method",
"type": "string",
"value": "POST"
},
{
"key": "http.server_name",
"type": "string",
"value": "127.0.0.1"
},
{
"key": "http.scheme",
"type": "string",
"value": "http"
},
{
"key": "host.port",
"type": "int64",
"value": 8082
},
{
"key": "http.host",
"type": "string",
"value": "localhost:8082"
},
{
"key": "http.target",
"type": "string",
"value": "/do_espresso"
},
{
"key": "net.peer.ip",
"type": "string",
"value": "127.0.0.1"
},
{
"key": "net.peer.port",
"type": "int64",
"value": 38692
},
{
"key": "http.flavor",
"type": "string",
"value": "1.1"
},
{
"key": "http.route",
"type": "string",
"value": "/do_espresso"
},
{
"key": "http.status_text",
"type": "string",
"value": "OK"
},
{
"key": "http.status_code",
"type": "int64",
"value": 200
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "SERVER"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p2",
"warnings": null
},
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "bf7c4dbac9943752",
"flags": 1,
"operationName": "/espresso",
"references": [
{
"refType": "CHILD_OF",
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "c3eba4eae4a758b3"
}
],
"startTime": 1592969640233035,
"duration": 1523076,
"tags": [
{
"key": "component",
"type": "string",
"value": "http"
},
{
"key": "http.method",
"type": "string",
"value": "POST"
},
{
"key": "http.url",
"type": "string",
"value": "http://localhost:8083/espresso"
},
{
"key": "http.status_code",
"type": "int64",
"value": 200
},
{
"key": "http.status_text",
"type": "string",
"value": "OK"
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "CLIENT"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p2",
"warnings": null
},
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "9eae5de3dc2b143d",
"flags": 1,
"operationName": "espresso",
"references": [
{
"refType": "CHILD_OF",
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "bf7c4dbac9943752"
}
],
"startTime": 1592969640241888,
"duration": 1510074,
"tags": [
{
"key": "component",
"type": "string",
"value": "http"
},
{
"key": "http.method",
"type": "string",
"value": "POST"
},
{
"key": "http.server_name",
"type": "string",
"value": "127.0.0.1"
},
{
"key": "http.scheme",
"type": "string",
"value": "http"
},
{
"key": "host.port",
"type": "int64",
"value": 8083
},
{
"key": "http.host",
"type": "string",
"value": "localhost:8083"
},
{
"key": "http.target",
"type": "string",
"value": "/espresso"
},
{
"key": "net.peer.ip",
"type": "string",
"value": "127.0.0.1"
},
{
"key": "net.peer.port",
"type": "int64",
"value": 59618
},
{
"key": "http.flavor",
"type": "string",
"value": "1.1"
},
{
"key": "http.route",
"type": "string",
"value": "/espresso"
},
{
"key": "http.status_text",
"type": "string",
"value": "OK"
},
{
"key": "http.status_code",
"type": "int64",
"value": 200
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "SERVER"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p3",
"warnings": null
},
{
"traceID": "771d70ff86fe03a66d7d97c221836cdf",
"spanID": "7d361a6ee4495aea",
"flags": 1,
"operationName": "/do_espresso",
"references": [],
"startTime": 1592969640220800,
"duration": 1630845,
"tags": [
{
"key": "component",
"type": "string",
"value": "http"
},
{
"key": "http.method",
"type": "string",
"value": "POST"
},
{
"key": "http.url",
"type": "string",
"value": "http://localhost:8082/do_espresso"
},
{
"key": "http.status_code",
"type": "int64",
"value": 200
},
{
"key": "http.status_text",
"type": "string",
"value": "OK"
},
{
"key": "status.code",
"type": "int64",
"value": 0
},
{
"key": "status.message",
"type": "string",
"value": ""
},
{
"key": "span.kind",
"type": "string",
"value": "CLIENT"
},
{
"key": "internal.span.format",
"type": "string",
"value": "proto"
}
],
"logs": [],
"processID": "p4",
"warnings": null
}
],
"processes": {
"p1": {
"serviceName": "the-cashdesk",
"tags": []
},
"p2": {
"serviceName": "the-coffee-bar",
"tags": []
},
"p3": {
"serviceName": "the-coffee-machine",
"tags": []
},
"p4": {
"serviceName": "the-coffee-lover",
"tags": []
}
},
"warnings": null
}
],
"total": 0,
"limit": 0,
"offset": 0,
"errors": null
} |
|
@ocelotl thanks a lot for fixing! :) I will wait till new release to check if everything works fine :) |
toumorokoshi
added a commit
that referenced
this issue
Jul 8, 2020
Fixes #832. By having tracer creation occur on demand, late tracer provider configuration will be honored. This resolves issues with instrumentation occurring before tracer providers are set by the application developer, which would result in the no-op tracer used for the lifetime of the instrumentation. Co-authored-by: alrex <[email protected]> Co-authored-by: Leighton Chen <[email protected]> Co-authored-by: Yusuke Tsutsumi <[email protected]>
cnnradams
pushed a commit
to cnnradams/opentelemetry-python
that referenced
this issue
Jul 23, 2020
Fixes open-telemetry#832. By having tracer creation occur on demand, late tracer provider configuration will be honored. This resolves issues with instrumentation occurring before tracer providers are set by the application developer, which would result in the no-op tracer used for the lifetime of the instrumentation. Co-authored-by: alrex <[email protected]> Co-authored-by: Leighton Chen <[email protected]> Co-authored-by: Yusuke Tsutsumi <[email protected]>
srikanthccv
pushed a commit
to srikanthccv/opentelemetry-python
that referenced
this issue
Nov 1, 2020
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Environment
Application:
Collector
Jaeger All In One = 1.18Application design
Simple test application called
Italian Coffee Barclient- The Coffee Lover3 http_servers- The Coffee Bar, The Coffee Machine and The CashdeskThe Coffee Lover - client,
requestslib,manuallyinstrumented byopentelemetry.ext.requests.RequestsInstrumentor().instrument()The Coffee Bar - libs:
flask, requests, instrumented byopentelemetry-instrumentThe Coffee Machine - libs:
flask, instrumented byopentelemetry-instrumentThe Cashdesk - libs:
flask, psycopg2, instrumented byopentelemetry-instrumentSpans exported by:
Flow
coffee_loverbyrequests.postcalling for espresso tocoffee_barFlask server.coffee_barbyrequsts.postcalling for coffee preparation tocoffee_machineFlask servercoffee_barbyrequests.postcalling for payment process tocashdeskFlask servercashdeskbypsycopg2is connecting to PosgresDB and performing updateWhat is the actual behavior?
What is the expected behavior?
Few spans are missing:
coffee_barresponse tocoffee_loverclient - Flow point 1coffee_machineresponse tocoffee_bar- Flow point 2.cashdeskresponse tocoffee_bar- Flow point 3.cashdeskconnection and query to PostgresDB - Flow point 4.Additional context
Click to expand spans
{ "data": [ { "traceID": "8523d69752962fe2c4717dae292e10f0", "spans": [ { "traceID": "8523d69752962fe2c4717dae292e10f0", "spanID": "cbdddda6d3c3acdb", "flags": 1, "operationName": "/do_espresso", "references": [], "startTime": 1592338788433391, "duration": 670280, "tags": [ { "key": "component", "type": "string", "value": "http" }, { "key": "http.method", "type": "string", "value": "POST" }, { "key": "http.url", "type": "string", "value": "http://the-coffee-bar:8082/do_espresso" }, { "key": "http.status_code", "type": "int64", "value": 200 }, { "key": "http.status_text", "type": "string", "value": "OK" }, { "key": "status.code", "type": "int64", "value": 0 }, { "key": "status.message", "type": "string", "value": "" }, { "key": "span.kind", "type": "string", "value": "CLIENT" }, { "key": "internal.span.format", "type": "string", "value": "proto" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "8523d69752962fe2c4717dae292e10f0", "spanID": "728b24849677fcdc", "flags": 1, "operationName": "espresso", "references": [ { "refType": "CHILD_OF", "traceID": "8523d69752962fe2c4717dae292e10f0", "spanID": "bf42c2b0caffd314" } ], "startTime": 1592338788440244, "duration": 634381, "tags": [ { "key": "component", "type": "string", "value": "http" }, { "key": "http.method", "type": "string", "value": "POST" }, { "key": "http.server_name", "type": "string", "value": "172.27.0.2" }, { "key": "http.scheme", "type": "string", "value": "http" }, { "key": "host.port", "type": "int64", "value": 8083 }, { "key": "http.host", "type": "string", "value": "the-coffee-machine:8083" }, { "key": "http.target", "type": "string", "value": "/espresso" }, { "key": "net.peer.ip", "type": "string", "value": "172.27.0.6" }, { "key": "net.peer.port", "type": "int64", "value": 52242 }, { "key": "http.flavor", "type": "string", "value": "1.1" }, { "key": "http.route", "type": "string", "value": "/espresso" }, { "key": "http.status_text", "type": "string", "value": "OK" }, { "key": "http.status_code", "type": "int64", "value": 200 }, { "key": "status.code", "type": "int64", "value": 0 }, { "key": "status.message", "type": "string", "value": "" }, { "key": "span.kind", "type": "string", "value": "SERVER" }, { "key": "internal.span.format", "type": "string", "value": "proto" } ], "logs": [], "processID": "p2", "warnings": null }, { "traceID": "8523d69752962fe2c4717dae292e10f0", "spanID": "9f320d4130e1cf77", "flags": 1, "operationName": "pay_in", "references": [ { "refType": "CHILD_OF", "traceID": "8523d69752962fe2c4717dae292e10f0", "spanID": "bf42c2b0caffd314" } ], "startTime": 1592338789080193, "duration": 18823, "tags": [ { "key": "component", "type": "string", "value": "http" }, { "key": "http.method", "type": "string", "value": "POST" }, { "key": "http.server_name", "type": "string", "value": "172.27.0.3" }, { "key": "http.scheme", "type": "string", "value": "http" }, { "key": "host.port", "type": "int64", "value": 8084 }, { "key": "http.host", "type": "string", "value": "the-cashdesk:8084" }, { "key": "http.target", "type": "string", "value": "/pay_in" }, { "key": "net.peer.ip", "type": "string", "value": "172.27.0.6" }, { "key": "net.peer.port", "type": "int64", "value": 46638 }, { "key": "http.flavor", "type": "string", "value": "1.1" }, { "key": "http.route", "type": "string", "value": "/pay_in" }, { "key": "http.status_text", "type": "string", "value": "OK" }, { "key": "http.status_code", "type": "int64", "value": 200 }, { "key": "status.code", "type": "int64", "value": 0 }, { "key": "status.message", "type": "string", "value": "" }, { "key": "span.kind", "type": "string", "value": "SERVER" }, { "key": "internal.span.format", "type": "string", "value": "proto" } ], "logs": [], "processID": "p3", "warnings": null }, { "traceID": "8523d69752962fe2c4717dae292e10f0", "spanID": "bf42c2b0caffd314", "flags": 1, "operationName": "do_espresso", "references": [ { "refType": "CHILD_OF", "traceID": "8523d69752962fe2c4717dae292e10f0", "spanID": "cbdddda6d3c3acdb" } ], "startTime": 1592338788436629, "duration": 664572, "tags": [ { "key": "component", "type": "string", "value": "http" }, { "key": "http.method", "type": "string", "value": "POST" }, { "key": "http.server_name", "type": "string", "value": "172.27.0.6" }, { "key": "http.scheme", "type": "string", "value": "http" }, { "key": "host.port", "type": "int64", "value": 8082 }, { "key": "http.host", "type": "string", "value": "the-coffee-bar:8082" }, { "key": "http.target", "type": "string", "value": "/do_espresso" }, { "key": "net.peer.ip", "type": "string", "value": "172.27.0.5" }, { "key": "net.peer.port", "type": "int64", "value": 36390 }, { "key": "http.flavor", "type": "string", "value": "1.1" }, { "key": "http.route", "type": "string", "value": "/do_espresso" }, { "key": "http.status_text", "type": "string", "value": "OK" }, { "key": "http.status_code", "type": "int64", "value": 200 }, { "key": "status.code", "type": "int64", "value": 0 }, { "key": "status.message", "type": "string", "value": "" }, { "key": "span.kind", "type": "string", "value": "SERVER" }, { "key": "internal.span.format", "type": "string", "value": "proto" } ], "logs": [], "processID": "p4", "warnings": null } ], "processes": { "p1": { "serviceName": "the-coffee-lover", "tags": [] }, "p2": { "serviceName": "the-coffee-machine", "tags": [] }, "p3": { "serviceName": "the-cashdesk", "tags": [] }, "p4": { "serviceName": "the-coffee-bar", "tags": [] } }, "warnings": null } ], "total": 0, "limit": 0, "offset": 0, "errors": null }The text was updated successfully, but these errors were encountered: