Comments (27)
agentzh
commented on June 21, 2024
On Fri, Aug 26, 2011 at 7:36 PM, simpl
[email protected]
wrote:
When using Lua 5.1.4 to do subrequests (e.g. ngx.location.capture() -> memc_pass), after the first or second subrequest, I've found that that I've had a host of problems, including:
- segfaulting
- 'attempt to call a nil value' errors
Can you provide a minimized standalone test case for these?
and (in versions around 2.0 - 2.1.7/8 of ngx_lua)
- 'attempt to yield across metamethod/C-call boundary' errors
This is a restriction in the standard Lua 5.1 interpreter because its
VM is not fully resumable while LuaJIT 2.0 is.
As mentioned in another post, I've been doing a lot of hacking, and didn't do any checking without my code compiled-in. However, when I switched to LuaJIT, these issues went away.
I don't know how interested you are in supporting 5.1.4 since you're using JIT,
We've been trying hard to support the standard Lua 5.1.4 interpreter :)
but just in case you were, I thought I'd pass it on. I'm afraid I haven't got the time to look into it in any more depth myself right now.
We definitely need more information for these issues :)
Thanks!
-agentzh
from lua-nginx-module.
commented on June 21, 2024
I've got a tight deadline at the moment, and don't really have the time to look into it again right now. When I'm a bit freer, I'll send you some more info.
from lua-nginx-module.
agentzh
commented on June 21, 2024
Any update on this issue?
from lua-nginx-module.
commented on June 21, 2024
Sorry, I'd forgotten about this - I've been very busy of late. I've been using LuaJIT recently, and haven't noticed these particular issues. When I'm less busy with stuff, I'll test out what I'm doing with 5.1 and the latest builds.
from lua-nginx-module.
agentzh
commented on June 21, 2024
Any updates on this issue?
from lua-nginx-module.
sztanpet
commented on June 21, 2024
seems I have a similar issue,
here is a backtrace for starters
#0 0x000000000052533e in luaH_next ()
#1 0x000000000051b51c in lua_next ()
#2 0x00000000004d67f0 in ngx_http_lua_calc_strlen_in_table (L=0x221ba20, arg_i=1, strict=0)
at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_output.c:253
#3 0x00000000004d626f in ngx_http_lua_ngx_echo (L=0x221ba20, newline=0)
at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_output.c:108
#4 0x00000000004d609f in ngx_http_lua_ngx_print (L=0x221ba20) at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_output.c:24
#5 0x000000000051e429 in luaD_precall ()
#6 0x0000000000527a79 in luaV_execute ()
#7 0x000000000051dfc7 in luaD_rawrunprotected ()
#8 0x000000000051e190 in lua_resume ()
#9 0x00000000004e3406 in ngx_http_lua_run_thread (L=0x222e970, r=0x2224b60, ctx=0x2225ff0, nret=1)
at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_util.c:775
#10 0x00000000004e414a in ngx_http_lua_wev_handler (r=0x2224b60) at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_util.c:1191
#11 0x00000000004e7467 in ngx_http_lua_content_wev_handler (r=0x2224b60)
at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_contentby.c:100
#12 0x0000000000464d9a in ngx_http_run_posted_requests (c=0x7f8a973db190) at src/http/ngx_http_request.c:1859
#13 0x000000000047a1e0 in ngx_http_upstream_handler (ev=0x7f8a973721b0) at src/http/ngx_http_upstream.c:921
#14 0x000000000043fc89 in ngx_event_process_posted (cycle=0x22177a0, posted=0x7861f8) at src/event/ngx_event_posted.c:40
#15 0x000000000043db8c in ngx_process_events_and_timers (cycle=0x22177a0) at src/event/ngx_event.c:273
#16 0x000000000044a651 in ngx_worker_process_cycle (cycle=0x22177a0, data=0x0) at src/os/unix/ngx_process_cycle.c:802
#17 0x000000000044713a in ngx_spawn_process (cycle=0x22177a0, proc=0x44a495 <ngx_worker_process_cycle>, data=0x0,
name=0x539b4b "worker process", respawn=1) at src/os/unix/ngx_process.c:197
#18 0x000000000044a0cc in ngx_reap_children (cycle=0x22177a0) at src/os/unix/ngx_process_cycle.c:618
#19 0x0000000000448dcd in ngx_master_process_cycle (cycle=0x22177a0) at src/os/unix/ngx_process_cycle.c:181
#20 0x000000000041a5e6 in main (argc=1, argv=0x7ffff3617068) at src/core/nginx.c:412
using openresty, compiled so:
./configure --prefix=/home/sztanpet/openresty --without-http_xss_module --with-ipv6 --with-http_sub_module --with-http_gzip_static_module --without-http_charset_module --without-http_geo_module --without-http_empty_gif_module --without-mail_pop3_module --without-mail_imap_module --without-mail_smtp_module --with-pcre --with-http_postgres_module --with-debug
full code that sometimes triggers it including comments and anything, maybe its lua bytecode related somehow:
local args = ngx.req.get_uri_args()
local questionid = tonumber( args.questionid )
local answerid = tonumber( args.answerid )
ngx.header.content_type = "application/json; charset=UTF-8"
if not questionid or not answerid or questionid == 0 or answerid == 0 then
ngx.say('{"success":false, "err":"invalidparams"}')
return ngx.exit(ngx.HTTP_OK)
end
local ipaddress = ngx.var.remote_addr
local parser = require "redis.parser"
local questionkey = 'question_' .. questionid
local ipsetkey = "ipset_question_" .. questionid
local requests = {
parser.build_query({'hexists', questionkey, answerid}),
parser.build_query({'sadd', ipsetkey, ipaddress}),
}
local params = {body = table.concat(requests)}
local result = ngx.location.capture("/redis?2", params)
if result.status ~= 200 or not result.body then
ngx.log(ngx.ERR, "failed to query redis")
ngx.exit(500)
end
local replies = parser.parse_replies(result.body, #requests)
if replies[1][1] ~= 1 then -- avoid setting cookie if the answer is non-existant
ngx.say('{"success":false, "err":"invalidparams"}')
return ngx.exit(ngx.HTTP_OK)
end
local cookie = {
'vote-',
questionid,
'=',
answerid,
'; expires=',
ngx.cookie_time( ngx.time() + 3240000 ),
'; path=/;'
}
ngx.header['Set-Cookie'] = table.concat(cookie)
--[[
if replies[2][1] == 1 then
ngx.say('{"success":false, "err":"alreadyvoted"}')
return ngx.exit(ngx.HTTP_OK)
end
]]
-- reuse table, there is a very small chance that the sadd will fail (race with other requests)
requests[1] = parser.build_query({'sadd', ipsetkey, ipaddress})
requests[2] = parser.build_query({'hincrby', questionkey, answerid, 1})
requests[3] = parser.build_query({'hgetall', questionkey})
params.body = table.concat(requests)
local result = ngx.location.capture("/redis?3", params)
if result.status ~= 200 or not result.body then
ngx.log(ngx.ERR, "failed to query redis")
ngx.exit(500)
end
local replies = parser.parse_replies(result.body, #requests)
if replies[1][1] ~= 1 then -- failed to add ip, meaning the race really happened, handle it
requests[1] = parser.build_query({'hincrby', questionkey, answerid, -1})
requests[2] = parser.build_query({'hgetall', questionkey})
requests[3] = nil
params.body = table.concat(requests)
result = ngx.location.capture("/redis?2", params)
if result.status ~= 200 or not result.body then
ngx.log(ngx.ERR, "failed to query redis")
ngx.exit(500)
end
replies = parser.parse_replies(result.body, #requests)
table.insert(replies, 1, "") -- shift elements down
end
local ret = {success = true, data = {}}
local reply = replies[3]
for i = 1, #reply, 2 do
ngx.print(reply[i], reply[i+1])
ret.data[ reply[i] ] = reply[i+1]
end
--local json = require "cjson"
--ngx.say(json.encode(ret))
-- try and sync the votes to postgres
local postgresupdating = true --ngx.shared.DICT.get('postgresupdating')
if postgresupdating then
return ngx.exit(ngx.HTTP_OK)
end
ngx.flush()
ngx.exit(ngx.HTTP_OK)
--ngx.shared.DICT.set('postgresupdating', true)
local sql = {}
for k, v in pairs(ret.data) do
table.insert(sql, "UPDATE answers SET count = '" .. v .. "' WHERE answerid = '" .. k .. "';")
end
local reply = ngx.location.capture("/postgres", {
method = ngx.HTTP_POST,
body = table.concat(sql)
})
--ngx.shared.DICT.set('postgresupdating', false)
relevant nginx config
location /redis {
internal;
redis2_raw_queries $args $echo_request_body;
redis2_pass redis;
}
upstream redis {
server 127.0.0.1:6379;
keepalive 1024 single;
}
from lua-nginx-module.
sztanpet
commented on June 21, 2024
also, lua_code_cache is off,
distro is gentoo with redhat kernel,
gcc-4.4.5
Linux feanor 2.6.35-28.50 #1 SMP Mon Oct 17 23:44:59 CEST 2011 x86_64 Intel(R) Pentium(R) Dual CPU E2160 @ 1.80GHz GenuineIntel GNU/Linux
from lua-nginx-module.
sztanpet
commented on June 21, 2024
https://dl.dropbox.com/u/195588/core.442 and the core dump
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hello!
On Sun, Jun 24, 2012 at 3:57 AM, sztanpet
[email protected]
wrote:
seems I have a similar issue,
here is a backtrace for starters
Thank you for the bug report! Just want to ask a few questions:
-
Is there anything interesting in your error.log?
-
Do you have to run multiple concurrent requests (i.e., concurrency
level > 1) to reproduce this issue? -
Can you reproduce this with lua_code_cache on?
-
Can you reproduce this with LuaJIT 2.0 instead of the standard Lua
5.1.4 interpreter? -
Could you please run valgrind's memcheck tool upon your nginx to
see if there's any memory issues prior to the crash? Basically, you
need to turn off both "daemon" and "master_process" in your nginx.conf
and run your nginx like this:valgrind --leak-check=full /path/to/your/nginx ...
You're recommended to rebuild your openresty using the
--with-no-pool-patch configure option before running it with valgrind,
so as to prevent nginx's memory pool from interfering with tools like
valgrind.
- Could you please try minimizing the sample code on your side to the
point that I can easily run and debug the bad example directly on my
side?
Best regards,
-agentzh
from lua-nginx-module.
sztanpet
commented on June 21, 2024
no, there is nothing in my error.log, (error_log /dev/kmsg error;)
no, i did not have to run multiple concurrent requests, I just edit the code and reload the page and sometimes there is a segfault
minimizing the sample code didnt seem like a good idea because the crashes were random, the only thing I noticed was that after the subrequest I'm trying to construct a lua hash from a redis hash and it didn't work (upon trying to print all the values I get an empty string for the value, but in the request.body I see that a value should be there) and json.encode errors out with saying that it cannot encode illegal values.
the redis data was hset question_1 1 5
from lua-nginx-module.
sztanpet
commented on June 21, 2024
with lua_code_cache on, daemon off, master_process off
also with lua 5.1.4
[07:27](/home/sztanpet/openresty/nginx/sbin)# valgrind --leak-check=full ./nginx
==23244== Memcheck, a memory error detector
==23244== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al.
==23244== Using Valgrind-3.6.1 and LibVEX; rerun with -h for copyright info
==23244== Command: ./nginx
==23244==
==23244== Invalid read of size 4
==23244== at 0x524F8E: luaH_next (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x51B16B: lua_next (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x4D6447: ngx_http_lua_calc_strlen_in_table (ngx_http_lua_output.c:253)
==23244== by 0x4D5EC6: ngx_http_lua_ngx_echo (ngx_http_lua_output.c:108)
==23244== by 0x4D5CF6: ngx_http_lua_ngx_print (ngx_http_lua_output.c:24)
==23244== by 0x51E078: luaD_precall (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x5276C8: luaV_execute (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x51DC16: luaD_rawrunprotected (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x51DDDF: lua_resume (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x4E305D: ngx_http_lua_run_thread (ngx_http_lua_util.c:775)
==23244== by 0x4E3DA1: ngx_http_lua_wev_handler (ngx_http_lua_util.c:1191)
==23244== by 0x4E70BE: ngx_http_lua_content_wev_handler (ngx_http_lua_contentby.c:100)
==23244== Address 0x4014000000000038 is not stack'd, malloc'd or (recently) free'd
==23244==
==23244==
==23244== Process terminating with default action of signal 11 (SIGSEGV)
==23244== General Protection Fault
==23244== at 0x524F8E: luaH_next (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x51B16B: lua_next (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x4D6447: ngx_http_lua_calc_strlen_in_table (ngx_http_lua_output.c:253)
==23244== by 0x4D5EC6: ngx_http_lua_ngx_echo (ngx_http_lua_output.c:108)
==23244== by 0x4D5CF6: ngx_http_lua_ngx_print (ngx_http_lua_output.c:24)
==23244== by 0x51E078: luaD_precall (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x5276C8: luaV_execute (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x51DC16: luaD_rawrunprotected (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x51DDDF: lua_resume (in /home/sztanpet/openresty/nginx/sbin/nginx)
==23244== by 0x4E305D: ngx_http_lua_run_thread (ngx_http_lua_util.c:775)
==23244== by 0x4E3DA1: ngx_http_lua_wev_handler (ngx_http_lua_util.c:1191)
==23244== by 0x4E70BE: ngx_http_lua_content_wev_handler (ngx_http_lua_contentby.c:100)
==23244==
==23244== HEAP SUMMARY:
==23244== in use at exit: 2,380,423 bytes in 6,945 blocks
==23244== total heap usage: 8,111 allocs, 1,166 frees, 2,553,637 bytes allocated
==23244==
==23244== 292 (52 direct, 240 indirect) bytes in 1 blocks are definitely lost in loss record 1,890 of 2,140
==23244== at 0x4C267CE: malloc (vg_replace_malloc.c:236)
==23244== by 0x64834CB: nss_parse_service_list (nsswitch.c:540)
==23244== by 0x6483CA5: __nss_database_lookup (nsswitch.c:134)
==23244== by 0x6AFD32F: ???
==23244== by 0x6AFE384: ???
==23244== by 0x644255C: getpwnam_r@@GLIBC_2.2.5 (getXXbyYY_r.c:253)
==23244== by 0x6441F3F: getpwnam (getXXbyYY.c:117)
==23244== by 0x41BD9D: ngx_set_user (nginx.c:1147)
==23244== by 0x433C23: ngx_conf_handler (ngx_conf_file.c:394)
==23244== by 0x4337B7: ngx_conf_parse (ngx_conf_file.c:244)
==23244== by 0x430366: ngx_init_cycle (ngx_cycle.c:268)
==23244== by 0x41A36F: main (nginx.c:333)
==23244==
==23244== 292 (52 direct, 240 indirect) bytes in 1 blocks are definitely lost in loss record 1,891 of 2,140
==23244== at 0x4C267CE: malloc (vg_replace_malloc.c:236)
==23244== by 0x64834CB: nss_parse_service_list (nsswitch.c:540)
==23244== by 0x6483CA5: __nss_database_lookup (nsswitch.c:134)
==23244== by 0x6AFC40F: ???
==23244== by 0x6AFCEDC: ???
==23244== by 0x64412AC: getgrnam_r@@GLIBC_2.2.5 (getXXbyYY_r.c:253)
==23244== by 0x644085F: getgrnam (getXXbyYY.c:117)
==23244== by 0x41BE3A: ngx_set_user (nginx.c:1159)
==23244== by 0x433C23: ngx_conf_handler (ngx_conf_file.c:394)
==23244== by 0x4337B7: ngx_conf_parse (ngx_conf_file.c:244)
==23244== by 0x430366: ngx_init_cycle (ngx_cycle.c:268)
==23244== by 0x41A36F: main (nginx.c:333)
==23244==
==23244== LEAK SUMMARY:
==23244== definitely lost: 104 bytes in 2 blocks
==23244== indirectly lost: 480 bytes in 20 blocks
==23244== possibly lost: 0 bytes in 0 blocks
==23244== still reachable: 2,379,839 bytes in 6,923 blocks
==23244== suppressed: 0 bytes in 0 blocks
==23244== Reachable blocks (those to which a pointer was found) are not shown.
==23244== To see them, rerun with: --leak-check=full --show-reachable=yes
==23244==
==23244== For counts of detected and suppressed errors, rerun with: -v
==23244== ERROR SUMMARY: 3 errors from 3 contexts (suppressed: 7 from 7)
Segmentation fault
from lua-nginx-module.
agentzh
commented on June 21, 2024
Thank you for the valgrind output!
Could you also use "error_log /dev/kmsg debug;" and paste out all the debug logs in your error.log right before the crash?
from lua-nginx-module.
sztanpet
commented on June 21, 2024
[07:37](/home/sztanpet/openresty/nginx/sbin)# dmesg -c
[7508426.898105] 2012/06/24 07:37:30 [debug] 23293#0: epoll add event: fd:6 op:1 ev:00000001
[7508427.015612] 2012/06/24 07:37:30 [debug] 23293#0: accept on 0.0.0.0:81, ready: 0
[7508427.021222] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0270:56
[7508427.021918] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D02F0:16
[7508427.021964] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0340:16
[7508427.022855] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0390:48
[7508427.022901] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0400:16
[7508427.026293] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0450:15
[7508427.026340] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D04A0:16
[7508427.028269] 2012/06/24 07:37:30 [debug] 23293#0: *1 accept: 192.168.1.2 fd:7
[7508427.029309] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D04F0:24
[7508427.029360] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0550:16
[7508427.035755] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer add: 7: 60000:1340516310527
[7508427.038170] 2012/06/24 07:37:30 [debug] 23293#0: *1 epoll add event: fd:7 op:1 ev:80000001
[7508427.041644] 2012/06/24 07:37:30 [debug] 23293#0: accept on 0.0.0.0:81, ready: 0
[7508427.041735] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D05A0:56
[7508427.041780] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0620:16
[7508427.041821] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0670:16
[7508427.041867] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D06C0:48
[7508427.041907] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0730:16
[7508427.041952] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0780:15
[7508427.041992] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D07D0:16
[7508427.042044] 2012/06/24 07:37:30 [debug] 23293#0: *2 accept: 192.168.1.2 fd:8
[7508427.042086] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0820:24
[7508427.042126] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069D0880:16
[7508427.042172] 2012/06/24 07:37:30 [debug] 23293#0: *2 event timer add: 8: 60000:1340516310527
[7508427.044193] 2012/06/24 07:37:30 [debug] 23293#0: *2 epoll add event: fd:8 op:1 ev:80000001
[7508427.045360] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D08D0:48
[7508427.045410] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D0940:16
[7508427.046160] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D0990:1264
[7508427.046210] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D0EC0:16
[7508427.049749] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D0F10:80
[7508427.049800] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D0FA0:16
[7508427.050439] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D0FF0:1024
[7508427.050488] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1430:16
[7508427.052349] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1480:56
[7508427.053137] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1500:960
[7508427.053187] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1900:16
[7508427.054527] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1950:432
[7508427.054577] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1B40:16
[7508427.055264] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1B90:384
[7508427.055313] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1D50:16
[7508427.058406] 2012/06/24 07:37:30 [debug] 23293#0: *1 http process request line
[7508427.062008] 2012/06/24 07:37:30 [debug] 23293#0: *1 recv: fd:7 502 of 1024
[7508427.079218] 2012/06/24 07:37:30 [debug] 23293#0: *1 http request line: "GET /vote?questionid=1&answerid=1 HTTP/1.1"
[7508427.079667] 2012/06/24 07:37:30 [debug] 23293#0: *1 http uri: "/vote"
[7508427.080149] 2012/06/24 07:37:30 [debug] 23293#0: *1 http args: "questionid=1&answerid=1"
[7508427.080597] 2012/06/24 07:37:30 [debug] 23293#0: *1 http exten: ""
[7508427.081474] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D1DA0:960
[7508427.081529] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D21A0:16
[7508427.082483] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D21F0:16
[7508427.082532] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2240:16
[7508427.084171] 2012/06/24 07:37:30 [debug] 23293#0: *1 http process request header line
[7508427.094501] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2290:4
[7508427.094552] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D22E0:16
[7508427.100951] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2330:17
[7508427.101001] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2390:16
[7508427.103019] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "Host: sztanpet.local:81"
[7508427.103206] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D23E0:10
[7508427.103253] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2430:16
[7508427.106726] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "Connection: keep-alive"
[7508427.106797] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2480:13
[7508427.106843] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D24D0:16
[7508427.107453] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "Cache-Control: max-age=0"
[7508427.108480] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2520:10
[7508427.108528] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2570:16
[7508427.113747] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "User-Agent: Mozilla/5.0 (Windows NT 6.0; WOW64) AppleWebKit/536.11 (KHTML, like Gecko) Chrome/20.0.1132.42 Safari/536.11"
[7508427.113828] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D25C0:6
[7508427.113873] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2610:16
[7508427.114169] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
[7508427.114236] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2660:15
[7508427.114281] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D26B0:16
[7508427.114898] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "Accept-Encoding: gzip,deflate,sdch"
[7508427.114969] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2700:15
[7508427.115015] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2750:16
[7508427.115057] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "Accept-Language: en,en-GB;q=0.8,en-US;q=0.6,hu;q=0.4"
[7508427.115114] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D27A0:14
[7508427.115158] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D27F0:16
[7508427.115403] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "Accept-Charset: UTF-8,*;q=0.5"
[7508427.115472] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2840:6
[7508427.115517] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2890:16
[7508427.116463] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header: "Cookie: PHPSESSID=765bd360856d75587bb50be68e0f6126; vote-1=1"
[7508427.118063] 2012/06/24 07:37:30 [debug] 23293#0: *1 http header done
[7508427.122529] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer del: 7: 1340516310527
[7508427.129206] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 0
[7508427.131056] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 1
[7508427.135416] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "/"
[7508427.137700] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "redis"
[7508427.138040] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "vote"
[7508427.141255] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: ~ "\.php$"
[7508427.155527] 2012/06/24 07:37:30 [debug] 23293#0: *1 using configuration "/vote"
[7508427.161405] 2012/06/24 07:37:30 [debug] 23293#0: *1 http cl:-1 max:1048576
[7508427.162026] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 3
[7508427.162068] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 4
[7508427.162721] 2012/06/24 07:37:30 [debug] 23293#0: *1 post rewrite phase: 5
[7508427.163831] 2012/06/24 07:37:30 [debug] 23293#0: *1 generic phase: 6
[7508427.165430] 2012/06/24 07:37:30 [debug] 23293#0: *1 generic phase: 7
[7508427.167087] 2012/06/24 07:37:30 [debug] 23293#0: *1 access phase: 8
[7508427.168370] 2012/06/24 07:37:30 [debug] 23293#0: *1 access phase: 9
[7508427.169316] 2012/06/24 07:37:30 [debug] 23293#0: *1 access phase: 10
[7508427.170640] 2012/06/24 07:37:30 [debug] 23293#0: *1 post access phase: 11
[7508427.172230] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua content handler, uri "/vote"
[7508427.173238] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D28E0:280
[7508427.173289] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2A40:16
[7508427.176755] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2A90:35
[7508427.176804] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069D2B00:16
[7508427.375530] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua reset ctx
[7508427.378328] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua creating new thread
[7508427.394657] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DD6B0:24
[7508427.394708] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DD710:16
[7508427.395709] 2012/06/24 07:37:30 [debug] 23293#0: *1 http cleanup add: 00000000069DD6B0
[7508427.397396] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run thread
[7508427.408263] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DD8C0:23
[7508427.408315] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DD920:16
[7508427.421105] 2012/06/24 07:37:30 [debug] 23293#0: *1 free: 00000000069DD8C0
[7508427.436085] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DE080:13
[7508427.436138] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DE0D0:16
[7508427.439666] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DE120:31
[7508427.439716] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DE180:16
[7508427.453245] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DE1D0:11
[7508427.453297] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069DE220:16
[7508427.588060] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E3D70:32
[7508427.588115] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E3DD0:16
[7508427.598562] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E3FC0:48
[7508427.598612] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4030:16
[7508427.599651] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4080:80
[7508427.599700] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4110:16
[7508427.599750] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4160:96
[7508427.599795] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4200:16
[7508427.601123] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4250:16
[7508427.601172] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E42A0:16
[7508427.603551] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E42F0:8
[7508427.603600] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4340:16
[7508427.607860] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4390:16
[7508427.607910] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E43E0:16
[7508427.608489] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4430:280
[7508427.608537] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4590:16
[7508427.610444] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E45E0:1264
[7508427.610494] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4B10:16
[7508427.611101] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4B60:432
[7508427.611151] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4D50:16
[7508427.611967] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E4DA0:960
[7508427.612016] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E51A0:16
[7508427.615970] 2012/06/24 07:37:30 [debug] 23293#0: *1 http subrequest "/redis?2"
[7508427.619518] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E51F0:24
[7508427.619570] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5250:16
[7508427.622663] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E52A0:16
[7508427.622715] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E52F0:16
[7508427.626267] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5340:960
[7508427.626317] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5740:16
[7508427.628105] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5790:14
[7508427.628154] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E57E0:16
[7508427.629338] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5830:20
[7508427.629387] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5890:16
[7508427.634963] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E58E0:384
[7508427.635013] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5AA0:16
[7508427.639161] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua resume returned 1
[7508427.640203] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua thread yielded
[7508427.644048] 2012/06/24 07:37:30 [debug] 23293#0: *1 http finalize request: -4, "/vote?questionid=1&answerid=1" a:0, c:3
[7508427.645866] 2012/06/24 07:37:30 [debug] 23293#0: *1 http request count:3 blk:0
[7508427.648856] 2012/06/24 07:37:30 [debug] 23293#0: *1 http posted request: "/redis?2"
[7508427.650131] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 0
[7508427.650174] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 1
[7508427.650217] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "/"
[7508427.650256] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "redis"
[7508427.650298] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: ~ "\.php$"
[7508427.650358] 2012/06/24 07:37:30 [debug] 23293#0: *1 using configuration "/redis"
[7508427.650579] 2012/06/24 07:37:30 [debug] 23293#0: *1 http cl:96 max:1048576
[7508427.651140] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 3
[7508427.651180] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 4
[7508427.651219] 2012/06/24 07:37:30 [debug] 23293#0: *1 post rewrite phase: 5
[7508427.651264] 2012/06/24 07:37:30 [debug] 23293#0: *1 generic phase: 6
[7508427.651306] 2012/06/24 07:37:30 [debug] 23293#0: *1 generic phase: 7
[7508427.653611] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5AF0:832
[7508427.653664] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5E70:16
[7508427.655562] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5EC0:64
[7508427.655612] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5F40:16
[7508427.657313] 2012/06/24 07:37:30 [debug] 23293#0: *1 http init upstream, client timer: 0
[7508427.659103] 2012/06/24 07:37:30 [debug] 23293#0: *1 epoll add event: fd:7 op:3 ev:80000005
[7508427.667717] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E5F90:96
[7508427.667767] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6030:16
[7508427.672025] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6080:96
[7508427.672075] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6120:16
[7508427.676084] 2012/06/24 07:37:30 [debug] 23293#0: *1 http script var: "*3
[7508427.676087] $7
[7508427.676088] hexists
[7508427.676089] $10
[7508427.676090] question_1
[7508427.676090] $1
[7508427.676091] 1
[7508427.676092] *3
[7508427.676093] $4
[7508427.676094] sadd
[7508427.676095] $16
[7508427.676096] ipset_question_1
[7508427.676097] $11
[7508427.676097] 192.168.1.2
[7508427.676098] "
[7508427.678707] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6170:1
[7508427.678760] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E61C0:16
[7508427.678805] 2012/06/24 07:37:30 [debug] 23293#0: *1 http script var: "2"
[7508427.680087] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6210:80
[7508427.680138] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E62A0:16
[7508427.680189] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E62F0:96
[7508427.680234] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6390:16
[7508427.681171] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E63E0:16
[7508427.681220] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6430:16
[7508427.682093] 2012/06/24 07:37:30 [debug] 23293#0: *1 http redis2 request: ""
[7508427.683874] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6480:40
[7508427.683924] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E64F0:16
[7508427.683984] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6540:56
[7508427.684029] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E65C0:16
[7508427.684747] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6610:24
[7508427.684796] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6670:16
[7508427.684836] 2012/06/24 07:37:30 [debug] 23293#0: *1 http cleanup add: 00000000069E6610
[7508427.686488] 2012/06/24 07:37:30 [debug] 23293#0: *1 init keepalive peer
[7508427.686902] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E66C0:64
[7508427.686950] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6740:16
[7508427.688056] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6790:32
[7508427.688104] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E67F0:16
[7508427.694497] 2012/06/24 07:37:30 [debug] 23293#0: *1 get keepalive peer
[7508427.695829] 2012/06/24 07:37:30 [debug] 23293#0: *1 get rr peer, try: 1
[7508427.698892] 2012/06/24 07:37:30 [debug] 23293#0: *1 socket 9
[7508427.703747] 2012/06/24 07:37:30 [debug] 23293#0: *1 epoll add connection: fd:9 ev:80000005
[7508427.705274] 2012/06/24 07:37:30 [debug] 23293#0: *1 connect to 127.0.0.1:6379, fd:9 #3
[7508427.708320] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream connect: -2
[7508427.713296] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer add: 9: 60000:1340516310527
[7508427.714893] 2012/06/24 07:37:30 [debug] 23293#0: *1 http finalize request: -4, "/redis?2" a:1, c:3
[7508427.714937] 2012/06/24 07:37:30 [debug] 23293#0: *1 http request count:3 blk:0
[7508427.716139] 2012/06/24 07:37:30 [debug] 23293#0: accept on 0.0.0.0:81, ready: 0
[7508427.716243] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E6840:56
[7508427.716290] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E68C0:16
[7508427.716331] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E6910:16
[7508427.716377] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E6960:48
[7508427.716416] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E69D0:16
[7508427.716463] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E6A20:15
[7508427.716502] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E6A70:16
[7508427.716556] 2012/06/24 07:37:30 [debug] 23293#0: *4 accept: 192.168.1.2 fd:10
[7508427.716599] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E6AC0:24
[7508427.716639] 2012/06/24 07:37:30 [debug] 23293#0: malloc: 00000000069E6B20:16
[7508427.716686] 2012/06/24 07:37:30 [debug] 23293#0: *4 event timer add: 10: 60000:1340516310527
[7508427.719373] 2012/06/24 07:37:30 [debug] 23293#0: *4 epoll add event: fd:10 op:1 ev:80000001
[7508427.721535] 2012/06/24 07:37:30 [debug] 23293#0: *1 http run request: "/redis?2"
[7508427.722972] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream check client, write event:1, "/redis"
[7508427.727861] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream recv(): -1 (11: Resource temporarily unavailable)
[7508427.730451] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream request: "/redis?2"
[7508427.731845] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream send request handler
[7508427.733498] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream send request
[7508427.740650] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer buf fl:0 s:96
[7508427.741118] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6B70:16
[7508427.741167] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6BC0:16
[7508427.742260] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer in: 00000000069E6B70
[7508427.751094] 2012/06/24 07:37:30 [debug] 23293#0: *1 writev: 96
[7508427.754873] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer out: 0000000000000000
[7508427.757041] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer del: 9: 1340516310527
[7508427.762493] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer add: 9: 60000:1340516310527
[7508427.764553] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream request: "/redis?2"
[7508427.765721] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream process header
[7508427.766913] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E6C10:4096
[7508427.766964] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E7C50:16
[7508427.768463] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E7CA0:384
[7508427.768513] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E7E60:16
[7508427.769946] 2012/06/24 07:37:30 [debug] 23293#0: *1 recv: fd:9 8 of 4096
[7508427.777775] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture header filter, uri "/redis"
[7508427.779279] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capturing response body
[7508427.783271] 2012/06/24 07:37:30 [debug] 23293#0: *1 tcp_nodelay
[7508427.789139] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E7EB0:16
[7508427.789191] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E7F00:16
[7508427.789749] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E7F50:80
[7508427.789805] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E7FE0:16
[7508427.794222] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream process non buffered downstream
[7508427.796220] 2012/06/24 07:37:30 [debug] 23293#0: *1 http output filter "/redis?2"
[7508427.797800] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: "/redis?2"
[7508427.798524] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8030:104
[7508427.798573] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E80E0:16
[7508427.805003] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter, uri "/redis"
[7508427.806649] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter capturing response body, uri "/redis"
[7508427.809651] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8130:16
[7508427.809701] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8180:16
[7508427.810287] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua allocate new chainlink and new buf of size 8, cl:00000000069E8130
[7508427.810713] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E81D0:80
[7508427.810761] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8260:16
[7508427.810811] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E82B0:8
[7508427.810855] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8300:16
[7508427.816486] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: 0 "/redis?2"
[7508427.821209] 2012/06/24 07:37:30 [debug] 23293#0: *1 finalize http upstream request: 0
[7508427.823632] 2012/06/24 07:37:30 [debug] 23293#0: *1 finalize http redis2 request
[7508427.825104] 2012/06/24 07:37:30 [debug] 23293#0: *1 free keepalive peer
[7508427.828573] 2012/06/24 07:37:30 [debug] 23293#0: *1 free keepalive peer: saving connection 00000000068403F0
[7508427.830988] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer del: 9: 1340516310527
[7508427.836918] 2012/06/24 07:37:30 [debug] 23293#0: *1 free rr peer 1 0
[7508427.839792] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8350:80
[7508427.839842] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E83E0:16
[7508427.841321] 2012/06/24 07:37:30 [debug] 23293#0: *1 http output filter "/redis?2"
[7508427.841364] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: "/redis?2"
[7508427.842381] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter, uri "/redis"
[7508427.842425] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter capturing response body, uri "/redis"
[7508427.843504] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: 0 "/redis?2"
[7508427.844275] 2012/06/24 07:37:30 [debug] 23293#0: *1 http finalize request: 0, "/redis?2" a:1, c:2
[7508427.846437] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run post subrequest handler: rc:0, waiting:0, done:0
[7508427.848877] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua restoring write event handler
[7508427.851270] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8430:8
[7508427.851319] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8480:16
[7508427.857194] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E84D0:16
[7508427.857244] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E8520:16
[7508427.857804] 2012/06/24 07:37:30 [debug] 23293#0: *1 http wake parent request: "/vote?questionid=1&answerid=1"
[7508427.859429] 2012/06/24 07:37:30 [debug] 23293#0: *1 http posted request: "/vote?questionid=1&answerid=1"
[7508427.860608] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run write event handler
[7508427.864349] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run subrequests done, resuming lua thread
[7508427.865415] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua handle subrequest responses
[7508427.868359] 2012/06/24 07:37:30 [debug] 23293#0: *1 free: 00000000069E8430
[7508427.872748] 2012/06/24 07:37:30 [debug] 23293#0: *1 free: 00000000069E3D70
[7508427.873481] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run thread
[7508427.890858] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9070:11
[7508427.890910] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E90C0:16
[7508427.891238] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9110:54
[7508427.891285] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9190:16
[7508427.893592] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E91E0:10
[7508427.893641] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9230:16
[7508427.896445] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9B50:32
[7508427.896495] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9BB0:16
[7508427.896602] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9C00:48
[7508427.896647] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9C70:16
[7508427.896697] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9CC0:80
[7508427.896741] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9D50:16
[7508427.896788] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9DA0:137
[7508427.896832] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9E70:16
[7508427.896880] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9EC0:16
[7508427.896923] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9F10:16
[7508427.896975] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9F60:8
[7508427.897020] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069E9FB0:16
[7508427.897087] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EA000:16
[7508427.897132] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EA050:16
[7508427.897178] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EA0A0:280
[7508427.897221] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EA200:16
[7508427.897273] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EA250:1264
[7508427.897316] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EA780:16
[7508427.897369] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EA7D0:432
[7508427.897412] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EA9C0:16
[7508427.897461] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EAA10:960
[7508427.897505] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EAE10:16
[7508427.897547] 2012/06/24 07:37:30 [debug] 23293#0: *1 http subrequest "/redis?3"
[7508427.897598] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EAE60:24
[7508427.897641] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EAEC0:16
[7508427.897688] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EAF10:16
[7508427.897731] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EAF60:16
[7508427.897787] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EAFB0:960
[7508427.897831] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EB3B0:16
[7508427.897879] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EB400:14
[7508427.897922] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EB450:16
[7508427.897972] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EB4A0:20
[7508427.898015] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EB500:16
[7508427.898083] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EB550:384
[7508427.898127] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EB710:16
[7508427.898177] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua resume returned 1
[7508427.898210] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua thread yielded
[7508427.899022] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run thread returned -2
[7508427.899533] 2012/06/24 07:37:30 [debug] 23293#0: *1 http posted request: "/redis?3"
[7508427.899576] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 0
[7508427.899615] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 1
[7508427.899656] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "/"
[7508427.899695] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "redis"
[7508427.899737] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: ~ "\.php$"
[7508427.899794] 2012/06/24 07:37:30 [debug] 23293#0: *1 using configuration "/redis"
[7508427.899837] 2012/06/24 07:37:30 [debug] 23293#0: *1 http cl:137 max:1048576
[7508427.899873] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 3
[7508427.899910] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 4
[7508427.899947] 2012/06/24 07:37:30 [debug] 23293#0: *1 post rewrite phase: 5
[7508427.899982] 2012/06/24 07:37:30 [debug] 23293#0: *1 generic phase: 6
[7508427.900062] 2012/06/24 07:37:30 [debug] 23293#0: *1 generic phase: 7
[7508427.900130] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EB760:832
[7508427.900177] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBAE0:16
[7508427.900233] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBB30:64
[7508427.900277] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBBB0:16
[7508427.900317] 2012/06/24 07:37:30 [debug] 23293#0: *1 http init upstream, client timer: 0
[7508427.900384] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBC00:137
[7508427.900427] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBCD0:16
[7508427.900480] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBD20:137
[7508427.900524] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBDF0:16
[7508427.900574] 2012/06/24 07:37:30 [debug] 23293#0: *1 http script var: "*3
[7508427.900576] $4
[7508427.900577] sadd
[7508427.900578] $16
[7508427.900579] ipset_question_1
[7508427.900580] $11
[7508427.900581] 192.168.1.2
[7508427.900581] *4
[7508427.900582] $7
[7508427.900583] hincrby
[7508427.900584] $10
[7508427.900585] question_1
[7508427.900586] $1
[7508427.900587] 1
[7508427.900587] $1
[7508427.900588] 1
[7508427.900589] *2
[7508427.900590] $7
[7508427.900591] hgetall
[7508427.900592] $10
[7508427.900593] question_1
[7508427.900594] "
[7508427.900651] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBE40:1
[7508427.900694] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBE90:16
[7508427.900733] 2012/06/24 07:37:30 [debug] 23293#0: *1 http script var: "3"
[7508427.900784] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBEE0:80
[7508427.900827] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBF70:16
[7508427.900884] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EBFC0:137
[7508427.900928] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC090:16
[7508427.900976] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC0E0:16
[7508427.901019] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC130:16
[7508427.901056] 2012/06/24 07:37:30 [debug] 23293#0: *1 http redis2 request: ""
[7508427.901102] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC180:40
[7508427.901145] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC1F0:16
[7508427.901190] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC240:56
[7508427.901232] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC2C0:16
[7508427.901278] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC310:24
[7508427.901322] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC370:16
[7508427.901360] 2012/06/24 07:37:30 [debug] 23293#0: *1 http cleanup add: 00000000069EC310
[7508427.901395] 2012/06/24 07:37:30 [debug] 23293#0: *1 init keepalive peer
[7508427.901439] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC3C0:64
[7508427.901482] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC440:16
[7508427.901529] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC490:32
[7508427.901572] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC4F0:16
[7508427.901616] 2012/06/24 07:37:30 [debug] 23293#0: *1 get keepalive peer
[7508427.903479] 2012/06/24 07:37:30 [debug] 23293#0: *1 get keepalive peer: using connection 00000000068403F0
[7508427.904752] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream connect: -4
[7508427.905510] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream send request
[7508427.905572] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer buf fl:0 s:137
[7508427.905632] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC540:16
[7508427.905678] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC590:16
[7508427.905717] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer in: 00000000069EC540
[7508427.905821] 2012/06/24 07:37:30 [debug] 23293#0: *1 writev: 137
[7508427.905865] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer out: 0000000000000000
[7508427.905917] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer add: 9: 60000:1340516310527
[7508427.906551] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream process header
[7508427.906623] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EC5E0:4096
[7508427.906675] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069ED620:16
[7508427.906725] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069ED670:384
[7508427.906769] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069ED830:16
[7508427.906843] 2012/06/24 07:37:30 [debug] 23293#0: *1 recv: fd:9 26 of 4096
[7508427.906897] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture header filter, uri "/redis"
[7508427.906931] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capturing response body
[7508427.907290] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069ED880:16
[7508427.907338] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069ED8D0:16
[7508427.907385] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069ED920:80
[7508427.907429] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069ED9B0:16
[7508427.921818] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream process non buffered downstream
[7508427.921863] 2012/06/24 07:37:30 [debug] 23293#0: *1 http output filter "/redis?3"
[7508427.921901] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: "/redis?3"
[7508427.921959] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDA00:104
[7508427.922003] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDAB0:16
[7508427.922056] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter, uri "/redis"
[7508427.922096] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter capturing response body, uri "/redis"
[7508427.923679] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua reuse free buf chain, but reallocate memory because 26 >= 8, cl:00000000069E8130, p:00000000069E82B0
[7508427.924474] 2012/06/24 07:37:30 [debug] 23293#0: *1 free: 00000000069E82B0
[7508427.924949] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDB00:26
[7508427.924997] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDB60:16
[7508427.925948] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: 0 "/redis?3"
[7508427.925996] 2012/06/24 07:37:30 [debug] 23293#0: *1 finalize http upstream request: 0
[7508427.926033] 2012/06/24 07:37:30 [debug] 23293#0: *1 finalize http redis2 request
[7508427.926066] 2012/06/24 07:37:30 [debug] 23293#0: *1 free keepalive peer
[7508427.926114] 2012/06/24 07:37:30 [debug] 23293#0: *1 free keepalive peer: saving connection 00000000068403F0
[7508427.926157] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer del: 9: 1340516310527
[7508427.926218] 2012/06/24 07:37:30 [debug] 23293#0: *1 free rr peer 1 0
[7508427.926277] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDBB0:80
[7508427.926322] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDC40:16
[7508427.926363] 2012/06/24 07:37:30 [debug] 23293#0: *1 http output filter "/redis?3"
[7508427.926399] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: "/redis?3"
[7508427.926439] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter, uri "/redis"
[7508427.926479] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter capturing response body, uri "/redis"
[7508427.926523] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: 0 "/redis?3"
[7508427.926568] 2012/06/24 07:37:30 [debug] 23293#0: *1 http finalize request: 0, "/redis?3" a:1, c:3
[7508427.926613] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run post subrequest handler: rc:0, waiting:0, done:0
[7508427.926649] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua restoring write event handler
[7508427.926698] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDC90:26
[7508427.926743] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDCF0:16
[7508427.926803] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDD40:16
[7508427.926847] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EDD90:16
[7508427.926887] 2012/06/24 07:37:30 [debug] 23293#0: *1 http wake parent request: "/vote?questionid=1&answerid=1"
[7508427.927313] 2012/06/24 07:37:30 [debug] 23293#0: *1 http finalize request: -4, "/redis?3" a:0, c:2
[7508427.927355] 2012/06/24 07:37:30 [debug] 23293#0: *1 http request count:2 blk:0
[7508427.927397] 2012/06/24 07:37:30 [debug] 23293#0: *1 http posted request: "/vote?questionid=1&answerid=1"
[7508427.927431] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run write event handler
[7508427.927471] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run subrequests done, resuming lua thread
[7508427.927506] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua handle subrequest responses
[7508427.927657] 2012/06/24 07:37:30 [debug] 23293#0: *1 free: 00000000069EDC90
[7508427.927791] 2012/06/24 07:37:30 [debug] 23293#0: *1 free: 00000000069E9B50
[7508427.927834] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run thread
[7508427.938021] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EEEC0:32
[7508427.938073] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EEF20:16
[7508427.938180] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EEF70:48
[7508427.938237] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EEFE0:16
[7508427.938288] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF030:80
[7508427.938332] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF0C0:16
[7508427.938379] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF110:83
[7508427.938422] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF1B0:16
[7508427.938470] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF200:16
[7508427.938514] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF250:16
[7508427.938566] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF2A0:8
[7508427.938610] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF2F0:16
[7508427.938664] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF340:16
[7508427.938708] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF390:16
[7508427.938755] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF3E0:280
[7508427.938798] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF540:16
[7508427.938850] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EF590:1264
[7508427.938893] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EFAC0:16
[7508427.938945] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EFB10:432
[7508427.938989] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EFD00:16
[7508427.939088] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069EFD50:960
[7508427.939133] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0150:16
[7508427.939176] 2012/06/24 07:37:30 [debug] 23293#0: *1 http subrequest "/redis?2"
[7508427.939226] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F01A0:24
[7508427.939270] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0200:16
[7508427.939317] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0250:16
[7508427.939360] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F02A0:16
[7508427.939411] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F02F0:960
[7508427.939454] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F06F0:16
[7508427.939503] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0740:14
[7508427.939546] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0790:16
[7508427.939597] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F07E0:20
[7508427.939640] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0840:16
[7508427.939708] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0890:384
[7508427.939752] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0A50:16
[7508427.939811] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua resume returned 1
[7508427.939844] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua thread yielded
[7508427.939881] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run thread returned -2
[7508427.939919] 2012/06/24 07:37:30 [debug] 23293#0: *1 http posted request: "/redis?2"
[7508427.939958] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 0
[7508427.940023] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 1
[7508427.940079] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "/"
[7508427.940118] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: "redis"
[7508427.940159] 2012/06/24 07:37:30 [debug] 23293#0: *1 test location: ~ "\.php$"
[7508427.940215] 2012/06/24 07:37:30 [debug] 23293#0: *1 using configuration "/redis"
[7508427.940258] 2012/06/24 07:37:30 [debug] 23293#0: *1 http cl:83 max:1048576
[7508427.940294] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 3
[7508427.940330] 2012/06/24 07:37:30 [debug] 23293#0: *1 rewrite phase: 4
[7508427.940367] 2012/06/24 07:37:30 [debug] 23293#0: *1 post rewrite phase: 5
[7508427.940402] 2012/06/24 07:37:30 [debug] 23293#0: *1 generic phase: 6
[7508427.940439] 2012/06/24 07:37:30 [debug] 23293#0: *1 generic phase: 7
[7508427.940499] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0AA0:832
[7508427.940544] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0E20:16
[7508427.940597] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0E70:64
[7508427.940640] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0EF0:16
[7508427.940680] 2012/06/24 07:37:30 [debug] 23293#0: *1 http init upstream, client timer: 0
[7508427.940745] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0F40:83
[7508427.940796] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F0FE0:16
[7508427.940847] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1030:83
[7508427.940891] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F10D0:16
[7508427.940938] 2012/06/24 07:37:30 [debug] 23293#0: *1 http script var: "*4
[7508427.940940] $7
[7508427.940941] hincrby
[7508427.940942] $10
[7508427.940943] question_1
[7508427.940944] $1
[7508427.940944] 1
[7508427.940945] $2
[7508427.940946] -1
[7508427.940947] *2
[7508427.940948] $7
[7508427.940949] hgetall
[7508427.940950] $10
[7508427.940951] question_1
[7508427.940952] "
[7508427.941008] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1120:1
[7508427.941051] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1170:16
[7508427.941090] 2012/06/24 07:37:30 [debug] 23293#0: *1 http script var: "2"
[7508427.941141] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F11C0:80
[7508427.941184] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1250:16
[7508427.941230] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F12A0:83
[7508427.941273] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1340:16
[7508427.941321] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1390:16
[7508427.941364] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F13E0:16
[7508427.941401] 2012/06/24 07:37:30 [debug] 23293#0: *1 http redis2 request: ""
[7508427.941446] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1430:40
[7508427.941489] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F14A0:16
[7508427.941534] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F14F0:56
[7508427.941577] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1570:16
[7508427.941623] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F15C0:24
[7508427.941666] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1620:16
[7508427.941705] 2012/06/24 07:37:30 [debug] 23293#0: *1 http cleanup add: 00000000069F15C0
[7508427.941739] 2012/06/24 07:37:30 [debug] 23293#0: *1 init keepalive peer
[7508427.941783] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1670:64
[7508427.941826] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F16F0:16
[7508427.941873] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1740:32
[7508427.941915] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F17A0:16
[7508427.941960] 2012/06/24 07:37:30 [debug] 23293#0: *1 get keepalive peer
[7508427.942001] 2012/06/24 07:37:30 [debug] 23293#0: *1 get keepalive peer: using connection 00000000068403F0
[7508427.942040] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream connect: -4
[7508427.942078] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream send request
[7508427.942131] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer buf fl:0 s:83
[7508427.942179] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F17F0:16
[7508427.942223] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1840:16
[7508427.942262] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer in: 00000000069F17F0
[7508427.942358] 2012/06/24 07:37:30 [debug] 23293#0: *1 writev: 83
[7508427.942401] 2012/06/24 07:37:30 [debug] 23293#0: *1 chain writer out: 0000000000000000
[7508427.942449] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer add: 9: 60000:1340516310527
[7508427.942489] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream process header
[7508427.942546] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F1890:4096
[7508427.942591] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F28D0:16
[7508427.942638] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2920:384
[7508427.942682] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2AE0:16
[7508427.942753] 2012/06/24 07:37:30 [debug] 23293#0: *1 recv: fd:9 22 of 4096
[7508427.942804] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture header filter, uri "/redis"
[7508427.942838] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capturing response body
[7508427.942903] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2B30:16
[7508427.942947] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2B80:16
[7508427.942993] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2BD0:80
[7508427.943036] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2C60:16
[7508427.943107] 2012/06/24 07:37:30 [debug] 23293#0: *1 http upstream process non buffered downstream
[7508427.943145] 2012/06/24 07:37:30 [debug] 23293#0: *1 http output filter "/redis?2"
[7508427.943182] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: "/redis?2"
[7508427.943230] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2CB0:104
[7508427.943274] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2D60:16
[7508427.943323] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter, uri "/redis"
[7508427.943364] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter capturing response body, uri "/redis"
[7508427.944088] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua reuse free buf memory 26 >= 22, cl:00000000069E8130, p:00000000069EDB00
[7508427.944498] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: 0 "/redis?2"
[7508427.944546] 2012/06/24 07:37:30 [debug] 23293#0: *1 finalize http upstream request: 0
[7508427.944583] 2012/06/24 07:37:30 [debug] 23293#0: *1 finalize http redis2 request
[7508427.944616] 2012/06/24 07:37:30 [debug] 23293#0: *1 free keepalive peer
[7508427.944662] 2012/06/24 07:37:30 [debug] 23293#0: *1 free keepalive peer: saving connection 00000000068403F0
[7508427.944706] 2012/06/24 07:37:30 [debug] 23293#0: *1 event timer del: 9: 1340516310527
[7508427.944765] 2012/06/24 07:37:30 [debug] 23293#0: *1 free rr peer 1 0
[7508427.944824] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2DB0:80
[7508427.944868] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2E40:16
[7508427.944909] 2012/06/24 07:37:30 [debug] 23293#0: *1 http output filter "/redis?2"
[7508427.944946] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: "/redis?2"
[7508427.944986] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter, uri "/redis"
[7508427.945025] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua capture body filter capturing response body, uri "/redis"
[7508427.945069] 2012/06/24 07:37:30 [debug] 23293#0: *1 http copy filter: 0 "/redis?2"
[7508427.945114] 2012/06/24 07:37:30 [debug] 23293#0: *1 http finalize request: 0, "/redis?2" a:1, c:3
[7508427.945159] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run post subrequest handler: rc:0, waiting:0, done:0
[7508427.945195] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua restoring write event handler
[7508427.945244] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2E90:22
[7508427.945287] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2EF0:16
[7508427.945348] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2F40:16
[7508427.945391] 2012/06/24 07:37:30 [debug] 23293#0: *1 malloc: 00000000069F2F90:16
[7508427.945431] 2012/06/24 07:37:30 [debug] 23293#0: *1 http wake parent request: "/vote?questionid=1&answerid=1"
[7508427.945481] 2012/06/24 07:37:30 [debug] 23293#0: *1 http finalize request: -4, "/redis?2" a:0, c:2
[7508427.945520] 2012/06/24 07:37:30 [debug] 23293#0: *1 http request count:2 blk:0
[7508427.945561] 2012/06/24 07:37:30 [debug] 23293#0: *1 http posted request: "/vote?questionid=1&answerid=1"
[7508427.945596] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run write event handler
[7508427.945635] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run subrequests done, resuming lua thread
[7508427.945669] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua handle subrequest responses
[7508427.945828] 2012/06/24 07:37:30 [debug] 23293#0: *1 free: 00000000069F2E90
[7508427.945950] 2012/06/24 07:37:30 [debug] 23293#0: *1 free: 00000000069EEEC0
[7508427.945993] 2012/06/24 07:37:30 [debug] 23293#0: *1 lua run thread
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hmm, I still need more information :P
So the crash happens on the ngx.print line in the following lines of
your Lua code?
local ret = {success = true, data = {}}
local reply = replies[3]
for i = 1, #reply, 2 do
ngx.print(reply[i], reply[i+1])
ret.data[ reply[i] ] = reply[i+1]
end
And could you try dumping out the reply[i] and reply[i+1] arguments using JSON?
Also, can you reproduce the crash with LuaJIT 2.0? You can enable
LuaJIT 2.0 in your ngx_openresty build by passing the --with-luajit
configure option, BTW.
Thanks!
-agentzh
from lua-nginx-module.
sztanpet
commented on June 21, 2024
yes, here is the valgrind output with luajit
[07:37](/home/sztanpet/openresty/nginx/sbin)# valgrind --leak-check=full ./nginx
==30156== Memcheck, a memory error detector
==30156== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al.
==30156== Using Valgrind-3.6.1 and LibVEX; rerun with -h for copyright info
==30156== Command: ./nginx
==30156==
==30156== Invalid read of size 4
==30156== at 0x54B7AF5: lj_str_new (lj_str.c:54)
==30156== by 0x54C035A: lua_pushlstring (lj_api.c:589)
==30156== by 0x4D84B0: ngx_http_lua_parse_args (ngx_http_lua_args.c:314)
==30156== by 0x4D7EBE: ngx_http_lua_ngx_req_get_uri_args (ngx_http_lua_args.c:120)
==30156== by 0x54B21E6: lj_BC_FUNCC (in /home/sztanpet/openresty/luajit/lib/libluajit-5.1.so.2.0.0)
==30156== by 0x4E131D: ngx_http_lua_run_thread (ngx_http_lua_util.c:775)
==30156== by 0x4E535F: ngx_http_lua_content_by_chunk (ngx_http_lua_contentby.c:93)
==30156== by 0x4E57EA: ngx_http_lua_content_handler_file (ngx_http_lua_contentby.c:247)
==30156== by 0x4E55B3: ngx_http_lua_content_handler (ngx_http_lua_contentby.c:176)
==30156== by 0x455F85: ngx_http_core_content_phase (ngx_http_core_module.c:1377)
==30156== by 0x454B6F: ngx_http_core_run_phases (ngx_http_core_module.c:872)
==30156== by 0x454AE6: ngx_http_handler (ngx_http_core_module.c:855)
==30156== Address 0x6e505e6 is 22 bytes inside a block of size 23 alloc'd
==30156== at 0x4C267CE: malloc (vg_replace_malloc.c:236)
==30156== by 0x442427: ngx_alloc (ngx_alloc.c:22)
==30156== by 0x41B582: ngx_malloc (ngx_palloc.c:119)
==30156== by 0x41B615: ngx_palloc (ngx_palloc.c:140)
==30156== by 0x4D7E42: ngx_http_lua_ngx_req_get_uri_args (ngx_http_lua_args.c:111)
==30156== by 0x54B21E6: lj_BC_FUNCC (in /home/sztanpet/openresty/luajit/lib/libluajit-5.1.so.2.0.0)
==30156== by 0x4E131D: ngx_http_lua_run_thread (ngx_http_lua_util.c:775)
==30156== by 0x4E535F: ngx_http_lua_content_by_chunk (ngx_http_lua_contentby.c:93)
==30156== by 0x4E57EA: ngx_http_lua_content_handler_file (ngx_http_lua_contentby.c:247)
==30156== by 0x4E55B3: ngx_http_lua_content_handler (ngx_http_lua_contentby.c:176)
==30156== by 0x455F85: ngx_http_core_content_phase (ngx_http_core_module.c:1377)
==30156== by 0x454B6F: ngx_http_core_run_phases (ngx_http_core_module.c:872)
==30156==
==30156== Conditional jump or move depends on uninitialised value(s)
==30156== at 0x54B7AF9: lj_str_new (lj_str.c:54)
==30156== by 0x54B8246: lj_str_fromnum (lj_str.c:281)
==30156== by 0x54BAADC: lj_meta_cat (lj_meta.c:233)
==30156== by 0x54B1284: lj_BC_CAT (in /home/sztanpet/openresty/luajit/lib/libluajit-5.1.so.2.0.0)
==30156== by 0x4E131D: ngx_http_lua_run_thread (ngx_http_lua_util.c:775)
==30156== by 0x4E535F: ngx_http_lua_content_by_chunk (ngx_http_lua_contentby.c:93)
==30156== by 0x4E57EA: ngx_http_lua_content_handler_file (ngx_http_lua_contentby.c:247)
==30156== by 0x4E55B3: ngx_http_lua_content_handler (ngx_http_lua_contentby.c:176)
==30156== by 0x455F85: ngx_http_core_content_phase (ngx_http_core_module.c:1377)
==30156== by 0x454B6F: ngx_http_core_run_phases (ngx_http_core_module.c:872)
==30156== by 0x454AE6: ngx_http_handler (ngx_http_core_module.c:855)
==30156== by 0x4627C5: ngx_http_process_request (ngx_http_request.c:1672)
==30156==
==30156== Conditional jump or move depends on uninitialised value(s)
==30156== at 0x54B7AF9: lj_str_new (lj_str.c:54)
==30156== by 0x54B8246: lj_str_fromnum (lj_str.c:281)
==30156== by 0x54C16B7: lua_tolstring (lj_api.c:439)
==30156== by 0x77CDD6B: redis_build_query (redis-parser.c:566)
==30156== by 0x54B21E6: lj_BC_FUNCC (in /home/sztanpet/openresty/luajit/lib/libluajit-5.1.so.2.0.0)
==30156== by 0x4E131D: ngx_http_lua_run_thread (ngx_http_lua_util.c:775)
==30156== by 0x4E535F: ngx_http_lua_content_by_chunk (ngx_http_lua_contentby.c:93)
==30156== by 0x4E57EA: ngx_http_lua_content_handler_file (ngx_http_lua_contentby.c:247)
==30156== by 0x4E55B3: ngx_http_lua_content_handler (ngx_http_lua_contentby.c:176)
==30156== by 0x455F85: ngx_http_core_content_phase (ngx_http_core_module.c:1377)
==30156== by 0x454B6F: ngx_http_core_run_phases (ngx_http_core_module.c:872)
==30156== by 0x454AE6: ngx_http_handler (ngx_http_core_module.c:855)
==30156==
==30156== Conditional jump or move depends on uninitialised value(s)
==30156== at 0x54B7AF9: lj_str_new (lj_str.c:54)
==30156== by 0x54B8246: lj_str_fromnum (lj_str.c:281)
==30156== by 0x54C18C7: luaL_checklstring (lj_api.c:458)
==30156== by 0x77CDEB3: redis_build_query (redis-parser.c:609)
==30156== by 0x54B21E6: lj_BC_FUNCC (in /home/sztanpet/openresty/luajit/lib/libluajit-5.1.so.2.0.0)
==30156== by 0x4E131D: ngx_http_lua_run_thread (ngx_http_lua_util.c:775)
==30156== by 0x4E535F: ngx_http_lua_content_by_chunk (ngx_http_lua_contentby.c:93)
==30156== by 0x4E57EA: ngx_http_lua_content_handler_file (ngx_http_lua_contentby.c:247)
==30156== by 0x4E55B3: ngx_http_lua_content_handler (ngx_http_lua_contentby.c:176)
==30156== by 0x455F85: ngx_http_core_content_phase (ngx_http_core_module.c:1377)
==30156== by 0x454B6F: ngx_http_core_run_phases (ngx_http_core_module.c:872)
==30156== by 0x454AE6: ngx_http_handler (ngx_http_core_module.c:855)
==30156==
==30156== Conditional jump or move depends on uninitialised value(s)
==30156== at 0x54B7AF9: lj_str_new (lj_str.c:54)
==30156== by 0x54B8246: lj_str_fromnum (lj_str.c:281)
==30156== by 0x54C16B7: lua_tolstring (lj_api.c:439)
==30156== by 0x54FFCEE: luaL_addvalue (lib_aux.c:175)
==30156== by 0x5504817: lj_cf_table_concat (lib_table.c:161)
==30156== by 0x54B21E6: lj_BC_FUNCC (in /home/sztanpet/openresty/luajit/lib/libluajit-5.1.so.2.0.0)
==30156== by 0x4E131D: ngx_http_lua_run_thread (ngx_http_lua_util.c:775)
==30156== by 0x4E2061: ngx_http_lua_wev_handler (ngx_http_lua_util.c:1191)
==30156== by 0x4E537E: ngx_http_lua_content_wev_handler (ngx_http_lua_contentby.c:100)
==30156== by 0x462CB1: ngx_http_run_posted_requests (ngx_http_request.c:1859)
==30156== by 0x4780F7: ngx_http_upstream_handler (ngx_http_upstream.c:921)
==30156== by 0x44A601: ngx_epoll_process_events (ngx_epoll_module.c:679)
==30156==
==30156== Conditional jump or move depends on uninitialised value(s)
==30156== at 0x54B7AF9: lj_str_new (lj_str.c:54)
==30156== by 0x54C035A: lua_pushlstring (lj_api.c:589)
==30156== by 0x4D0242: ngx_http_lua_handle_subreq_responses (ngx_http_lua_subrequest.c:1167)
==30156== by 0x4E1F70: ngx_http_lua_wev_handler (ngx_http_lua_util.c:1158)
==30156== by 0x4E537E: ngx_http_lua_content_wev_handler (ngx_http_lua_contentby.c:100)
==30156== by 0x462CB1: ngx_http_run_posted_requests (ngx_http_request.c:1859)
==30156== by 0x4780F7: ngx_http_upstream_handler (ngx_http_upstream.c:921)
==30156== by 0x44A601: ngx_epoll_process_events (ngx_epoll_module.c:679)
==30156== by 0x43B99B: ngx_process_events_and_timers (ngx_event.c:246)
==30156== by 0x447200: ngx_single_process_cycle (ngx_process_cycle.c:312)
==30156== by 0x4188C7: main (nginx.c:409)
==30156==
==30156==
==30156== HEAP SUMMARY:
==30156== in use at exit: 2,305,819 bytes in 6,024 blocks
==30156== total heap usage: 7,003 allocs, 979 frees, 2,439,809 bytes allocated
==30156==
==30156== 292 (52 direct, 240 indirect) bytes in 1 blocks are definitely lost in loss record 1,454 of 1,651
==30156== at 0x4C267CE: malloc (vg_replace_malloc.c:236)
==30156== by 0x67064CB: nss_parse_service_list (nsswitch.c:540)
==30156== by 0x6706CA5: __nss_database_lookup (nsswitch.c:134)
==30156== by 0x6F9732F: ???
==30156== by 0x6F98384: ???
==30156== by 0x66C555C: getpwnam_r@@GLIBC_2.2.5 (getXXbyYY_r.c:253)
==30156== by 0x66C4F3F: getpwnam (getXXbyYY.c:117)
==30156== by 0x41A05D: ngx_set_user (nginx.c:1147)
==30156== by 0x431EE3: ngx_conf_handler (ngx_conf_file.c:394)
==30156== by 0x431A77: ngx_conf_parse (ngx_conf_file.c:244)
==30156== by 0x42E626: ngx_init_cycle (ngx_cycle.c:268)
==30156== by 0x41862F: main (nginx.c:333)
==30156==
==30156== 292 (52 direct, 240 indirect) bytes in 1 blocks are definitely lost in loss record 1,455 of 1,651
==30156== at 0x4C267CE: malloc (vg_replace_malloc.c:236)
==30156== by 0x67064CB: nss_parse_service_list (nsswitch.c:540)
==30156== by 0x6706CA5: __nss_database_lookup (nsswitch.c:134)
==30156== by 0x6F9640F: ???
==30156== by 0x6F96EDC: ???
==30156== by 0x66C42AC: getgrnam_r@@GLIBC_2.2.5 (getXXbyYY_r.c:253)
==30156== by 0x66C385F: getgrnam (getXXbyYY.c:117)
==30156== by 0x41A0FA: ngx_set_user (nginx.c:1159)
==30156== by 0x431EE3: ngx_conf_handler (ngx_conf_file.c:394)
==30156== by 0x431A77: ngx_conf_parse (ngx_conf_file.c:244)
==30156== by 0x42E626: ngx_init_cycle (ngx_cycle.c:268)
==30156== by 0x41862F: main (nginx.c:333)
==30156==
==30156== LEAK SUMMARY:
==30156== definitely lost: 104 bytes in 2 blocks
==30156== indirectly lost: 480 bytes in 20 blocks
==30156== possibly lost: 0 bytes in 0 blocks
==30156== still reachable: 2,305,235 bytes in 6,002 blocks
==30156== suppressed: 0 bytes in 0 blocks
==30156== Reachable blocks (those to which a pointer was found) are not shown.
==30156== To see them, rerun with: --leak-check=full --show-reachable=yes
==30156==
==30156== For counts of detected and suppressed errors, rerun with: -v
==30156== Use --track-origins=yes to see where uninitialised values come from
==30156== ERROR SUMMARY: 18 errors from 8 contexts (suppressed: 7 from 7)
Aborted
and the json dump of reply[i] and reply[i+1] is the following
local json = require "cjson"
for i = 1, #reply, 2 do
--ngx.print(reply[i], reply[i+1])
ngx.say( json.encode( reply[i] ) )
ngx.say( json.encode( reply[i+1] ) )
ret.data[ reply[i] ] = reply[i+1]
end
with the following code, it does not segfault
and this is the output
["1","5"] -- this seems wrong, this should be the key, 1
5
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hello!
On Sun, Jun 24, 2012 at 2:09 PM, sztanpet
[email protected]
wrote:
yes, here is the valgrind output with luajit
[...]
==30156== ERROR SUMMARY: 18 errors from 8 contexts (suppressed: 7 from 7)
Aborted
Valgrind says the nginx process is aborted. Then there should be an
assertion failure in your nginx's error.log. Can you check it out?
Also, please use gdb to obtain the backtrace for this assertion failure. Thanks!
and the json dump of reply[i] and reply[i+1] is the following
local json = require "cjson"
for i = 1, #reply, 2 do
--ngx.print(reply[i], reply[i+1])
ngx.say( json.encode( reply[i] ) )
ngx.say( json.encode( reply[i+1] ) )
ret.data[ reply[i] ] = reply[i+1]
endwith the following code, it does not segfault
and this is the output["1","5"] -- this seems wrong, this should be the key, 1
5
Can you output the "replies" table with cjson.encode right after
calling parse_replies? That is, right after the line
local replies = parser.parse_replies(result.body, #requests)
Also, what is exactly in result.body? Can you output it as a string directly?
Thanks!
-agentzh
from lua-nginx-module.
sztanpet
commented on June 21, 2024
Program received signal SIGABRT, Aborted.
0x00007ffff62c0065 in *__GI_raise (sig=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
64 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
in ../nptl/sysdeps/unix/sysv/linux/raise.c
(gdb) bt
#0 0x00007ffff62c0065 in *__GI_raise (sig=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1 0x00007ffff62c12ff in *__GI_abort () at abort.c:92
#2 0x00007ffff62b91e1 in *__GI___assert_fail (assertion=0x7ffff7547e15 "(((t)->it) == (~11u))", file=<optimized out>,
line=833, function=0x7ffff7547bd0 "lua_next") at assert.c:81
#3 0x00007ffff74f7a51 in lua_next (L=0x4000c770, idx=<optimized out>) at lj_api.c:833
#4 0x00000000004d4708 in ngx_http_lua_calc_strlen_in_table (L=0x4000c770, arg_i=1, strict=0)
at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_output.c:253
#5 0x00000000004d4187 in ngx_http_lua_ngx_echo (L=0x4000c770, newline=0)
at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_output.c:108
#6 0x00000000004d3fb7 in ngx_http_lua_ngx_print (L=0x4000c770) at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_output.c:24
#7 0x00007ffff74e91e7 in lj_BC_FUNCC () from /home/sztanpet/openresty/luajit/lib/libluajit-5.1.so.2
#8 0x00000000004e131e in ngx_http_lua_run_thread (L=0x40000378, r=0x7a9ec0, ctx=0x7c40f0, nret=1)
at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_util.c:775
#9 0x00000000004e2062 in ngx_http_lua_wev_handler (r=0x7a9ec0) at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_util.c:1191
#10 0x00000000004e537f in ngx_http_lua_content_wev_handler (r=0x7a9ec0)
at ../ngx_lua-0.5.0rc30/src/ngx_http_lua_contentby.c:100
#11 0x0000000000462cb2 in ngx_http_run_posted_requests (c=0x7ffff7ecc0d0) at src/http/ngx_http_request.c:1859
#12 0x00000000004780f8 in ngx_http_upstream_handler (ev=0x7ffff7e63148) at src/http/ngx_http_upstream.c:921
#13 0x000000000044a602 in ngx_epoll_process_events (cycle=0x78d3f0, timer=18446744073709551615, flags=0)
at src/event/modules/ngx_epoll_module.c:679
#14 0x000000000043b99c in ngx_process_events_and_timers (cycle=0x78d3f0) at src/event/ngx_event.c:246
#15 0x0000000000447201 in ngx_single_process_cycle (cycle=0x78d3f0) at src/os/unix/ngx_process_cycle.c:312
#16 0x00000000004188c8 in main (argc=1, argv=0x7fffffffe2b8) at src/core/nginx.c:409
the result.body
:5
*2
$1
1
$1
5
the json.encode( replies )
[[5,3],[["1","5"],5]]
EDIT: the json encode right after parsing, and no, there is nothing extra in the error log, I can paste it again if you want
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hello!
On Sun, Jun 24, 2012 at 2:39 PM, sztanpet
[email protected]
wrote:
Program received signal SIGABRT, Aborted.
0x00007ffff62c0065 in *__GI_raise (sig=) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
64 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
in ../nptl/sysdeps/unix/sysv/linux/raise.c
(gdb) bt
#0 0x00007ffff62c0065 in *__GI_raise (sig=) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1 0x00007ffff62c12ff in *__GI_abort () at abort.c:92
#2 0x00007ffff62b91e1 in *__GI___assert_fail (assertion=0x7ffff7547e15 "(((t)->it) == (~11u))", file=,
line=833, function=0x7ffff7547bd0 "lua_next") at assert.c:81
#3 0x00007ffff74f7a51 in lua_next (L=0x4000c770, idx=) at lj_api.c:833
This backtrace is invaluable! I've just reproduced this on my side and
it is indeed a very silly bug. I'll fix it later today and send you a
new version to try :)
Thank you very much!
-agentzh
from lua-nginx-module.
sztanpet
commented on June 21, 2024
thanks for your time and the awesome software
was this issue related to what the ticket is about? :D
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hello!
On Sun, Jun 24, 2012 at 4:22 PM, sztanpet
[email protected]
wrote:
thanks for your time and the awesome software
was this issue related to what the ticket is about? :D
I don't think so. It's an issue in ngx.print()/ngx.say() when table
arguments are given.
Best regards,
-agentzh
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hello!
On Sun, Jun 24, 2012 at 4:16 PM, agentzh [email protected] wrote:
I've just reproduced this on my side and
it is indeed a very silly bug. I'll fix it later today and send you a
new version to try :)
I've just committed a patch for this issue to ngx_lua's git master branch:
https://github.com/chaoslawful/lua-nginx-module/commit/0178d4e
Could you please try out this patch (or the git master HEAD) on your
side? This fix will be included in the next version of ngx_lua and
ngx_openresty :)
Thanks!
-agentzh
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hello!
On Sun, Jun 24, 2012 at 10:05 PM, agentzh [email protected] wrote:
I've just committed a patch for this issue to ngx_lua's git master branch:
Could you please try out this patch (or the git master HEAD) on your
side? This fix will be included in the next version of ngx_lua and
ngx_openresty :)
To make your life easier, I've just put a new (rc) version of the
ngx_openresty tarball including the fix here for you to try:
http://agentzh.org/misc/nginx/ngx_openresty-1.2.1.3rc1.tar.gz
Thanks!
-agentzh
from lua-nginx-module.
sztanpet
commented on June 21, 2024
yes, the segfault is gone but this parsed response seems wrong for this body:
:5
*2
$1
1
$1
5
[[5,3],[["1","5"],5]]
is that table valid tho for the response? the parsing seems a bit off or my code is buggy, anyway that should probably be another ticket if its not on my end
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hello!
On Mon, Jun 25, 2012 at 12:01 AM, sztanpet
[email protected]
wrote:
yes, the segfault is gone but this parsed response seems wrong for this body:
:5
*2
$1
1
$1
5
[[5,3],[["1","5"],5]]is that table valid tho for the response?
Please provide a minimal example for this because it could be an issue
in your own Lua code :)
BTW, nowadays it's recommended to use the lua-resty-redis library that
is based on ngx_lua's cosocket API:
https://github.com/agentzh/lua-resty-redis
This is much simpler to use than the old approach you're using,
i.e., ngx.location.capture + ngx_redis2 + lua-redis-parser, and it's
also reported to be more efficient.
Best regards,
-agentzh
from lua-nginx-module.
sztanpet
commented on June 21, 2024
nope, nevermind it was on my end,
does lua-resty-redis support connection pools the same way location.capture does tho?
from lua-nginx-module.
agentzh
commented on June 21, 2024
Hello!
On Mon, Jun 25, 2012 at 1:33 PM, sztanpet
[email protected]
wrote:
does lua-resty-redis support connection pools the same way location.capture does tho?
Sure thing! Check out its set_keepalive method which puts the current
redis connection into the ngx_lua cosocket connection pools. It does
not use ngx_http_upstream_keepalive though. The ngx_lua module
implements its own.
Best regards,
-agentzh
from lua-nginx-module.
agentzh
commented on June 21, 2024
Consider it resolved.
from lua-nginx-module.
Related Issues (20)
- Why is global environment of each lua handler not isolated when OpenResty's LuaJIT is used?
- Lua code in header_filter phase still runs after ngx.exit(401) is executed in access phase HOT 3
- Shared dictionary cannot retrieve stale data HOT 1
- Content-Length header ignored for HEAD methods HOT 1
- In order to set the headers of the upstream request, I use `ngx.req.set_header` in `rewrite_by_lua_block`, but my upstream endpoint cannot receive such header. HOT 5
- How to share ctx in dfferent locations HOT 2
- http2 request failed HOT 3
- Is the dynamic module available precompiled? HOT 1
- Problem with post request reading in balancer_by_lua_block HOT 2
- huge size response via ngx.location.capture has been truncated HOT 1
- Search in POST request HOT 2
- issue use lua code beside modsecurity module HOT 2
- bug: the connection won't be closed normally when set arg[1] = "" HOT 1
- LUA_PATH must contain /usr/share/lua and /usr/lib/x86_64-linux-gnu/lua/
- the docs site doesn't reflect the updated features in the module
- time filter for shdict get_keys HOT 2
- Question on memory handling in shared_dict HOT 4
- conditional shm get, eagain HOT 3
- Aborting Nginx reload on condition HOT 1
- 500 Internal Server Error HOT 1
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from lua-nginx-module.