problem in writing handler module which should be called via ssi
Mauro Stettler
mauro.stettler at gmail.com
Thu Jul 22 12:06:15 MSD 2010
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. ...
On Thu, Jul 22, 2010 at 15:37, Weibin Yao <nbubingo at gmail.com> wrote:
> Mauro Stettler at 2010-7-22 14:10 wrote:
>>
>> i have also realized that this problem really only happens if i access
>> the location which has the generate_secure_download_link enabled via
>> ssi. if i directly request a uri in the location with the module
>> enabled i don't have any problem at all, only if the location gets
>> called via the virtual of the ssi, i run into this problem that
>> sometimes nginx doesn't close the connection to the client right.
>>
>> would there maybe be any better way to implement what i am trying to
>> achieve? do i really have to do search and replace on the output
>> buffer chain?
>>
>>
>
> What does the debug.log show?
>>
>> On Wed, Jul 21, 2010 at 16:23, Mauro Stettler <mauro.stettler at gmail.com>
>> wrote:
>>
>>>
>>> hi
>>>
>>> i have a problem while writing an nginx module which i want to
>>> generate secure download links, which can then be verified by the
>>> NginxHttpSecureDownload module and later maybe also the secure link
>>> module. i wrote it as a content handler which can then be called over
>>> an ssi include, like in the following example:
>>>
>>> <a href="<!--# include virtual="/gen_sec_link/this_is_my_link" -->">my
>>> link</a>
>>>
>>> together with the nginx conf:
>>>
>>>
>>> location / {
>>> ssi on;
>>> root html;
>>> }
>>>
>>> location /gen_sec_link {
>>> generate_secure_download_link_expiration_time 3600;
>>> generate_secure_download_link_secret $remote_addr;
>>> generate_secure_download_link_url $uri;
>>> generate_secure_download_link;
>>> }
>>>
>>> the result will be something like:
>>>
>>> <a
>>> href="/gen_sec_link/this_is_my_link/3c5e04f315af807f3e757abd49dc14d3/4C46ABAF">my
>>> link</a>
>>>
>>> by using SSI i can save all the pattern matching and operating on the
>>> buffer chain, thats why i did it as handler module, instead of an
>>> output filter.
>>>
>>> i pushed the code to github:
>>>
>>> http://github.com/replay/ngx_http_generate_secure_download_links
>>>
>>> now my problem is that sometimes when i request many times from one
>>> browser it just never closes the connection and the browser seems to
>>> keep loading. first i thought the problem might be a mistake in the
>>> calculation of the content-length, but after many tests i believe that
>>> the content length that i give back is correct. i'm guessing that i
>>> missed something to tell nginx that the content is really finished
>>> now. on the other hand its strange that i only have this problem after
>>> refreshing a page which i requested already, the first request is
>>> always working.
>>>
>>> i would be glad for a few tips what else i have to check,
>>>
>>> thanks,
>>>
>>> mauro
>>>
>>>
>>
>> _______________________________________________
>> nginx mailing list
>> nginx at nginx.org
>> http://nginx.org/mailman/listinfo/nginx
>>
>>
>
>
> --
> Weibin Yao
>
>
> _______________________________________________
> nginx mailing list
> nginx at nginx.org
> http://nginx.org/mailman/listinfo/nginx
>
More information about the nginx
mailing list