Kong/kong-plugin-zipkin

No metrics reaching to zipkin from kong api

ayan1207 opened this issue · 7 comments

@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,

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

And could you share any kong logs you have?

Yes, I set sample_ratio to 1 but no luck.

Yes, I set sample_ratio to 1 but no luck.

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

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

@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.

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

@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"