Skip to content

unable to capture grpc span for grpc smoke test app #277

Open
Open
unable to capture grpc span for grpc smoke test app#277
Labels
area:testsbugSomething isn't working
@samarth-gupta-traceable

Description

@samarth-gupta-traceable
samarth-gupta-traceable
opened on Feb 26, 2021

If we run GrpcSmokeTest with latest app docker image in OTEL repo
"ghcr.io/open-telemetry/java-test-containers:smoke-grpc-jdk$jdk-20210225.598590600" test fail.
They fail since expected spans are 2 but we are able to capture only 1 span.
Below are test logs:

Expected spans & once captured for current app test container image:
image: "ghcr.io/open-telemetry/java-test-containers:smoke-grpc-jdk$jdk-20210129.520311770"
spans:

09:33:28.534 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: 2021-02-26T04:03:28.547Z	INFO	loggingexporter/logging_exporter.go:313	TracesExporter	{"#spans": 2}
09:33:28.534 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: 2021-02-26T04:03:28.547Z	DEBUG	loggingexporter/logging_exporter.go:352	ResourceSpans #0
09:33:28.534 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: Resource labels:
09:33:28.534 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> os.description: STRING(Linux 4.19.121-linuxkit)
09:33:28.534 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> os.type: STRING(LINUX)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.command_line: STRING(/usr/lib/jvm/jdk-8u282-bellsoft-x86_64/jre:bin:java -javaagent:/opentelemetry-javaagent-all.jar -Dio.opentelemetry.javaagent.slf4j.simpleLogger.log.muzzleMatcher=true)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.executable.path: STRING(/usr/lib/jvm/jdk-8u282-bellsoft-x86_64/jre:bin:java)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.pid: INT(1)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.runtime.description: STRING(BellSoft OpenJDK 64-Bit Server VM 25.282-b08)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.runtime.name: STRING(OpenJDK Runtime Environment)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.runtime.version: STRING(1.8.0_282-b08)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> service.name: STRING(unknown_service:java)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> telemetry.auto.version: STRING(0.18.0-SNAPSHOT)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> telemetry.sdk.language: STRING(java)
09:33:28.535 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> telemetry.sdk.name: STRING(opentelemetry)
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> telemetry.sdk.version: STRING(0.17.0)
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: InstrumentationLibrarySpans #0
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: InstrumentationLibrary io.opentelemetry.javaagent.opentelemetry-annotations 0.18.0-SNAPSHOT
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: Span #0
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Trace ID       : fcd5a02658dbc10b76fe10d675a25aab
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Parent ID      : 62fad3024df1c7e2
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     ID             : da8a3c15a8fedf41
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Name           : TestService.withSpan
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Kind           : SPAN_KIND_INTERNAL
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Start time     : 2021-02-26 04:03:27.7053465 +0000 UTC
09:33:28.536 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     End time       : 2021-02-26 04:03:27.7054067 +0000 UTC
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Status code    : STATUS_CODE_UNSET
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Status message : 
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: Attributes:
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> thread.id: INT(18)
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> thread.name: STRING(grpc-default-worker-ELG-3-2)
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: ResourceSpans #1
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: Resource labels:
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> os.description: STRING(Linux 4.19.121-linuxkit)
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> os.type: STRING(LINUX)
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.command_line: STRING(/usr/lib/jvm/jdk-8u282-bellsoft-x86_64/jre:bin:java -javaagent:/opentelemetry-javaagent-all.jar -Dio.opentelemetry.javaagent.slf4j.simpleLogger.log.muzzleMatcher=true)
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.executable.path: STRING(/usr/lib/jvm/jdk-8u282-bellsoft-x86_64/jre:bin:java)
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.pid: INT(1)
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.runtime.description: STRING(BellSoft OpenJDK 64-Bit Server VM 25.282-b08)
09:33:28.537 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.runtime.name: STRING(OpenJDK Runtime Environment)
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> process.runtime.version: STRING(1.8.0_282-b08)
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> service.name: STRING(unknown_service:java)
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> telemetry.auto.version: STRING(0.18.0-SNAPSHOT)
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> telemetry.sdk.language: STRING(java)
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> telemetry.sdk.name: STRING(opentelemetry)
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> telemetry.sdk.version: STRING(0.17.0)
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: InstrumentationLibrarySpans #0
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: InstrumentationLibrary io.opentelemetry.javaagent.grpc 0.18.0-SNAPSHOT
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: Span #0
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Trace ID       : fcd5a02658dbc10b76fe10d675a25aab
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Parent ID      : 
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     ID             : 62fad3024df1c7e2
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Name           : opentelemetry.proto.collector.trace.v1.TraceService/Export
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Kind           : SPAN_KIND_SERVER
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Start time     : 2021-02-26 04:03:27.6423997 +0000 UTC
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     End time       : 2021-02-26 04:03:27.8173893 +0000 UTC
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Status code    : STATUS_CODE_UNSET
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:     Status message : 
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: Attributes:
09:33:28.538 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> rpc.system: STRING(grpc)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> thread.id: INT(18)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> thread.name: STRING(grpc-default-worker-ELG-3-2)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> net.peer.port: INT(63106)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> net.peer.ip: STRING(192.168.128.1)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> rpc.service: STRING(opentelemetry.proto.collector.trace.v1.TraceService)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> rpc.method: STRING(Export)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: Events:
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: SpanEvent #0
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> Name: message
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> Timestamp: 1614312207692882400
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> DroppedAttributesCount: 0
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:      -> Attributes:
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:          -> message.id: INT(1)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR:          -> message.type: STRING(RECEIVED)
09:33:28.539 [docker-java-stream-1033333351] INFO smoke.tests.collector - STDERR: 
09:33:29.024 [Test worker] DEBUG http-client - --> GET http://localhost:57107/get-requests
09:33:29.037 [Test worker] DEBUG http-client - <-- 200 OK http://localhost:57107/get-requests (13ms, 6250-byte body)

