Kong: [kong 2.1.0][DB-less] init_worker phase not ran for plugins configured from /config endpoint

[cciechao]

Summary

Open the prometheus plugin in DB-less mode to report an error

Steps To Reproduce
1.configure kong

 sed -i "/^#database/i\database = off" /etc/kong/kong.conf 

2.configure routes&services&plugins

cat > /tmp/kong.yml <<EOF
_format_version: "1.1"
services:
- name: service-httpbin
    url: http://localhost:8080
    routes:
  - name: v1
    paths:
    - /v1
plugins:
- name: prometheus
EOF

3.start kong

4.update declarative config file

curl -F  "config=@/tmp/kong.yml" localhost:8001/config

5.open a new terminal and send request

 curl http://127.0.0.1:8000/v1

6.after a while, view logs/error.log

Additional Details & Logs

1. Kong version 2.1.0
2. CentOS Linux release 7.6.1810 (Core)
3. Hardware 8Core16G

[cciechao]

ping @hbagdi

[hbagdi]

Can you share all the logs of Kong?
This has been previously seen and the root cause here is an error that happens during startup and results in plugins not being initialized correctly. Looking at logs, we can figure out why the initialization fails.

[cciechao]

sure

[root@localhost ~]# cat /usr/local/kong/logs/error.log 
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"

[root@localhost ~]# cat /usr/local/kong/logs/access.log 
{"time_local":"29/Jul/2020:07:40:19 +0800","remote_addr":"127.0.0.1","http_x_forwarded_for":"","remote_user":"","bytes_sent":248,"status":200,"vhost": "127.0.0.1","request":"GET /v1 HTTP/1.1","request_time":0.004,"request_length":80,"body_bytes_sent":2,"http_referer":"","http_user_agent":"curl/7.70.0","upstream_addr":"127.0.0.1:8080","upstream_status":"200","upstream_connect_time":"0.000","upstream_header_time":"0.003","upstream_response_time":"0.004"}

ping @hbagdi

[hbagdi]

Seems like your logs were reset. The necessary logs are truncated in the logs you have shared. Can you restart kong and then share the logs?

[cciechao]

Steps To Reproduce
1.restart kong

[root@localhost ~]# kong restart
Kong stopped
Kong started

2.update declarative config file

[root@localhost ~]# curl -F  "config=@/tmp/kong.yml" localhost:8001/config
{"services":{"02721903-3b5a-5c99-a76a-524639a48522":{"host":"localhost","id":"02721903-3b5a-5c99-a76a-524639a48522","protocol":"http","read_timeout":60000,"port":8080,"updated_at":1595981184,"created_at":1595981184,"connect_timeout":60000,"write_timeout":60000,"name":"service-httpbin","retries":5}},"routes":{"7f7e3420-3266-517c-a283-63430f203bbf":{"id":"7f7e3420-3266-517c-a283-63430f203bbf","path_handling":"v0","paths":["\/v1"],"protocols":["http","https"],"created_at":1595981184,"name":"v1","service":{"id":"02721903-3b5a-5c99-a76a-524639a48522"},"preserve_host":false,"regex_priority":0,"https_redirect_status_code":426,"updated_at":1595981184,"strip_path":true}},"plugins":{"86e6f637-64e2-5672-920c-32e17e76e0fe":{"created_at":1595981184,"id":"86e6f637-64e2-5672-920c-32e17e76e0fe","name":"prometheus","enabled":true,"config":{},"protocols":["grpc","grpcs","http","https"]}}}

3.open a new terminal and send request

curl http://127.0.0.1:8000/v1

Logs

