No metrics reaching to zipkin from kong api

[ayan1207]

@james-callahan , We are using config.sample_ratio=0.2. Below is steps we have followed to created zipkin plugin.

ZIPKIN running in docker container.

 docker run -d -p 9411:9411 openzipkin/zipkin

ZIPKIN logs

ava.util.Map<java.lang.String, java.lang.String>)
2018-07-26 12:17:21.984  INFO 1 --- [           main] s.b.a.e.w.s.WebMvcEndpointHandlerMapping : Mapped "{[/actuator],methods=[GET],produces=[application/vnd.spring-boot.actuator.v2+json || application/json]}" onto protected java.util.Map<java.lang.String, java.util.Map<java.lang.String, org.springframework.boot.actuate.endpoint.web.Link>> org.springframework.boot.actuate.endpoint.web.servlet.WebMvcEndpointHandlerMapping.links(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2018-07-26 12:17:22.113  INFO 1 --- [           main] o.xnio                                   : XNIO version 3.3.8.Final
2018-07-26 12:17:22.138  INFO 1 --- [           main] o.x.nio                                  : XNIO NIO Implementation Version 3.3.8.Final
2018-07-26 12:17:22.264  INFO 1 --- [           main] o.s.b.w.e.u.UndertowServletWebServer     : Undertow started on port(s) 9411 (http) with context path ''
2018-07-26 12:17:22.270  INFO 1 --- [           main] z.s.ZipkinServer                         : Started ZipkinServer in 6.391 seconds (JVM running for 7.631)
2018-07-26 12:17:24.722  INFO 1 --- [  XNIO-1 task-1] i.u.servlet                              : Initializing Spring FrameworkServlet 'dispatcherServlet'
2018-07-26 12:17:24.722  INFO 1 --- [  XNIO-1 task-1] o.s.w.s.DispatcherServlet                : FrameworkServlet 'dispatcherServlet': initialization started
2018-07-26 12:17:24.745  INFO 1 --- [  XNIO-1 task-1] o.s.w.s.DispatcherServlet                : FrameworkServlet 'dispatcherServlet': initialization completed in 23 ms

Setup for kong- zipkin plugin we followed

creating API

/ # curl -i -X POST \
>    --url http://localhost:8001/apis/ \
>    --data 'uris=/Stub' \
>    --data 'name=example-api' \
>    --data 'upstream_url=http://backend-application-server:9999/Stub/Stub'
HTTP/1.1 201 Created
Date: Mon, 30 Jul 2018 08:09:41 GMT
Content-Type: application/json; charset=utf-8
Connection: keep-alive
Access-Control-Allow-Origin: *
Server: kong/0.14.0
Content-Length: 360

{"created_at":1532938181592,"strip_uri":true,"id":"93b6e693-ab1a-481a-bfc1-bd0206f26fbf","name":"example-api","http_if_terminated":false,"preserve_host":false,"upstream_url":"http:\/\/backend-application-server:9999\/Stub\/Stub","uris":["\/Stub"],"upstream_connect_timeout":60000,"upstream_send_timeout":60000,"upstream_read_timeout":60000,"retries":5,"https_only":false}

enable zipkin plugin for api

/ # curl -X POST http://localhost:8001/apis/example-api/plugins \
>     --data "name=zipkin"  \
>     --data "config.http_endpoint=http://zipkin-server:9411/api/v2/spans" \
>     --data "config.sample_ratio=0.2"
{"created_at":1532938213000,"config":{"sample_ratio":0.2,"http_endpoint":"http:\/\/zipkin-server:9411\/api\/v2\/spans"},"id":"444441f9-cc57-4728-af2f-ae85081951ce","name":"zipkin","api_id":"93b6e693-ab1a-481a-bfc1-bd0206f26fbf","enabled":true}

Please suggest what could be the main culprit here. Thanks in advance!!

Regards,

[james-callahan]

For the purposes of debugging, could you try with a sample_ratio of 1?

And could you share any kong logs you have?

[ayan1207]

Yes, I set sample_ratio to 1 but no luck.

[james-callahan]

Yes, I set sample_ratio to 1 but no luck.

What do your kong logs show? (both error and access logs)

[ayan1207]

cant see any content in logs in /usr/local/kong/logs/. we are running kong instance in kubernetes .

[ayan1207]

@james-callahan , We have installed one more kong instance in centos machine as we are unable to find kong kubernetes instance log and follow the same steps which i mentioned earlier. We found some error in error.log when kong is trying to export zipkin metrics.

2018/07/30 18:56:49 [debug] 19466#0: *4299 [lua] handler.lua:439: before(): rebuilding API router
2018/07/30 18:56:49 [debug] 19466#0: *4299 [lua] base_plugin.lua:24: access(): executing plugin "opentracing": access
2018/07/30 18:56:49 [debug] 19466#0: *4299 [lua] init.lua:411: balancer(): setting address (try 1): 10.141.127.240:9999
2018/07/30 18:56:49 [debug] 19466#0: *4299 [lua] base_plugin.lua:28: header_filter(): executing plugin "opentracing": header_filter
2018/07/30 18:56:49 [debug] 19466#0: *4299 [lua] base_plugin.lua:32: body_filter(): executing plugin "opentracing": body_filter
2018/07/30 18:56:49 [debug] 19466#0: *4299 [lua] base_plugin.lua:32: body_filter(): executing plugin "opentracing": body_filter
2018/07/30 18:56:49 [debug] 19466#0: *4299 [lua] base_plugin.lua:36: log(): executing plugin "opentracing": log
2018/07/30 18:56:49 [error] 19466#0: *4299 failed to run log_by_lua*: /usr/local/share/lua/5.1/opentracing/span.lua:65: invalid tag value
stack traceback:
        [C]: in function 'assert'
        /usr/local/share/lua/5.1/opentracing/span.lua:65: in function 'set_tag'
        .../local/share/lua/5.1/kong/plugins/zipkin/opentracing.lua:215: in function 'log'
        /usr/local/share/lua/5.1/kong/plugins/zipkin/handler.lua:34: in function 'log'
        /usr/local/share/lua/5.1/kong/init.lua:529: in function 'log'
        log_by_lua(nginx-kong.conf:124):2: in function <log_by_lua(nginx-kong.conf:124):1> while logging request, client: 10.140.224.38, server: kong, request: "POST /Stub HTTP/1.1", upstream: "http://10.xx.xx.xx:9999/Stub/Stub", host: "xx.xx.xx.xx:8000"
2018/07/30 18:56:51 [debug] 19467#0: *4317 [lua] cluster_events.lua:222: [cluster_events] polling events from: 1532956931.803 to: 1532957211.873

Please suggest what could be the issue.

[james-callahan]

we are unable to find kong kubernetes instance log

Do the error logs not end up in the pod's logs? Which kubernetes pod/deployment definition are you using? (though it appears we don't need to go down this route further, because:)

