Re: Сбор статистики о файле

[ForJest <forjest@xxxxxxxxx>]

Судя по логам они всё же связаны получаются.
----------- лог без post_action -------------
2006/04/21 19:01:50 [debug] 56633#0: *1 http write filter to send 6087
2006/04/21 19:01:50 [debug] 56633#0: *1 sendfile: 0, @1757184 8192:8192
2006/04/21 19:01:50 [debug] 56633#0: *1 http write filter 080B0974
2006/04/21 19:01:50 [debug] 56633#0: *1 event timer add: 3: 2730:3177612081
2006/04/21 19:01:50 [debug] 56633#0: *1 copy filter: -2
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:50 [debug] 56633#0: *1 http writer output filter: -2,
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 http read blocked
2006/04/21 19:01:52 [debug] 56633#0: *1 http read blocked
2006/04/21 19:01:52 [debug] 56633#0: *1 event timer del: 3: 3177612081
2006/04/21 19:01:52 [debug] 56633#0: *1 http writer handler:
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 http output filter
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 copy filter:
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 request stats write handler
2006/04/21 19:01:52 [debug] 56633#0: *1 request stats filename:
/usr/home/forj/tst/xeres.txt 28
2006/04/21 19:01:52 [debug] 56633#0: *1 http postpone filter
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?" 00000000
2006/04/21 19:01:52 [debug] 56633#0: *1 http postpone filter out
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 write old buf t:0 f:1
00000000, pos 00000000, size: 0 file: 1765376, size: 101737262
2006/04/21 19:01:52 [debug] 56633#0: *1 http write filter: l:1 f:0 s:101737262
2006/04/21 19:01:52 [debug] 56633#0: *1 http write filter to send 3895
2006/04/21 19:01:52 [info] 56633#0: *1 sendfile() failed (57: Socket
is not connected) while sending response to client, client:
195.248.186.243, server: 88.85.65.13, URL:
"/stats-xeres/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm", host:
"******", referrer: "http://******/stats-xeres";
2006/04/21 19:01:52 [debug] 56633#0: *1 http write filter FFFFFFFF
2006/04/21 19:01:52 [debug] 56633#0: *1 copy filter: -1
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 http writer output filter: -1,
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 http writer done:
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 http finalize request: -1,
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:01:52 [debug] 56633#0: *1 http close request
2006/04/21 19:01:52 [debug] 56633#0: *1 request stats cleanup
2006/04/21 19:01:52 [debug] 56633#0: *1 request stats filename:
/usr/home/forj/tst/xeres.txt 28
2006/04/21 19:01:52 [debug] 56633#0: *1 http log handler
2006/04/21 19:01:52 [debug] 56633#0: *1 run cleanup: 080B05D4, fd:7
2006/04/21 19:01:52 [debug] 56633#0: *1 free: 080B0000, unused: 1128
2006/04/21 19:01:52 [debug] 56633#0: *1 close http connection: 3
2006/04/21 19:01:52 [debug] 56633#0: *1 free: 080A4000
2006/04/21 19:01:52 [debug] 56633#0: *1 free: 080A0000
2006/04/21 19:01:52 [debug] 56633#0: *1 free: 080B2100, unused: 68
----------------------------
в конце запроса вызывается request stats cleanup

