Mailing List Archive

Transient storage killing memory
Hi all,

Occasionally I encounter the following crash:

Nov 13 19:44:03 vc-varnish-02 kernel: [4029833.862916] apt-get[30000]: segfault at ffffffffffffffff ip 00007f3acce7456a sp 00007fffa93b00a0 error 5 in libapt-pkg.so.4.12.0[7f3acce1d000+168000]
Nov 13 19:45:33 vc-varnish-02 varnishd[12731]: Child (12732) died signal=6
Nov 13 19:45:33 vc-varnish-02 varnishd[12731]: Child (12732) Panic at: Sun, 13 Nov 2016 18:45:32 GMT#012"Assert error in mpl_alloc(), cache/cache_mempool.c line 79:#012 Condition((mi) != 0) not true.#012errno = 12 (Cannot allocate memory)#012thread = (cache-worker)#012version = varnish-5.0.0 revision 99d036f#012ident = Linux,3.16.0-4-amd64,x86_64,-junix,-smalloc,-smalloc,-hcritbit,epoll#012Backtrace:#012#012"

I've included the apt-get segfault in case it's relevant.

SMA.s0.c_bytes 1598929523 11755.71 Bytes allocated
SMA.s0.c_freed 1473918175 10836.60 Bytes freed
SMA.s0.g_bytes 125011348 . Bytes outstanding
SMA.s0.g_space 948730476 . Bytes available
SMA.Transient.c_bytes 4731618771 34787.99 Bytes allocated
SMA.Transient.c_freed 3838779376 28223.62 Bytes freed
SMA.Transient.g_bytes 892839395 . Bytes outstanding
SMA.Transient.g_space 0 . Bytes available

I'm wondering if someone could put me in the right direction in how
to further investigate the content of transient storage, and why it's
larger than the regular cache.

The parameter itself is the default of 10 seconds, and I set a ttl of 5
minutes. It's Varnish 5.0.0-1 on Debian jessie. Never experienced it
with 4.13, but there were probably conf changes since we upgraded.

Regards,

--
Niall Murphy

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Transient storage killing memory [ In reply to ]
On Tue, 15 Nov 2016 03:42:29 -0500, Niall Murphy
<niall.murphy@sparwelt.de> wrote:

> I'm wondering if someone could put me in the right direction in how
> to further investigate the content of transient storage, and why it's
> larger than the regular cache.

Hi Niall,

This is a longstanding Varnish behavior, if one is not specified, a
Transient storage pool is created as type "malloc" with no limit.

https://www.varnish-cache.org/docs/5.0/users-guide/storage-backends.html#transient-storage

The short-term solution to put a limit on this is to create a storage pool
named "Transient" when starting varnishd. For example, this will create
an 128M pool - add your existing "-s pool=settings" along with this one on
the command line or startup script.

"-s Transient=malloc,128m"

It might also be useful to capture some varnishlog output and determine
what objects are being stored in the Transient pool, and whether or not
your "shortlived" parameter, or default grace value needs to be adjusted.
Even if you do determine you need to do some things differently here that
will prevent the Transient pool from growing beyond your ideal limit, IMO
it's a good idea to keep this limited anyway.

Cheers,
-=Mark

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Transient storage killing memory [ In reply to ]
On Mon, 21 Nov 2016 15:09:08 -0500
Mark Staudinger <mark.staudinger@nyi.net> wrote:

> It might also be useful to capture some varnishlog output and
> determine what objects are being stored in the Transient pool, and
> whether or not your "shortlived" parameter, or default grace value
> needs to be adjusted. Even if you do determine you need to do some
> things differently here that will prevent the Transient pool from
> growing beyond your ideal limit, IMO it's a good idea to keep this
> limited anyway.
>
Hi Mark,

I took a look into ttl < 10s objects and saw that they are requests we
intentionally apply either "max-age=0, private" or "no-cache, private"
to. However their storage field is still "malloc Transient", and
transient storage usage only appears to be going up.

