No ESI processing, first char not ‘<'
After installing Varnish 2.0.5 on a machine, ESI Includes didn’t work. When using varnishlog, the first error that occurred when debugging was:
No ESI processing, first char not ‘< '
12 SessionClose – timeout 12 StatSess – 124.177.181.149 50662 4 0 0 0 0 0 0 0 12 SessionOpen c 68.212.183.136 60087 66.244.147.44:80 12 ReqStart c 68.212.183.136 60087 409391565 12 RxRequest c GET 12 RxURL c /esi.html 12 RxProtocol c HTTP/1.1 12 RxHeader c Host: cd34.colocdn.com 12 RxHeader c User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.6; en-US; rv:1.9.2b4) Gecko/20091124 Firefox/3.6b4 12 RxHeader c Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 12 RxHeader c Accept-Language: en-us,en;q=0.5 12 RxHeader c Accept-Encoding: gzip,deflate 12 RxHeader c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 12 RxHeader c Keep-Alive: 115 12 RxHeader c Connection: keep-alive 12 RxHeader c X-lori-time-1: 1259718658980 12 RxHeader c Cache-Control: max-age=0 12 VCL_call c recv 12 VCL_return c lookup 12 VCL_call c hash 12 VCL_return c hash 12 VCL_call c miss 12 VCL_return c fetch 12 Backend c 14 cd34_com cd34_com 12 ObjProtocol c HTTP/1.1 12 ObjStatus c 200 12 ObjResponse c OK 12 ObjHeader c Date: Wed, 02 Dec 2009 01:50:59 GMT 12 ObjHeader c Server: Apache 12 ObjHeader c Vary: Accept-Encoding 12 ObjHeader c Content-Encoding: gzip 12 ObjHeader c Content-Type: text/html 12 TTL c 409391565 RFC 120 1259718659 0 0 0 0 12 VCL_call c fetch 12 TTL c 409391565 VCL 43200 1259718659 12 ESI_xmlerror c No ESI processing, first char not ‘< ' 12 TTL c 409391565 VCL 0 1259718659 12 VCL_info c XID 409391565: obj.prefetch (-30) less than ttl (-1), ignored. 12 VCL_return c deliver 12 Length c 68 12 VCL_call c deliver 12 VCL_return c deliver 12 TxProtocol c HTTP/1.1 12 TxStatus c 200 12 TxResponse c OK 12 TxHeader c Server: Apache 12 TxHeader c Vary: Accept-Encoding 12 TxHeader c Content-Encoding: gzip 12 TxHeader c Content-Type: text/html 12 TxHeader c Content-Length: 68 12 TxHeader c Date: Wed, 02 Dec 2009 01:50:59 GMT 12 TxHeader c X-Varnish: 409391565 12 TxHeader c Age: 0 12 TxHeader c Via: 1.1 varnish 12 TxHeader c Connection: keep-alive 12 TxHeader c X-Cache: MISS 12 ReqEnd c 409391565 1259718659.088263512 1259718659.127703667 0.000059366 0.039401770 0.000038385 12 Debug c "herding"
ESI received significant performance enhancements in 2.0.4 and 2.0.5 so, it seemed something was incompatible. Downgrading to 2.0.3 and using the VCL from another machine still resulted in ESI not working.
In this case, mod_deflate was running on the backend which was causing the issue. However, in reading the source code, it appears that message could also occur if your ESI include wasn’t handing back properly formed XML/HTML content. If your include doesn’t contain valid content and is only returning a small snippet, you might consider passing:
-p esi_syntax=0x1
on the command line that starts Varnish.
The changes in Varnish address the issue of ESI being enabled on binary content. Since the first character isn’t an < in almost all binary files (jpg, mpg, gif) and isn't the start of most .css/.js files, varnish doesn't need to spend extra time checking those files for includes. While you can and should selectively enable esi processing, this is just an added safeguard and a performance boost to compensate for vcl that might have an esi directive on static/binary content. Since Varnish 2.0.3 now worked properly with the new machine, we upgraded to Varnish 2.0.5 which introduced a very odd issue:
[Tue Dec 01 20:58:11 2009] [error] [client 66.244.147.40] File does not exist: /gfs/www/cd/cd34.com/index.htmlt [Tue Dec 01 20:58:13 2009] [error] [client 66.244.147.40] File does not exist: /gfs/www/cd/cd34.com/index.html7 [Tue Dec 01 20:58:24 2009] [error] [client 66.244.147.40] File does not exist: /gfs/www/cd/cd34.com/index.html\xfa [Tue Dec 01 20:59:01 2009] [error] [client 66.244.147.40] File does not exist: /gfs/www/cd/cd34.com/index.html\xb5 [Tue Dec 01 20:59:06 2009] [error] [client 66.244.147.40] File does not exist: /gfs/www/cd/cd34.com/index.html\xe7 [Tue Dec 01 20:59:07 2009] [error] [client 66.244.147.40] File does not exist: /gfs/www/cd/cd34.com/index.html\xd4 [Tue Dec 01 20:59:08 2009] [error] [client 66.244.147.40] File does not exist: /gfs/www/cd/cd34.com/index.html\x1c
This generated 404s on the piece of the page that contained the ESI include. Downgrading to 2.0.4 fixed the issue and the issue appears to already be fixed in Trunk. Varnish Ticket #585
Varnish 2.0.4 and mod_deflate disabled addressed the two issues that prevented ESI from working correctly on this new installation.
Tags: edge side include, esi, Varnish
December 4th, 2009 at 3:41 am
Rather than disable mod_deflate on the backend, for ESI parsed pages you can use VCL to strip out the Accept-Encoding and Vary headers. In vcl_recv, within a condition that matches the urls/hostname you can place:
and within vcl_fetch, create a condition that matches the uri’s that you want to parse for ESI and place:
esi;This will allow the backend to serve content with mod_deflate/mod_gzip while allowing ESI to be procesed.