[root@localhost ~]# cat /usr/local/kong/logs/access.log
{"time_local":"29/Jul/2020:07:40:19 +0800","remote_addr":"127.0.0.1","http_x_forwarded_for":"","remote_user":"","bytes_sent":248,"status":200,"vhost": "127.0.0.1","request":"GET /v1 HTTP/1.1","request_time":0.004,"request_length":80,"body_bytes_sent":2,"http_referer":"","http_user_agent":"curl/7.70.0","upstream_addr":"127.0.0.1:8080","upstream_status":"200","upstream_connect_time":"0.000","upstream_header_time":"0.003","upstream_response_time":"0.004"}
{"time_local":"29/Jul/2020:08:09:03 +0800","remote_addr":"127.0.0.1","http_x_forwarded_for":"","remote_user":"","bytes_sent":248,"status":200,"vhost": "127.0.0.1","request":"GET /v1 HTTP/1.1","request_time":0.005,"request_length":80,"body_bytes_sent":2,"http_referer":"","http_user_agent":"curl/7.70.0","upstream_addr":"127.0.0.1:8080","upstream_status":"200","upstream_connect_time":"0.001","upstream_header_time":"0.004","upstream_response_time":"0.004"}

[root@localhost ~]# cat /usr/local/kong/logs/error.log
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 07:40:19 [error] 18867#0: *4478 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:03:50 [notice] 18859#0: signal 15 (SIGTERM) received from 22001, exiting
2020/07/29 08:03:50 [notice] 18860#0: exiting
2020/07/29 08:03:50 [notice] 18861#0: exiting
2020/07/29 08:03:50 [notice] 18862#0: exiting
2020/07/29 08:03:50 [notice] 18866#0: exiting
2020/07/29 08:03:50 [notice] 18865#0: exiting
2020/07/29 08:03:50 [notice] 18867#0: exiting
2020/07/29 08:03:50 [notice] 18863#0: exiting
2020/07/29 08:03:50 [notice] 18864#0: exiting
2020/07/29 08:03:50 [notice] 18861#0: exit
2020/07/29 08:03:50 [notice] 18866#0: exit
2020/07/29 08:03:50 [notice] 18863#0: exit
2020/07/29 08:03:50 [notice] 18867#0: exit
2020/07/29 08:03:50 [notice] 18864#0: exit
2020/07/29 08:03:50 [notice] 18862#0: exit
2020/07/29 08:03:50 [notice] 18859#0: signal 17 (SIGCHLD) received from 18861
2020/07/29 08:03:50 [notice] 18859#0: worker process 18861 exited with code 0
2020/07/29 08:03:50 [notice] 18859#0: worker process 18867 exited with code 0
2020/07/29 08:03:50 [notice] 18859#0: signal 29 (SIGIO) received
2020/07/29 08:03:50 [notice] 18859#0: signal 17 (SIGCHLD) received from 18867
2020/07/29 08:03:50 [notice] 18859#0: signal 17 (SIGCHLD) received from 18866
2020/07/29 08:03:50 [notice] 18859#0: worker process 18862 exited with code 0
2020/07/29 08:03:50 [notice] 18859#0: worker process 18863 exited with code 0
2020/07/29 08:03:50 [notice] 18859#0: worker process 18864 exited with code 0
2020/07/29 08:03:50 [notice] 18859#0: worker process 18866 exited with code 0
2020/07/29 08:03:50 [notice] 18859#0: signal 29 (SIGIO) received
2020/07/29 08:03:50 [notice] 18865#0: exit
2020/07/29 08:03:50 [notice] 18860#0: exit
2020/07/29 08:03:50 [notice] 18859#0: signal 17 (SIGCHLD) received from 18865
2020/07/29 08:03:50 [notice] 18859#0: worker process 18865 exited with code 0
2020/07/29 08:03:50 [notice] 18859#0: signal 29 (SIGIO) received
2020/07/29 08:03:50 [notice] 18859#0: signal 17 (SIGCHLD) received from 18860
2020/07/29 08:03:50 [notice] 18859#0: worker process 18860 exited with code 0
2020/07/29 08:03:50 [notice] 18859#0: exit
2020/07/29 08:03:50 [warn] 22017#0: load balancing method redefined in /usr/local/kong/nginx-kong.conf:60
2020/07/29 08:03:50 [warn] 22024#0: load balancing method redefined in /usr/local/kong/nginx-kong.conf:60
2020/07/29 08:03:50 [notice] 22024#0: using the "epoll" event method
2020/07/29 08:03:50 [notice] 22024#0: openresty/1.15.8.3
2020/07/29 08:03:50 [notice] 22024#0: built by gcc 4.8.5 20150623 (Red Hat 4.8.5-39) (GCC) 
2020/07/29 08:03:50 [notice] 22024#0: OS: Linux 3.10.0-957.5.1.el7.x86_64
2020/07/29 08:03:50 [notice] 22024#0: getrlimit(RLIMIT_NOFILE): 1000000:1000000
2020/07/29 08:03:50 [notice] 22032#0: start worker processes
2020/07/29 08:03:50 [notice] 22032#0: start worker process 22033
2020/07/29 08:03:50 [notice] 22032#0: start worker process 22034
2020/07/29 08:03:50 [notice] 22032#0: start worker process 22035
2020/07/29 08:03:50 [notice] 22032#0: start worker process 22036
2020/07/29 08:03:50 [notice] 22032#0: start worker process 22037
2020/07/29 08:03:50 [notice] 22032#0: start worker process 22038
2020/07/29 08:03:50 [notice] 22032#0: start worker process 22039
2020/07/29 08:03:50 [notice] 22032#0: start worker process 22040
2020/07/29 08:03:50 [notice] 22037#0: *5 [lua] cache.lua:374: purge(): [DB cache] purging (local) cache, context: init_worker_by_lua*
2020/07/29 08:03:50 [notice] 22037#0: *5 [lua] cache.lua:374: purge(): [DB cache] purging (local) cache, context: init_worker_by_lua*
2020/07/29 08:03:50 [warn] 22036#0: *3 [lua] globalpatches.lua:55: sleep(): executing a blocking 'sleep' (0.001 seconds), context: init_worker_by_lua*
2020/07/29 08:03:50 [warn] 22034#0: *2 [lua] globalpatches.lua:55: sleep(): executing a blocking 'sleep' (0.001 seconds), context: init_worker_by_lua*
2020/07/29 08:05:29 [notice] 22039#0: *899 [lua] cache.lua:374: purge(): [DB cache] purging (local) cache, client: 127.0.0.1, server: kong_admin, request: "POST /config HTTP/1.1", host: "localhost:8001"
2020/07/29 08:05:29 [notice] 22039#0: *899 [lua] cache.lua:374: purge(): [DB cache] purging (local) cache, client: 127.0.0.1, server: kong_admin, request: "POST /config HTTP/1.1", host: "localhost:8001"
2020/07/29 08:06:24 [notice] 22037#0: *1406 [lua] cache.lua:374: purge(): [DB cache] purging (local) cache, client: 127.0.0.1, server: kong_admin, request: "POST /config HTTP/1.1", host: "localhost:8001"
2020/07/29 08:06:24 [notice] 22037#0: *1406 [lua] cache.lua:374: purge(): [DB cache] purging (local) cache, client: 127.0.0.1, server: kong_admin, request: "POST /config HTTP/1.1", host: "localhost:8001"
2020/07/29 08:08:52 [error] 22039#0: *2750 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:08:52 [error] 22039#0: *2750 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:08:52 [error] 22039#0: *2750 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:08:52 [error] 22039#0: *2750 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:08:52 [error] 22039#0: *2750 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:08:52 [error] 22039#0: *2750 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:09:03 [error] 22038#0: *2856 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:09:03 [error] 22038#0: *2856 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:09:03 [error] 22038#0: *2856 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:09:03 [error] 22038#0: *2856 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:09:03 [error] 22038#0: *2856 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"
2020/07/29 08:09:03 [error] 22038#0: *2856 [lua] prometheus.lua:671: log_error(): counter not initialied while logging request, client: 127.0.0.1, server: kong, request: "GET /v1 HTTP/1.1", upstream: "http://127.0.0.1:8080/", host: "127.0.0.1:8000"

