Mailing List Archive

#1815: Child died on pipe request
-------------------------+--------------------
Reporter: jferjan | Owner:
Type: defect | Status: new
Priority: normal | Milestone:
Component: varnishd | Version: 4.0.3
Severity: major | Resolution:
Keywords: pipe, panic |
-------------------------+--------------------
Description changed by phk:

Old description:

> Child died on pipe request. It is possible that backend was not properly
> responding or was unreachable at that time.
>
> Nov 10 14:49:51 varnish4 varnishd[25760]: Child (30586) not responding to
> CLI, killing it.
> Nov 10 14:49:51 varnish4 varnishd[25760]: Child (30586) not responding to
> CLI, killing it.
> Nov 10 14:49:51 varnish4 varnishd[25760]: Child (30586) died signal=6
> Nov 10 14:49:51 varnish4 varnishd[25760]: Child (30586) Panic message:
> Assert error in VDI_GetFd(), cache/cache_dir.c line 111:
> Condition((d) != NULL) not true.
> thread = (cache-worker)
> version = varnish-4.0.3 revision b8c4a34
> ident =
> Linux,3.10.0-229.4.2.el7.x86_64,x86_64,-smalloc,-smalloc,-hcritbit,epoll
> Backtrace:
> 0x433dbd: /usr/sbin/varnishd() [0x433dbd]
> 0x418915: /usr/sbin/varnishd(VDI_GetFd+0xc5) [0x418915]
> 0x434855: /usr/sbin/varnishd(PipeRequest+0xc5) [0x434855]
> 0x4384f1: /usr/sbin/varnishd(CNT_Request+0xac1) [0x4384f1]
> 0x42e14b: /usr/sbin/varnishd(HTTP1_Session+0x7ab) [0x42e14b]
> 0x43c2c7: /usr/sbin/varnishd() [0x43c2c7]
> 0x43d228: /usr/sbin/varnishd(SES_pool_accept_task+0x2a8) [0x43d228]
> 0x436c82: /usr/sbin/varnishd(Pool_Work_Thread+0x392) [0x436c82]
> 0x449dbc: /usr/sbin/varnishd() [0x449dbc]
> 0x7f42aa319df5: /lib64/libpthread.so.0(+0x7df5) [0x7f42aa319df5]
> req = 0x7f38ebde6020 {
> sp = 0x7f393bca3d60, vxid = 1150288528, step = R_STP_PIPE,
> req_body = R_BODY_NONE,
> restarts = 0, esi_level = 0,
> sp = 0x7f393bca3d60 {
> fd = 167, vxid = 76546703,
> client = 193.24.248.30 8902,
> step = S_STP_WORKING,
> },
> worker = 0x7f36cd5f2c50 {
> ws = 0x7f36cd5f2e70 {
> id = "wrk",
> {s,f,r,e} = {0x7f36cd5f2450,0x7f36cd5f2450,(nil),+2048},
> },
> VCL::method = 0x0,
> VCL::return = pipe,
> },
> ws = 0x7f38ebde61b8 {
> id = "req",
> {s,f,r,e} = {0x7f38ebde8010,+344,(nil),+57360},
> },
> http[req] = {
> ws = 0x7f38ebde61b8[req]
> "PROPFIND",
> "/fileadmin/pageuploads/foo",
> "HTTP/1.1",
> "Via: 1.1 TMG2-SI",
> "User-Agent: Microsoft-WebDAV-MiniRedir/6.1.7601",
> "Host: www.example.com",
> "Depth: 0",
> "translate: f",
> "Connection: Keep-Alive",
> "Content-Length: 0",
> "X-Forwarded-For: 123.123.123.123",
> },
> vcl = {
> srcname = {
> "input",
> "Builtin",
> },
> },
> },
> Nov 10 14:49:51 varnish4 varnishd[25760]: child (25732) Started
> Nov 10 14:49:51 varnish4 varnishd[25760]: Child (25732) said Child starts
>
> possible duplicate: https://www.varnish-cache.org/trac/ticket/1730

New description:

Child died on pipe request. It is possible that backend was not properly
responding or was unreachable at that time.

