<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=ISO-8859-1">
</head>
<body bgcolor="#FFFFFF" text="#000000">
Hey guys,<br>
<br>
still running Ubuntu 11.10, nginx 1.0.5 (built from source - also
tried the latest 1.2.0) and PHP 5.3.6 (package php-fpm).<br>
<br>
So, to fix an issue I am having with nginx buffering fastcgi's
output against my will, I changed the SSL buffer (NGX_SSL_BUFSIZE)
to 800 bytes. What I am doing is echo'ing some events in PHP (it's
really just an echo, nothing fancy) every 0,5 seconds that I would
like to be shown immediately by the client (it's kind of a live
stream) - and so I don't want buffering or anything that might delay
the output. I've disabled buffering in PHP-FPM and have the
following options for this Location in particular:<br>
<br>
postpone_output 0;<br>
fastcgi_buffer_size 600;<br>
fastcgi_buffers 2 800;<br>
fastcgi_busy_buffers_size 800;<br>
fastcgi_max_temp_file_size 0;<br>
proxy_buffering off;<br>
gzip off;<br>
fastcgi_cache off;<br>
<br>
<br>
Unfortunately, even though each event is roughly 750 bytes, setting
a buffer size of 800 bytes still means a lot of events get buffered
and don't arrive to the client in "real-time".<br>
<br>
After a lot of painful debugging, I realized that the culprit is the
FastCGi header (always about 494 bytes, by the way). What happens
is:<br>
<ol>
<li> nginx gets the first packet of information, which is (in my
case) always 1127bytes. It parses the FasctCGI headers, puts
them (~500 bytes) in the SSL buffer, and carries on processing
the rest of the output. The event itself (the "echo" from the
PHP script - let's call it Event 0) is, like I said, about
750bytes in size, and the first 250bytes get SSL-buffered, at
which point the buffer is wrote out (remember the SSL buffer is
hard-coded to 800bytes), containing the headers and part of
event 0 (the remaining 500bytes are written into the SSL
buffer).</li>
<li>When event 1 comes along, its first 300 bytes get
SSL-buffered, at which point the buffer gets written to the
client (containing the final part of event 0 and some of event
1). </li>
</ol>
So, I assume that when only the "end" of the data is SSL_written
does it show up in the client side (in a javascript event). Problem
is if the end of 2 events are in the same buffer, they will be sent
together, arrives at the same time and the whole "live stream" idea
is lost (because the client won't be able to see the "transition"
between say events 4, 5 and 6 - it will see events 5 and 6 arrive at
the same time, so in all effects it is as if it went from 4 to 6).<br>
<br>
This ia all finding I made over a few whole days of a lot of
debugging, which weren't fun at all. I have also tried for instance,
a SSL buffer size of 700 bytes, which is smaller than single events.
This should, in theory, force every event to be written immediately,
but I still get packs of events arriving together (I "lose" about
6-10 events per every 30 events sent - quite a lot, actually). A
buffer size of like 50 bytes solves this, but that means too many
SSL_writes per event...<br>
<br>
It is also interesting that, for instance, for Event 0 (with 1154
bytes), only the first 719 bytes get SSL-buffered. Only when event 1
comes along are the remaining bytes buffered and writen. I don't get
it, it is processing a 1154 byte output, why isn't it buffering the
whole thing?! it seems to be an issue with whatever calls
ngx_ssl_send_chain() and not from this function itself, but I got
lost trying to figure out who calls it...<br>
<br>
So, the question is: is there a way to force immediate SSL_writes
for the FastCGI headers, while still buffering the data itself to
avoid unnecessary writes? Or can I only get this done if I disable
buffering altogether?<br>
<br>
I'm thankful of any pointer in the right direction, as by now I am
sick and tired of looking into nginx source code :-)<br>
<br>
Cheers,<br>
<br>
ps: here's a typical debug log for the first 3 events (I replaced
some sensitive data with XX but kept its length):<br>
<br>
// New upstream request (event 0)<br>
<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream request:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream process header<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 recv: fd:35 600 of 600<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 06<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 00<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 04<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 67<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 00<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record length:
1127<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header:
"X-Powered-By: PHP/5.3.6-13ubuntu3.7"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header:
"Set-Cookie:
Authorization=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX;
path=/; secure; httponly"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header:
"Set-Cookie: Date=30-May-2012+15%3A18%3A40; path=/; secure;
httponly"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header:
"Set-Cookie: Nonce=123804486; path=/; secure; httponly"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header:
"Content-Type: text/event-stream"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header:
"Cache-Control: no-cache"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 1<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header done<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 HTTP/1.1 200 OK<br>
Server: nginx<br>
Date: Wed, 30 May 2012 15:18:41 GMT<br>
Content-Type: text/event-stream<br>
Transfer-Encoding: chunked<br>
Connection: keep-alive<br>
X-Powered-By: PHP/5.3.6-13ubuntu3.7<br>
Set-Cookie:
Authorization=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX;
path=/; secure; httponly<br>
Set-Cookie: Date=30-May-2012+15%3A18%3A40; path=/; secure; httponly<br>
Set-Cookie: Nonce=123804486; path=/; secure; httponly<br>
Cache-Control: no-cache<br>
<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 write new buf t:1 f:0
0000000001336528, pos 0000000001336528, size: 494 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter: l:0 f:0
s:494<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter limit 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 malloc: 00000000013426A0:900<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 494<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter
0000000000000000<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http cacheable: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream process
upstream<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe read upstream: 1<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe preread: 219<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf #0 000000000133609D<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf 000000000133609D
219<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 readv: 1:800<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe recv chain: 536<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 readv: 1:264<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 readv() not ready (11:
Resource temporarily unavailable)<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe recv chain: -2<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf in s:1 t:1 f:0
0000000001335F20, pos 000000000133609D, size: 219 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
00000000013368D0, pos 00000000013368D0, size: 536 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write downstream: 1<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write busy: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write buf ls:1
000000000133609D 219<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write:
out:0000000001336870, f:0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http output filter
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http copy filter:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http postpone filter
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"
0000000001336870<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http chunk: 219<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 write new buf t:1 f:0
0000000001336CC8, pos 0000000001336CC8, size: 4 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 write new buf t:1 f:0
0000000001335F20, pos 000000000133609D, size: 219 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 write new buf t:0 f:0
0000000000000000, pos 000000000047560D, size: 2 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter: l:0 f:1
s:225<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter limit 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 4<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 219<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 2<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter
0000000000000000<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http copy filter: -2
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write busy: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write:
out:0000000000000000, f:0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe read upstream: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
00000000013368D0, pos 00000000013368D0, size: 536 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
0000000001335F20, pos 0000000001335F20, size: 0 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 event timer del: 35:
1338391180656<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 event timer add: 35:
60000:1338391181007<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 post event 00000000012CC0B8<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 post event 00000000013000C8<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 delete posted event
00000000013000C8<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream request:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream dummy handler<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 delete posted event
00000000012CC0B8<br>
<br>
// New upstream request (event 1)<br>
<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream request:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream process
upstream<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe read upstream: 1<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 readv: 2:600<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe recv chain: 768<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf #1 00000000013368D0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 06<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 00<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 02<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: F2<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 06<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 00<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record length:
754<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf #1 0000000001336AF0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf 0000000001336AF0
256<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 readv: 1:96<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 readv() not ready (11:
Resource temporarily unavailable)<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe recv chain: -2<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf in s:1 t:1 f:0
00000000013368D0, pos 00000000013368D0, size: 535 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf in s:1 t:1 f:0
00000000013368D0, pos 0000000001336AF0, size: 256 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
0000000001335F20, pos 0000000001335F20, size: 504 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write downstream: 1<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write busy: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write buf ls:0
00000000013368D0 535<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write buf ls:1
0000000001336AF0 256<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write:
out:0000000001336870, f:0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http output filter
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http copy filter:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http postpone filter
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"
0000000001336718<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http chunk: 535<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http chunk: 256<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 write new buf t:1 f:0
0000000001336DE0, pos 0000000001336DE0, size: 5 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 write new buf t:1 f:0
00000000013368D0, pos 00000000013368D0, size: 535 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 write new buf t:1 f:0
00000000013368D0, pos 0000000001336AF0, size: 256 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 write new buf t:0 f:0
0000000001336CC8, pos 000000000047560D, size: 2 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter: l:0 f:1
s:798<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter limit 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 5<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 176<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL to write: 900<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL_write: 900<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 359<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 256<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 2<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter
0000000000000000<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 http copy filter: -2
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write busy: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write:
out:0000000000000000, f:0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe read upstream: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
0000000001335F20, pos 0000000001335F20, size: 504 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
00000000013368D0, pos 00000000013368D0, size: 0 file: 0, size: 0<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 event timer del: 35:
1338391181007<br>
2012/05/30 17:18:41 [debug] 8735#0: *7 event timer add: 35:
60000:1338391181799<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 post event 00000000012CC0B8<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 post event 00000000013000C8<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 delete posted event
00000000013000C8<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http upstream request:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http upstream dummy handler<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 delete posted event
00000000012CC0B8<br>
<br>
// New upstream request (event 2)<br>
<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http upstream request:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http upstream process
upstream<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe read upstream: 1<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 readv: 2:800<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe recv chain: 768<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 input buf #2 0000000001335F20<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 01<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 06<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 00<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 01<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 02<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: F2<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 06<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 00<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record length:
754<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 input buf #2 0000000001336120<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 input buf 0000000001336120 88<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 readv: 1:128<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 readv() not ready (11:
Resource temporarily unavailable)<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe recv chain: -2<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe buf in s:1 t:1 f:0
0000000001335F20, pos 0000000001335F20, size: 498 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe buf in s:1 t:1 f:0
0000000001335F20, pos 0000000001336120, size: 88 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
00000000013368D0, pos 00000000013368D0, size: 672 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write downstream: 1<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write busy: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write buf ls:0
0000000001335F20 498<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write buf ls:1
0000000001336120 88<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write:
out:0000000001336D50, f:0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http output filter
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http copy filter:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http postpone filter
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"
0000000001336D60<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http chunk: 498<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http chunk: 88<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 write new buf t:1 f:0
0000000001336CC8, pos 0000000001336CC8, size: 5 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 write new buf t:1 f:0
0000000001335F20, pos 0000000001335F20, size: 498 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 write new buf t:1 f:0
0000000001335F20, pos 0000000001336120, size: 88 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 write new buf t:0 f:0
0000000001336DE0, pos 000000000047560D, size: 2 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http write filter: l:0 f:1
s:593<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http write filter limit 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 5<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 278<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL to write: 900<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL_write: 900<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 220<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 88<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 2<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http write filter
0000000000000000<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 http copy filter: -2
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write busy: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write:
out:0000000000000000, f:0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe read upstream: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
00000000013368D0, pos 00000000013368D0, size: 672 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe buf free s:0 t:1 f:0
0000000001335F20, pos 0000000001335F20, size: 0 file: 0, size: 0<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 event timer del: 35:
1338391181799<br>
2012/05/30 17:18:42 [debug] 8735#0: *7 event timer add: 35:
60000:1338391182631<br>
2012/05/30 17:18:43 [debug] 8735#0: *7 post event 00000000012CC0B8<br>
2012/05/30 17:18:43 [debug] 8735#0: *7 post event 00000000013000C8<br>
2012/05/30 17:18:43 [debug] 8735#0: *7 delete posted event
00000000013000C8<br>
2012/05/30 17:18:43 [debug] 8735#0: *7 http upstream request:
"/api/index.php/eventstream/?&campaign_id=187&start_date=1328486400&end_date=1338249600&publisher_aggregation=1&advertiser_aggregation=1"<br>
2012/05/30 17:18:43 [debug] 8735#0: *7 http upstream dummy handler<br>
2012/05/30 17:18:43 [debug] 8735#0: *7 delete posted event
00000000012CC0B8<br>
<pre class="moz-signature" cols="72">--
Daniel</pre>
</body>
</html>