---------------- лог с post_action -----------
2006/04/21 19:05:04 [debug] 56805#0: *2 http write filter: l:1 f:0 s:101720878
2006/04/21 19:05:04 [debug] 56805#0: *2 http write filter to send 4145
2006/04/21 19:05:04 [debug] 56805#0: *2 sendfile: 0, @1781760 8192:8192
2006/04/21 19:05:04 [debug] 56805#0: *2 http write filter 080B0974
2006/04/21 19:05:04 [debug] 56805#0: *2 event timer add: 5: 2730:3177806334
2006/04/21 19:05:04 [debug] 56805#0: *2 copy filter: -2
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:04 [debug] 56805#0: *2 http writer output filter: -2,
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:07 [debug] 56805#0: *2 event timer del: 5: 3177806334
2006/04/21 19:05:07 [debug] 56805#0: *2 http writer handler:
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:07 [debug] 56805#0: *2 http output filter
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:07 [debug] 56805#0: *2 copy filter:
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:07 [debug] 56805#0: *2 request stats write handler
2006/04/21 19:05:07 [debug] 56805#0: *2 request stats filename:
/usr/home/forj/tst/xeres.txt 28
2006/04/21 19:05:07 [debug] 56805#0: *2 http postpone filter
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?" 00000000
2006/04/21 19:05:07 [debug] 56805#0: *2 http postpone filter out
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:07 [debug] 56805#0: *2 write old buf t:0 f:1
00000000, pos 00000000, size: 0 file: 1789952, size: 101712686
2006/04/21 19:05:07 [debug] 56805#0: *2 http write filter: l:1 f:0 s:101712686
2006/04/21 19:05:07 [debug] 56805#0: *2 http write filter to send 4953
2006/04/21 19:05:07 [debug] 56805#0: *2 sendfile: 0, @1789952 8192:8192
2006/04/21 19:05:07 [debug] 56805#0: *2 http write filter 080B0974
2006/04/21 19:05:07 [debug] 56805#0: *2 event timer add: 5: 2730:3177809074
2006/04/21 19:05:07 [debug] 56805#0: *2 copy filter: -2
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:07 [debug] 56805#0: *2 http writer output filter: -2,
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 http read blocked
2006/04/21 19:05:09 [debug] 56805#0: *2 http read blocked
2006/04/21 19:05:09 [debug] 56805#0: *2 event timer del: 5: 3177809074
2006/04/21 19:05:09 [debug] 56805#0: *2 http writer handler:
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 http output filter
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 copy filter:
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 request stats write handler
2006/04/21 19:05:09 [debug] 56805#0: *2 request stats filename:
/usr/home/forj/tst/xeres.txt 28
2006/04/21 19:05:09 [debug] 56805#0: *2 http postpone filter
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?" 00000000
2006/04/21 19:05:09 [debug] 56805#0: *2 http postpone filter out
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 write old buf t:0 f:1
00000000, pos 00000000, size: 0 file: 1798144, size: 101704494
2006/04/21 19:05:09 [debug] 56805#0: *2 http write filter: l:1 f:0 s:101704494
2006/04/21 19:05:09 [debug] 56805#0: *2 http write filter to send 2761
2006/04/21 19:05:09 [info] 56805#0: *2 sendfile() failed (57: Socket
is not connected) while sending response to client, client:
195.248.186.243, server: 88.85.65.13, URL:
"/stats-xeres/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm", host:
"******", referrer: "http://******/stats-xeres";
2006/04/21 19:05:09 [debug] 56805#0: *2 http write filter FFFFFFFF
2006/04/21 19:05:09 [debug] 56805#0: *2 copy filter: -1
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 http writer output filter: -1,
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 http writer done:
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 http finalize request: -1,
"/statsed/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm?"
2006/04/21 19:05:09 [debug] 56805#0: *2 post action: "/end_statsed"
2006/04/21 19:05:09 [debug] 56805#0: *2 internal redirect: "/end_statsed?"
2006/04/21 19:05:09 [debug] 56805#0: *2 http phase handler
2006/04/21 19:05:09 [debug] 56805#0: *2 http script regex:
"^/stats-([^/]+)/(.+)$"
2006/04/21 19:05:09 [debug] 56805#0: *2 http script complex value
2006/04/21 19:05:09 [debug] 56805#0: *2 http script capture: ""
2006/04/21 19:05:09 [debug] 56805#0: *2 http script set var
2006/04/21 19:05:09 [debug] 56805#0: *2 find location for "/end_statsed"
2006/04/21 19:05:09 [debug] 56805#0: *2 find location: = "/end_statsed"
2006/04/21 19:05:09 [debug] 56805#0: *2 using configuration "=/end_statsed"
2006/04/21 19:05:09 [debug] 56805#0: *2 http cl:-1 max:1048576
2006/04/21 19:05:09 [debug] 56805#0: *2 http set discard body
2006/04/21 19:05:09 [debug] 56805#0: *2 http filename:
"/usr/home/forj/tst/end_statsed"
2006/04/21 19:05:09 [debug] 56805#0: *2 add cleanup: 080B0AD0
2006/04/21 19:05:09 [error] 56805#0: *2 open()
"/usr/home/forj/tst/end_statsed" failed (2: No such file or
directory), client: 195.248.186.243, server: 88.85.65.13, URL:
"/stats-xeres/Xerxes_-_The_Mirror_Formula-Retail-2006-gEm", host:
"******", referrer: "http://******/stats-xeres";
2006/04/21 19:05:09 [debug] 56805#0: *2 http finalize request: 404,
"/end_statsed?"
2006/04/21 19:05:09 [debug] 56805#0: *2 http close request
2006/04/21 19:05:09 [debug] 56805#0: *2 http log handler
2006/04/21 19:05:09 [debug] 56805#0: *2 run cleanup: 080B05D4, fd:9
2006/04/21 19:05:09 [debug] 56805#0: *2 free: 080B0000, unused: 1044
2006/04/21 19:05:09 [debug] 56805#0: *2 close http connection: 5
2006/04/21 19:05:09 [debug] 56805#0: *2 free: 080A4000
2006/04/21 19:05:09 [debug] 56805#0: *2 free: 080A0000
2006/04/21 19:05:09 [debug] 56805#0: *2 free: 080B2100, unused: 68
---------------------------------
Как я понял cleanup вызывается после close request, а не после
finalize request. Потому он видимо срабатывает в последней
конфигурации, которая найдена перед request close.... А там уже нет
моего обработчика получается.
Попытаюсь решить это ещё с помощью конфигурации, добавить туда свой
обработчик, именно на cleanup.

On 4/21/06, Igor Sysoev <is@xxxxxxxxxxxxx> wrote:
> On Fri, 21 Apr 2006, ForJest wrote:
>
> > Игорь, а где исправить, чтобы начало работать и post_action и cleanup
> > процедура? Я могу сделать workaround в этом самом post_action, но хочу
> > сделать по уму.
>
> cleanup и post_action не связаны. cleanup вызывается только для основного
> запроса.
>