actual spans collected:
image: "ghcr.io/open-telemetry/java-test-containers:smoke-grpc-jdk$jdk-20210225.598590600"
spans:

10:12:49.184 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: 2021-02-26T04:42:49.188Z	INFO	loggingexporter/logging_exporter.go:313	TracesExporter	{"#spans": 1}
10:12:49.185 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: 2021-02-26T04:42:49.188Z	DEBUG	loggingexporter/logging_exporter.go:352	ResourceSpans #0
10:12:49.186 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: Resource labels:
10:12:49.187 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> container.id: STRING(13a39d28cba3f06088e87a19069b03485ee2868fe2e51268222fda28cad93bda)
10:12:49.187 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> os.description: STRING(Linux 4.19.121-linuxkit)
10:12:49.187 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> os.type: STRING(LINUX)
10:12:49.187 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> process.command_line: STRING(/usr/lib/jvm/jdk-8u282-bellsoft-x86_64/jre:bin:java -javaagent:/hypertrace-agent-all.jar -Dorg.hypertrace.agent.slf4j.simpleLogger.log.muzzleMatcher=true)
10:12:49.187 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> process.executable.path: STRING(/usr/lib/jvm/jdk-8u282-bellsoft-x86_64/jre:bin:java)
10:12:49.188 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> process.pid: INT(1)
10:12:49.188 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> process.runtime.description: STRING(BellSoft OpenJDK 64-Bit Server VM 25.282-b08)
10:12:49.188 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> process.runtime.name: STRING(OpenJDK Runtime Environment)
10:12:49.188 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> process.runtime.version: STRING(1.8.0_282-b08)
10:12:49.188 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> service.name: STRING(CIService)
10:12:49.188 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> telemetry.auto.version: STRING(0.10.4-SNAPSHOT)
10:12:49.188 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> telemetry.sdk.language: STRING(java)
10:12:49.188 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> telemetry.sdk.name: STRING(opentelemetry)
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> telemetry.sdk.version: STRING(0.15.0)
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: InstrumentationLibrarySpans #0
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: InstrumentationLibrary io.opentelemetry.javaagent.grpc 0.10.4-SNAPSHOT
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: Span #0
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     Trace ID       : 87e035a2e3d3d21ce8e2579151d9c92f
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     Parent ID      : 
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     ID             : 63fc6f3e9fd4b334
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     Name           : opentelemetry.proto.collector.trace.v1.TraceService/Export
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     Kind           : SPAN_KIND_SERVER
10:12:49.189 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     Start time     : 2021-02-26 04:42:48.3591115 +0000 UTC
10:12:49.190 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     End time       : 2021-02-26 04:42:48.5408777 +0000 UTC
10:12:49.190 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     Status code    : STATUS_CODE_UNSET
10:12:49.190 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:     Status message : 
10:12:49.190 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: Attributes:
10:12:49.190 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> rpc.system: STRING(grpc)
10:12:49.190 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> container.id: STRING(13a39d28cba3f06088e87a19069b03485ee2868fe2e51268222fda28cad93bda)
10:12:49.191 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> thread.id: INT(17)
10:12:49.191 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> thread.name: STRING(grpc-default-worker-ELG-3-2)
10:12:49.191 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> net.peer.port: INT(57296)
10:12:49.191 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> net.peer.ip: STRING(192.168.208.1)
10:12:49.191 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> rpc.service: STRING(opentelemetry.proto.collector.trace.v1.TraceService)
10:12:49.191 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> rpc.method: STRING(Export)
10:12:49.191 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> rpc.request.metadata.content-type: STRING(application/grpc)
10:12:49.191 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> rpc.request.metadata.user-agent: STRING(grpc-java-netty/1.34.1)
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> rpc.request.metadata.grpc-accept-encoding: STRING(gzip)
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> rpc.response.metadata.grpc-encoding: STRING(identity)
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> rpc.response.metadata.grpc-accept-encoding: STRING(gzip)
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: Events:
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR: SpanEvent #0
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> Name: message
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> Timestamp: 1614314568422489500
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> DroppedAttributesCount: 0
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:      -> Attributes:
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:          -> message.id: INT(1)
10:12:49.192 [docker-java-stream-2070049192] INFO  smoke.tests.collector - STDERR:          -> message.type: STRING(RECEIVED)

Steps to reproduce:

Replace getTargetImage version in GrpcSmokeTest file with the second one and run locally.

Metadata

Metadata

Assignees

No one assigned

    Labels

    area:testsbugSomething isn't working

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions