FasctCGI headers and SSL

Daniel Gomes blink0 at gmail.com
Wed May 30 15:50:08 UTC 2012 

Hey guys,

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).

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:

postpone_output 0;
fastcgi_buffer_size 600;
fastcgi_buffers 2 800;
fastcgi_busy_buffers_size 800;
fastcgi_max_temp_file_size 0;
proxy_buffering off;
gzip off;
fastcgi_cache off;


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".

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:

 1.   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).
 2. 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).

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).

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...

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...

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?

I'm thankful of any pointer in the right direction, as by now I am sick 
and tired of looking into nginx source code :-)

Cheers,

ps: here's a typical debug log for the first 3 events (I replaced some 
sensitive data with XX but kept its length):

// New upstream request (event 0)

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"
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream process header
2012/05/30 17:18:41 [debug] 8735#0: *7 recv: fd:35 600 of 600
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 06
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 00
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 04
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 67
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 00
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record length: 1127
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header: 
"X-Powered-By: PHP/5.3.6-13ubuntu3.7"
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header: "Set-Cookie: 
Authorization=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX; 
path=/; secure; httponly"
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0
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"
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header: "Set-Cookie: 
Nonce=123804486; path=/; secure; httponly"
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header: 
"Content-Type: text/event-stream"
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header: 
"Cache-Control: no-cache"
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi parser: 1
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi header done
2012/05/30 17:18:41 [debug] 8735#0: *7 HTTP/1.1 200 OK
Server: nginx
Date: Wed, 30 May 2012 15:18:41 GMT
Content-Type: text/event-stream
Transfer-Encoding: chunked
Connection: keep-alive
X-Powered-By: PHP/5.3.6-13ubuntu3.7
Set-Cookie: 
Authorization=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX; 
path=/; secure; httponly
Set-Cookie: Date=30-May-2012+15%3A18%3A40; path=/; secure; httponly
Set-Cookie: Nonce=123804486; path=/; secure; httponly
Cache-Control: no-cache

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
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter: l:0 f:0 s:494
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter limit 0
2012/05/30 17:18:41 [debug] 8735#0: *7 malloc: 00000000013426A0:900
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 494
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter 0000000000000000
2012/05/30 17:18:41 [debug] 8735#0: *7 http cacheable: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream process upstream
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe read upstream: 1
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe preread: 219
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf #0 000000000133609D
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf 000000000133609D 219
2012/05/30 17:18:41 [debug] 8735#0: *7 readv: 1:800
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe recv chain: 536
2012/05/30 17:18:41 [debug] 8735#0: *7 readv: 1:264
2012/05/30 17:18:41 [debug] 8735#0: *7 readv() not ready (11: Resource 
temporarily unavailable)
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe recv chain: -2
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
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
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write downstream: 1
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write busy: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write buf ls:1 
000000000133609D 219
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write: out:0000000001336870, f:0
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"
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"
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
2012/05/30 17:18:41 [debug] 8735#0: *7 http chunk: 219
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
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
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
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter: l:0 f:1 s:225
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter limit 0
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 4
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 219
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 2
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter 0000000000000000
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"
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write busy: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write: out:0000000000000000, f:0
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe read upstream: 0
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
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
2012/05/30 17:18:41 [debug] 8735#0: *7 event timer del: 35: 1338391180656
2012/05/30 17:18:41 [debug] 8735#0: *7 event timer add: 35: 
60000:1338391181007
2012/05/30 17:18:41 [debug] 8735#0: *7 post event 00000000012CC0B8
2012/05/30 17:18:41 [debug] 8735#0: *7 post event 00000000013000C8
2012/05/30 17:18:41 [debug] 8735#0: *7 delete posted event 00000000013000C8
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"
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream dummy handler
2012/05/30 17:18:41 [debug] 8735#0: *7 delete posted event 00000000012CC0B8

