⚝
One Hat Cyber Team
⚝
Your IP:
216.73.216.124
Server IP:
50.28.103.30
Server:
Linux host.jcukjv-lwsites.com 4.18.0-553.22.1.el8_10.x86_64 #1 SMP Tue Sep 24 05:16:59 EDT 2024 x86_64
Server Software:
nginx/1.28.0
PHP Version:
8.3.12
Buat File
|
Buat Folder
Eksekusi
Dir :
~
/
www
/
server
/
nginx
/
src
/
lua_nginx_module
/
t
/
View File Name :
106-timer.t
# vim:set ft= ts=4 sw=4 et fdm=marker: use Test::Nginx::Socket::Lua; use t::StapThread; our $GCScript = $t::StapThread::GCScript; our $StapScript = $t::StapThread::StapScript; #worker_connections(1014); #master_on(); #workers(2); #log_level('warn'); repeat_each(2); plan tests => repeat_each() * (blocks() * 8 + 61); #no_diff(); no_long_string(); our $HtmlDir = html_dir; $ENV{TEST_NGINX_MEMCACHED_PORT} ||= 11211; $ENV{TEST_NGINX_HTML_DIR} = $HtmlDir; worker_connections(1024); run_tests(); __DATA__ === TEST 1: simple at --- config location /t { content_by_lua ' local begin = ngx.now() local function f(premature) print("elapsed: ", ngx.now() - begin) print("timer prematurely expired: ", premature) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] timer prematurely expired: true --- error_log eval [ qr/\[lua\] content_by_lua\(nginx\.conf:\d+\):\d+: elapsed: 0\.0(?:4[4-9]|5[0-6])\d*, context: ngx\.timer, client: \d+\.\d+\.\d+\.\d+, server: 0\.0\.0\.0:\d+/, "lua ngx.timer expired", "http lua close fake http connection", "timer prematurely expired: false", ] --- grep_error_log eval: qr/lua caching unused lua thread|lua reusing cached lua thread/ --- grep_error_log_out eval [ "lua caching unused lua thread lua caching unused lua thread ", "lua reusing cached lua thread lua reusing cached lua thread lua caching unused lua thread lua caching unused lua thread ", ] === TEST 2: globals are shared --- config location /t { content_by_lua ' local begin = ngx.now() local function f() foo = 3 print("elapsed: ", ngx.now() - begin) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") ngx.sleep(0.06) ngx.say("foo = ", foo) '; } --- request GET /t --- stap2 F(ngx_http_lua_timer_handler) { println("lua timer handler") } --- response_body registered timer foo = 3 --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ qr/\[lua\] content_by_lua\(nginx\.conf:\d+\):\d+: elapsed: 0\.0(?:4[4-9]|5[0-6])/, "lua ngx.timer expired", "http lua close fake http connection" ] === TEST 3: lua variable sharing via upvalue --- config location /t { content_by_lua ' local begin = ngx.now() local foo local function f() foo = 3 print("elapsed: ", ngx.now() - begin) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") ngx.sleep(0.06) ngx.say("foo = ", foo) '; } --- request GET /t --- stap2 F(ngx_http_lua_timer_handler) { println("lua timer handler") } --- response_body registered timer foo = 3 --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log eval [ qr/\[lua\] content_by_lua\(nginx\.conf:\d+\):\d+: elapsed: 0\.0(?:4[4-9]|5[0-6])/, "lua ngx.timer expired", "http lua close fake http connection" ] === TEST 4: simple at (sleep in the timer callback) --- config location /t { content_by_lua ' local begin = ngx.now() local function f() print("my lua timer handler") ngx.sleep(0.2) print("elapsed: ", ngx.now() - begin) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.3 --- no_error_log [error] [alert] [crit] --- error_log eval [ qr/\[lua\] .*? my lua timer handler/, qr/\[lua\] content_by_lua\(nginx\.conf:\d+\):\d+: elapsed: 0\.(?:1[4-9]|2[0-6]?)/, "lua ngx.timer expired", "http lua close fake http connection" ] === TEST 5: tcp cosocket in timer handler (short connections) --- config server_tokens off; location = /gc { content_by_lua_block { local c = collectgarbage("count") ngx.say("before: ", c) collectgarbage("collect") c = collectgarbage("count") ngx.say("after: ", c) } } location = /t { content_by_lua ' collectgarbage() -- ngx.say("gc size: ", collectgarbage("count")) local begin = ngx.now() local function fail(...) ngx.log(ngx.ERR, ...) end local function f() print("my lua timer handler") local sock = ngx.socket.tcp() local port = $TEST_NGINX_SERVER_PORT local ok, err = sock:connect("127.0.0.1", port) if not ok then fail("failed to connect: ", err) return end print("connected: ", ok) local req = "GET /foo HTTP/1.0\\r\\nHost: localhost\\r\\nConnection: close\\r\\n\\r\\n" -- req = "OK" local bytes, err = sock:send(req) if not bytes then fail("failed to send request: ", err) return end print("request sent: ", bytes) while true do local line, err, part = sock:receive() if line then print("received: ", line) else if err == "closed" then break end fail("failed to receive a line: ", err, " [", part, "]") break end end ok, err = sock:close() print("close: ", ok, " ", err) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end -- ngx.sleep(0.1) ngx.say("registered timer") '; } location = /foo { content_by_lua 'ngx.say("foo")'; more_clear_headers Date; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ qr/\[lua\] .*? my lua timer handler/, "lua ngx.timer expired", "http lua close fake http connection", "connected: 1", "request sent: 57", "received: HTTP/1.1 200 OK", qr/received: Server: \S+/, "received: Content-Type: text/plain", "received: Content-Length: 4", "received: Connection: close", "received: foo", "close: 1 nil", ] === TEST 6: tcp cosocket in timer handler (keep-alive connections) --- http_config eval "lua_package_path '$::HtmlDir/?.lua;./?.lua;;';" --- config location = /t { content_by_lua ' local begin = ngx.now() local function f() print("my lua timer handler") local test = require "test" local port = $TEST_NGINX_MEMCACHED_PORT test.go(port) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- user_files >>> test.lua module("test", package.seeall) local function fail(...) ngx.log(ngx.ERR, ...) end function go(port) local sock = ngx.socket.tcp() local ok, err = sock:connect("127.0.0.1", port) if not ok then fail("failed to connect: ", err) return end print("connected: ", ok, ", reused: ", sock:getreusedtimes()) local req = "flush_all\r\n" local bytes, err = sock:send(req) if not bytes then fail("failed to send request: ", err) return end print("request sent: ", bytes) local line, err, part = sock:receive() if line then print("received: ", line) else fail("failed to receive a line: ", err, " [", part, "]") end local ok, err = sock:setkeepalive() if not ok then fail("failed to set reusable: ", err) end end --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ qr/\[lua\] .*? my lua timer handler/, "lua ngx.timer expired", "http lua close fake http connection", qr/go\(\): connected: 1, reused: \d+/, "go(): request sent: 11", "go(): received: OK", ] === TEST 7: 0 timer --- config location /t { content_by_lua ' local begin = ngx.now() local function f() print("elapsed: ", ngx.now() - begin) end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ qr/\[lua\] content_by_lua\(nginx\.conf:\d+\):\d+: elapsed: 0(?:[^.]|\.00)/, "lua ngx.timer expired", "http lua close fake http connection" ] === TEST 8: udp cosocket in timer handler --- config location = /t { content_by_lua ' local begin = ngx.now() local function fail(...) ngx.log(ngx.ERR, ...) end local function f() print("my lua timer handler") local socket = ngx.socket -- local socket = require "socket" local udp = socket.udp() local port = $TEST_NGINX_MEMCACHED_PORT udp:settimeout(1000) -- 1 sec local ok, err = udp:setpeername("127.0.0.1", port) if not ok then fail("failed to connect: ", err) return end print("connected: ", ok) local req = "\\0\\1\\0\\0\\0\\1\\0\\0flush_all\\r\\n" local ok, err = udp:send(req) if not ok then fail("failed to send: ", err) return end local data, err = udp:receive() if not data then fail("failed to receive data: ", err) return end print("received ", #data, " bytes: ", data) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } location = /foo { content_by_lua 'ngx.say("foo")'; more_clear_headers Date; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ qr/\[lua\] .*? my lua timer handler/, "lua ngx.timer expired", "http lua close fake http connection", "connected: 1", "received 12 bytes: \x{00}\x{01}\x{00}\x{00}\x{00}\x{01}\x{00}\x{00}OK\x{0d}\x{0a}" ] === TEST 9: simple at (sleep in the timer callback) - log_by_lua --- config location /t { echo hello world; log_by_lua ' local begin = ngx.now() local function f() print("my lua timer handler") ngx.sleep(0.02) print("elapsed: ", ngx.now() - begin) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.log(ngx.ERR, "failed to set timer: ", err) return end print("registered timer") '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 2: ok delete thread 2 --- response_body hello world --- wait: 0.3 --- no_error_log [error] [alert] [crit] --- error_log eval [ "registered timer", qr/\[lua\] .*? my lua timer handler/, qr/\[lua\] log_by_lua\(nginx\.conf:\d+\):\d+: elapsed: 0\.0(?:6[4-9]|7[0-9]|8[1-3])/, "lua ngx.timer expired", "http lua close fake http connection" ] === TEST 10: tcp cosocket in timer handler (keep-alive connections) - log_by_lua --- http_config eval "lua_package_path '$::HtmlDir/?.lua;./?.lua;;';" --- config location = /t { echo hello; log_by_lua ' local begin = ngx.now() local function f() print("my lua timer handler") local test = require "test" local port = $TEST_NGINX_MEMCACHED_PORT test.go(port) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.log(ngx.ERR, "failed to set timer: ", err) return end print("registered timer") '; } --- user_files >>> test.lua module("test", package.seeall) local function fail(...) ngx.log(ngx.ERR, ...) end function go(port) local sock = ngx.socket.tcp() local ok, err = sock:connect("127.0.0.1", port) if not ok then fail("failed to connect: ", err) return end print("connected: ", ok, ", reused: ", sock:getreusedtimes()) local req = "flush_all\r\n" local bytes, err = sock:send(req) if not bytes then fail("failed to send request: ", err) return end print("request sent: ", bytes) local line, err, part = sock:receive() if line then print("received: ", line) else fail("failed to receive a line: ", err, " [", part, "]") end local ok, err = sock:setkeepalive() if not ok then fail("failed to set reusable: ", err) end end --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 2: ok delete thread 2 --- response_body hello --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ "registered timer", qr/\[lua\] .*? my lua timer handler/, "lua ngx.timer expired", "http lua close fake http connection", qr/go\(\): connected: 1, reused: \d+/, "go(): request sent: 11", "go(): received: OK", ] === TEST 11: tcp cosocket in timer handler (keep-alive connections) - header_filter_by_lua --- http_config eval "lua_package_path '$::HtmlDir/?.lua;./?.lua;;';" --- config location = /t { echo hello; header_filter_by_lua ' local begin = ngx.now() local function f() print("my lua timer handler") local test = require "test" local port = $TEST_NGINX_MEMCACHED_PORT test.go(port) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.log(ngx.ERR, "failed to set timer: ", err) return end print("registered timer") '; } --- user_files >>> test.lua module("test", package.seeall) local function fail(...) ngx.log(ngx.ERR, ...) end function go(port) local sock = ngx.socket.tcp() local ok, err = sock:connect("127.0.0.1", port) if not ok then fail("failed to connect: ", err) return end print("connected: ", ok, ", reused: ", sock:getreusedtimes()) local req = "flush_all\r\n" local bytes, err = sock:send(req) if not bytes then fail("failed to send request: ", err) return end print("request sent: ", bytes) local line, err, part = sock:receive() if line then print("received: ", line) else fail("failed to receive a line: ", err, " [", part, "]") end local ok, err = sock:setkeepalive() if not ok then fail("failed to set reusable: ", err) end end --- request GET /t --- stap2 eval: $::StapScript --- stap3 global count = 0 F(ngx_http_lua_header_filter) { if (count++ == 10) { println("header filter") print_ubacktrace() } } --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 2: ok delete thread 2 --- response_body hello --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ "registered timer", qr/\[lua\] .*? my lua timer handler/, "lua ngx.timer expired", "http lua close fake http connection", qr/go\(\): connected: 1, reused: \d+/, "go(): request sent: 11", "go(): received: OK", ] === TEST 12: tcp cosocket in timer handler (keep-alive connections) - body_filter_by_lua --- http_config eval "lua_package_path '$::HtmlDir/?.lua;./?.lua;;';" --- config location = /t { echo hello; body_filter_by_lua ' local begin = ngx.now() local function f() print("my lua timer handler") local test = require "test" local port = $TEST_NGINX_MEMCACHED_PORT test.go(port) end local ok, err = ngx.timer.at(0.01, f) if not ok then ngx.log(ngx.ERR, "failed to set timer: ", err) return end print("registered timer") '; } --- user_files >>> test.lua module("test", package.seeall) local function fail(...) ngx.log(ngx.ERR, ...) end function go(port) local sock = ngx.socket.tcp() local ok, err = sock:connect("127.0.0.1", port) if not ok then fail("failed to connect: ", err) return end print("connected: ", ok, ", reused: ", sock:getreusedtimes()) local req = "flush_all\r\n" local bytes, err = sock:send(req) if not bytes then fail("failed to send request: ", err) return end print("request sent: ", bytes) local line, err, part = sock:receive() if line then print("received: ", line) else fail("failed to receive a line: ", err, " [", part, "]") end local ok, err = sock:setkeepalive() if not ok then fail("failed to set keep alive: ", err) end end --- request GET /t --- stap2 eval: $::StapScript --- stap3 global count = 0 F(ngx_http_lua_header_filter) { if (count++ == 10) { println("header filter") print_ubacktrace() } } --- stap eval: $::GCScript --- stap_out_like chop create 2 in 1 create 3 in 1 (?:terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 |terminate 3: ok delete thread 3 terminate 2: ok delete thread 2)$ --- response_body hello --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ "registered timer", qr/\[lua\] .*? my lua timer handler/, "lua ngx.timer expired", "http lua close fake http connection", qr/go\(\): connected: 1, reused: \d+/, "go(): request sent: 11", "go(): received: OK", ] === TEST 13: tcp cosocket in timer handler (keep-alive connections) - set_by_lua --- http_config eval "lua_package_path '$::HtmlDir/?.lua;./?.lua;;';" --- config location = /t { set_by_lua $a ' local begin = ngx.now() local function f() print("my lua timer handler") local test = require "test" local port = $TEST_NGINX_MEMCACHED_PORT test.go(port) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.log(ngx.ERR, "failed to set timer: ", err) return end print("registered timer") return 32 '; echo $a; } --- user_files >>> test.lua module("test", package.seeall) local function fail(...) ngx.log(ngx.ERR, ...) end function go(port) local sock = ngx.socket.tcp() local ok, err = sock:connect("127.0.0.1", port) if not ok then fail("failed to connect: ", err) return end print("connected: ", ok, ", reused: ", sock:getreusedtimes()) local req = "flush_all\r\n" local bytes, err = sock:send(req) if not bytes then fail("failed to send request: ", err) return end print("request sent: ", bytes) local line, err, part = sock:receive() if line then print("received: ", line) else fail("failed to receive a line: ", err, " [", part, "]") end local ok, err = sock:setkeepalive() if not ok then fail("failed to set reusable: ", err) end end --- request GET /t --- stap2 eval: $::StapScript --- stap3 global count = 0 F(ngx_http_lua_header_filter) { if (count++ == 10) { println("header filter") print_ubacktrace() } } --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 2: ok delete thread 2 --- response_body 32 --- wait: 0.2 --- no_error_log [error] [alert] [crit] --- error_log eval [ "registered timer", qr/\[lua\] .*? my lua timer handler/, "lua ngx.timer expired", "http lua close fake http connection", qr/go\(\): connected: 1, reused: \d+/, "go(): request sent: 11", "go(): received: OK", ] === TEST 14: coroutine API --- config location /t { content_by_lua ' local cc, cr, cy = coroutine.create, coroutine.resume, coroutine.yield local function f() local function f() local cnt = 0 for i = 1, 20 do print("cnt = ", cnt) cy() cnt = cnt + 1 end end local c = cc(f) for i=1,3 do cr(c) print("after resume, i = ", i) end end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 create 3 in 2 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log eval [ "lua ngx.timer expired", "http lua close fake http connection", "cnt = 0", "after resume, i = 1", "cnt = 1", "after resume, i = 2", "cnt = 2", "after resume, i = 3", ] === TEST 15: ngx.thread API --- config location /t { content_by_lua ' local function fail (...) ngx.log(ngx.ERR, ...) end local function handle() local function f() print("hello in thread") return "done" end local t, err = ngx.thread.spawn(f) if not t then fail("failed to spawn thread: ", err) return end print("thread created: ", coroutine.status(t)) collectgarbage() local ok, res = ngx.thread.wait(t) if not ok then fail("failed to run thread: ", res) return end print("wait result: ", res) end local ok, err = ngx.timer.at(0.01, handle) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 create 3 in 2 spawn user thread 3 in 2 terminate 3: ok delete thread 3 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log eval [ "lua ngx.timer expired", "http lua close fake http connection", "hello in thread", "thread created: zombie", "wait result: done", ] === TEST 16: shared dict --- http_config lua_shared_dict dogs 1m; --- config location /t { content_by_lua ' local function f() local dogs = ngx.shared.dogs dogs:set("foo", 32) dogs:set("bah", 10502) local val = dogs:get("foo") print("get foo: ", val, " ", type(val)) val = dogs:get("bah") print("get bah: ", val, " ", type(val)) end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log eval [ "lua ngx.timer expired", "http lua close fake http connection", "get foo: 32 number", "get bah: 10502 number", ] === TEST 17: ngx.exit(0) --- config location /t { content_by_lua ' local function f() local function g() print("BEFORE ngx.exit") ngx.exit(0) end g() print("CANNOT REACH HERE") end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 F(ngx_http_lua_timer_handler) { println("lua timer handler") } --- response_body registered timer --- wait: 0.1 --- no_error_log [alert] [crit] --- error_log eval [ "lua ngx.timer expired", "http lua close fake http connection", "BEFORE ngx.exit", ] --- no_error_log CANNOT REACH HERE API disabled === TEST 18: ngx.exit(403) --- config location /t { content_by_lua ' local function f() local function g() print("BEFORE ngx.exit") ngx.exit(403) end g() print("CANNOT REACH HERE") end local ok, err = ngx.timer.at(0.05, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 F(ngx_http_lua_timer_handler) { println("lua timer handler") } --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] CANNOT REACH HERE API disabled --- error_log eval [ "lua ngx.timer expired", "http lua close fake http connection", "BEFORE ngx.exit", ] === TEST 19: exit in user thread (entry thread is still pending on ngx.sleep) --- config location /t { content_by_lua ' local function handle() local function f() print("hello in thread") ngx.sleep(0.1) ngx.exit(0) end print("BEFORE thread spawn") ngx.thread.spawn(f) print("AFTER thread spawn") ngx.sleep(1) print("entry thread END") end local ok, err = ngx.timer.at(0.05, handle) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap eval <<'_EOC_' . $::GCScript; global timers F(ngx_http_free_request) { println("free request") } M(timer-add) { if ($arg2 == 1000 || $arg2 == 100) { timers[$arg1] = $arg2 printf("add timer %d\n", $arg2) } } M(timer-del) { tm = timers[$arg1] if (tm == 1000 || tm == 100) { printf("delete timer %d\n", tm) delete timers[$arg1] } /* if (tm == 1000) { print_ubacktrace() } */ } M(timer-expire) { tm = timers[$arg1] if (tm == 1000 || tm == 100) { printf("expire timer %d\n", timers[$arg1]) delete timers[$arg1] } } F(ngx_http_lua_sleep_cleanup) { println("lua sleep cleanup") } _EOC_ --- stap_out_like chop (?:create 2 in 1 terminate 1: ok delete thread 1 free request create 3 in 2 spawn user thread 3 in 2 add timer 100 add timer 1000 expire timer 100 terminate 3: ok delete thread 3 lua sleep cleanup delete timer 1000 delete thread 2|create 2 in 1 terminate 1: ok delete thread 1 create 3 in 2 spawn user thread 3 in 2 add timer 100 add timer 1000 free request expire timer 100 terminate 3: ok delete thread 3 lua sleep cleanup delete timer 1000 delete thread 2)$ --- response_body registered timer --- wait: 0.2 --- no_error_log [error] [alert] [crit] API disabled entry thread END --- error_log eval [ "lua ngx.timer expired", "http lua close fake http connection", "BEFORE thread spawn", "hello in thread", "AFTER thread spawn", ] === TEST 20: chained timers (0 delay) --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local function g() s = s .. "[g]" print("trace: ", s) end local function f() local ok, err = ngx.timer.at(0, g) if not ok then fail("failed to set timer: ", err) return end s = s .. "[f]" end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 create 3 in 2 terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log eval [ 'lua ngx.timer expired', 'http lua close fake http connection', qr/trace: \[m\]\[f\]\[g\], context: ngx\.timer, client: \d+\.\d+\.\d+\.\d+, server: 0\.0\.0\.0:\d+/, ] === TEST 21: chained timers (non-zero delay) --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local function g() s = s .. "[g]" print("trace: ", s) end local function f() local ok, err = ngx.timer.at(0.01, g) if not ok then fail("failed to set timer: ", err) return end s = s .. "[f]" end local ok, err = ngx.timer.at(0.01, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 create 3 in 2 terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log lua ngx.timer expired http lua close fake http connection trace: [m][f][g] === TEST 22: multiple parallel timers --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local function g() s = s .. "[g]" print("trace: ", s) end local function f() s = s .. "[f]" end local ok, err = ngx.timer.at(0.01, f) if not ok then fail("failed to set timer: ", err) return end local ok, err = ngx.timer.at(0.01, g) if not ok then fail("failed to set timer: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 create 3 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log lua ngx.timer expired http lua close fake http connection trace: [m][f][g] === TEST 23: lua_max_pending_timers --- http_config lua_max_pending_timers 1; --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local function g() s = s .. "[g]" print("trace: ", s) end local function f() s = s .. "[f]" end local ok, err = ngx.timer.at(0.01, f) if not ok then ngx.say("failed to set timer f: ", err) return end local ok, err = ngx.timer.at(0.01, g) if not ok then ngx.say("failed to set timer g: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body failed to set timer g: too many pending timers --- wait: 0.1 --- no_error_log [alert] [crit] [error] --- error_log lua ngx.timer expired http lua close fake http connection === TEST 24: lua_max_pending_timers (just not exceeding) --- http_config lua_max_pending_timers 2; --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local function g() s = s .. "[g]" print("trace: ", s) end local function f() s = s .. "[f]" end local ok, err = ngx.timer.at(0.01, f) if not ok then ngx.say("failed to set timer f: ", err) return end local ok, err = ngx.timer.at(0.01, g) if not ok then ngx.say("failed to set timer g: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 create 3 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 --- response_body registered timer --- wait: 0.1 --- no_error_log [alert] [crit] [error] --- error_log lua ngx.timer expired http lua close fake http connection trace: [m][f][g] === TEST 25: lua_max_pending_timers - chained timers (non-zero delay) - not exceeding --- http_config lua_max_pending_timers 1; --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local function g() s = s .. "[g]" print("trace: ", s) end local function f() local ok, err = ngx.timer.at(0.01, g) if not ok then fail("failed to set timer: ", err) return end s = s .. "[f]" end local ok, err = ngx.timer.at(0.01, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 create 3 in 2 terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log lua ngx.timer expired http lua close fake http connection trace: [m][f][g] === TEST 26: lua_max_pending_timers - chained timers (zero delay) - not exceeding --- http_config lua_max_pending_timers 1; --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local function g() s = s .. "[g]" print("trace: ", s) end local function f() local ok, err = ngx.timer.at(0, g) if not ok then fail("failed to set timer: ", err) return end s = s .. "[f]" end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 create 3 in 2 terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] --- error_log lua ngx.timer expired http lua close fake http connection trace: [m][f][g] === TEST 27: lua_max_running_timers (just not enough) --- http_config lua_max_running_timers 1; --- config location /t { content_by_lua ' collectgarbage() local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local f, g g = function () ngx.sleep(0.01) end f = function () ngx.sleep(0.01) end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to set timer f: ", err) return end local ok, err = ngx.timer.at(0, g) if not ok then ngx.say("failed to set timer g: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 create 3 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.1 --- no_error_log [crit] [error] --- error_log eval [ qr/\[alert\] .*? lua failed to run timer with function defined at =content_by_lua\(nginx.conf:\d+\):11: 1 lua_max_running_timers are not enough/, "lua ngx.timer expired", "http lua close fake http connection", ] === TEST 28: lua_max_running_timers (just enough) --- http_config lua_max_running_timers 2; --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local f, g g = function () ngx.sleep(0.01) end f = function () ngx.sleep(0.01) end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to set timer f: ", err) return end local ok, err = ngx.timer.at(0, g) if not ok then ngx.say("failed to set timer g: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 create 3 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 --- response_body registered timer --- wait: 0.1 --- no_error_log [alert] [crit] [error] --- error_log lua ngx.timer expired http lua close fake http connection === TEST 29: lua_max_running_timers (just enough) - 2 --- http_config lua_max_running_timers 2; --- config location /t { content_by_lua ' local s = "" local function fail(...) ngx.log(ngx.ERR, ...) end local f, g g = function () ngx.timer.at(0.02, f) ngx.sleep(0.01) end f = function () ngx.sleep(0.01) end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to set timer f: ", err) return end local ok, err = ngx.timer.at(0, g) if not ok then ngx.say("failed to set timer g: ", err) return end ngx.say("registered timer") s = "[m]" '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 create 3 in 1 terminate 1: ok delete thread 1 create 4 in 3 terminate 2: ok delete thread 2 terminate 3: ok delete thread 3 terminate 4: ok delete thread 4 --- response_body registered timer --- wait: 0.1 --- no_error_log [alert] [crit] [error] --- error_log lua ngx.timer expired http lua close fake http connection === TEST 30: user args --- config location /t { content_by_lua ' local begin = ngx.now() local function f(premature, a, b, c) print("elapsed: ", ngx.now() - begin) print("timer prematurely expired: ", premature) print("timer user args: ", a, " ", b, " ", c) end local ok, err = ngx.timer.at(0.05, f, 1, "hello", true) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- stap2 eval: $::StapScript --- stap eval: $::GCScript --- stap_out create 2 in 1 terminate 1: ok delete thread 1 terminate 2: ok delete thread 2 --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] timer prematurely expired: true --- error_log eval [ qr/\[lua\] content_by_lua\(nginx\.conf:\d+\):\d+: elapsed: 0\.0(?:4[4-9]|5[0-6])\d*, context: ngx\.timer/, "lua ngx.timer expired", "http lua close fake http connection", "timer prematurely expired: false", "timer user args: 1 hello true", ] === TEST 31: use of ngx.ctx --- config location /t { content_by_lua ' local begin = ngx.now() local function f(premature) ngx.ctx.s = "hello" print("elapsed: ", ngx.now() - begin) print("timer prematurely expired: ", premature) end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("registered timer") '; } --- request GET /t --- response_body registered timer --- wait: 0.1 --- no_error_log [error] [alert] [crit] timer prematurely expired: true --- error_log eval [ qr/\[lua\] content_by_lua\(nginx\.conf:\d+\):\d+: elapsed: .*?, context: ngx\.timer/, "lua ngx.timer expired", "http lua close fake http connection", "timer prematurely expired: false", "lua release ngx.ctx at ref ", ] === TEST 32: syslog error log --- http_config #error_log syslog:server=127.0.0.1:12345 error; --- config location /t { content_by_lua ' local function f() ngx.log(ngx.ERR, "Bad bad bad") end ngx.timer.at(0, f) ngx.sleep(0.001) ngx.say("ok") '; } --- log_level: error --- error_log_file: syslog:server=127.0.0.1:12345 --- udp_listen: 12345 --- udp_query eval: qr/Bad bad bad/ --- udp_reply: hello --- wait: 0.1 --- request GET /t --- response_body ok --- error_log Bad bad bad --- skip_nginx: 4: < 1.7.1 === TEST 33: log function location when failed to run a timer --- http_config lua_max_running_timers 1; --- config location /t { content_by_lua_block { local function g() ngx.sleep(0.01) end local function f() ngx.sleep(0.01) end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to create timer f: ", err) return end local ok, err = ngx.timer.at(0, g) if not ok then ngx.say("failed to create timer g: ", err) return end ngx.say("ok") } } --- request GET /t --- response_body ok --- wait: 0.1 --- error_log eval qr/\[alert\] .*? lua failed to run timer with function defined at =content_by_lua\(nginx.conf:\d+\):2: 1 lua_max_running_timers are not enough/ --- no_error_log [crit] [error] === TEST 34: log function location when failed to run a timer (anonymous function) --- http_config lua_max_running_timers 1; --- config location /t { content_by_lua_block { local function f() ngx.sleep(0.01) end local ok, err = ngx.timer.at(0, f) if not ok then ngx.say("failed to set timer f: ", err) return end local ok, err = ngx.timer.at(0, function() ngx.sleep(0.01) end) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("ok") } } --- request GET /t --- response_body ok --- wait: 0.1 --- error_log eval qr/\[alert\] .*? lua failed to run timer with function defined at =content_by_lua\(nginx.conf:\d+\):12: 1 lua_max_running_timers are not enough/ --- no_error_log [crit] [error] === TEST 35: log function location when failed to run a timer (lua file) --- user_files >>> test.lua local _M = {} function _M.run() ngx.sleep(0.01) end return _M --- http_config lua_package_path '$TEST_NGINX_HTML_DIR/?.lua;./?.lua;;'; lua_max_running_timers 1; --- config location /t { content_by_lua_block { local test = require "test" local ok, err = ngx.timer.at(0, test.run) if not ok then ngx.say("failed to set timer: ", err) return end local ok, err = ngx.timer.at(0, test.run) if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("ok") } } --- request GET /t --- response_body ok --- wait: 0.1 --- no_error_log [crit] [error] --- error_log eval qr/\[alert\] .*? lua failed to run timer with function defined at @.+\/test.lua:3: 1 lua_max_running_timers are not enough/ === TEST 36: log function location when failed to run a timer with args (lua file) --- user_files >>> test.lua local _M = {} function _M.run(premature, arg) ngx.sleep(0.01) end return _M --- http_config lua_package_path '$TEST_NGINX_HTML_DIR/?.lua;./?.lua;;'; lua_max_running_timers 1; --- config location /t { content_by_lua_block { local test = require "test" local ok, err = ngx.timer.at(0, test.run, "arg") if not ok then ngx.say("failed to set timer: ", err) return end local ok, err = ngx.timer.at(0, test.run, "arg") if not ok then ngx.say("failed to set timer: ", err) return end ngx.say("ok") } } --- request GET /t --- response_body ok --- wait: 0.1 --- no_error_log [crit] [error] --- error_log eval qr/\[alert\] .*? lua failed to run timer with function defined at @.+\/test.lua:3: 1 lua_max_running_timers are not enough/