Child panics on OpenSolaris

Paul Wright wrighty+varnishmisc at gmail.com
Thu Feb 18 11:08:11 CET 2010


On 17 February 2010 18:46, Poul-Henning Kamp <phk at phk.freebsd.dk> wrote:
> In message <282e72051002170852g532cd8acqb570e6db4b82974c at mail.gmail.com>, Paul
> Wright writes:
>
>>(The cookie header ensures the request is passed through to the
>>backend. Curl will respond with "Failure when receiving data from the
>>peer".)
>
> How on earth did you get the Range header to be passed through to
> the backend ?  It should have been filtered out...
>
> Can you capture a varnishlog for this one ?

Here's the output:

    0 CLI          - Rd ping
    0 CLI          - Wr 200 PONG 1266486712 1.0
    5 SessionOpen  c 192.168.0.30 60069 :80
    5 ReqStart     c 192.168.0.30 60069 1736091917
    5 RxRequest    c GET
    5 RxURL        c /robots.txt
    5 RxProtocol   c HTTP/1.1
    5 RxHeader     c User-Agent: curl/7.19.4 (i386-pc-solaris2.11)
libcurl/7.19.4 OpenSSL/0.9.8a zlib/1.2.3 libidn/1.9
    5 RxHeader     c Host: 192.168.0.35
    5 RxHeader     c Accept: */*
    5 RxHeader     c Range: bytes=0-1
    5 RxHeader     c Cookie: foo
    5 VCL_call     c recv
    5 VCL_return   c pass
    5 VCL_call     c hash
    5 VCL_return   c hash
    5 VCL_call     c pass
    5 VCL_return   c pass
    9 BackendOpen  b martin 192.168.0.35 54372 192.168.0.31 80
    5 Backend      c 9 dynamic_director martin
    9 TxRequest    b GET
    9 TxURL        b /robots.txt
    9 TxProtocol   b HTTP/1.1
    9 TxHeader     b User-Agent: curl/7.19.4 (i386-pc-solaris2.11)
libcurl/7.19.4 OpenSSL/0.9.8a zlib/1.2.3 libidn/1.9
    9 TxHeader     b Host: 192.168.0.35
    9 TxHeader     b Accept: */*
    9 TxHeader     b Range: bytes=0-1
    9 TxHeader     b Cookie: foo
    9 TxHeader     b X-Forwarded-For: 192.168.0.30
    9 TxHeader     b X-Varnish: 1736091917
    0 WorkThread   - fffffd7ff9e00d30 start
    0 CLI          - Rd vcl.load "boot" ./vcl.ORk8t3RP.so
    0 CLI          - Wr 200 Loaded "./vcl.ORk8t3RP.so" as "boot"
    0 CLI          - Rd vcl.use "boot"
    0 CLI          - Wr 200
    0 CLI          - Rd start
    0 Debug        - "Acceptor poll space increased to 512"
    0 Debug        - "Acceptor is poll"
    0 CLI          - Wr 200
    0 WorkThread   - fffffd7ff9206d30 start
    0 WorkThread   - fffffd7ff9007d30 start
    0 WorkThread   - fffffd7ff8e08d30 start
    0 WorkThread   - fffffd7ff8c09d30 start
    0 WorkThread   - fffffd7ff8a0ad30 start
    0 WorkThread   - fffffd7ff880bd30 start
    0 WorkThread   - fffffd7ff860cd30 start
    0 WorkThread   - fffffd7ff840dd30 start
    0 WorkThread   - fffffd7ff820ed30 start

The VCL used hasn't changed substantially from the original included
at the beginning of this thread, only vcl_recv is defined and I don't
think it's doing anything stupid.

sub vcl_recv {
        // normalise static requests
        if ( req.http.host ~ "media([0-9]+).firebox.com" ) {
                set req.http.host = "media.firebox.com";
        }

        //catch any relative image URLs that haven't been repointed to media
        if ( req.http.host != "media.firebox.com" &&
             ( req.url ~ "^/pic/.+" || req.url ~ "^/i/.+" ) ) {
                        set req.http.host = "media.firebox.com";
        }

        // split traffic based on host name
        if ( req.http.host == "media.firebox.com" ) {
                remove req.http.cookie;
                set req.backend = static_director;
        } else {
                // dynamic content that should be cached (ie no
cookies required)
                // these patterns should match up with settings.inc on
the PHP side
                if ( req.url ~ "^/styles/(.+).css$" ||
                     req.url ~ "^/js/(.+).js$" ) {
                        remove req.http.cookie;
                }
                //default all requests to the dynamic backend
                set req.backend = dynamic_director;
        }
}

