problem in writing handler module which should be called via ssi
Mauro Stettler
mauro.stettler at gmail.com
Tue Jul 27 06:28:15 MSD 2010
just now i discovered something strange, or maybe i just don't
understand it. i did a very simple test of the nginx ssi module with
the following nginx conf:
37 location / {
38 ssi on;
39 root html;
40 }
41
42 location /gen_sec_link {
43 rewrite . /abc.html last;
45 }
inside the html folder i have two files
file test.html, no newlines or linebreaks:
thisisatest <!--# include virtual="/gen_sec_link/this_is_my_link" -->
some text abc <!--# include
virtual="/gen_sec_link/this_is_another_link" -->
file abc.html, no newlines or linebreaks:
abc
so if i request /test.html, as expected is the nginx doing two
internal subrequests to /gen_sec_link and rewrites them to /abc.html.
the content of /abc.html is the simple string "abc", so the two ssi
tags will be replaced by "abc" and in the browser everything looks
correct. but now i discovered that in the result that is sent to the
browser there are some strange other characters somehow getting
inbetween the replaced parts of the output and the original parts, but
they are not shown in the browser so its not very obvious.
this is what wireshark shows me as reply from nginx:
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 75 65 .7.67..D ate: Tue
00000030 2c 20 32 37 20 4a 75 6c 20 32 30 31 30 20 30 32 , 27 Jul 2010 02
00000040 3a 31 38 3a 31 36 20 47 4d 54 0d 0a 43 6f 6e 74 :18:16 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 63 0d 0a 74 68 p-alive. ...c..th
000000A0 69 73 69 73 61 74 65 73 74 20 0d 0a 34 0d 0a 61 isisates t ..4..a
000000B0 62 63 0a 0d 0a 66 0d 0a 20 73 6f 6d 65 20 74 65 bc...f.. some te
000000C0 78 74 20 61 62 63 20 0d 0a 34 0d 0a 61 62 63 0a xt abc . .4..abc.
000000D0 0d 0a 31 0d 0a 0a 0d 0a 30 0d 0a 0d 0a ..1..... 0....
so what is for example the byte number 13 on line 000000A0, why is
there this 4? another example is the byte number 6 on line 000000B0,
why is there an f?
do i maybe understand something wrong or is that a problem of the ssi module?
On Fri, Jul 23, 2010 at 15:13, Mauro Stettler <mauro.stettler at gmail.com> wrote:
> 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