{{{
Nov 10 14:49:51 varnish4 varnishd[25760]: Child (30586) not responding to
CLI, killing it.
Nov 10 14:49:51 varnish4 varnishd[25760]: Child (30586) not responding to
CLI, killing it.
Nov 10 14:49:51 varnish4 varnishd[25760]: Child (30586) died signal=6
Nov 10 14:49:51 varnish4 varnishd[25760]: Child (30586) Panic message:
Assert error in VDI_GetFd(), cache/cache_dir.c line 111:
Condition((d) != NULL) not true.
thread = (cache-worker)
version = varnish-4.0.3 revision b8c4a34
ident =
Linux,3.10.0-229.4.2.el7.x86_64,x86_64,-smalloc,-smalloc,-hcritbit,epoll
Backtrace:
0x433dbd: /usr/sbin/varnishd() [0x433dbd]
0x418915: /usr/sbin/varnishd(VDI_GetFd+0xc5) [0x418915]
0x434855: /usr/sbin/varnishd(PipeRequest+0xc5) [0x434855]
0x4384f1: /usr/sbin/varnishd(CNT_Request+0xac1) [0x4384f1]
0x42e14b: /usr/sbin/varnishd(HTTP1_Session+0x7ab) [0x42e14b]
0x43c2c7: /usr/sbin/varnishd() [0x43c2c7]
0x43d228: /usr/sbin/varnishd(SES_pool_accept_task+0x2a8) [0x43d228]
0x436c82: /usr/sbin/varnishd(Pool_Work_Thread+0x392) [0x436c82]
0x449dbc: /usr/sbin/varnishd() [0x449dbc]
0x7f42aa319df5: /lib64/libpthread.so.0(+0x7df5) [0x7f42aa319df5]
req = 0x7f38ebde6020 {
sp = 0x7f393bca3d60, vxid = 1150288528, step = R_STP_PIPE,
req_body = R_BODY_NONE,
restarts = 0, esi_level = 0,
sp = 0x7f393bca3d60 {
fd = 167, vxid = 76546703,
client = 193.24.248.30 8902,
step = S_STP_WORKING,
},
worker = 0x7f36cd5f2c50 {
ws = 0x7f36cd5f2e70 {
id = "wrk",
{s,f,r,e} = {0x7f36cd5f2450,0x7f36cd5f2450,(nil),+2048},
},
VCL::method = 0x0,
VCL::return = pipe,
},
ws = 0x7f38ebde61b8 {
id = "req",
{s,f,r,e} = {0x7f38ebde8010,+344,(nil),+57360},
},
http[req] = {
ws = 0x7f38ebde61b8[req]
"PROPFIND",
"/fileadmin/pageuploads/foo",
"HTTP/1.1",
"Via: 1.1 TMG2-SI",
"User-Agent: Microsoft-WebDAV-MiniRedir/6.1.7601",
"Host: www.example.com",
"Depth: 0",
"translate: f",
"Connection: Keep-Alive",
"Content-Length: 0",
"X-Forwarded-For: 123.123.123.123",
},
vcl = {
srcname = {
"input",
"Builtin",
},
},
},
Nov 10 14:49:51 varnish4 varnishd[25760]: child (25732) Started
Nov 10 14:49:51 varnish4 varnishd[25760]: Child (25732) said Child starts
}}}
possible duplicate: https://www.varnish-cache.org/trac/ticket/1730

--

--
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1815#comment:1>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator

_______________________________________________
varnish-bugs mailing list
varnish-bugs@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-bugs

#1815: Child died on pipe request
-------------------------+--------------------
Reporter: jferjan | Owner: Dridi
Type: defect | Status: new
Priority: normal | Milestone:
Component: varnishd | Version: 4.0.3
Severity: major | Resolution:
Keywords: pipe, panic |
-------------------------+--------------------
Changes (by Dridi):

* owner: => Dridi


--
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1815#comment:2>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator

_______________________________________________
varnish-bugs mailing list
varnish-bugs@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-bugs

#1815: Child died on pipe request
-------------------------+-----------------------
Reporter: jferjan | Owner: Dridi
Type: defect | Status: assigned
Priority: normal | Milestone:
Component: varnishd | Version: 4.0.3
Severity: major | Resolution:
Keywords: pipe, panic |
-------------------------+-----------------------
Changes (by Dridi):

* status: new => assigned


Comment:

This doesn't look like a duplicate because in #1730 the assertion triggers
after a failed getfd, whereas in this case it's before.

I have tried to reproduce it and AFAICT the only VCL way to end up with a
NULL {{{(struct busyobj).director}}} is to either set the
{{{req.backend_hint}}} or {{{bereq.backend}}} to NULL which is not allowed
by the VCL compiler unless you use a VMOD? When setting a NULL
{{{bereq.backend}}} Varnish seems to recover and pick the default backend.

I narrowed it down to this:

{{{
$ cat bin/varnishtest/tests/r01815.vtc
varnishtest "backend unreachable on piped request"

server s1 {
rxreq
txresp
} -start

varnish v1 -vcl+backend {
import ${vmod_debug};

sub vcl_recv {
set req.backend_hint = debug.no_backend();
}
} -start

client c1 {
txreq -req PROPFIND
rxresp
expect resp.status == 200
} -run
}}}

It looks an awful lot like #1501 for piped requests :)

jferjan, are you using a director? Can you share your VCL or confirm it
may be a director failing to pick a backend?

phk, it looks like something Varnish should handle properly with either a
synthetic 500 response or picking the default backend.

Thoughts?

--
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1815#comment:3>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator

_______________________________________________
varnish-bugs mailing list
varnish-bugs@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-bugs

#1815: Child died on pipe request
-------------------------+-----------------------
Reporter: jferjan | Owner: Dridi
Type: defect | Status: assigned
Priority: normal | Milestone:
Component: varnishd | Version: 4.0.3
Severity: major | Resolution:
Keywords: pipe, panic |
-------------------------+-----------------------

Comment (by Dridi):

Discussed during today's bugwash, Varnish should serve a 503 Service
Unavailable if no backend is available. I will try to do that.

--
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1815#comment:4>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator

_______________________________________________
varnish-bugs mailing list
varnish-bugs@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-bugs