This is on r4574, compiled with Sun Studio.

Cheers,

Paul.

Child (2570) died signal=6
Child (2570) Panic message: Assert error in http_copyheader(),
cache_http.c line 647:
  Condition(n < to->shd) not true.
thread = (cache-worker)
ident = -smalloc,-hcritbit,poll
Backtrace:
  447b2b: /opt/sbin/varnishd'pan_backtrace+0x1b [0x447b2b]
  447e35: /opt/sbin/varnishd'pan_ic+0x1c5 [0x447e35]
  4407e1: /opt/sbin/varnishd'http_copyheader+0x1c1 [0x4407e1]
  442401: /opt/sbin/varnishd'http_FilterFields+0xdc1 [0x442401]
  429c9d: /opt/sbin/varnishd'cnt_fetch+0x11fd [0x429c9d]
  42cf8a: /opt/sbin/varnishd'CNT_Session+0x78a [0x42cf8a]
  44a83f: /opt/sbin/varnishd'wrk_do_cnt_sess+0x1bf [0x44a83f]
  449db2: /opt/sbin/varnishd'wrk_thread_real+0x882 [0x449db2]
  44a365: /opt/sbin/varnishd'wrk_thread+0x135 [0x44a365]
  fffffd7ff653acf5: /lib/amd64/libc.so.1'_thrp_setup+0x8d [0xfffffd7ff653acf5]
sp = 5eec58 {
  fd = 5, id = 5, xid = 1315520023,
  client = 192.168.0.30:41925,
  step = STP_FETCH,
  handling = pass,
  err_code = 206, err_reason = (null),
  restarts = 0, esis = 0
  ws = 5eecc8 {
    id = "sess",
    {s,f,r,e} = {5f0250,+257,0,+65536},
  },
  http[req] = {
    ws = 5eecc8[sess]
      "GET",
      "/robots.txt",
      "HTTP/1.1",
      "User-Agent: curl/7.19.4 (i386-pc-solaris2.11) libcurl/7.19.4
OpenSSL/0.9.8a zlib/1.2.3 libidn/1.9",
      "Host: 192.168.0.35",
      "Accept: */*",
      "Range: bytes=0-1",
      "Cookie: foo",
      "X-Forwarded-For: 192.168.0.30",
  },
  worker = fffffd7ff820ed30 {
    ws = fffffd7ff820ee78 {
      id = "wrk",
      {s,f,r,e} = {fffffd7ff81fcc40,+305,0,+65536},
    },
    http[bereq] = {
      ws = fffffd7ff820ee78[wrk]
        "GET",
        "/robots.txt",
        "HTTP/1.1",
        "User-Agent: curl/7.19.4 (i386-pc-solaris2.11) libcurl/7.19.4
OpenSSL/0.9.8a zlib/1.2.3 libidn/1.9",
        "Host: 192.168.0.35",
        "Accept: */*",
        "Range: bytes=0-1",
        "Cookie: foo",
        "X-Forwarded-For: 192.168.0.30",
        "X-Varnish: 1315520023",
    },
    http[beresp] = {
      ws = fffffd7ff820ee78[wrk]
        "HTTP/1.1",
        "206",
        "Partial Content",
        "Date: Thu, 18 Feb 2010 09:57:51 GMT",
        "Server: Apache",
        "Last-Modified: Fri, 11 Dec 2009 18:15:28 GMT",
        "ETag: "19c0073-de-47a77e88b9000"",
        "Accept-Ranges: bytes",
        "Content-Length: 2",
        "Content-Range: bytes 0-1/222",
        "Connection: close",
        "Content-Type: text/plain",
    },
    },
    vcl = {
      srcname = {
        "input",
        "Default",
      },
    },
  obj = 600260 {
    xid = 1315520023,
    ws = 600280 {
      id = "obj",
      {s,f,r,e} = {600465,600465,0,+213},
    },
    http[obj] = {
      ws = 600280[obj]
        "HTTP/1.1",
        "206",
        "Partial Content",
        "Date: Thu, 18 Feb 2010 09:57:51 GMT",
        "Server: Apache",
        "Last-Modified: Fri, 11 Dec 2009 18:15:28 GMT",
        "ETag: "19c0073-de-47a77e88b9000"",
    },
    len = 0,
    store = {
    },
  },
},


More information about the varnish-misc mailing list