// New upstream request (event 1)

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"
2012/05/30 17:18:41 [debug] 8735#0: *7 http upstream process upstream
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe read upstream: 1
2012/05/30 17:18:41 [debug] 8735#0: *7 readv: 2:600
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe recv chain: 768
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf #1 00000000013368D0
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 06
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 00
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 01
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 02
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: F2
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 06
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record byte: 00
2012/05/30 17:18:41 [debug] 8735#0: *7 http fastcgi record length: 754
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf #1 0000000001336AF0
2012/05/30 17:18:41 [debug] 8735#0: *7 input buf 0000000001336AF0 256
2012/05/30 17:18:41 [debug] 8735#0: *7 readv: 1:96
2012/05/30 17:18:41 [debug] 8735#0: *7 readv() not ready (11: Resource 
temporarily unavailable)
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe recv chain: -2
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
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
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
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write downstream: 1
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write busy: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write buf ls:0 
00000000013368D0 535
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write buf ls:1 
0000000001336AF0 256
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write: out:0000000001336870, f:0
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"
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"
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
2012/05/30 17:18:41 [debug] 8735#0: *7 http chunk: 535
2012/05/30 17:18:41 [debug] 8735#0: *7 http chunk: 256
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
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
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
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
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter: l:0 f:1 s:798
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter limit 0
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 5
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 176
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL to write: 900
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL_write: 900
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 359
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 256
2012/05/30 17:18:41 [debug] 8735#0: *7 SSL buf copy: 2
2012/05/30 17:18:41 [debug] 8735#0: *7 http write filter 0000000000000000
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"
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write busy: 0
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe write: out:0000000000000000, f:0
2012/05/30 17:18:41 [debug] 8735#0: *7 pipe read upstream: 0
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
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
2012/05/30 17:18:41 [debug] 8735#0: *7 event timer del: 35: 1338391181007
2012/05/30 17:18:41 [debug] 8735#0: *7 event timer add: 35: 
60000:1338391181799
2012/05/30 17:18:42 [debug] 8735#0: *7 post event 00000000012CC0B8
2012/05/30 17:18:42 [debug] 8735#0: *7 post event 00000000013000C8
2012/05/30 17:18:42 [debug] 8735#0: *7 delete posted event 00000000013000C8
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"
2012/05/30 17:18:42 [debug] 8735#0: *7 http upstream dummy handler
2012/05/30 17:18:42 [debug] 8735#0: *7 delete posted event 00000000012CC0B8

// New upstream request (event 2)

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"
2012/05/30 17:18:42 [debug] 8735#0: *7 http upstream process upstream
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe read upstream: 1
2012/05/30 17:18:42 [debug] 8735#0: *7 readv: 2:800
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe recv chain: 768
2012/05/30 17:18:42 [debug] 8735#0: *7 input buf #2 0000000001335F20
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 01
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 06
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 00
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 01
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 02
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: F2
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 06
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record byte: 00
2012/05/30 17:18:42 [debug] 8735#0: *7 http fastcgi record length: 754
2012/05/30 17:18:42 [debug] 8735#0: *7 input buf #2 0000000001336120
2012/05/30 17:18:42 [debug] 8735#0: *7 input buf 0000000001336120 88
2012/05/30 17:18:42 [debug] 8735#0: *7 readv: 1:128
2012/05/30 17:18:42 [debug] 8735#0: *7 readv() not ready (11: Resource 
temporarily unavailable)
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe recv chain: -2
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
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
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
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write downstream: 1
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write busy: 0
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write buf ls:0 
0000000001335F20 498
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write buf ls:1 
0000000001336120 88
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write: out:0000000001336D50, f:0
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"
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"
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
2012/05/30 17:18:42 [debug] 8735#0: *7 http chunk: 498
2012/05/30 17:18:42 [debug] 8735#0: *7 http chunk: 88
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
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
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
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
2012/05/30 17:18:42 [debug] 8735#0: *7 http write filter: l:0 f:1 s:593
2012/05/30 17:18:42 [debug] 8735#0: *7 http write filter limit 0
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 5
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 278
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL to write: 900
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL_write: 900
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 220
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 88
2012/05/30 17:18:42 [debug] 8735#0: *7 SSL buf copy: 2
2012/05/30 17:18:42 [debug] 8735#0: *7 http write filter 0000000000000000
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"
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write busy: 0
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe write: out:0000000000000000, f:0
2012/05/30 17:18:42 [debug] 8735#0: *7 pipe read upstream: 0
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
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
2012/05/30 17:18:42 [debug] 8735#0: *7 event timer del: 35: 1338391181799
2012/05/30 17:18:42 [debug] 8735#0: *7 event timer add: 35: 
60000:1338391182631
2012/05/30 17:18:43 [debug] 8735#0: *7 post event 00000000012CC0B8
2012/05/30 17:18:43 [debug] 8735#0: *7 post event 00000000013000C8
2012/05/30 17:18:43 [debug] 8735#0: *7 delete posted event 00000000013000C8
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"
2012/05/30 17:18:43 [debug] 8735#0: *7 http upstream dummy handler
2012/05/30 17:18:43 [debug] 8735#0: *7 delete posted event 00000000012CC0B8

-- 
Daniel

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20120530/5e79c856/attachment-0001.html>

More information about the nginx mailing list