Consumer failed to collect logs #121

calvinxu · 2023-07-14T05:05:27Z

calvinxu
Jul 14, 2023

with audit-log webhook setting as below:

apiVersion: v1
clusters:
- cluster:
    server: http://xxxxx:8080/audit
  name: audit
contexts:
- context:
    cluster: audit
  name: main
current-context: main
kind: Config
preferences: {}

apiserver logs is normal, while from the kelemetry consumer pod log, it have the following error:

time="2023-07-14T05:00:40Z" level=error msg="cannot access cluster from object reference" error="cluster \"10.120.127.221\" is not available" mod=owner-linker object=10.120.127.221//pods/default/hello-6c64f775c6-hlmdn
time="2023-07-14T05:00:40Z" level=error msg="cannot access cluster from object reference" error="cluster \"10.120.127.221\" is not available" mod=owner-linker object=10.120.127.221//pods/default/hello-5ccd6d84d6-zldzw
time="2023-07-14T05:00:40Z" level=error msg="cannot access cluster from object reference" error="cluster \"10.120.127.221\" is not available" mod=owner-linker object=10.120.127.221//pods/default/hello-5ccd6d84d6-8dwk6
time="2023-07-14T05:00:41Z" level=error msg="cannot access cluster from object reference" error="cluster \"10.120.127.221\" is not available" mod=owner-linker object=10.120.127.221//pods/default/hello-5ccd6d84d6-qp7g4

any advice for the webhook setting or any other setting need to be adjusted to make it work?
from the Jaegure UI, there is no tracing data..

#NAME                                   READY   STATUS    RESTARTS   AGE
hello-6c64f775c6-56ghh                 1/1     Running   0          5m31s
hello-6c64f775c6-hlmdn                 1/1     Running   0          5m30s
hello-6c64f775c6-kwbvw                 1/1     Running   0          5m31s
hello-6c64f775c6-nx2gd                 1/1     Running   0          5m31s
hello-6c64f775c6-wb5kz                 1/1     Running   0          5m30s
kelemetry-collector-7459c48b85-psdk9   1/1     Running   0          3h6m
kelemetry-collector-7459c48b85-qzxrn   1/1     Running   0          3h6m
kelemetry-collector-7459c48b85-smm84   1/1     Running   0          3h6m
kelemetry-consumer-549d4b664b-nh7fd    1/1     Running   0          153m
kelemetry-consumer-549d4b664b-xbxtq    1/1     Running   0          153m
kelemetry-consumer-549d4b664b-zfglq    1/1     Running   0          153m
kelemetry-etcd-0                       1/1     Running   0          14h
kelemetry-etcd-1                       1/1     Running   0          14h
kelemetry-etcd-2                       1/1     Running   0          14h
kelemetry-frontend-d984d9fb9-7mb6j     2/2     Running   0          3h6m
kelemetry-frontend-d984d9fb9-p2w7h     2/2     Running   0          3h6m
kelemetry-frontend-d984d9fb9-qp4h4     2/2     Running   0          3h6m
kelemetry-informers-fb8ddb6b4-8wvsn    1/1     Running   0          3h6m
kelemetry-informers-fb8ddb6b4-drh8w    1/1     Running   0          3h6m
kelemetry-informers-fb8ddb6b4-l4cpk    1/1     Running   0          3h6m
kelemetry-storage-0                    1/1     Running   0          14h

# kubectl get svc
NAME                  TYPE           CLUSTER-IP       EXTERNAL-IP      PORT(S)                          AGE
kelemetry-collector   LoadBalancer   10.100.80.232    10.120.127.224   4317:31324/TCP                   80m
kelemetry-etcd        LoadBalancer   10.98.116.229    10.120.127.224   2379:31447/TCP,2380:32611/TCP    75m
kelemetry-query       LoadBalancer   10.110.123.5     10.120.127.224   16686:32328/TCP,8090:30873/TCP   86m
kelemetry-storage     ClusterIP      None             <none>           17271/TCP                        86m
kelemetry-webhook     LoadBalancer   10.108.9.80      10.120.127.224   8080:31597/TCP                   86m

#kubectl logs kelemetry-consumer-8599cb4cc5-cbfkf 
...
2023/07/14 07:21:02 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp 10.100.80.232:4317: connect: connection refused"
2023/07/14 07:21:02 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp 10.100.80.232:4317: connect: connection refused"
2023/07/14 07:21:02 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp 10.100.80.232:4317: connect: connection refused"
2023/07/14 07:21:17 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp 10.100.80.232:4317: connect: connection refused"
2023/07/14 07:21:27 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp 10.100.80.232:4317: connect: connection refused"
2023/07/14 07:21:27 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp 10.100.80.232:4317: connect: connection refused"
2023/07/14 07:21:27 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp 10.100.80.232:4317: connect: connection refused"
.....

there is no 4317 port is listening in the collector container, is that something wrong with the collector?

#kubectl exec -it kelemetry-collector-7cf7988fd5-pfvcb -- sh
/ # netstat -tulp
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 :::14268                :::*                    LISTEN      1/collector-linux
tcp        0      0 :::14269                :::*                    LISTEN      1/collector-linux
tcp        0      0 :::14250                :::*                    LISTEN      1/collector-linux

Answered by SOF3

Jul 19, 2023

fixed in #125

View full answer

calvinxu · 2023-07-14T08:59:36Z