Any ideas how to investigate further?

It's varnish 5.0.0-1, and this didn't happen with 4.1, thought there
may well have been configuration changes since then.

Regards,

--
Niall

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Transient storage killing memory [ In reply to ]
On Tue, 29 Nov 2016 11:09:04 -0500, Niall Murphy
<niall.murphy@sparwelt.de> wrote:

> On Mon, 21 Nov 2016 15:09:08 -0500
> Mark Staudinger <mark.staudinger@nyi.net> wrote:
>
>> It might also be useful to capture some varnishlog output and
>> determine what objects are being stored in the Transient pool, and
>> whether or not your "shortlived" parameter, or default grace value
>> needs to be adjusted. Even if you do determine you need to do some
>> things differently here that will prevent the Transient pool from
>> growing beyond your ideal limit, IMO it's a good idea to keep this
>> limited anyway.
>>
> Hi Mark,
>
> I took a look into ttl < 10s objects and saw that they are requests we
> intentionally apply either "max-age=0, private" or "no-cache, private"
> to. However their storage field is still "malloc Transient", and
> transient storage usage only appears to be going up.
>
> Any ideas how to investigate further?
>
> It's varnish 5.0.0-1, and this didn't happen with 4.1, thought there
> may well have been configuration changes since then.
>
> Regards,
>
> --
> Niall

Hi Niall,

It's not clear if you actually wish to cache these requests.

The best way to proceed would be to look at the output of varnishlog for a
few sample requests, and see what the values are for the "TTL" log entry,
and make sure they match the desired settings/behavior. Not that if you
change TTL/grace/keep settings during the request, there will be multiple
entries in the log. Here's a sample entry for an object that was not
cached:

-- TTL VCL 0 0 0 1480436502

Best,
-=Mark

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Transient storage killing memory [ In reply to ]
> I took a look into ttl < 10s objects and saw that they are requests we
> intentionally apply either "max-age=0, private" or "no-cache, private"
> to. However their storage field is still "malloc Transient", and
> transient storage usage only appears to be going up.

Transient storage is used for short-lived object, but also for pass'ed
transactions. The storage is freed when the response is consumed by
the client.

Which counters appears to only go up?

> Any ideas how to investigate further?
>
> It's varnish 5.0.0-1, and this didn't happen with 4.1, thought there
> may well have been configuration changes since then.

It could be caused by a change of behavior from your backend, or a
different access pattern from your clients.

Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Transient storage killing memory [ In reply to ]
On Tue, 29 Nov 2016 11:26:50 -0500
Mark Staudinger <mark.staudinger@nyi.net> wrote:
>
> It's not clear if you actually wish to cache these requests.
>
> The best way to proceed would be to look at the output of varnishlog
> for a few sample requests, and see what the values are for the "TTL"
> log entry, and make sure they match the desired settings/behavior.
> Not that if you change TTL/grace/keep settings during the request,
> there will be multiple entries in the log. Here's a sample entry for
> an object that was not cached:
>
> -- TTL VCL 0 0 0 1480436502
>

Hi,

I've observed that the requests I don't want to cache have ttl and
max-age = 0 as intended, but that they're stored in transient storage
regardless.

"Hit-For-Pass is now actually Hit-For-Miss"
https://varnish-cache.org/docs/5.0/whats-new/changes-5.0.html

I don't understand the finer repercussions of this but I thought it
would result in less transient storage, not more.

Also I have

if ( beresp.http.Pragma ~ "no-cache" || beresp.http.Cache-Control ~
"no-cache" || beresp.http.Cache-Control ~ "private") {
set beresp.uncacheable = true;
set beresp.ttl = 120s;
return (deliver);
} else {
unset beresp.http.set-cookie;
}

in vcl_backend_response. So i'm wondering if .uncacheable even applies
to transient storage.

Despite the counters going up, "varnishlog -q HitPass" returns nothing.

