problem in writing handler module which should be called via ssi
Mauro Stettler
mauro.stettler at gmail.com
Fri Jul 23 11:13:50 MSD 2010
thanks for the tip
i did what you said and pushed the newest version of the code to
github. but i still haven't found the problem, it keeps behaving the
same way. in gdb the buffer which i am returning from my handler
function looks perfectly fine to me and its so simply that i can
hardly imagine that there is a problem:
Breakpoint 2, ngx_http_generate_secure_download_link_handler
(r=0x100860a18) at
src/http/modules/ngx_http_generate_secure_download_link//ngx_http_generate_secure_download_link.c:267
267 return ngx_http_output_filter(r,&out);
(gdb) print *out->buf
$3 = {
pos = 0x100861520
"/gen_sec_link/this_is_my_link/88bf88c2dfb3f5e71e4107711e749bea/4C49405B",
last = 0x100861567 "",
file_pos = 0,
file_last = 0,
start = 0x0,
end = 0x0,
tag = 0x0,
file = 0x0,
shadow = 0x0,
temporary = 0,
memory = 1,
mmap = 0,
recycled = 0,
in_file = 0,
flush = 0,
sync = 0,
last_buf = 1,
last_in_chain = 0,
last_shadow = 0,
temp_file = 0,
num = 0
}
(gdb) print out
$4 = {
buf = 0x1008614d0,
next = 0x0
}
looks like a perfectly fine buffer, no? or is there anything wrong
with that? i guess i will start debugging the ssi module to find out
what exactly is happening there.
mauro
On Thu, Jul 22, 2010 at 17:44, Weibin Yao <nbubingo at gmail.com> wrote:
> Mauro Stettler at 2010-7-22 16:06 wrote:
>>
>> thanks for the reply,
>>
>> i added the output of two requests to this mail. the first was working
>> perfectly, the nginx gave the browser the result back and then closed
>> the connection. in the second request the nginx also sent the result
>> back to the browser but did then not close the connection... to me it
>> seems like the problem happens if i refresh in very short time after i
>> requested a page already, which does not really make any sense to me.
>>
>> i have noticed one more thing when i looked at the network traffic in
>> wireshark. if i request a location with my module directly, which
>> works perfectly, the output that comes from the nginx looks just as
>> expected. but when i request a location with my module via ssi, there
>> are some strange non-ascii characters in the output... is it possible
>> that this is an ssi problem? that the ssi is maybe adding those
>> strange characters when it operates on the buffer chain? in the end of
>> the mail i also attached the output of the nginx in hex.
>>
>> good request
>> ---------------------------------------------------------------------------------------
>>
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http keepalive handler
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 malloc: 0000000100803A00:1024
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 recv: eof:0, avail:410, err:0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 recv: fd:7 410 of 1024
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 malloc: 0000000100810600:1248
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 malloc: 0000000100818200:4096
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http process request line
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http request line: "GET
>> /test.html HTTP/1.1"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http uri: "/test.html"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http args: ""
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http exten: "html"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http process request header line
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "Host:
>> localhost:8080"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "User-Agent:
>> Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.6; en-US; rv:1.9.2.7)
>> Gecko/20100713 Firefox/3.6.7"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "Accept:
>> text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "Accept-Language:
>> en-us,en;q=0.5"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "Accept-Encoding:
>> gzip,deflate"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "Accept-Charset:
>> ISO-8859-1,utf-8;q=0.7,*;q=0.7"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "Keep-Alive: 115"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "Connection:
>> keep-alive"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header: "Cache-Control:
>> max-age=0"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http header done
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 event timer del: 7: 1279785053298
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 generic phase: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 test location: "/"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 test location: "gen_sec_link"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 using configuration "/"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http cl:-1 max:1048576
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 generic phase: 2
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 post rewrite phase: 3
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 generic phase: 4
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 generic phase: 5
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 access phase: 6
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 access phase: 7
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 post access phase: 8
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 content phase: 9
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 content phase: 10
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 content phase: 11
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http filename:
>> "/usr/local/nginx/0.7.67-gsdl/html/test.html"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 add cleanup: 0000000100818BF8
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http static fd: 8
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http set discard body
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 HTTP/1.1 200 OK
>> Server: nginx/0.7.67
>> Date: Thu, 22 Jul 2010 07:49:50 GMT
>> Content-Type: text/html
>> Transfer-Encoding: chunked
>> Connection: keep-alive
>>
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:1 f:0
>> 0000000100818F60, pos 0000000100818F60, size: 155 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http write filter: l:0 f:0 s:155
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http output filter "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 copy filter: "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 read: 8, 00000001008190D0, 71, 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http ssi filter "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 saved: 0 state: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 malloc: 0000000100860A00:4096
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 parse: 0, looked: 0
>> 00000001008190D0-00000001008190E0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 saved: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 ssi flush
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 ssi out: 0000000100819198
>> 00000001008190D0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http postpone filter
>> "/test.html?" 00000001008191E8
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http chunk: 16
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write old buf t:1 f:0
>> 0000000100818F60, pos 0000000100818F60, size: 155 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:1 f:0
>> 0000000000000000, pos 0000000100860B80, size: 4 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:1 f:0
>> 00000001008190D0, pos 00000001008190D0, size: 16 file: 0, size: 71
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:0 f:0
>> 0000000000000000, pos 00000001000B3968, size: 2 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http write filter: l:0 f:0 s:177
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 ssi include:
>> "/gen_sec_link/this_is_my_link"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http subrequest
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 copy filter: -2 "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http finalize request: -2,
>> "/test.html?" 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 event timer add: 7:
>> 60000:1279785050458
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http posted request:
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 generic phase: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 test location: "/"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 test location: "gen_sec_link"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 using configuration
>> "/gen_sec_link"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http cl:-1 max:1048576
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 generic phase: 2
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 post rewrite phase: 3
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 generic phase: 4
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 generic phase: 5
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http script var: "127.0.0.1"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http script var:
>> "/gen_sec_link/this_is_my_link"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http output filter
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 copy filter:
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http postpone filter
>> "/gen_sec_link/this_is_my_link?" 00007FFF5FBFEC10
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http chunk: 71
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write old buf t:1 f:0
>> 0000000100818F60, pos 0000000100818F60, size: 155 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write old buf t:1 f:0
>> 0000000000000000, pos 0000000100860B80, size: 4 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write old buf t:1 f:0
>> 00000001008190D0, pos 00000001008190D0, size: 16 file: 0, size: 71
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write old buf t:0 f:0
>> 0000000000000000, pos 00000001000B3968, size: 2 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:1 f:0
>> 0000000000000000, pos 00000001008617A8, size: 4 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:0 f:0
>> 0000000000000000, pos 0000000100861668, size: 71 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:0 f:0
>> 0000000000000000, pos 00000001000B3960, size: 7 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http write filter: l:1 f:0 s:259
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http write filter limit 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 writev: 259 of 259
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http write filter 0000000000000000
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 copy filter: 0
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http finalize request: 0,
>> "/gen_sec_link/this_is_my_link?" 1
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http wake parent request:
>> "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http posted request: "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http writer handler: "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http output filter "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 copy filter: "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http ssi filter "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http ssi filter wait
>> "/gen_sec_link/this_is_my_link?" done
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 saved: 0 state: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 parse: -2, looked: 0
>> 0000000100819116-0000000100819117
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 saved: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 ssi out: 0000000100861850
>> 0000000100819116
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http postpone filter
>> "/test.html?" 0000000100861830
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http chunk: 1
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:1 f:0
>> 0000000000000000, pos 00000001008618F0, size: 3 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:1 f:0
>> 00000001008190D0, pos 0000000100819116, size: 1 file: 0, size: 71
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 write new buf t:0 f:0
>> 0000000000000000, pos 00000001000B3960, size: 7 file: 0, size: 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http write filter: l:1 f:0 s:11
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http write filter limit 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 writev: 11 of 11
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http write filter 0000000000000000
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 copy filter: 0 "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http writer output filter: 0,
>> "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http writer done: "/test.html?"
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http finalize request: 0,
>> "/test.html?" 1
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 event timer del: 7: 1279785050458
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 set http keepalive handler
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http close request
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 http log handler
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 malloc: 000000010081E200:4096
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 run cleanup: 0000000100818BF8
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 file cleanup: fd:8
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 free: 0000000100818200, unused: 8
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 free: 0000000100860A00, unused:
>> 168
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 free: 000000010081E200, unused:
>> 3868
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 event timer add: 7:
>> 65000:1279785055458
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 free: 0000000100810600
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 free: 0000000100803A00
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 hc free: 0000000000000000 0
>> 2010/07/22 15:49:50 [debug] 22731#0: *2 hc busy: 0000000000000000 0
>>
>>
>>
>> bad request
>> ---------------------------------------------------------------------------------------
>>
>>
>>
>>
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http keepalive handler
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 malloc: 0000000100803A00:1024
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 recv: eof:0, avail:410, err:0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 recv: fd:7 410 of 1024
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 malloc: 0000000100810600:1248
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 malloc: 0000000100860A00:4096
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http process request line
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http request line: "GET
>> /test.html HTTP/1.1"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http uri: "/test.html"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http args: ""
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http exten: "html"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http process request header line
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "Host:
>> localhost:8080"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "User-Agent:
>> Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.6; en-US; rv:1.9.2.7)
>> Gecko/20100713 Firefox/3.6.7"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "Accept:
>> text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "Accept-Language:
>> en-us,en;q=0.5"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "Accept-Encoding:
>> gzip,deflate"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "Accept-Charset:
>> ISO-8859-1,utf-8;q=0.7,*;q=0.7"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "Keep-Alive: 115"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "Connection:
>> keep-alive"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header: "Cache-Control:
>> max-age=0"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http header done
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 event timer del: 7: 1279785055458
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 generic phase: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 test location: "/"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 test location: "gen_sec_link"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 using configuration "/"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http cl:-1 max:1048576
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 generic phase: 2
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 post rewrite phase: 3
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 generic phase: 4
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 generic phase: 5
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 access phase: 6
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 access phase: 7
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 post access phase: 8
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 content phase: 9
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 content phase: 10
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 content phase: 11
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http filename:
>> "/usr/local/nginx/0.7.67-gsdl/html/test.html"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 add cleanup: 00000001008613F8
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http static fd: 8
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http set discard body
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 HTTP/1.1 200 OK
>> Server: nginx/0.7.67
>> Date: Thu, 22 Jul 2010 07:49:52 GMT
>> Content-Type: text/html
>> Transfer-Encoding: chunked
>> Connection: keep-alive
>>
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:1 f:0
>> 0000000100861760, pos 0000000100861760, size: 155 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http write filter: l:0 f:0 s:155
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http output filter "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 copy filter: "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 read: 8, 00000001008618D0, 71, 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http ssi filter "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 saved: 0 state: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 malloc: 0000000100818200:4096
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 parse: 0, looked: 0
>> 00000001008618D0-00000001008618E0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 saved: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 ssi flush
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 ssi out: 0000000100861998
>> 00000001008618D0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http postpone filter
>> "/test.html?" 00000001008619E8
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http chunk: 16
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write old buf t:1 f:0
>> 0000000100861760, pos 0000000100861760, size: 155 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:1 f:0
>> 0000000000000000, pos 0000000100818380, size: 4 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:1 f:0
>> 00000001008618D0, pos 00000001008618D0, size: 16 file: 0, size: 71
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:0 f:0
>> 0000000000000000, pos 00000001000B3968, size: 2 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http write filter: l:0 f:0 s:177
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 ssi include:
>> "/gen_sec_link/this_is_my_link"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http subrequest
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 copy filter: -2 "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http finalize request: -2,
>> "/test.html?" 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 event timer add: 7:
>> 60000:1279785052318
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http posted request:
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 generic phase: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 test location: "/"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 test location: "gen_sec_link"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 using configuration
>> "/gen_sec_link"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http cl:-1 max:1048576
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 generic phase: 2
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 post rewrite phase: 3
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 generic phase: 4
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 generic phase: 5
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http script var: "127.0.0.1"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http script var:
>> "/gen_sec_link/this_is_my_link"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http output filter
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 copy filter:
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http postpone filter
>> "/gen_sec_link/this_is_my_link?" 00007FFF5FBFEC10
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http chunk: 71
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write old buf t:1 f:0
>> 0000000100861760, pos 0000000100861760, size: 155 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write old buf t:1 f:0
>> 0000000000000000, pos 0000000100818380, size: 4 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write old buf t:1 f:0
>> 00000001008618D0, pos 00000001008618D0, size: 16 file: 0, size: 71
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write old buf t:0 f:0
>> 0000000000000000, pos 00000001000B3968, size: 2 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:1 f:0
>> 0000000000000000, pos 0000000100818FA8, size: 4 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:0 f:0
>> 0000000000000000, pos 0000000100818E68, size: 71 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:0 f:0
>> 0000000000000000, pos 00000001000B3960, size: 7 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http write filter: l:1 f:0 s:259
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http write filter limit 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 writev: 259 of 259
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http write filter 0000000000000000
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 copy filter: 0
>> "/gen_sec_link/this_is_my_link?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http finalize request: 0,
>> "/gen_sec_link/this_is_my_link?" 1
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http wake parent request:
>> "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http posted request: "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http writer handler: "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http output filter "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 copy filter: "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http ssi filter "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http ssi filter wait
>> "/gen_sec_link/this_is_my_link?" done
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 saved: 0 state: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 parse: -2, looked: 0
>> 0000000100861916-0000000100861917
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 saved: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 ssi out: 0000000100819050
>> 0000000100861916
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http postpone filter
>> "/test.html?" 0000000100819030
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http chunk: 1
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:1 f:0
>> 0000000000000000, pos 00000001008190F0, size: 3 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:1 f:0
>> 00000001008618D0, pos 0000000100861916, size: 1 file: 0, size: 71
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 write new buf t:0 f:0
>> 0000000000000000, pos 00000001000B3960, size: 7 file: 0, size: 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http write filter: l:1 f:0 s:11
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http write filter limit 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 writev: 11 of 11
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http write filter 0000000000000000
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 copy filter: 0 "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http writer output filter: 0,
>> "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http writer done: "/test.html?"
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http finalize request: 0,
>> "/test.html?" 1
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 event timer del: 7: 1279785052318
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 set http keepalive handler
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http close request
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 http log handler
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 malloc: 000000010081E200:4096
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 run cleanup: 00000001008613F8
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 file cleanup: fd:8
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 free: 0000000100860A00, unused: 8
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 free: 0000000100818200, unused:
>> 168
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 free: 000000010081E200, unused:
>> 3868
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 event timer add: 7:
>> 65000:1279785057318
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 free: 0000000100810600
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 free: 0000000100803A00
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 hc free: 0000000000000000 0
>> 2010/07/22 15:49:52 [debug] 22731#0: *2 hc busy: 0000000000000000 0
>>
>>
>> < pressing esc in browser after waiting around 20sec >
>>
>>
>> 2010/07/22 15:49:57 [debug] 22731#0: *2 http keepalive handler
>> 2010/07/22 15:49:57 [info] 22731#0: *2 kevent() reported that client
>> 127.0.0.1 closed keepalive connection
>> 2010/07/22 15:49:57 [debug] 22731#0: *2 close http connection: 7
>> 2010/07/22 15:49:57 [debug] 22731#0: *2 event timer del: 7: 1279785057318
>> 2010/07/22 15:49:57 [debug] 22731#0: *2 free: 0000000000000000
>> 2010/07/22 15:49:57 [debug] 22731#0: *2 free: 0000000000000000
>> 2010/07/22 15:49:57 [debug] 22731#0: *2 free: 00000001002002A0, unused: 8
>> 2010/07/22 15:49:57 [debug] 22731#0: *2 free: 00000001002003A0, unused:
>> 128
>>
>>
>>
>> hex output of request via ssi
>>
>> ---------------------------------------------------------------------------------------
>>
>> (for example the second and third byte on line 000000B0 are strange)
>>
>> 00000000 48 54 54 50 2f 31 2e 31 20 32 30 30 20 4f 4b 0d HTTP/1.1
>> 200 OK.
>> 00000010 0a 53 65 72 76 65 72 3a 20 6e 67 69 6e 78 2f 30 .Server:
>> nginx/0
>> 00000020 2e 37 2e 36 37 0d 0a 44 61 74 65 3a 20 54 68 75 .7.67..D
>> ate: Thu
>> 00000030 2c 20 32 32 20 4a 75 6c 20 32 30 31 30 20 30 37 , 22 Jul
>> 2010 07
>> 00000040 3a 31 32 3a 35 35 20 47 4d 54 0d 0a 43 6f 6e 74 :12:55 G
>> MT..Cont
>> 00000050 65 6e 74 2d 54 79 70 65 3a 20 74 65 78 74 2f 68 ent-Type :
>> text/h
>> 00000060 74 6d 6c 0d 0a 54 72 61 6e 73 66 65 72 2d 45 6e tml..Tra
>> nsfer-En
>> 00000070 63 6f 64 69 6e 67 3a 20 63 68 75 6e 6b 65 64 0d coding:
>> chunked.
>> 00000080 0a 43 6f 6e 6e 65 63 74 69 6f 6e 3a 20 6b 65 65 .Connect
>> ion: kee
>> 00000090 70 2d 61 6c 69 76 65 0d 0a 0d 0a 31 30 0d 0a 74 p-alive.
>> ...10..t
>> 000000A0 68 69 73 69 73 61 74 65 73 74 3c 62 72 3e 0a 0d hisisate
>> st<br>..
>> 000000B0 0a 34 37 0d 0a 2f 67 65 6e 5f 73 65 63 5f 6c 69 .47../ge
>> n_sec_li
>> 000000C0 6e 6b 2f 74 68 69 73 5f 69 73 5f 6d 79 5f 6c 69 nk/this_
>> is_my_li
>> 000000D0 6e 6b 2f 33 31 38 32 64 32 61 38 36 31 39 36 35 nk/3182d
>> 2a861965
>> 000000E0 38 38 36 30 62 63 32 35 30 61 65 62 36 37 36 66 8860bc25
>> 0aeb676f
>> 000000F0 66 66 36 2f 34 43 34 37 45 46 37 37 0d 0a 30 0d ff6/4C47
>> EF77..0.
>> 00000100 0a 0d 0a ...
>> 00000103 31 0d 0a 0a 0d 0a 30 0d 0a 0d 0a 1.....0. ...
>>
>
> There must be some memory overlaps in your module.
>
> I have read your source roughly. I suggest your use a local variable instead
> of '&state->conf->secret' in the function of ngx_http_script_run, and also
> the '&state->conf->url'.
>
> This may be helpful.
>
> --
> Weibin Yao
>
>
> _______________________________________________
> nginx mailing list
> nginx at nginx.org
> http://nginx.org/mailman/listinfo/nginx
>
More information about the nginx
mailing list