ping @hbagdi

[hbagdi]

ping @fffonion

[fffonion]

@cciechao I didn't reproduce it locally, which distribution for 2.1.0 you are using? Is it source code, docker or binary package?

[cciechao]

Currently I have tried binary installation and docker running, both have the same error

[root@localhost ~]# kong version -vv
2020/07/29 13:18:22 [verbose] Kong: 2.1.0
2020/07/29 13:18:22 [debug] ngx_lua: 10015
2020/07/29 13:18:22 [debug] nginx: 1015008
2020/07/29 13:18:22 [debug] Lua: LuaJIT 2.1.0-beta3
2.1.0

@fffonion

[fffonion]

cool, could you share the docker environment variables, args passed to kong container and kong.conf if there's any?

[cciechao]

There is a binary installation machine, the adjusted configuration content is as follows

[root@localhost ~]# grep -vE '#|^$' /etc/kong/kong.conf
admin_listen = 0.0.0.0:8001 reuseport backlog=16384, 0.0.0.0:8444 http2 ssl reuseport backlog=16384
database = off

Today, I tried to reinstall kong again. After opening the prometheus plugin, a new error occurred.

[root@localhost ~]# cat /usr/local/kong/logs/error.log
2020/07/29 22:39:00 [error] 1252#0: *5684 lua coroutine: runtime error: ...cal/share/lua/5.1/kong/plugins/prometheus/prometheus.lua:620: attempt to index field '_counter' (a nil value)
stack traceback:
coroutine 0:
    ...cal/share/lua/5.1/kong/plugins/prometheus/prometheus.lua: in function 'metric_data'
    ...cal/share/lua/5.1/kong/plugins/prometheus/prometheus.lua:666: in function 'collect'
    ...local/share/lua/5.1/kong/plugins/prometheus/exporter.lua:239: in function 'collect'
    /usr/local/share/lua/5.1/kong/plugins/prometheus/api.lua:6: in function 'fn'
    /usr/local/share/lua/5.1/kong/api/api_helpers.lua:258: in function </usr/local/share/lua/5.1/kong/api/api_helpers.lua:241>
