moonming opened a new issue, #14204:
URL: https://github.com/apache/apisix/issues/14204
### Current Behavior
When the Lua timers running in a worker reach `lua_max_running_timers`
(`nginx_config.max_running_timers`, 4096 by default), lua-nginx-module does not
run a timer that expires; it never calls the timer's function, not even with
`premature = true`, and only logs an alert:
```
[alert] ... lua failed to run timer with function defined at
@/usr/local/apisix/apisix/utils/batch-processor.lua:90: 4096
lua_max_running_timers are not enough
```
This is the `lmcf->running_timers >= lmcf->max_running_timers` branch of
`ngx_http_lua_timer_handler` in `src/ngx_http_lua_timer.c` of
openresty/lua-nginx-module, which jumps to `failed:`. The same label is used
when the timer cannot get a fake connection or request, e.g. when the worker
has no free connection.
The batch processor runs every batch in a timer of its own
(`schedule_func_exec` → `execute_func` in `apisix/utils/batch-processor.lua`),
and a batch is added to `processed_entries` only inside `execute_func`. A batch
whose timer is not run is therefore neither sent nor counted. Since #13826
(3.18.0) the manager limits the backlog to `max_pending_entries` (8192 by
default) and computes it as `total_pushed_entries` minus the processed counts,
so every entry of such a batch stays pending for the rest of the worker's life.
Once enough of them have accumulated, the logger discards every new entry in
that worker, and it does not recover when the log server or the timer pressure
goes away; only a reload or restart does.
The running timers can be used up by a different logger. A logger whose
endpoint hangs instead of refusing keeps each batch's timer running for the
whole send timeout. With `batch_max_size = 1` and http-logger's default 3 s
timeout, about 1,400 requests per second per worker keep 4096 timers running.
From then on the batch timers of every other logger in that worker are dropped
as well, although their own endpoints are healthy.
The buffer timer is exposed in the same way: if a `flush_buffer` timer is
not run, `is_timer_running` stays set with no timer behind it, so that
processor's buffer is no longer flushed by time, only when it reaches
`batch_max_size`. (This part is from reading the code; the reproduction below
covers the batch timer.)
Raising `max_running_timers`, as the comment in `config.yaml.example`
suggests for this alert, raises the threshold but does not stop the backlog
from filling up once it is crossed.
#14192 makes the batch processor count every batch that it gives up on, but
the processor cannot see a timer that lua-nginx-module does not run, so this
case is not covered there.
### Expected Behavior
A temporary shortage of running timers should cost at most the batches that
could not run, and the logger should log again once the pressure is gone. One
logger's slow endpoint should not stop other loggers in the same worker.
### Error Logs
From the reproduction below (scaled-down limits):
```
[alert] 49#49: lua failed to run timer with function defined at
@/usr/local/apisix/apisix/utils/batch-processor.lua:90: 16
lua_max_running_timers are not enough
...
[error] ... report_discard(): max pending entries limit exceeded. discarding
entry. total_pushed_entries: 22 total_processed_entries: 2 max_pending_entries:
20 discarded_entries: 3
```
### Steps to Reproduce
The limits are scaled down so that a few dozen requests are enough:
`max_running_timers: 16` and `max_pending_entries: 20` (the defaults are 4096
and 8192).
1. Run `apache/apisix:3.19.0-debian` in standalone mode with this
`conf/config.yaml`:
```yaml
apisix:
node_listen: 9080
deployment:
role: data_plane
role_data_plane:
config_provider: yaml
nginx_config:
worker_processes: 1
max_running_timers: 16
```
and this `conf/apisix.yaml`. The route `/app` has an http-logger that
posts to `/slow`, which takes 3 s to answer, and a udp-logger. UDP sends do not
wait for anything, so the udp-logger's own endpoint is never slow.
```yaml
routes:
- id: slow-log-server
uri: /slow
plugins:
serverless-pre-function:
phase: access
functions:
- |
return function(_, _)
ngx.sleep(3)
require("apisix.core").response.exit(200, "ok\n")
end
- id: app
uri: /app
upstream:
type: roundrobin
nodes:
"127.0.0.1:9080": 1
plugins:
proxy-rewrite:
uri: /backend
http-logger:
uri: http://127.0.0.1:9080/slow
batch_max_size: 1
timeout: 5
udp-logger:
host: 127.0.0.1
port: 5555
batch_max_size: 1
- id: backend
uri: /backend
plugins:
serverless-pre-function:
phase: access
functions:
- |
return function(_, _)
require("apisix.core").response.exit(200, "ok\n")
end
plugin_metadata:
- id: udp-logger
max_pending_entries: 20
#END
```
2. Send 60 concurrent requests to `/app`, for example `curl -s --parallel
--parallel-max 60 "http://127.0.0.1:9080/app?b=[1-60]"; > /dev/null`.
3. Wait about 12 seconds, so that every http-logger batch has finished, then
send 10 requests to `/app` one after another.
4. The error log shows 126 `lua_max_running_timers are not enough` alerts
during the burst. During the 10 later requests no timer is running any more,
yet the udp-logger discards all of their entries, with `total_pushed_entries:
22 total_processed_entries: 2 max_pending_entries: 20`, and keeps doing so.
### Environment
- APISIX version: 3.19.0; the batch processor files are the same on master
(64d831f4f3).
- OpenResty: openresty/1.29.2.4, as shipped in the
`apache/apisix:3.19.0-debian` image.
- Docker, `worker_processes: 1`.
### Possible directions
- Bound the number of timers a processor uses (for example one long-lived
timer per processor that drains its batches in order) instead of one timer per
batch, so that a slow endpoint cannot hold an unbounded number of running
timers.
- Or record when each batch was scheduled, and let the periodic stale sweep
count a batch whose timer never started as dropped, so that the backlog
recovers.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