Please suggest what could be the issue.

Looks to be the same as Kong/kong#3654

[ayan1207]

@james-callahan , yes found the error log too in kubernetes pod .

2018/07/30 14:03:49 [error] 42#0: *475 failed to run log_by_lua*: /usr/local/share/lua/5.1/opentracing/span.lua:65: invalid tag value
stack traceback:
        [C]: in function 'assert'
10.32.0.1 - - [30/Jul/2018:14:03:49 +0000] "POST /Stub HTTP/1.1" 200 366 "-" "Apache-HttpClient/4.1.1 (java 1.5)"
        /usr/local/share/lua/5.1/opentracing/span.lua:65: in function 'set_tag'
        .../local/share/lua/5.1/kong/plugins/zipkin/opentracing.lua:215: in function 'log'
        /usr/local/share/lua/5.1/kong/plugins/zipkin/handler.lua:34: in function 'log'
        /usr/local/share/lua/5.1/kong/init.lua:529: in function 'log'
        log_by_lua(nginx-kong.conf:124):2: in function <log_by_lua(nginx-kong.conf:124):1> while logging request, client: 10.32.0.1, server: kong, request: "POST /Stub HTTP/1.1", upstream: "http://xx.xx.xx.xx:9999/Stub/Stub", host: "xx.xx.xx.xx:31332"