Skip to content

Commit 4d81068

Browse files
authored
fix: batch-processor infinite timer loop prevents graceful shutdown (#13288)
1 parent 08bf624 commit 4d81068

4 files changed

Lines changed: 69 additions & 4 deletions

File tree

apisix/utils/batch-processor.lua

Lines changed: 9 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ local ipairs = ipairs
2121
local table = table
2222
local now = ngx.now
2323
local type = type
24+
local exiting = ngx.worker.exiting
2425
local batch_processor = {}
2526
local batch_processor_mt = {
2627
__index = batch_processor
@@ -52,9 +53,12 @@ local function schedule_func_exec(self, delay, batch)
5253
local hdl, err = timer_at(delay, execute_func, self, batch)
5354
if not hdl then
5455
if err == "process exiting" then
55-
-- it is allowed to create zero-delay timers even when
56-
-- the Nginx worker process starts shutting down
57-
timer_at(0, execute_func, self)
56+
local hdl2, err2 = timer_at(0, execute_func, self, batch)
57+
if not hdl2 then
58+
core.log.error("failed to create fallback process timer ",
59+
"while exiting: ", err2)
60+
return
61+
end
5862
else
5963
core.log.error("failed to create process timer: ", err)
6064
return
@@ -118,7 +122,8 @@ end
118122

119123

120124
local function flush_buffer(premature, self)
121-
if now() - self.last_entry_t >= self.inactive_timeout or
125+
if premature or exiting() or
126+
now() - self.last_entry_t >= self.inactive_timeout or
122127
now() - self.first_entry_t >= self.buffer_duration
123128
then
124129
core.log.debug("Batch Processor[", self.name ,"] buffer ",

t/plugin/prometheus2.t

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -458,6 +458,8 @@ GET /apisix/prometheus/metrics
458458
--- error_code: 200
459459
--- response_body_like eval
460460
qr/apisix_batch_process_entries\{name="zipkin_report",route_id="9",server_addr="127.0.0.1"\} \d+/
461+
--- error_log
462+
Batch Processor[zipkin_report] failed to process entries
461463
462464
463465
@@ -519,6 +521,8 @@ GET /apisix/prometheus/metrics
519521
--- error_code: 200
520522
--- response_body_like eval
521523
qr/apisix_batch_process_entries\{name="http-logger",route_id="9",server_addr="127.0.0.1"\} \d+/
524+
--- error_log
525+
Batch Processor[http-logger] failed to process entries
522526
523527
524528
@@ -581,6 +585,8 @@ GET /apisix/prometheus/metrics
581585
--- error_code: 200
582586
--- response_body_like eval
583587
qr/apisix_batch_process_entries\{name="tcp-logger",route_id="10",server_addr="127.0.0.1"\} \d+/
588+
--- error_log
589+
Batch Processor[tcp-logger] failed to process entries
584590
585591
586592
@@ -704,6 +710,8 @@ GET /apisix/prometheus/metrics
704710
--- error_code: 200
705711
--- response_body_like eval
706712
qr/apisix_batch_process_entries\{name="sls-logger",route_id="10",server_addr="127.0.0.1"\} \d+/
713+
--- error_log
714+
Batch Processor[sls-logger] failed to process entries
707715
708716
709717

t/plugin/prometheus3.t

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -255,6 +255,8 @@ qr/apisix_batch_process_entries\{name="http logger",route_id="1",server_addr="12
255255
}
256256
--- response_body
257257
passed
258+
--- error_log
259+
Batch Processor[error-log-logger] failed to process entries
258260
259261
260262

t/utils/batch-processor.t

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -481,3 +481,53 @@ Batch Processor[log buffer] failed to process entries [2/3]: error after consumi
481481
Batch Processor[log buffer] failed to process entries [1/2]: error after consuming single entry
482482
[{"msg":"4"}]
483483
--- wait: 2
484+
485+
486+
487+
=== TEST 13: batch processor exits cleanly during shutdown with active entries
488+
# The real bug triggers when a buffer timer naturally expires (not via abort_pending_timers)
489+
# during shutdown. With short inactive_timeout, the timer fires with premature=false while
490+
# ngx.worker.exiting() is true. Without the exiting() check, flush_buffer would re-arm a
491+
# zero-delay timer in an infinite loop, preventing worker exit.
492+
# Using short timeouts + continuous pushing to create the race condition.
493+
--- config
494+
location /t {
495+
content_by_lua_block {
496+
local Batch = require("apisix.utils.batch-processor")
497+
local func_to_send = function(elements)
498+
return true
499+
end
500+
501+
local config = {
502+
max_retry_count = 0,
503+
batch_max_size = 1000,
504+
buffer_duration = 60,
505+
inactive_timeout = 1,
506+
retry_delay = 0,
507+
}
508+
509+
local log_buffer, err = Batch:new(func_to_send, config)
510+
if not log_buffer then
511+
ngx.say(err)
512+
return
513+
end
514+
515+
-- push entries with short gaps to keep last_entry_t fresh
516+
local count = 0
517+
local function keep_pushing(premature)
518+
if premature then return end
519+
log_buffer:push({msg = "entry-" .. count})
520+
count = count + 1
521+
if count < 5 then
522+
ngx.timer.at(0.3, keep_pushing)
523+
end
524+
end
525+
keep_pushing(false)
526+
ngx.say("done")
527+
}
528+
}
529+
--- request
530+
GET /t
531+
--- response_body
532+
done
533+
--- wait: 2

0 commit comments

Comments
 (0)