--
Niall Murphy
System Engineer

Telefon: +49 30 / 92 10 64-23
Telefax: +49 30 / 92 10 64-323

SPARWELT GmbH
Wöhlertstr. 12-13
10115 Berlin

SPARWELT Webseiten:
www.sparwelt.de - www.deals.de - www.promoszop.pl

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Transient storage killing memory [ In reply to ]
On Tue, 29 Nov 2016 11:26:50 -0500
Mark Staudinger <mark.staudinger@nyi.net> wrote:
>
> It's not clear if you actually wish to cache these requests.
>
> The best way to proceed would be to look at the output of varnishlog
> for a few sample requests, and see what the values are for the "TTL"
> log entry, and make sure they match the desired settings/behavior.
> Not that if you change TTL/grace/keep settings during the request,
> there will be multiple entries in the log. Here's a sample entry for
> an object that was not cached:
>
> -- TTL VCL 0 0 0 1480436502
>

Hi,

I've observed that the requests I don't want to cache have ttl and
max-age = 0 as intended, but that they're stored in transient storage
regardless.

"Hit-For-Pass is now actually Hit-For-Miss"
https://varnish-cache.org/docs/5.0/whats-new/changes-5.0.html

I don't understand the finer repercussions of this but I thought it
would result in less transient storage, not more.

Also I have

if ( beresp.http.Pragma ~ "no-cache" || beresp.http.Cache-Control ~
"no-cache" || beresp.http.Cache-Control ~ "private") {
set beresp.uncacheable = true;
set beresp.ttl = 120s;
return (deliver);
} else {
unset beresp.http.set-cookie;
}

in vcl_backend_response. So i'm wondering if .uncacheable even applies
to transient storage.

Despite the counters going up, "varnishlog -q HitPass" returns nothing.


_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Transient storage killing memory [ In reply to ]
On Tue, 29 Nov 2016 17:32:17 +0100
Dridi Boukelmoune <dridi@varni.sh> wrote:

> > I took a look into ttl < 10s objects and saw that they are requests
> > we intentionally apply either "max-age=0, private" or "no-cache,
> > private" to. However their storage field is still "malloc
> > Transient", and transient storage usage only appears to be going
> > up.
>
> Transient storage is used for short-lived object, but also for pass'ed
> transactions. The storage is freed when the response is consumed by
> the client.
>
> Which counters appears to only go up?
>
SMA.s0.c_req 210375 2.65 Allocator requests
SMA.s0.c_fail 0 0.00 Allocator failures
SMA.s0.c_bytes 976439262 12317.58 Bytes allocated
SMA.s0.c_freed 888098949 11203.19 Bytes freed
SMA.s0.g_alloc 22425 . Allocations outstanding
SMA.s0.g_bytes 88340313 . Bytes outstanding
SMA.s0.g_space 698091687 . Bytes available
SMA.Transient.c_req 622804 7.86 Allocator requests
SMA.Transient.c_fail 0 0.00 Allocator failures
SMA.Transient.c_bytes 2780556626 35076.15 Bytes allocated
SMA.Transient.c_freed 2224419585 28060.60 Bytes freed
SMA.Transient.g_alloc 337153 . Allocations outstanding
SMA.Transient.g_bytes 556137041 . Bytes outstanding
SMA.Transient.g_space 0 . Bytes available

Transient I thought but it appears it _is_ being freed at least, but
it's unusually large compared to s0 when you consider only 7% of
requests have a ttl < shortlived wouldn't you say?

Synthetic error responses are low, but hit-pass (return(miss) in v5)
are high:

MAIN.client_req 597833 7.52 Good client requests received
MAIN.cache_hit 289103 3.64 Cache hits
MAIN.cache_hitpass 284475 3.58 Cache hits for pass
MAIN.cache_miss 307426 3.87 Cache misses

But I only tell varnish to miss on the above 7%.

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