coroutine 1:
    [C]: in function 'resume'
    /usr/local/share/lua/5.1/lapis/application.lua:397: in function 'handler'
    /usr/local/share/lua/5.1/lapis/application.lua:130: in function 'resolve'
    /usr/local/share/lua/5.1/lapis/application.lua:167: in function </usr/local/share/lua/5.1/lapis/application.lua:165>
    [C]: in function 'xpcall'
    /usr/local/share/lua/5.1/lapis/application.lua:173: in function 'dispatch'
    /usr/local/share/lua/5.1/lapis/nginx.lua:230: in function 'serve'
    /usr/local/share/lua/5.1/kong/init.lua:1219: in function 'admin_content'
    content_by_lua(nginx-kong.conf:243):2: in main chunk, client: 127.0.0.1, server: kong_admin, request: "GET /metrics HTTP/1.1", host: "localhost:8001"
2020/07/29 22:39:00 [error] 1252#0: *5684 [lua] api_helpers.lua:429: handle_error(): /usr/local/share/lua/5.1/lapis/application.lua:401: ...cal/share/lua/5.1/kong/plugins/prometheus/prometheus.lua:620: attempt to index field '_counter' (a nil value)
stack traceback:
    ...cal/share/lua/5.1/kong/plugins/prometheus/prometheus.lua: in function 'metric_data'
    ...cal/share/lua/5.1/kong/plugins/prometheus/prometheus.lua:666: in function 'collect'
    ...local/share/lua/5.1/kong/plugins/prometheus/exporter.lua:239: in function 'collect'
    /usr/local/share/lua/5.1/kong/plugins/prometheus/api.lua:6: in function 'fn'
    /usr/local/share/lua/5.1/kong/api/api_helpers.lua:258: in function </usr/local/share/lua/5.1/kong/api/api_helpers.lua:241>

stack traceback:
    [C]: in function 'error'
    /usr/local/share/lua/5.1/lapis/application.lua:401: in function 'handler'
    /usr/local/share/lua/5.1/lapis/application.lua:130: in function 'resolve'
    /usr/local/share/lua/5.1/lapis/application.lua:167: in function </usr/local/share/lua/5.1/lapis/application.lua:165>
    [C]: in function 'xpcall'
    /usr/local/share/lua/5.1/lapis/application.lua:173: in function 'dispatch'
    /usr/local/share/lua/5.1/lapis/nginx.lua:230: in function 'serve'
    /usr/local/share/lua/5.1/kong/init.lua:1219: in function 'admin_content'
    content_by_lua(nginx-kong.conf:243):2: in main chunk, client: 127.0.0.1, server: kong_admin, request: "GET /metrics HTTP/1.1", host: "localhost:8001"

