You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@trafficserver.apache.org by 黄英才 <b1...@gmail.com> on 2012/09/22 06:01:49 UTC
ESI issue
Hi all,
I'm compiling the ESI plugin in my trafficserver-3.3.1-dev from git
when i enable the esi.so and get the esi.html .The chrome return the blank
page with nothing
Here is the debug message
[Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
[isInterceptRequest] Skipping external request
[Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
[globalHookHandler] handling read request header event...
[Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
[globalHookHandler] Not setting up intercept
[Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
[isInterceptRequest] Skipping external request
[Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
[globalHookHandler] handling cache lookup complete event...
[Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
[globalHookHandler] handling cache lookup complete event...
[Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
[isCacheObjTransformable] cache object's status is 0; not transformable
[Sep 22 11:59:41.941] Server {0x2ac882236700} DIAG: (plugin_esi)
[isInterceptRequest] Skipping external request
[Sep 22 11:59:41.941] Server {0x2ac882236700} DIAG: (plugin_esi)
[globalHookHandler] handling read response header event...
[Sep 22 11:59:41.941] Server {0x2ac882236700} DIAG: (plugin_esi)
[isCacheObjTransformable] cache object's status is 0; not transformable
[Sep 22 11:59:41.941] Server {0x2ac882236700} DIAG: (plugin_esi)
[getClientState] Got request URL [http://127.0.0.1/esi.html]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Connection]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Cache-Control]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Cache-Control]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Pragma]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Accept-Encoding]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG: (plugin_esi)
[getClientState] Client accepts gzip encoding; will compress output
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Accept-Encoding]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Accept-Encoding]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Accept-Charset]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Accept-Charset]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Accept-Charset]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
[Accept-Charset]
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG: (plugin_esi)
[getServerState] Not retaining 'Content-length' header
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG: (plugin_esi)
[getServerState] Not retaining 'X-Esi' header
[Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG: (plugin_esi)
[addTransform] Added transformation (0x0x2ac89400ceb0)
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [init] Set input data type to [RAW_ESI]
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] initialized continuation data
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_fetcher_0x2ac89400ceb0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10000)
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] handling
TS_EVENT_IMMEDIATE...
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] upstream VC has 165 bytes
available to read[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] handling
TS_EVENT_IMMEDIATE...
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] upstream VC has 165 bytes
available to read
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_processor_0x2ac89400ceb0) [addParseData] Implicit call to
start()
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_parse], Adding data of size 27 before
(newly found) ESI tag as PRE node
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_compareData] string [include ] is
equal to data at position 32
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_compareData] string [include ] is
equal to data at position 32
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_parse] Found [INCLUDE] tag at position
27
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_parse] Found [INCLUDE] tag at position
27
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_searchData] Found full match of /> in
[src="...] at position 95
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_parse] Handling include tag...
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_processIncludeTag] Added include tag
with url [http://61.160.245.195/esi.php][Sep 22 11:59:41.943] Server
{0x2ac882236700} DIAG: (plugin_esi_parser_0x2ac89400ceb0)
[_processIncludeTag] Added include tag with url [
http://61.160.245.195/esi.php]
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_parse] Added 2 node(s) during parse
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_processor_0x2ac89400ceb0) [_preprocess] Adding fetch request
for url [http://61.160.245.195/esi.php]
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_vars_0x2ac89400ceb0) [expand] Returning final expanded
expression [http://61.160.245.195/esi.php]
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_failureInfo) [_preprocess] URL request [
http://61.160.245.195/esi.php] 2183358208
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_fetcher_0x2ac89400ceb0) [_buildHeadersString] Building header
string...
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_fetcher_0x2ac89400ceb0) [addFetchRequest] Successfully added
fetch request for URL [http://61.160.245.195/esi.php]
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] Added chunk of 165 bytes
starting with [<HTML>
<BO] to parse list
[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] Added chunk of 165 bytes
starting with [<HTML>
<BO] to parse list
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] Consumed 165 bytes from
upstream VC
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] Completed reading input...[Sep
22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi_0x2ac89400ceb0)
[transformData] Consumed 165 bytes from upstream VC
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] Completed reading input...
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_setup] Returning true for empty data
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_parse] Adding trailing text of size 68
starting at [
at t] as a PRE node
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_setup] Returning true for empty data
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_parse] Adding trailing text of size 68
starting at [
at t] as a PRE node
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_parser_0x2ac89400ceb0) [_parse] Added 1 node(s) during parse
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_processor_0x2ac89400ceb0) [_handleParseComplete] Parsed ESI
document with 3 nodes
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] Data not available yet; cannot
process document
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi)
[isInterceptRequest] Method [GET] invalid, [POST] expected
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi)
[globalHookHandler] handling read request header event...
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi)
[globalHookHandler] Not setting up intercept
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi)
[globalHookHandler] Not setting up intercept
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] Handling fetch event 10000...
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_fetcher_0x2ac89400ceb0) [handleFetchEvent] Received non-OK
status 404 for request [http://61.160.245.195/esi.php]
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] fetcher is ready with data,
going into process stage
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] input_vio NULL, but processing
needs to (and can) be completed
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] data ready; going to process doc
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] data ready; going to process doc
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_processor_0x2ac89400ceb0) [process] Processing ESI node [PRE]
with data of size 27 starting with [<HTML...][Sep 22 11:59:41.944] Server
{0x2ac882236700} DIAG: (plugin_esi_processor_0x2ac89400ceb0) [process]
Processing ESI node [PRE] with data of size 27 starting with [<HTML...]
[Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
(plugin_esi_processor_0x2ac89400ceb0) [process] Processing ESI node
[INCLUDE] with data of size 0 starting with [(null...]
[Sep 22 11:59:41.945] Server {0x2ac882236700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] Compressed document from size 0
to 20 bytes
[Sep 22 11:59:41.945] Server {0x2ac88263a700} DIAG:
(plugin_esi_fetcher_0x2ac89400ceb0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10003)
[Sep 22 11:59:41.945] Server {0x2ac88263a700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] handling
TS_EVENT_IMMEDIATE...
[Sep 22 11:59:41.945] Server {0x2ac88263a700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformData] input_vio NULL, marking
transformation to be terminated
[Sep 22 11:59:41.954] Server {0x2ac882337700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [Cache-Control]
[Sep 22 11:59:41.954] Server {0x2ac882337700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [X-Esi]
[Sep 22 11:59:41.954] Server {0x2ac882337700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [Age]
[Sep 22 11:59:41.954] Server {0x2ac882337700} DIAG: (plugin_esi)
[modifyResponseHeader] Inspected client-bound headers[Sep 22 11:59:41.954]
Server {0x2ac882337700} DIAG: (plugin_esi) [modifyResponseHeader] Inspected
client-bound headers
[Sep 22 11:59:41.954] Server {0x2ac88283c700} DIAG:
(plugin_esi_fetcher_0x2ac89400ceb0) [_isFetchEvent] Event id 103 not within
fetch event id range [10000, 10003)
[Sep 22 11:59:41.954] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] shutting down transformation
[Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
(plugin_esi_0x2ac89400ceb0) [checkXformStatus] Vconn closed
[Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
(plugin_esi_fetcher_0x2ac89400ceb0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10003)
[Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] Transformation closed.
Post-processing...
[Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] Processing is complete, not
processing current event 1
[Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] Processing is complete, not
processing current event 1
[Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
(plugin_esi_0x2ac89400ceb0) [transformHandler] transformation closed;
cleaning up data...
[Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
(plugin_esi_0x2ac89400ceb0) [~ContData] Destroying continuation data
[Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
(plugin_esi_0x2ac89400ceb0) [~ContData] Destroying continuation data
It works for my get the http://61.160.245.195/esi.php .
why debug said 404?
Re: ESI issue
Posted by 黄英才 <b1...@gmail.com>.
Yeah. It' wroks. thanks!
2012/9/25 Shu Kit Chan <ch...@gmail.com>
> I have filed a JIRA for this -
> https://issues.apache.org/jira/browse/TS-1499
>
> And there is a patch file in that JIRA you can try out as well.
>
> Thanks.
>
> Kit
>
>
> On Sat, Sep 22, 2012 at 12:58 AM, Shu Kit Chan <ch...@gmail.com>wrote:
>
>> I find out that it is a problem with "Connection: keep-alive"
>> Your browsers will send requests with this header.
>>
>> curl -v -H 'Connection: keep-alive' 'http://61.160.245.195:8080/esi.html'
>>
>> It will result in an empty response.
>> I was not able to reproduce this in my previous use case because my
>> origin server that i was using is ignoring the keepalive. (i.e. KeepAlive
>> Off in apache)
>> I think the proper fix is to strip this request header from all async
>> requests from the plugin for ESI includes.
>>
>> You can create a jira ticket and I can quickly submit a patch early next
>> week.
>>
>> Thanks.
>>
>> Kit
>>
>>
>>
>> On Fri, Sep 21, 2012 at 10:14 PM, 黄英才 <b1...@gmail.com> wrote:
>>
>>> Sorry, forgot the esi doc
>>>
>>> esi.html
>>>
>>> <HTML>
>>> <BODY>
>>> The time is: <esi:include src="http://61.160.245.195/esi.php"
>>> onerror="continue" />
>>> at this very moment. power by yingcai............
>>> </BODY>
>>> </HTML>
>>>
>>> esi.php
>>> <?php
>>> echo date('l jS \of F Y h:i:s A');
>>> ?>
>>>
>>>
>>> 2012/9/22 黄英才 <b1...@gmail.com>
>>>
>>>> my remap.config
>>>> map http://61.160.245.195:8080/ http://61.160.245.195/
>>>> map http://61.160.245.195/ http://61.160.245.195/
>>>> When i use the chrome for visit http://61.160.245.195:8080/esi.html
>>>> I get the follow
>>>> [image: 内嵌图片 1]
>>>>
>>>> The debug message:
>>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [isInterceptRequest] Skipping external request
>>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [globalHookHandler] handling read request header event...
>>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [globalHookHandler] Not setting up intercept
>>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [isInterceptRequest] Skipping external request
>>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [globalHookHandler] handling cache lookup complete event...
>>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [isCacheObjTransformable] cache object's status is 0; not transformable
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [isInterceptRequest] Skipping external request
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [globalHookHandler] handling read response header event...
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [isCacheObjTransformable] cache object's status is 0; not transformable
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [getClientState] Got request URL [http://61.160.245.195/esi.html]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>>> [Connection]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>>> [Cache-Control]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Pragma]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>>> [Accept-Encoding]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [getClientState] Client accepts gzip encoding; will compress output
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>>> [Accept-Encoding]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>>> [Accept-Encoding]
>>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>>> [Accept-Charset]
>>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>>> [Accept-Charset]
>>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>>> [Accept-Charset]
>>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [getServerState] Not retaining 'Content-length' header
>>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [getServerState] Not retaining 'X-Esi' header
>>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>>> [addTransform] Added transformation (0x0x2ac89400cbe0)
>>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [init] Set input data type to [RAW_ESI]
>>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] initialized continuation data
>>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>>>> fetch event id range [10000, 10000)
>>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] handling
>>>> TS_EVENT_IMMEDIATE...
>>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] upstream VC has 165 bytes
>>>> available to read
>>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [addParseData] Implicit call to
>>>> start()
>>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse], Adding data of size 27 before
>>>> (newly found) ESI tag as PRE node
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_compareData] string [include ] is
>>>> equal to data at position 32
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Found [INCLUDE] tag at position
>>>> 27
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_searchData] Found full match of /> in
>>>> [src="...] at position 95
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Handling include tag...
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_processIncludeTag] Added include tag
>>>> with url [http://61.160.245.195/esi.php]
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 2 node(s) during parse
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [_preprocess] Adding fetch request
>>>> for url [http://61.160.245.195/esi.php]
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400cbe0) [expand] Returning final expanded
>>>> expression [http://61.160.245.195/esi.php]
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_failureInfo) [_preprocess] URL request [
>>>> http://61.160.245.195/esi.php] 2189674240
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_buildHeadersString] Building header
>>>> string...
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cbe0) [addFetchRequest] Successfully added
>>>> fetch request for URL [http://61.160.245.195/esi.php]
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] Added chunk of 165 bytes
>>>> starting with [<HTML>
>>>> <BO] to parse list
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] Consumed 165 bytes from
>>>> upstream VC
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] Completed reading input...
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_setup] Returning true for empty data
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Adding trailing text of size 68
>>>> starting at [
>>>> at t] as a PRE node
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 1 node(s) during parse
>>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [_handleParseComplete] Parsed ESI
>>>> document with 3 nodes
>>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] Data not available yet; cannot
>>>> process document
>>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [globalHookHandler] handling read request header event...
>>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [globalHookHandler] Not setting up intercept
>>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [globalHookHandler] handling cache lookup complete event...
>>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [isCacheObjTransformable] cache object's status is 0; not transformable
>>>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>>>> fetch event id range [10000, 10003)
>>>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] handling
>>>> TS_EVENT_IMMEDIATE...
>>>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but data needs
>>>> to be fetched. Returning control
>>>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>>>> [modifyResponseHeader] Removing header with name [Cache-Control]
>>>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>>>> [modifyResponseHeader] Removing header with name [X-Esi]
>>>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>>>> [modifyResponseHeader] Removing header with name [Age]
>>>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>>>> [modifyResponseHeader] Inspected client-bound headers
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [globalHookHandler] handling read response header event...
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [isCacheObjTransformable] cache object's status is 0; not transformable
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [getClientState] Got request URL [http://61.160.245.195/esi.php]
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Pragma]
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>>>> [Accept-Encoding]
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>>>> [Accept-Charset]
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>>>> [Connection]
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Accept]
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>>>> [Cache-Control]
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [getServerState] Not retaining 'X-Esi' header
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [getServerState] Not retaining 'Content-length' header
>>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>>> [addTransform] Added transformation (0x0x2ac89400caf0)
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [init] Set input data type to [RAW_ESI]
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformHandler] initialized continuation data
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
>>>> fetch event id range [10000, 10000)
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformHandler] handling
>>>> TS_EVENT_IMMEDIATE...
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformData] upstream VC has 44 bytes
>>>> available to read
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400caf0) [addParseData] Implicit call to
>>>> start()
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Added 0 node(s) during parse
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformData] Added chunk of 44 bytes
>>>> starting with [Saturday 2] to parse list
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformData] Consumed 44 bytes from upstream
>>>> VC
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformData] Completed reading input...
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400caf0) [_setup] Returning true for empty data
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Adding trailing text of size 44
>>>> starting at [Satur] as a PRE node
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Added 1 node(s) during parse
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400caf0) [_handleParseComplete] Parsed ESI
>>>> document with 1 nodes
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformData] data ready; going to process doc
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400caf0) [process] Processing ESI node [PRE]
>>>> with data of size 44 starting with [Satur...]
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400caf0) [process] ESI processed document of
>>>> size 44 starting with [Saturday 2]
>>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformData] ESI processor output document
>>>> of size 44 starting with [Saturday 2]
>>>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>>>> [modifyResponseHeader] Removing header with name [Cache-Control]
>>>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>>>> [modifyResponseHeader] Removing header with name [X-Esi]
>>>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>>>> [modifyResponseHeader] Removing header with name [Age]
>>>> [Sep 22 13:05:10.500] Server {0x2ac882539700} DIAG: (plugin_esi)
>>>> [modifyResponseHeader] Inspected client-bound headers
>>>> [Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 103 not within
>>>> fetch event id range [10000, 10000)
>>>> [Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformHandler] shutting down transformation
>>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [checkXformStatus] Vconn closed
>>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
>>>> fetch event id range [10000, 10000)
>>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformHandler] Transformation closed.
>>>> Post-processing...
>>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformHandler] Processing is complete, not
>>>> processing current event 1
>>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [transformHandler] transformation closed;
>>>> cleaning up data...
>>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>>> (plugin_esi_0x2ac89400caf0) [~ContData] Destroying continuation data
>>>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [checkXformStatus] Error while getting close
>>>> status of transformation at state 1
>>>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>>>> fetch event id range [10000, 10003)
>>>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>>>> Post-processing...
>>>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Ignoring event 1; Will wait
>>>> for pending data
>>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Handling fetch event 10000...
>>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cdc0) [handleFetchEvent] Inserted page data
>>>> of size 44 starting with [Saturd] for request [
>>>> http://61.160.245.195/esi.php]
>>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] fetcher is ready with data,
>>>> going into process stage
>>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformData] input_vio NULL, but processing
>>>> needs to (and can) be completed
>>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformData] data ready; going to process doc
>>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
>>>> with data of size 27 starting with [<HTML...]
>>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node
>>>> [INCLUDE] with data of size 0 starting with [(null...]
>>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cdc0) [getData] Found data for URL [
>>>> http://61.160.245.195/esi.php] of size 44 starting with [Satur]
>>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cdc0) [_getIncludeData] Got content
>>>> successfully for URL [http://61.160.245.195/esi.php]
>>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cdc0) [_processEsiNode] Processed ESI
>>>> [INCLUDE] node
>>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
>>>> with data of size 68 starting with [
>>>> at t...]
>>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cdc0) [process] ESI processed document of
>>>> size 139 starting with [<HTML>
>>>> <BO]
>>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformData] ESI processor output document
>>>> of size 139 starting with [<HTML>
>>>> <BO]
>>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformData] Compressed document from size
>>>> 139 to 139 bytes
>>>> [Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 103 not within
>>>> fetch event id range [10000, 10003)
>>>> [Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] shutting down transformation
>>>> [Sep 22 13:06:11.770] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [checkXformStatus] Vconn closed
>>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 1 not within
>>>> fetch event id range [10000, 10003)
>>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Transformation closed.
>>>> Post-processing...
>>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Processing is complete, not
>>>> processing current event 1
>>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] transformation closed;
>>>> cleaning up data...
>>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>>> (plugin_esi_0x2ac89400cdc0) [~ContData] Destroying continuation data
>>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>>>> Post-processing...
>>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Going to process received
>>>> data
>>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Handling fetch event 10000...
>>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cbe0) [handleFetchEvent] Inserted page data
>>>> of size 44 starting with [Saturd] for request [
>>>> http://61.160.245.195/esi.php]
>>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] fetcher is ready with data,
>>>> going into process stage
>>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but processing
>>>> needs to (and can) be completed
>>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] data ready; going to process doc
>>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
>>>> with data of size 27 starting with [<HTML...]
>>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node
>>>> [INCLUDE] with data of size 0 starting with [(null...]
>>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cbe0) [getData] Found data for URL [
>>>> http://61.160.245.195/esi.php] of size 44 starting with [Satur]
>>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [_getIncludeData] Got content
>>>> successfully for URL [http://61.160.245.195/esi.php]
>>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [_processEsiNode] Processed ESI
>>>> [INCLUDE] node
>>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
>>>> with data of size 68 starting with [
>>>> at t...]
>>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_processor_0x2ac89400cbe0) [process] ESI processed document of
>>>> size 139 starting with [<HTML>
>>>> <BO]
>>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformData] ESI processor output document
>>>> of size 139 starting with [<HTML>
>>>> <BO]
>>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Deferring shutdown as data
>>>> event was just processed
>>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 2 not within
>>>> fetch event id range [10000, 10003)
>>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>>>> Post-processing...
>>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Processing is complete, not
>>>> processing current event 2
>>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] transformation closed;
>>>> cleaning up data...
>>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>>> (plugin_esi_0x2ac89400cbe0) [~ContData] Destroying continuation data
>>>>
>>>>
>>>> When i use the curl to test. It's works for me.why?
>>>>
>>>> [root@yingcai html]# curl -v http://61.160.245.195:8080/esi.html
>>>> * About to connect() to 61.160.245.195 port 8080 (#0)
>>>> * Trying 61.160.245.195... connected
>>>> * Connected to 61.160.245.195 (61.160.245.195) port 8080 (#0)
>>>> > GET /esi.html HTTP/1.1
>>>> > User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/
>>>> 3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2
>>>> > Host: 61.160.245.195:8080
>>>> > Accept: */*
>>>> >
>>>> < HTTP/1.1 200 OK
>>>> < Date: Sat, 22 Sep 2012 05:02:30 GMT
>>>> < Server: ATS/3.3.1-dev
>>>> < Last-Modified: Sat, 22 Sep 2012 05:00:30 GMT
>>>> < Accept-Ranges: bytes
>>>> < Content-Type: text/html; charset=UTF-8
>>>> < Content-Length: 139
>>>> < Connection: keep-alive
>>>> <
>>>> <HTML>
>>>> <BODY>
>>>> The time is: Saturday 22nd of September 2012 01:02:30 PM
>>>>
>>>> at this very moment. power by yingcai............
>>>> </BODY>
>>>> </HTML>
>>>>
>>>> * Connection #0 to host 61.160.245.195 left intact
>>>> * Closing connection #0
>>>>
>>>> But the same issue in firefox. why curl worked?
>>>>
>>>
>>>
>>
>
Re: ESI issue
Posted by Shu Kit Chan <ch...@gmail.com>.
I have filed a JIRA for this - https://issues.apache.org/jira/browse/TS-1499
And there is a patch file in that JIRA you can try out as well.
Thanks.
Kit
On Sat, Sep 22, 2012 at 12:58 AM, Shu Kit Chan <ch...@gmail.com> wrote:
> I find out that it is a problem with "Connection: keep-alive"
> Your browsers will send requests with this header.
>
> curl -v -H 'Connection: keep-alive' 'http://61.160.245.195:8080/esi.html'
>
> It will result in an empty response.
> I was not able to reproduce this in my previous use case because my origin
> server that i was using is ignoring the keepalive. (i.e. KeepAlive Off in
> apache)
> I think the proper fix is to strip this request header from all async
> requests from the plugin for ESI includes.
>
> You can create a jira ticket and I can quickly submit a patch early next
> week.
>
> Thanks.
>
> Kit
>
>
>
> On Fri, Sep 21, 2012 at 10:14 PM, 黄英才 <b1...@gmail.com> wrote:
>
>> Sorry, forgot the esi doc
>>
>> esi.html
>>
>> <HTML>
>> <BODY>
>> The time is: <esi:include src="http://61.160.245.195/esi.php"
>> onerror="continue" />
>> at this very moment. power by yingcai............
>> </BODY>
>> </HTML>
>>
>> esi.php
>> <?php
>> echo date('l jS \of F Y h:i:s A');
>> ?>
>>
>>
>> 2012/9/22 黄英才 <b1...@gmail.com>
>>
>>> my remap.config
>>> map http://61.160.245.195:8080/ http://61.160.245.195/
>>> map http://61.160.245.195/ http://61.160.245.195/
>>> When i use the chrome for visit http://61.160.245.195:8080/esi.html
>>> I get the follow
>>> [image: 内嵌图片 1]
>>>
>>> The debug message:
>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [isInterceptRequest] Skipping external request
>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [globalHookHandler] handling read request header event...
>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [globalHookHandler] Not setting up intercept
>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [isInterceptRequest] Skipping external request
>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [globalHookHandler] handling cache lookup complete event...
>>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [isCacheObjTransformable] cache object's status is 0; not transformable
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [isInterceptRequest] Skipping external request
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [globalHookHandler] handling read response header event...
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [isCacheObjTransformable] cache object's status is 0; not transformable
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [getClientState] Got request URL [http://61.160.245.195/esi.html]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>> [Connection]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>> [Cache-Control]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Pragma]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>> [Accept-Encoding]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [getClientState] Client accepts gzip encoding; will compress output
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>> [Accept-Encoding]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>> [Accept-Encoding]
>>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>> [Accept-Charset]
>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>> [Accept-Charset]
>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>>> [Accept-Charset]
>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [getServerState] Not retaining 'Content-length' header
>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [getServerState] Not retaining 'X-Esi' header
>>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>>> [addTransform] Added transformation (0x0x2ac89400cbe0)
>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [init] Set input data type to [RAW_ESI]
>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] initialized continuation data
>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>>> fetch event id range [10000, 10000)
>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] handling
>>> TS_EVENT_IMMEDIATE...
>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] upstream VC has 165 bytes
>>> available to read
>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [addParseData] Implicit call to
>>> start()
>>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse], Adding data of size 27 before
>>> (newly found) ESI tag as PRE node
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_compareData] string [include ] is
>>> equal to data at position 32
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Found [INCLUDE] tag at position
>>> 27
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_searchData] Found full match of /> in
>>> [src="...] at position 95
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Handling include tag...
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_processIncludeTag] Added include tag
>>> with url [http://61.160.245.195/esi.php]
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 2 node(s) during parse
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [_preprocess] Adding fetch request
>>> for url [http://61.160.245.195/esi.php]
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_vars_0x2ac89400cbe0) [expand] Returning final expanded
>>> expression [http://61.160.245.195/esi.php]
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_failureInfo) [_preprocess] URL request [
>>> http://61.160.245.195/esi.php] 2189674240
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_buildHeadersString] Building header
>>> string...
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cbe0) [addFetchRequest] Successfully added
>>> fetch request for URL [http://61.160.245.195/esi.php]
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] Added chunk of 165 bytes
>>> starting with [<HTML>
>>> <BO] to parse list
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] Consumed 165 bytes from
>>> upstream VC
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] Completed reading input...
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_setup] Returning true for empty data
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Adding trailing text of size 68
>>> starting at [
>>> at t] as a PRE node
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 1 node(s) during parse
>>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [_handleParseComplete] Parsed ESI
>>> document with 3 nodes
>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] Data not available yet; cannot
>>> process document
>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [globalHookHandler] handling read request header event...
>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [globalHookHandler] Not setting up intercept
>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [globalHookHandler] handling cache lookup complete event...
>>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [isCacheObjTransformable] cache object's status is 0; not transformable
>>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>>> fetch event id range [10000, 10003)
>>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] handling
>>> TS_EVENT_IMMEDIATE...
>>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but data needs
>>> to be fetched. Returning control
>>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>>> [modifyResponseHeader] Removing header with name [Cache-Control]
>>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>>> [modifyResponseHeader] Removing header with name [X-Esi]
>>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>>> [modifyResponseHeader] Removing header with name [Age]
>>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>>> [modifyResponseHeader] Inspected client-bound headers
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [globalHookHandler] handling read response header event...
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [isCacheObjTransformable] cache object's status is 0; not transformable
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [getClientState] Got request URL [http://61.160.245.195/esi.php]
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Pragma]
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>>> [Accept-Encoding]
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>>> [Accept-Charset]
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>>> [Connection]
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Accept]
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>>> [Cache-Control]
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [getServerState] Not retaining 'X-Esi' header
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [getServerState] Not retaining 'Content-length' header
>>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>>> [addTransform] Added transformation (0x0x2ac89400caf0)
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [init] Set input data type to [RAW_ESI]
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformHandler] initialized continuation data
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
>>> fetch event id range [10000, 10000)
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformHandler] handling
>>> TS_EVENT_IMMEDIATE...
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformData] upstream VC has 44 bytes
>>> available to read
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_processor_0x2ac89400caf0) [addParseData] Implicit call to
>>> start()
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Added 0 node(s) during parse
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformData] Added chunk of 44 bytes
>>> starting with [Saturday 2] to parse list
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformData] Consumed 44 bytes from upstream
>>> VC
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformData] Completed reading input...
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_parser_0x2ac89400caf0) [_setup] Returning true for empty data
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Adding trailing text of size 44
>>> starting at [Satur] as a PRE node
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Added 1 node(s) during parse
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_processor_0x2ac89400caf0) [_handleParseComplete] Parsed ESI
>>> document with 1 nodes
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformData] data ready; going to process doc
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_processor_0x2ac89400caf0) [process] Processing ESI node [PRE]
>>> with data of size 44 starting with [Satur...]
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_processor_0x2ac89400caf0) [process] ESI processed document of
>>> size 44 starting with [Saturday 2]
>>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformData] ESI processor output document
>>> of size 44 starting with [Saturday 2]
>>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>>> [modifyResponseHeader] Removing header with name [Cache-Control]
>>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>>> [modifyResponseHeader] Removing header with name [X-Esi]
>>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>>> [modifyResponseHeader] Removing header with name [Age]
>>> [Sep 22 13:05:10.500] Server {0x2ac882539700} DIAG: (plugin_esi)
>>> [modifyResponseHeader] Inspected client-bound headers
>>> [Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 103 not within
>>> fetch event id range [10000, 10000)
>>> [Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformHandler] shutting down transformation
>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [checkXformStatus] Vconn closed
>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
>>> fetch event id range [10000, 10000)
>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformHandler] Transformation closed.
>>> Post-processing...
>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformHandler] Processing is complete, not
>>> processing current event 1
>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [transformHandler] transformation closed;
>>> cleaning up data...
>>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>>> (plugin_esi_0x2ac89400caf0) [~ContData] Destroying continuation data
>>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [checkXformStatus] Error while getting close
>>> status of transformation at state 1
>>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>>> fetch event id range [10000, 10003)
>>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>>> Post-processing...
>>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Ignoring event 1; Will wait
>>> for pending data
>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Handling fetch event 10000...
>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cdc0) [handleFetchEvent] Inserted page data
>>> of size 44 starting with [Saturd] for request [
>>> http://61.160.245.195/esi.php]
>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] fetcher is ready with data,
>>> going into process stage
>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformData] input_vio NULL, but processing
>>> needs to (and can) be completed
>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformData] data ready; going to process doc
>>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
>>> with data of size 27 starting with [<HTML...]
>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node
>>> [INCLUDE] with data of size 0 starting with [(null...]
>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cdc0) [getData] Found data for URL [
>>> http://61.160.245.195/esi.php] of size 44 starting with [Satur]
>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cdc0) [_getIncludeData] Got content
>>> successfully for URL [http://61.160.245.195/esi.php]
>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cdc0) [_processEsiNode] Processed ESI
>>> [INCLUDE] node
>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
>>> with data of size 68 starting with [
>>> at t...]
>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cdc0) [process] ESI processed document of
>>> size 139 starting with [<HTML>
>>> <BO]
>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformData] ESI processor output document
>>> of size 139 starting with [<HTML>
>>> <BO]
>>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformData] Compressed document from size
>>> 139 to 139 bytes
>>> [Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 103 not within
>>> fetch event id range [10000, 10003)
>>> [Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] shutting down transformation
>>> [Sep 22 13:06:11.770] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [checkXformStatus] Vconn closed
>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 1 not within
>>> fetch event id range [10000, 10003)
>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Transformation closed.
>>> Post-processing...
>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Processing is complete, not
>>> processing current event 1
>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [transformHandler] transformation closed;
>>> cleaning up data...
>>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>>> (plugin_esi_0x2ac89400cdc0) [~ContData] Destroying continuation data
>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>>> Post-processing...
>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Going to process received
>>> data
>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Handling fetch event 10000...
>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cbe0) [handleFetchEvent] Inserted page data
>>> of size 44 starting with [Saturd] for request [
>>> http://61.160.245.195/esi.php]
>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] fetcher is ready with data,
>>> going into process stage
>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but processing
>>> needs to (and can) be completed
>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] data ready; going to process doc
>>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
>>> with data of size 27 starting with [<HTML...]
>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node
>>> [INCLUDE] with data of size 0 starting with [(null...]
>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cbe0) [getData] Found data for URL [
>>> http://61.160.245.195/esi.php] of size 44 starting with [Satur]
>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [_getIncludeData] Got content
>>> successfully for URL [http://61.160.245.195/esi.php]
>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [_processEsiNode] Processed ESI
>>> [INCLUDE] node
>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
>>> with data of size 68 starting with [
>>> at t...]
>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_processor_0x2ac89400cbe0) [process] ESI processed document of
>>> size 139 starting with [<HTML>
>>> <BO]
>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformData] ESI processor output document
>>> of size 139 starting with [<HTML>
>>> <BO]
>>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Deferring shutdown as data
>>> event was just processed
>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 2 not within
>>> fetch event id range [10000, 10003)
>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>>> Post-processing...
>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Processing is complete, not
>>> processing current event 2
>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [transformHandler] transformation closed;
>>> cleaning up data...
>>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>>> (plugin_esi_0x2ac89400cbe0) [~ContData] Destroying continuation data
>>>
>>>
>>> When i use the curl to test. It's works for me.why?
>>>
>>> [root@yingcai html]# curl -v http://61.160.245.195:8080/esi.html
>>> * About to connect() to 61.160.245.195 port 8080 (#0)
>>> * Trying 61.160.245.195... connected
>>> * Connected to 61.160.245.195 (61.160.245.195) port 8080 (#0)
>>> > GET /esi.html HTTP/1.1
>>> > User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/
>>> 3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2
>>> > Host: 61.160.245.195:8080
>>> > Accept: */*
>>> >
>>> < HTTP/1.1 200 OK
>>> < Date: Sat, 22 Sep 2012 05:02:30 GMT
>>> < Server: ATS/3.3.1-dev
>>> < Last-Modified: Sat, 22 Sep 2012 05:00:30 GMT
>>> < Accept-Ranges: bytes
>>> < Content-Type: text/html; charset=UTF-8
>>> < Content-Length: 139
>>> < Connection: keep-alive
>>> <
>>> <HTML>
>>> <BODY>
>>> The time is: Saturday 22nd of September 2012 01:02:30 PM
>>>
>>> at this very moment. power by yingcai............
>>> </BODY>
>>> </HTML>
>>>
>>> * Connection #0 to host 61.160.245.195 left intact
>>> * Closing connection #0
>>>
>>> But the same issue in firefox. why curl worked?
>>>
>>
>>
>
Re: ESI issue
Posted by Shu Kit Chan <ch...@gmail.com>.
I find out that it is a problem with "Connection: keep-alive"
Your browsers will send requests with this header.
curl -v -H 'Connection: keep-alive' 'http://61.160.245.195:8080/esi.html'
It will result in an empty response.
I was not able to reproduce this in my previous use case because my origin
server that i was using is ignoring the keepalive. (i.e. KeepAlive Off in
apache)
I think the proper fix is to strip this request header from all async
requests from the plugin for ESI includes.
You can create a jira ticket and I can quickly submit a patch early next
week.
Thanks.
Kit
On Fri, Sep 21, 2012 at 10:14 PM, 黄英才 <b1...@gmail.com> wrote:
> Sorry, forgot the esi doc
>
> esi.html
>
> <HTML>
> <BODY>
> The time is: <esi:include src="http://61.160.245.195/esi.php"
> onerror="continue" />
> at this very moment. power by yingcai............
> </BODY>
> </HTML>
>
> esi.php
> <?php
> echo date('l jS \of F Y h:i:s A');
> ?>
>
>
> 2012/9/22 黄英才 <b1...@gmail.com>
>
>> my remap.config
>> map http://61.160.245.195:8080/ http://61.160.245.195/
>> map http://61.160.245.195/ http://61.160.245.195/
>> When i use the chrome for visit http://61.160.245.195:8080/esi.html
>> I get the follow
>> [image: 内嵌图片 1]
>>
>> The debug message:
>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [isInterceptRequest] Skipping external request
>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [globalHookHandler] handling read request header event...
>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [globalHookHandler] Not setting up intercept
>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [isInterceptRequest] Skipping external request
>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [globalHookHandler] handling cache lookup complete event...
>> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [isCacheObjTransformable] cache object's status is 0; not transformable
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [isInterceptRequest] Skipping external request
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [globalHookHandler] handling read response header event...
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [isCacheObjTransformable] cache object's status is 0; not transformable
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [getClientState] Got request URL [http://61.160.245.195/esi.html]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>> [Connection]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>> [Cache-Control]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Pragma]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>> [Accept-Encoding]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [getClientState] Client accepts gzip encoding; will compress output
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>> [Accept-Encoding]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>> [Accept-Encoding]
>> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>> [Accept-Charset]
>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>> [Accept-Charset]
>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
>> [Accept-Charset]
>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [getServerState] Not retaining 'Content-length' header
>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [getServerState] Not retaining 'X-Esi' header
>> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
>> [addTransform] Added transformation (0x0x2ac89400cbe0)
>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [init] Set input data type to [RAW_ESI]
>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] initialized continuation data
>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>> fetch event id range [10000, 10000)
>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] handling
>> TS_EVENT_IMMEDIATE...
>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] upstream VC has 165 bytes
>> available to read
>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [addParseData] Implicit call to
>> start()
>> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_parse], Adding data of size 27 before
>> (newly found) ESI tag as PRE node
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_compareData] string [include ] is
>> equal to data at position 32
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Found [INCLUDE] tag at position
>> 27
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_searchData] Found full match of /> in
>> [src="...] at position 95
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Handling include tag...
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_processIncludeTag] Added include tag
>> with url [http://61.160.245.195/esi.php]
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 2 node(s) during parse
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [_preprocess] Adding fetch request
>> for url [http://61.160.245.195/esi.php]
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_vars_0x2ac89400cbe0) [expand] Returning final expanded
>> expression [http://61.160.245.195/esi.php]
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_failureInfo) [_preprocess] URL request [
>> http://61.160.245.195/esi.php] 2189674240
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cbe0) [_buildHeadersString] Building header
>> string...
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cbe0) [addFetchRequest] Successfully added
>> fetch request for URL [http://61.160.245.195/esi.php]
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] Added chunk of 165 bytes
>> starting with [<HTML>
>> <BO] to parse list
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] Consumed 165 bytes from
>> upstream VC
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] Completed reading input...
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_setup] Returning true for empty data
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Adding trailing text of size 68
>> starting at [
>> at t] as a PRE node
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 1 node(s) during parse
>> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [_handleParseComplete] Parsed ESI
>> document with 3 nodes
>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] Data not available yet; cannot
>> process document
>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [globalHookHandler] handling read request header event...
>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [globalHookHandler] Not setting up intercept
>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [globalHookHandler] handling cache lookup complete event...
>> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [isCacheObjTransformable] cache object's status is 0; not transformable
>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>> fetch event id range [10000, 10003)
>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] handling
>> TS_EVENT_IMMEDIATE...
>> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but data needs
>> to be fetched. Returning control
>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>> [modifyResponseHeader] Removing header with name [Cache-Control]
>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>> [modifyResponseHeader] Removing header with name [X-Esi]
>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>> [modifyResponseHeader] Removing header with name [Age]
>> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
>> [modifyResponseHeader] Inspected client-bound headers
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [isInterceptRequest] Method [GET] invalid, [POST] expected
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [globalHookHandler] handling read response header event...
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [isCacheObjTransformable] cache object's status is 0; not transformable
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [getClientState] Got request URL [http://61.160.245.195/esi.php]
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Pragma]
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>> [Accept-Encoding]
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>> [Accept-Charset]
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>> [Connection]
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Accept]
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
>> [Cache-Control]
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [getServerState] Not retaining 'X-Esi' header
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [getServerState] Not retaining 'Content-length' header
>> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
>> [addTransform] Added transformation (0x0x2ac89400caf0)
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [init] Set input data type to [RAW_ESI]
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformHandler] initialized continuation data
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
>> fetch event id range [10000, 10000)
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformHandler] handling
>> TS_EVENT_IMMEDIATE...
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformData] upstream VC has 44 bytes
>> available to read
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_processor_0x2ac89400caf0) [addParseData] Implicit call to
>> start()
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Added 0 node(s) during parse
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformData] Added chunk of 44 bytes
>> starting with [Saturday 2] to parse list
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformData] Consumed 44 bytes from upstream
>> VC
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformData] Completed reading input...
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_parser_0x2ac89400caf0) [_setup] Returning true for empty data
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Adding trailing text of size 44
>> starting at [Satur] as a PRE node
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_parser_0x2ac89400caf0) [_parse] Added 1 node(s) during parse
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_processor_0x2ac89400caf0) [_handleParseComplete] Parsed ESI
>> document with 1 nodes
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformData] data ready; going to process doc
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_processor_0x2ac89400caf0) [process] Processing ESI node [PRE]
>> with data of size 44 starting with [Satur...]
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_processor_0x2ac89400caf0) [process] ESI processed document of
>> size 44 starting with [Saturday 2]
>> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformData] ESI processor output document
>> of size 44 starting with [Saturday 2]
>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>> [modifyResponseHeader] Removing header with name [Cache-Control]
>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>> [modifyResponseHeader] Removing header with name [X-Esi]
>> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
>> [modifyResponseHeader] Removing header with name [Age]
>> [Sep 22 13:05:10.500] Server {0x2ac882539700} DIAG: (plugin_esi)
>> [modifyResponseHeader] Inspected client-bound headers
>> [Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 103 not within
>> fetch event id range [10000, 10000)
>> [Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformHandler] shutting down transformation
>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [checkXformStatus] Vconn closed
>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
>> fetch event id range [10000, 10000)
>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformHandler] Transformation closed.
>> Post-processing...
>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformHandler] Processing is complete, not
>> processing current event 1
>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [transformHandler] transformation closed;
>> cleaning up data...
>> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
>> (plugin_esi_0x2ac89400caf0) [~ContData] Destroying continuation data
>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [checkXformStatus] Error while getting close
>> status of transformation at state 1
>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
>> fetch event id range [10000, 10003)
>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>> Post-processing...
>> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Ignoring event 1; Will wait
>> for pending data
>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Handling fetch event 10000...
>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cdc0) [handleFetchEvent] Inserted page data
>> of size 44 starting with [Saturd] for request [
>> http://61.160.245.195/esi.php]
>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformHandler] fetcher is ready with data,
>> going into process stage
>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformData] input_vio NULL, but processing
>> needs to (and can) be completed
>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformData] data ready; going to process doc
>> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
>> with data of size 27 starting with [<HTML...]
>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node
>> [INCLUDE] with data of size 0 starting with [(null...]
>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cdc0) [getData] Found data for URL [
>> http://61.160.245.195/esi.php] of size 44 starting with [Satur]
>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_processor_0x2ac89400cdc0) [_getIncludeData] Got content
>> successfully for URL [http://61.160.245.195/esi.php]
>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_processor_0x2ac89400cdc0) [_processEsiNode] Processed ESI
>> [INCLUDE] node
>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
>> with data of size 68 starting with [
>> at t...]
>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_processor_0x2ac89400cdc0) [process] ESI processed document of
>> size 139 starting with [<HTML>
>> <BO]
>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformData] ESI processor output document
>> of size 139 starting with [<HTML>
>> <BO]
>> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformData] Compressed document from size
>> 139 to 139 bytes
>> [Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 103 not within
>> fetch event id range [10000, 10003)
>> [Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformHandler] shutting down transformation
>> [Sep 22 13:06:11.770] Server {0x2ac882034700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [checkXformStatus] Vconn closed
>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 1 not within
>> fetch event id range [10000, 10003)
>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Transformation closed.
>> Post-processing...
>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformHandler] Processing is complete, not
>> processing current event 1
>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [transformHandler] transformation closed;
>> cleaning up data...
>> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
>> (plugin_esi_0x2ac89400cdc0) [~ContData] Destroying continuation data
>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>> Post-processing...
>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Going to process received
>> data
>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Handling fetch event 10000...
>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cbe0) [handleFetchEvent] Inserted page data
>> of size 44 starting with [Saturd] for request [
>> http://61.160.245.195/esi.php]
>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] fetcher is ready with data,
>> going into process stage
>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but processing
>> needs to (and can) be completed
>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] data ready; going to process doc
>> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
>> with data of size 27 starting with [<HTML...]
>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node
>> [INCLUDE] with data of size 0 starting with [(null...]
>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cbe0) [getData] Found data for URL [
>> http://61.160.245.195/esi.php] of size 44 starting with [Satur]
>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [_getIncludeData] Got content
>> successfully for URL [http://61.160.245.195/esi.php]
>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [_processEsiNode] Processed ESI
>> [INCLUDE] node
>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
>> with data of size 68 starting with [
>> at t...]
>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_processor_0x2ac89400cbe0) [process] ESI processed document of
>> size 139 starting with [<HTML>
>> <BO]
>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformData] ESI processor output document
>> of size 139 starting with [<HTML>
>> <BO]
>> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Deferring shutdown as data
>> event was just processed
>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 2 not within
>> fetch event id range [10000, 10003)
>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
>> Post-processing...
>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] Processing is complete, not
>> processing current event 2
>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [transformHandler] transformation closed;
>> cleaning up data...
>> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
>> (plugin_esi_0x2ac89400cbe0) [~ContData] Destroying continuation data
>>
>>
>> When i use the curl to test. It's works for me.why?
>>
>> [root@yingcai html]# curl -v http://61.160.245.195:8080/esi.html
>> * About to connect() to 61.160.245.195 port 8080 (#0)
>> * Trying 61.160.245.195... connected
>> * Connected to 61.160.245.195 (61.160.245.195) port 8080 (#0)
>> > GET /esi.html HTTP/1.1
>> > User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/
>> 3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2
>> > Host: 61.160.245.195:8080
>> > Accept: */*
>> >
>> < HTTP/1.1 200 OK
>> < Date: Sat, 22 Sep 2012 05:02:30 GMT
>> < Server: ATS/3.3.1-dev
>> < Last-Modified: Sat, 22 Sep 2012 05:00:30 GMT
>> < Accept-Ranges: bytes
>> < Content-Type: text/html; charset=UTF-8
>> < Content-Length: 139
>> < Connection: keep-alive
>> <
>> <HTML>
>> <BODY>
>> The time is: Saturday 22nd of September 2012 01:02:30 PM
>>
>> at this very moment. power by yingcai............
>> </BODY>
>> </HTML>
>>
>> * Connection #0 to host 61.160.245.195 left intact
>> * Closing connection #0
>>
>> But the same issue in firefox. why curl worked?
>>
>
>
Re: ESI issue
Posted by 黄英才 <b1...@gmail.com>.
Sorry, forgot the esi doc
esi.html
<HTML>
<BODY>
The time is: <esi:include src="http://61.160.245.195/esi.php"
onerror="continue" />
at this very moment. power by yingcai............
</BODY>
</HTML>
esi.php
<?php
echo date('l jS \of F Y h:i:s A');
?>
2012/9/22 黄英才 <b1...@gmail.com>
> my remap.config
> map http://61.160.245.195:8080/ http://61.160.245.195/
> map http://61.160.245.195/ http://61.160.245.195/
> When i use the chrome for visit http://61.160.245.195:8080/esi.html
> I get the follow
> [image: 内嵌图片 1]
>
> The debug message:
> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [isInterceptRequest] Skipping external request
> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [globalHookHandler] handling read request header event...
> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [globalHookHandler] Not setting up intercept
> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [isInterceptRequest] Skipping external request
> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [globalHookHandler] handling cache lookup complete event...
> [Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [isCacheObjTransformable] cache object's status is 0; not transformable
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [isInterceptRequest] Skipping external request
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [globalHookHandler] handling read response header event...
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [isCacheObjTransformable] cache object's status is 0; not transformable
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [getClientState] Got request URL [http://61.160.245.195/esi.html]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
> [Connection]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
> [Cache-Control]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Pragma]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
> [Accept-Encoding]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [getClientState] Client accepts gzip encoding; will compress output
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
> [Accept-Encoding]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
> [Accept-Encoding]
> [Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
> [Accept-Charset]
> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
> [Accept-Charset]
> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
> [Accept-Charset]
> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [getServerState] Not retaining 'Content-length' header
> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [getServerState] Not retaining 'X-Esi' header
> [Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
> [addTransform] Added transformation (0x0x2ac89400cbe0)
> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [init] Set input data type to [RAW_ESI]
> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] initialized continuation data
> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10000)
> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] handling
> TS_EVENT_IMMEDIATE...
> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] upstream VC has 165 bytes
> available to read
> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [addParseData] Implicit call to
> start()
> [Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_parse], Adding data of size 27 before
> (newly found) ESI tag as PRE node
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_compareData] string [include ] is
> equal to data at position 32
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Found [INCLUDE] tag at position
> 27
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_searchData] Found full match of /> in
> [src="...] at position 95
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Handling include tag...
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_processIncludeTag] Added include tag
> with url [http://61.160.245.195/esi.php]
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 2 node(s) during parse
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [_preprocess] Adding fetch request
> for url [http://61.160.245.195/esi.php]
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_vars_0x2ac89400cbe0) [expand] Returning final expanded
> expression [http://61.160.245.195/esi.php]
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_failureInfo) [_preprocess] URL request [
> http://61.160.245.195/esi.php] 2189674240
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cbe0) [_buildHeadersString] Building header
> string...
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cbe0) [addFetchRequest] Successfully added
> fetch request for URL [http://61.160.245.195/esi.php]
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] Added chunk of 165 bytes
> starting with [<HTML>
> <BO] to parse list
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] Consumed 165 bytes from
> upstream VC
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] Completed reading input...
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_setup] Returning true for empty data
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Adding trailing text of size 68
> starting at [
> at t] as a PRE node
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 1 node(s) during parse
> [Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [_handleParseComplete] Parsed ESI
> document with 3 nodes
> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] Data not available yet; cannot
> process document
> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [isInterceptRequest] Method [GET] invalid, [POST] expected
> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [globalHookHandler] handling read request header event...
> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [globalHookHandler] Not setting up intercept
> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [isInterceptRequest] Method [GET] invalid, [POST] expected
> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [globalHookHandler] handling cache lookup complete event...
> [Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [isCacheObjTransformable] cache object's status is 0; not transformable
> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10003)
> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] handling
> TS_EVENT_IMMEDIATE...
> [Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but data needs
> to be fetched. Returning control
> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [Cache-Control]
> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [X-Esi]
> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [Age]
> [Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
> [modifyResponseHeader] Inspected client-bound headers
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [isInterceptRequest] Method [GET] invalid, [POST] expected
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [globalHookHandler] handling read response header event...
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [isCacheObjTransformable] cache object's status is 0; not transformable
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [getClientState] Got request URL [http://61.160.245.195/esi.php]
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Pragma]
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
> [Accept-Encoding]
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
> [Accept-Charset]
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
> [Connection]
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Accept]
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
> (plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
> [Cache-Control]
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [getServerState] Not retaining 'X-Esi' header
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [getServerState] Not retaining 'Content-length' header
> [Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
> [addTransform] Added transformation (0x0x2ac89400caf0)
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [init] Set input data type to [RAW_ESI]
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformHandler] initialized continuation data
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10000)
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformHandler] handling
> TS_EVENT_IMMEDIATE...
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformData] upstream VC has 44 bytes
> available to read
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_processor_0x2ac89400caf0) [addParseData] Implicit call to
> start()
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_parser_0x2ac89400caf0) [_parse] Added 0 node(s) during parse
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformData] Added chunk of 44 bytes
> starting with [Saturday 2] to parse list
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformData] Consumed 44 bytes from upstream
> VC
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformData] Completed reading input...
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_parser_0x2ac89400caf0) [_setup] Returning true for empty data
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_parser_0x2ac89400caf0) [_parse] Adding trailing text of size 44
> starting at [Satur] as a PRE node
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_parser_0x2ac89400caf0) [_parse] Added 1 node(s) during parse
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_processor_0x2ac89400caf0) [_handleParseComplete] Parsed ESI
> document with 1 nodes
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformData] data ready; going to process doc
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_processor_0x2ac89400caf0) [process] Processing ESI node [PRE]
> with data of size 44 starting with [Satur...]
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_processor_0x2ac89400caf0) [process] ESI processed document of
> size 44 starting with [Saturday 2]
> [Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformData] ESI processor output document
> of size 44 starting with [Saturday 2]
> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [Cache-Control]
> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [X-Esi]
> [Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [Age]
> [Sep 22 13:05:10.500] Server {0x2ac882539700} DIAG: (plugin_esi)
> [modifyResponseHeader] Inspected client-bound headers
> [Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 103 not within
> fetch event id range [10000, 10000)
> [Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformHandler] shutting down transformation
> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
> (plugin_esi_0x2ac89400caf0) [checkXformStatus] Vconn closed
> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
> (plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10000)
> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformHandler] Transformation closed.
> Post-processing...
> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformHandler] Processing is complete, not
> processing current event 1
> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
> (plugin_esi_0x2ac89400caf0) [transformHandler] transformation closed;
> cleaning up data...
> [Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
> (plugin_esi_0x2ac89400caf0) [~ContData] Destroying continuation data
> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [checkXformStatus] Error while getting close
> status of transformation at state 1
> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10003)
> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
> Post-processing...
> [Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] Ignoring event 1; Will wait
> for pending data
> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformHandler] Handling fetch event 10000...
> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cdc0) [handleFetchEvent] Inserted page data
> of size 44 starting with [Saturd] for request [
> http://61.160.245.195/esi.php]
> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformHandler] fetcher is ready with data,
> going into process stage
> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformData] input_vio NULL, but processing
> needs to (and can) be completed
> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformData] data ready; going to process doc
> [Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
> with data of size 27 starting with [<HTML...]
> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node
> [INCLUDE] with data of size 0 starting with [(null...]
> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cdc0) [getData] Found data for URL [
> http://61.160.245.195/esi.php] of size 44 starting with [Satur]
> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
> (plugin_esi_processor_0x2ac89400cdc0) [_getIncludeData] Got content
> successfully for URL [http://61.160.245.195/esi.php]
> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
> (plugin_esi_processor_0x2ac89400cdc0) [_processEsiNode] Processed ESI
> [INCLUDE] node
> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
> (plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
> with data of size 68 starting with [
> at t...]
> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
> (plugin_esi_processor_0x2ac89400cdc0) [process] ESI processed document of
> size 139 starting with [<HTML>
> <BO]
> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformData] ESI processor output document
> of size 139 starting with [<HTML>
> <BO]
> [Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformData] Compressed document from size
> 139 to 139 bytes
> [Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 103 not within
> fetch event id range [10000, 10003)
> [Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformHandler] shutting down transformation
> [Sep 22 13:06:11.770] Server {0x2ac882034700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [checkXformStatus] Vconn closed
> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10003)
> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformHandler] Transformation closed.
> Post-processing...
> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformHandler] Processing is complete, not
> processing current event 1
> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [transformHandler] transformation closed;
> cleaning up data...
> [Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
> (plugin_esi_0x2ac89400cdc0) [~ContData] Destroying continuation data
> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
> Post-processing...
> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] Going to process received
> data
> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] Handling fetch event 10000...
> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cbe0) [handleFetchEvent] Inserted page data
> of size 44 starting with [Saturd] for request [
> http://61.160.245.195/esi.php]
> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] fetcher is ready with data,
> going into process stage
> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but processing
> needs to (and can) be completed
> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] data ready; going to process doc
> [Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
> with data of size 27 starting with [<HTML...]
> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node
> [INCLUDE] with data of size 0 starting with [(null...]
> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cbe0) [getData] Found data for URL [
> http://61.160.245.195/esi.php] of size 44 starting with [Satur]
> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [_getIncludeData] Got content
> successfully for URL [http://61.160.245.195/esi.php]
> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [_processEsiNode] Processed ESI
> [INCLUDE] node
> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
> with data of size 68 starting with [
> at t...]
> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
> (plugin_esi_processor_0x2ac89400cbe0) [process] ESI processed document of
> size 139 starting with [<HTML>
> <BO]
> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformData] ESI processor output document
> of size 139 starting with [<HTML>
> <BO]
> [Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] Deferring shutdown as data
> event was just processed
> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
> (plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 2 not within
> fetch event id range [10000, 10003)
> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
> Post-processing...
> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] Processing is complete, not
> processing current event 2
> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [transformHandler] transformation closed;
> cleaning up data...
> [Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
> (plugin_esi_0x2ac89400cbe0) [~ContData] Destroying continuation data
>
>
> When i use the curl to test. It's works for me.why?
>
> [root@yingcai html]# curl -v http://61.160.245.195:8080/esi.html
> * About to connect() to 61.160.245.195 port 8080 (#0)
> * Trying 61.160.245.195... connected
> * Connected to 61.160.245.195 (61.160.245.195) port 8080 (#0)
> > GET /esi.html HTTP/1.1
> > User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/
> 3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2
> > Host: 61.160.245.195:8080
> > Accept: */*
> >
> < HTTP/1.1 200 OK
> < Date: Sat, 22 Sep 2012 05:02:30 GMT
> < Server: ATS/3.3.1-dev
> < Last-Modified: Sat, 22 Sep 2012 05:00:30 GMT
> < Accept-Ranges: bytes
> < Content-Type: text/html; charset=UTF-8
> < Content-Length: 139
> < Connection: keep-alive
> <
> <HTML>
> <BODY>
> The time is: Saturday 22nd of September 2012 01:02:30 PM
>
> at this very moment. power by yingcai............
> </BODY>
> </HTML>
>
> * Connection #0 to host 61.160.245.195 left intact
> * Closing connection #0
>
> But the same issue in firefox. why curl worked?
>
Re: ESI issue
Posted by 黄英才 <b1...@gmail.com>.
my remap.config
map http://61.160.245.195:8080/ http://61.160.245.195/
map http://61.160.245.195/ http://61.160.245.195/
When i use the chrome for visit http://61.160.245.195:8080/esi.html
I get the follow
[image: 内嵌图片 1]
The debug message:
[Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
[isInterceptRequest] Skipping external request
[Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
[globalHookHandler] handling read request header event...
[Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
[globalHookHandler] Not setting up intercept
[Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
[isInterceptRequest] Skipping external request
[Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
[globalHookHandler] handling cache lookup complete event...
[Sep 22 13:05:10.488] Server {0x2ac88273b700} DIAG: (plugin_esi)
[isCacheObjTransformable] cache object's status is 0; not transformable
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
[isInterceptRequest] Skipping external request
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
[globalHookHandler] handling read response header event...
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
[isCacheObjTransformable] cache object's status is 0; not transformable
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
[getClientState] Got request URL [http://61.160.245.195/esi.html]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
[Connection]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
[Cache-Control]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Pragma]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header [Accept]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
[Accept-Encoding]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG: (plugin_esi)
[getClientState] Client accepts gzip encoding; will compress output
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
[Accept-Encoding]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
[Accept-Encoding]
[Sep 22 13:05:10.493] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
[Accept-Charset]
[Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
[Accept-Charset]
[Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [populate] Not retaining header
[Accept-Charset]
[Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
[getServerState] Not retaining 'Content-length' header
[Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
[getServerState] Not retaining 'X-Esi' header
[Sep 22 13:05:10.494] Server {0x2ac88273b700} DIAG: (plugin_esi)
[addTransform] Added transformation (0x0x2ac89400cbe0)
[Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [init] Set input data type to [RAW_ESI]
[Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] initialized continuation data
[Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
(plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10000)
[Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] handling
TS_EVENT_IMMEDIATE...
[Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] upstream VC has 165 bytes
available to read
[Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [addParseData] Implicit call to
start()
[Sep 22 13:05:10.494] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_parse], Adding data of size 27 before
(newly found) ESI tag as PRE node
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_compareData] string [include ] is
equal to data at position 32
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_parse] Found [INCLUDE] tag at position
27
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_searchData] Found full match of /> in
[src="...] at position 95
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_parse] Handling include tag...
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_processIncludeTag] Added include tag
with url [http://61.160.245.195/esi.php]
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 2 node(s) during parse
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [_preprocess] Adding fetch request
for url [http://61.160.245.195/esi.php]
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_vars_0x2ac89400cbe0) [expand] Returning final expanded
expression [http://61.160.245.195/esi.php]
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_failureInfo) [_preprocess] URL request [
http://61.160.245.195/esi.php] 2189674240
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_fetcher_0x2ac89400cbe0) [_buildHeadersString] Building header
string...
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_fetcher_0x2ac89400cbe0) [addFetchRequest] Successfully added
fetch request for URL [http://61.160.245.195/esi.php]
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] Added chunk of 165 bytes
starting with [<HTML>
<BO] to parse list
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] Consumed 165 bytes from
upstream VC
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] Completed reading input...
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_setup] Returning true for empty data
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_parse] Adding trailing text of size 68
starting at [
at t] as a PRE node
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_parser_0x2ac89400cbe0) [_parse] Added 1 node(s) during parse
[Sep 22 13:05:10.495] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [_handleParseComplete] Parsed ESI
document with 3 nodes
[Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] Data not available yet; cannot
process document
[Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
[isInterceptRequest] Method [GET] invalid, [POST] expected
[Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
[globalHookHandler] handling read request header event...
[Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
[globalHookHandler] Not setting up intercept
[Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
[isInterceptRequest] Method [GET] invalid, [POST] expected
[Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
[globalHookHandler] handling cache lookup complete event...
[Sep 22 13:05:10.496] Server {0x2ac88283c700} DIAG: (plugin_esi)
[isCacheObjTransformable] cache object's status is 0; not transformable
[Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
(plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10003)
[Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] handling
TS_EVENT_IMMEDIATE...
[Sep 22 13:05:10.496] Server {0x2ac882034700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but data needs
to be fetched. Returning control
[Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [Cache-Control]
[Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [X-Esi]
[Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [Age]
[Sep 22 13:05:10.497] Server {0x2ac88293d700} DIAG: (plugin_esi)
[modifyResponseHeader] Inspected client-bound headers
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
[isInterceptRequest] Method [GET] invalid, [POST] expected
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
[globalHookHandler] handling read response header event...
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
[isCacheObjTransformable] cache object's status is 0; not transformable
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
[getClientState] Got request URL [http://61.160.245.195/esi.php]
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
(plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Pragma]
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
(plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
[Accept-Encoding]
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
(plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
[Accept-Charset]
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
(plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
[Connection]
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
(plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header [Accept]
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG:
(plugin_esi_vars_0x2ac89400caf0) [populate] Not retaining header
[Cache-Control]
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
[getServerState] Not retaining 'X-Esi' header
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
[getServerState] Not retaining 'Content-length' header
[Sep 22 13:05:10.498] Server {0x2ac88283c700} DIAG: (plugin_esi)
[addTransform] Added transformation (0x0x2ac89400caf0)
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [init] Set input data type to [RAW_ESI]
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformHandler] initialized continuation data
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10000)
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformHandler] handling
TS_EVENT_IMMEDIATE...
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformData] upstream VC has 44 bytes
available to read
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_processor_0x2ac89400caf0) [addParseData] Implicit call to
start()
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_parser_0x2ac89400caf0) [_parse] Added 0 node(s) during parse
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformData] Added chunk of 44 bytes
starting with [Saturday 2] to parse list
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformData] Consumed 44 bytes from upstream
VC
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformData] Completed reading input...
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_parser_0x2ac89400caf0) [_setup] Returning true for empty data
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_parser_0x2ac89400caf0) [_parse] Adding trailing text of size 44
starting at [Satur] as a PRE node
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_parser_0x2ac89400caf0) [_parse] Added 1 node(s) during parse
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_processor_0x2ac89400caf0) [_handleParseComplete] Parsed ESI
document with 1 nodes
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformData] data ready; going to process doc
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_processor_0x2ac89400caf0) [process] Processing ESI node [PRE]
with data of size 44 starting with [Satur...]
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_processor_0x2ac89400caf0) [process] ESI processed document of
size 44 starting with [Saturday 2]
[Sep 22 13:05:10.499] Server {0x2ac882438700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformData] ESI processor output document
of size 44 starting with [Saturday 2]
[Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [Cache-Control]
[Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [X-Esi]
[Sep 22 13:05:10.499] Server {0x2ac882539700} DIAG: (plugin_esi)
[modifyResponseHeader] Removing header with name [Age]
[Sep 22 13:05:10.500] Server {0x2ac882539700} DIAG: (plugin_esi)
[modifyResponseHeader] Inspected client-bound headers
[Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
(plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 103 not within
fetch event id range [10000, 10000)
[Sep 22 13:05:10.500] Server {0x2ac88293d700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformHandler] shutting down transformation
[Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
(plugin_esi_0x2ac89400caf0) [checkXformStatus] Vconn closed
[Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
(plugin_esi_fetcher_0x2ac89400caf0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10000)
[Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformHandler] Transformation closed.
Post-processing...
[Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformHandler] Processing is complete, not
processing current event 1
[Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
(plugin_esi_0x2ac89400caf0) [transformHandler] transformation closed;
cleaning up data...
[Sep 22 13:05:10.500] Server {0x2ac881f33700} DIAG:
(plugin_esi_0x2ac89400caf0) [~ContData] Destroying continuation data
[Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
(plugin_esi_0x2ac89400cbe0) [checkXformStatus] Error while getting close
status of transformation at state 1
[Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
(plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10003)
[Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
Post-processing...
[Sep 22 13:05:41.336] Server {0x2ac882539700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] Ignoring event 1; Will wait
for pending data
[Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformHandler] Handling fetch event 10000...
[Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
(plugin_esi_fetcher_0x2ac89400cdc0) [handleFetchEvent] Inserted page data
of size 44 starting with [Saturd] for request [http://61.160.245.195/esi.php
]
[Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformHandler] fetcher is ready with data,
going into process stage
[Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformData] input_vio NULL, but processing
needs to (and can) be completed
[Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformData] data ready; going to process doc
[Sep 22 13:06:11.750] Server {0x2ac88293d700} DIAG:
(plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
with data of size 27 starting with [<HTML...]
[Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
(plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node
[INCLUDE] with data of size 0 starting with [(null...]
[Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
(plugin_esi_fetcher_0x2ac89400cdc0) [getData] Found data for URL [
http://61.160.245.195/esi.php] of size 44 starting with [Satur]
[Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
(plugin_esi_processor_0x2ac89400cdc0) [_getIncludeData] Got content
successfully for URL [http://61.160.245.195/esi.php]
[Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
(plugin_esi_processor_0x2ac89400cdc0) [_processEsiNode] Processed ESI
[INCLUDE] node
[Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
(plugin_esi_processor_0x2ac89400cdc0) [process] Processing ESI node [PRE]
with data of size 68 starting with [
at t...]
[Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
(plugin_esi_processor_0x2ac89400cdc0) [process] ESI processed document of
size 139 starting with [<HTML>
<BO]
[Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformData] ESI processor output document
of size 139 starting with [<HTML>
<BO]
[Sep 22 13:06:11.751] Server {0x2ac88293d700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformData] Compressed document from size
139 to 139 bytes
[Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
(plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 103 not within
fetch event id range [10000, 10003)
[Sep 22 13:06:11.760] Server {0x2ac880c67e20} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformHandler] shutting down transformation
[Sep 22 13:06:11.770] Server {0x2ac882034700} DIAG:
(plugin_esi_0x2ac89400cdc0) [checkXformStatus] Vconn closed
[Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
(plugin_esi_fetcher_0x2ac89400cdc0) [_isFetchEvent] Event id 1 not within
fetch event id range [10000, 10003)
[Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformHandler] Transformation closed.
Post-processing...
[Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformHandler] Processing is complete, not
processing current event 1
[Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
(plugin_esi_0x2ac89400cdc0) [transformHandler] transformation closed;
cleaning up data...
[Sep 22 13:06:11.771] Server {0x2ac882034700} DIAG:
(plugin_esi_0x2ac89400cdc0) [~ContData] Destroying continuation data
[Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
Post-processing...
[Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] Going to process received
data
[Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] Handling fetch event 10000...
[Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
(plugin_esi_fetcher_0x2ac89400cbe0) [handleFetchEvent] Inserted page data
of size 44 starting with [Saturd] for request [http://61.160.245.195/esi.php
]
[Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] fetcher is ready with data,
going into process stage
[Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] input_vio NULL, but processing
needs to (and can) be completed
[Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] data ready; going to process doc
[Sep 22 13:07:05.529] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
with data of size 27 starting with [<HTML...]
[Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node
[INCLUDE] with data of size 0 starting with [(null...]
[Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
(plugin_esi_fetcher_0x2ac89400cbe0) [getData] Found data for URL [
http://61.160.245.195/esi.php] of size 44 starting with [Satur]
[Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [_getIncludeData] Got content
successfully for URL [http://61.160.245.195/esi.php]
[Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [_processEsiNode] Processed ESI
[INCLUDE] node
[Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [process] Processing ESI node [PRE]
with data of size 68 starting with [
at t...]
[Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
(plugin_esi_processor_0x2ac89400cbe0) [process] ESI processed document of
size 139 starting with [<HTML>
<BO]
[Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformData] ESI processor output document
of size 139 starting with [<HTML>
<BO]
[Sep 22 13:07:05.530] Server {0x2ac88283c700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] Deferring shutdown as data
event was just processed
[Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
(plugin_esi_fetcher_0x2ac89400cbe0) [_isFetchEvent] Event id 2 not within
fetch event id range [10000, 10003)
[Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] Transformation closed.
Post-processing...
[Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] Processing is complete, not
processing current event 2
[Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
(plugin_esi_0x2ac89400cbe0) [transformHandler] transformation closed;
cleaning up data...
[Sep 22 13:07:05.539] Server {0x2ac898f03700} DIAG:
(plugin_esi_0x2ac89400cbe0) [~ContData] Destroying continuation data
When i use the curl to test. It's works for me.why?
[root@yingcai html]# curl -v http://61.160.245.195:8080/esi.html
* About to connect() to 61.160.245.195 port 8080 (#0)
* Trying 61.160.245.195... connected
* Connected to 61.160.245.195 (61.160.245.195) port 8080 (#0)
> GET /esi.html HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/
3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2
> Host: 61.160.245.195:8080
> Accept: */*
>
< HTTP/1.1 200 OK
< Date: Sat, 22 Sep 2012 05:02:30 GMT
< Server: ATS/3.3.1-dev
< Last-Modified: Sat, 22 Sep 2012 05:00:30 GMT
< Accept-Ranges: bytes
< Content-Type: text/html; charset=UTF-8
< Content-Length: 139
< Connection: keep-alive
<
<HTML>
<BODY>
The time is: Saturday 22nd of September 2012 01:02:30 PM
at this very moment. power by yingcai............
</BODY>
</HTML>
* Connection #0 to host 61.160.245.195 left intact
* Closing connection #0
But the same issue in firefox. why curl worked?
Re: ESI issue
Posted by Shu Kit Chan <ch...@gmail.com>.
I think this is the problem. Inside remap.config, you need a line like
the following. i.e. mapping a host name back to itself.
map http://61.160.245.195/ http://61.160.245.195/
And let's see if it will work for you.
The theory here is this - An internal async request issued by the
plugin is programmed to go through the ATS again. There is no remap
rules for host name of "61.160.245.195" and so it returns an error.
If it still doesn't work, can you please give me more info such as
remap.config and the content of your ESI document.
Thanks.
Kit
On Fri, Sep 21, 2012 at 9:01 PM, 黄英才 <b1...@gmail.com> wrote:
> Hi all,
>
> I'm compiling the ESI plugin in my trafficserver-3.3.1-dev from git
>
> when i enable the esi.so and get the esi.html .The chrome return the blank
> page with nothing
>
> Here is the debug message
> [Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
> [isInterceptRequest] Skipping external request
> [Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
> [globalHookHandler] handling read request header event...
> [Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
> [globalHookHandler] Not setting up intercept
> [Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
> [isInterceptRequest] Skipping external request
> [Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
> [globalHookHandler] handling cache lookup complete event...
> [Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
> [globalHookHandler] handling cache lookup complete event...
> [Sep 22 11:59:41.940] Server {0x2ac882236700} DIAG: (plugin_esi)
> [isCacheObjTransformable] cache object's status is 0; not transformable
>
> [Sep 22 11:59:41.941] Server {0x2ac882236700} DIAG: (plugin_esi)
> [isInterceptRequest] Skipping external request
> [Sep 22 11:59:41.941] Server {0x2ac882236700} DIAG: (plugin_esi)
> [globalHookHandler] handling read response header event...
> [Sep 22 11:59:41.941] Server {0x2ac882236700} DIAG: (plugin_esi)
> [isCacheObjTransformable] cache object's status is 0; not transformable
>
> [Sep 22 11:59:41.941] Server {0x2ac882236700} DIAG: (plugin_esi)
> [getClientState] Got request URL [http://127.0.0.1/esi.html]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Connection]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Cache-Control]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Cache-Control]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Pragma]
>
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
>
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header [Accept]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Accept-Encoding]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG: (plugin_esi)
> [getClientState] Client accepts gzip encoding; will compress output
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Accept-Encoding]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Accept-Encoding]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Accept-Charset]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Accept-Charset]
>
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Accept-Charset]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [populate] Not retaining header
> [Accept-Charset]
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG: (plugin_esi)
> [getServerState] Not retaining 'Content-length' header
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG: (plugin_esi)
> [getServerState] Not retaining 'X-Esi' header
> [Sep 22 11:59:41.942] Server {0x2ac882236700} DIAG: (plugin_esi)
> [addTransform] Added transformation (0x0x2ac89400ceb0)
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [init] Set input data type to [RAW_ESI]
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] initialized continuation data
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_fetcher_0x2ac89400ceb0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10000)
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] handling
> TS_EVENT_IMMEDIATE...
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] upstream VC has 165 bytes
> available to read[Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] handling
> TS_EVENT_IMMEDIATE...
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] upstream VC has 165 bytes
> available to read
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_processor_0x2ac89400ceb0) [addParseData] Implicit call to
> start()
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_parse], Adding data of size 27 before
> (newly found) ESI tag as PRE node
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_compareData] string [include ] is equal
> to data at position 32
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_compareData] string [include ] is equal
> to data at position 32
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_parse] Found [INCLUDE] tag at position
> 27
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_parse] Found [INCLUDE] tag at position
> 27
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_searchData] Found full match of /> in
> [src="...] at position 95
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_parse] Handling include tag...
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_processIncludeTag] Added include tag
> with url [http://61.160.245.195/esi.php][Sep 22 11:59:41.943] Server
> {0x2ac882236700} DIAG: (plugin_esi_parser_0x2ac89400ceb0)
> [_processIncludeTag] Added include tag with url
> [http://61.160.245.195/esi.php]
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_parse] Added 2 node(s) during parse
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_processor_0x2ac89400ceb0) [_preprocess] Adding fetch request for
> url [http://61.160.245.195/esi.php]
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_vars_0x2ac89400ceb0) [expand] Returning final expanded
> expression [http://61.160.245.195/esi.php]
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG: (plugin_esi_failureInfo)
> [_preprocess] URL request [http://61.160.245.195/esi.php] 2183358208
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_fetcher_0x2ac89400ceb0) [_buildHeadersString] Building header
> string...
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_fetcher_0x2ac89400ceb0) [addFetchRequest] Successfully added
> fetch request for URL [http://61.160.245.195/esi.php]
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] Added chunk of 165 bytes
> starting with [<HTML>
> <BO] to parse list
> [Sep 22 11:59:41.943] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] Added chunk of 165 bytes
> starting with [<HTML>
> <BO] to parse list
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] Consumed 165 bytes from upstream
> VC
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] Completed reading input...[Sep
> 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi_0x2ac89400ceb0)
> [transformData] Consumed 165 bytes from upstream VC
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] Completed reading input...
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_setup] Returning true for empty data
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_parse] Adding trailing text of size 68
> starting at [
> at t] as a PRE node
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_setup] Returning true for empty data
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_parse] Adding trailing text of size 68
> starting at [
> at t] as a PRE node
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_parser_0x2ac89400ceb0) [_parse] Added 1 node(s) during parse
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_processor_0x2ac89400ceb0) [_handleParseComplete] Parsed ESI
> document with 3 nodes
>
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] Data not available yet; cannot
> process document
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi)
> [isInterceptRequest] Method [GET] invalid, [POST] expected
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi)
> [globalHookHandler] handling read request header event...
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi)
> [globalHookHandler] Not setting up intercept
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG: (plugin_esi)
> [globalHookHandler] Not setting up intercept
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] Handling fetch event 10000...
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_fetcher_0x2ac89400ceb0) [handleFetchEvent] Received non-OK
> status 404 for request [http://61.160.245.195/esi.php]
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] fetcher is ready with data,
> going into process stage
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] input_vio NULL, but processing
> needs to (and can) be completed
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] data ready; going to process doc
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] data ready; going to process doc
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_processor_0x2ac89400ceb0) [process] Processing ESI node [PRE]
> with data of size 27 starting with [<HTML...][Sep 22 11:59:41.944] Server
> {0x2ac882236700} DIAG: (plugin_esi_processor_0x2ac89400ceb0) [process]
> Processing ESI node [PRE] with data of size 27 starting with [<HTML...]
> [Sep 22 11:59:41.944] Server {0x2ac882236700} DIAG:
> (plugin_esi_processor_0x2ac89400ceb0) [process] Processing ESI node
> [INCLUDE] with data of size 0 starting with [(null...]
>
> [Sep 22 11:59:41.945] Server {0x2ac882236700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] Compressed document from size 0
> to 20 bytes
> [Sep 22 11:59:41.945] Server {0x2ac88263a700} DIAG:
> (plugin_esi_fetcher_0x2ac89400ceb0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10003)
> [Sep 22 11:59:41.945] Server {0x2ac88263a700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] handling
> TS_EVENT_IMMEDIATE...
> [Sep 22 11:59:41.945] Server {0x2ac88263a700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformData] input_vio NULL, marking
> transformation to be terminated
> [Sep 22 11:59:41.954] Server {0x2ac882337700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [Cache-Control]
> [Sep 22 11:59:41.954] Server {0x2ac882337700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [X-Esi]
> [Sep 22 11:59:41.954] Server {0x2ac882337700} DIAG: (plugin_esi)
> [modifyResponseHeader] Removing header with name [Age]
> [Sep 22 11:59:41.954] Server {0x2ac882337700} DIAG: (plugin_esi)
> [modifyResponseHeader] Inspected client-bound headers[Sep 22 11:59:41.954]
> Server {0x2ac882337700} DIAG: (plugin_esi) [modifyResponseHeader] Inspected
> client-bound headers
> [Sep 22 11:59:41.954] Server {0x2ac88283c700} DIAG:
> (plugin_esi_fetcher_0x2ac89400ceb0) [_isFetchEvent] Event id 103 not within
> fetch event id range [10000, 10003)
> [Sep 22 11:59:41.954] Server {0x2ac88283c700} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] shutting down transformation
>
> [Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_0x2ac89400ceb0) [checkXformStatus] Vconn closed
> [Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_fetcher_0x2ac89400ceb0) [_isFetchEvent] Event id 1 not within
> fetch event id range [10000, 10003)
> [Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] Transformation closed.
> Post-processing...
> [Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] Processing is complete, not
> processing current event 1
> [Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] Processing is complete, not
> processing current event 1
> [Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_0x2ac89400ceb0) [transformHandler] transformation closed;
> cleaning up data...
> [Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_0x2ac89400ceb0) [~ContData] Destroying continuation data
>
> [Sep 22 11:59:41.964] Server {0x2ac880c67e20} DIAG:
> (plugin_esi_0x2ac89400ceb0) [~ContData] Destroying continuation data
>
>
> It works for my get the http://61.160.245.195/esi.php .
> why debug said 404?