calvinxu
Jul 14, 2023
Author

the default values.yaml uses jaeger-collector 1.42, which does not have 4317 listening, change to 1.47, issue "2023/07/14 07:21:02 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing: dial tcp 10.100.80.232:4317: connect: connection refused"" disppear.
However, there are

"2023/07/14 08:50:14 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:50:24 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:50:24 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:50:34 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:50:49 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:50:59 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:51:14 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:51:29 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:51:44 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:51:59 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:52:09 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:52:19 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:52:29 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:52:39 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:52:54 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:53:09 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:53:24 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:53:34 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"
2023/07/14 08:53:38 traces export: context deadline exceeded: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: tls: first record does not look like a TLS handshake"

in the "kelemetry-consumer" pod logs, in the Jaeger UI still not tracing data display.

0 replies

calvinxu · 2023-07-14T09:01:07Z

calvinxu
Jul 14, 2023
Author

And in the "kelemetry-collector" log

{"level":"info","ts":1689324582.5249555,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03\\xffaEQ<\\t\\xb8\\x97\\xe4]\\x80c\\xd7\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324614.0206738,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03^1\\x0f\\xf0j*X\\x17\\xb2\\xd9K!\\xef\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324619.0438497,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03\\xc5\\xd9\\xdd\\xda\\x13\\xbbA\\x9e\\x1cYS 9\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324641.776904,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03\\xf5%#\\xbf\\x17\\x8aϩ\\xe9.\\xf3}\\x85\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324664.026703,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03q\\x97\\xd6\\x19E0\\x04\\xabBK\\x94M\\xc8\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324739.0333607,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03\\xbaʀB#۷\\bˣ&f\\xbf\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324752.1091967,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03\\xac\\xf7\\xd8\\xfa\\xb7\\xa4\\xf3=_\\x05AH\\xb5\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324804.0385287,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03\\xb2\\xb9\\x051`]\\x049^a;\\xf7v\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324822.2767112,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03:\\xa0\\x9a2垯\\xe5\\xf7\\xf8Pܭ\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689324977.1356747,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"\\x16\\x03\\x01\\x01\\x1b\\x01\\x00\\x01\\x17\\x03\\x03\\xab\\xe6P\\x17 dV1\\x98\\x1d\\xc5fw\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689325014.603474,"caller":"[email protected]/server.go:932","msg":"[core][Server #6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: \"GET / HTTP/1.1\\r\\nHost: 10\""","system":"grpc","grpc_log":true}
{"level":"info","ts":1689325031.8503332,"c

0 replies

SOF3 · 2023-07-16T11:40:29Z

SOF3
Jul 16, 2023
Maintainer

Right, it appears that kelemetry-collector does not listen on port 4317. Not sure why it worked in my tests before; I will upgrade the chart in a few days after testing the new version.

3 replies

calvinxu Jul 17, 2023
Author

so I changed to use the collector 1.47, but from the log there is something wrong, any suggestion on this, is that related to the collector version?
{"level":"info","ts":1689324582.5249555,"caller":"[email protected]/server.go:932","msg":"[core][Server https://github.com//pull/6] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: http2Server.HandleStreams received bogus greeting from client: "\x16\x03\x01\x01\x1b\x01\x00\x01\x17\x03\x03\xffaEQ<\t\xb8\x97\xe4]\x80c\xd7""","system":"grpc","grpc_log":true}

calvinxu Jul 17, 2023
Author

some additional info: 1.42-1.45, does not listen on 4317; since 1.46 onwards it listens 4317

SOF3 Jul 19, 2023
Maintainer

Oh, turns out I forgot to pass the tracer-otel-insecure flag. Fixing this in #125.

SOF3 · 2023-07-17T02:14:58Z

SOF3
Jul 17, 2023
Maintainer

The quickstart also uses 1.42 here:

kelemetry/quickstart.docker-compose.yaml

Line 30 in a832d28

jaeger-collector:

but there is no problem collecting traces in the quickstart

1 reply

calvinxu Jul 17, 2023
Author

Yes, I managed to run quick-start normally and it worked, but when deployed into k8s clustser using helm charts, it did not work as expected

SOF3 · 2023-07-19T11:07:49Z

SOF3
Jul 19, 2023
Maintainer

fixed in #125

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Consumer failed to collect logs #121

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 5 comments 4 replies

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

Consumer failed to collect logs #121

calvinxu Jul 14, 2023

Replies: 5 comments · 4 replies

calvinxu Jul 14, 2023 Author

calvinxu Jul 14, 2023 Author

SOF3 Jul 16, 2023 Maintainer

calvinxu Jul 17, 2023 Author

calvinxu Jul 17, 2023 Author

SOF3 Jul 19, 2023 Maintainer

SOF3 Jul 17, 2023 Maintainer

calvinxu Jul 17, 2023 Author

SOF3 Jul 19, 2023 Maintainer

calvinxu
Jul 14, 2023

Replies: 5 comments 4 replies

calvinxu
Jul 14, 2023
Author

calvinxu
Jul 14, 2023
Author

SOF3
Jul 16, 2023
Maintainer

calvinxu Jul 17, 2023
Author

calvinxu Jul 17, 2023
Author

SOF3 Jul 19, 2023
Maintainer

SOF3
Jul 17, 2023
Maintainer

calvinxu Jul 17, 2023
Author

SOF3
Jul 19, 2023
Maintainer