search

apache / apisix

The Cloud-Native API Gateway
https://apisix.apache.org/blog/
Apache License 2.0
14.3k stars 2.49k forks source link

bug: Log file flooded with multiple entries for the same problem #10414

Closed markokocic closed 10 months ago

markokocic commented 10 months ago

Current Behavior

I started APISIX 3.6 in standalone mode, and in the console, I noticed that many log entries are repeated 9 times. Log message is the same, the only difference is the number at the beginning of the log message.

Expected Behavior

I expect that every log entry is displayed only once.

Error Logs

example-apisix-1  | 2023/10/30 07:47:35 [warn] 29#29: *3 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 34#34: *6 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 35#35: *5 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 30#30: *4 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 33#33: *2 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 31#31: *7 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 28#28: *8 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 38#38: *9 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 32#32: *1 [lua] plugin.lua:202: load(): new plugins: {"tcp-logger":true,"request-validation":true,"rocketmq-logger":true,"ip-restriction":true,"authz-casdoor":true,"openwhisk":true,"referer-restriction":true,"serverless-post-function":true,"response-rewrite":true,"mocking":true,"cas-auth":true,"serverless-pre-function":true,"grpc-web":true,"loggly":true,"server-info":true,"example-plugin":true,"google-cloud-logging":true,"ext-plugin-post-resp":true,"proxy-mirror":true,"tencent-cloud-cls":true,"opa":true,"redirect":true,"kafka-proxy":true,"splunk-hec-logging":true,"limit-conn":true,"request-id":true,"cors":true,"workflow":true,"elasticsearch-logger":true,"wolf-rbac":true,"kafka-logger":true,"degraphql":true,"basic-auth":true,"sls-logger":true,"ua-restriction":true,"client-control":true,"authz-casbin":true,"consumer-restriction":true,"inspect":true,"echo":true,"key-auth":true,"ext-plugin-pre-req":true,"azure-functions":true,"skywalking-logger":true,"openfunction":true,"aws-lambda":true,"public-api":true,"traffic-split":true,"proxy-rewrite":true,"clickhouse-logger":true,"http-logger":true,"api-breaker":true,"openid-connect":true,"file-logger":true,"loki-logger":true,"proxy-cache":true,"syslog":true,"zipkin":true,"real-ip":true,"prometheus":true,"grpc-transcode":true,"ldap-auth":true,"limit-req":true,"hmac-auth":true,"ext-plugin-post-req":true,"chaitin-waf":true,"body-transformer":true,"ai":true,"csrf":true,"limit-count":true,"uri-blocker":true,"udp-logger":true,"gzip":true,"fault-injection":true,"authz-keycloak":true,"proxy-control":true,"jwt-auth":true,"forward-auth":true,"datadog":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 29#29: *3 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 28#28: *8 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 32#32: *1 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 33#33: *2 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 38#38: *9 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 34#34: *6 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 31#31: *7 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 35#35: *5 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*
example-apisix-1  | 2023/10/30 07:47:35 [warn] 30#30: *4 [lua] plugin.lua:252: load_stream(): new plugins: {"syslog":true,"limit-conn":true,"ip-restriction":true,"mqtt-proxy":true}, context: init_worker_by_lua*

Steps to Reproduce

  1. Run APISIX in a docker image (I used standalone from docker examples)
  2. Check console log

Environment

monkeyDluffy6017 commented 10 months ago

This is because APISIX has multiple workers, each worker will print a log image

monkeyDluffy6017 commented 10 months ago

I think this issue has been resolved. feel free to reopen it