@fffonion

[fffonion]

Now it rings a bell to me, I think that's because the init_worker phases are not ran with config reload. @cciechao The temporary fix is to fed kong with an initial declarative config that includes the prometheus plugin.
You can add declarative_config=/tmp/kong.yml in kong.conf and use the /config endpoint as usual.

I will update the issue title.

[fffonion]

Maybe related to #6011, which seems not in 2.1.0.

[locao]

I ran some tests here and it seems that the init_worker phases are being run for plugins on config reload.

Is it possible that errors in creating new counters from lua-resty-counter are not being caught? The new function is not returning the expected nil, err [1] [2].

I was able to get those counter not initialied log entries by forcing errors in the new method in lua-resty-counter.

[fffonion]

@locao I can see one condition for this is to have more than one workers, since the init_worker phase looks like only runs on worker 0

$ docker run -it --rm -e KONG_DATABASE=off -e KONG_LOG_LEVEL=debug --name kong kong:2.1.0-alpine|grep timer
2020/08/10 17:32:57 [debug] 22#0: *1 [lua] counter.lua:70: new(): start timer for shdict kong on worker 0
2020/08/10 17:32:57 [debug] 23#0: *2 [lua] counter.lua:70: new(): start timer for shdict kong on worker 1
2020/08/10 17:32:57 [info] 22#0: *1 [kong] handler.lua:53 [acme] acme renew timer started on worker 0, context: init_worker_by_lua*
2020/08/10 17:32:57 [debug] 25#0: *3 [lua] counter.lua:70: new(): start timer for shdict kong on worker 3
2020/08/10 17:32:57 [debug] 22#0: *1 [lua] counter.lua:70: new(): start timer for shdict prometheus_metrics on worker 0
2020/08/10 17:32:57 [debug] 24#0: *4 [lua] counter.lua:70: new(): start timer for shdict kong on worker 2

note the log both from prometheus and acme plugin, only timer on worker 0 is started

Also 2.0.5 seems to be fine.

$ docker run -it --rm -e KONG_DATABASE=off -e KONG_LOG_LEVEL=debug --name kong kong:2.0.5-alpine|grep timer
2020/08/10 17:45:20 [debug] 22#0: *1 [lua] counter.lua:50: new(): start timer for shdict kong on worker 0
2020/08/10 17:45:20 [debug] 25#0: *2 [lua] counter.lua:50: new(): start timer for shdict kong on worker 3
2020/08/10 17:45:20 [info] 22#0: *1 [kong] handler.lua:53 [acme] acme renew timer started on worker 0, context: init_worker_by_lua*
2020/08/10 17:45:20 [debug] 22#0: *1 [lua] counter.lua:50: new(): start timer for shdict prometheus_metrics on worker 0
2020/08/10 17:45:20 [info] 25#0: *2 [kong] handler.lua:53 [acme] acme renew timer started on worker 3, context: init_worker_by_lua*
2020/08/10 17:45:20 [debug] 25#0: *2 [lua] counter.lua:50: new(): start timer for shdict prometheus_metrics on worker 3
2020/08/10 17:45:20 [debug] 23#0: *3 [lua] counter.lua:50: new(): start timer for shdict kong on worker 1
2020/08/10 17:45:20 [info] 23#0: *3 [kong] handler.lua:53 [acme] acme renew timer started on worker 1, context: init_worker_by_lua*
2020/08/10 17:45:20 [debug] 23#0: *3 [lua] counter.lua:50: new(): start timer for shdict prometheus_metrics on worker 1
2020/08/10 17:45:20 [debug] 24#0: *4 [lua] counter.lua:50: new(): start timer for shdict kong on worker 2
2020/08/10 17:45:20 [info] 24#0: *4 [kong] handler.lua:53 [acme] acme renew timer started on worker 2, context: init_worker_by_lua*
2020/08/10 17:45:20 [debug] 24#0: *4 [lua] counter.lua:50: new(): start timer for shdict prometheus_metrics on worker 2

[locao]

That was a great investigation, thanks @fffonion! It seems that the plugins_iterator was being wrongfully built, but it wasn't the same issue fixed by #6011. I opened a PR that should fix this.