vmod_var memory alloc assert -> panic again
Guillaume Quintard
guillaume at varnish-software.com
Mon Jul 23 22:20:53 UTC 2018
Hi Tom,
You ran out of workspace ("OVERFLOWED") so you can try to double the
client_workspace parameter and see if that helps.
Note that it's not really a vmod_var issue, you just happen to have big
requests (should you be publishing such cookies, by the way?) and vmod_var
was the straw that broke the camel's back. If you do a lot of regex
manipulations that will count against the workspace, specially when
operating on long strings.
as to your original question about debugging, I may have something for you
if you are ready for some inline C!
First thing first, run varnishd with "-p vcc_allow_inline_c=true", or use
"varnishadm param.set vcc_allow_inline_c true".
Then the real fun begin, we need to tell the vcl shared library about the
ws struct layout and the VSLb function because it usually doesn't know
about these. Place this near the top of your vcl:
C{
struct ws {
unsigned magic;
#define WS_MAGIC 0x35fac554
char id[4]; /* identity */
char *s; /* (S)tart of buffer */
char *f; /* (F)ree/front pointer */
char *r; /* (R)eserved length */
char *e; /* (E)nd of buffer */
};
void VSLb(struct vsl_log *vsl, int, const char *fmt, ...);
}C
Then, whenever you need it, use this line:
C{ VSLb(ctx->vsl, 1, "WS: %ld %ld", ctx->ws->f - ctx->ws->s, ctx->ws->e -
ctx->ws->s); }C
that'll get you a VSL line in varnishlog looking like this:
1001 Debug c WS: 96 57328
First number is the used amount of space, and the second one the total
amount.
You can use "varnishlog -q 'Debug:WS[1] > 1000.0' " to filter logs that are
using a bit too much workspace (don't forget to compare to a float, that's
one quirk of the vsl-query language (man vsl-query for more info)). You can
also use varnishncsa with "-F '%{VSL:Debug:WS[1]}x ' " to log just the
field you want.
Hope that helps.
--
Guillaume Quintard
On Mon, Jul 23, 2018 at 12:27 AM, Anheyer, Tom <Tom.Anheyer at berlinonline.de>
wrote:
> Hello,
> In the last few days we observe some cache resets. These are triggered by
> mod_var while allocation memory. I have seen different bug reports
> regarding to this issue in the last years but no stable solution.
>
> We use varnish 6.0, varnish_modules 0.15 with the default workspace
> settings.
>
> Is their a way to debug the workspace memory usage?
> Any other solution?
>
> Panic at: Sat, 21 Jul 2018 07:28:58 GMT
> Assert error in vh_get_var_alloc(), vmod_var.c line 112:
> Condition((v) != 0) not true.
> version = varnish-6.0.0 revision a068361dff0d25a0d85cf82a6e5fdaf315e06a7d, vrt api = 7.0
> ident = Linux,4.4.0-130-generic,x86_64,-junix,-smalloc,-sdefault,-hcritbit,epoll
> now = 1355228.763723 (mono), 1532158138.334678 (real)
> Backtrace:
> 0x438fb8: /usr/sbin/varnishd() [0x438fb8]
> 0x495e50: /usr/sbin/varnishd(VAS_Fail+0x40) [0x495e50]
> 0x7fbf837bc244: ./vmod_cache/_vmod_var.DILAEPESJTTNHFSZENLGFJXNZZCJCQJX(+0x1244) [0x7fbf837bc244]
> 0x7fbf837bc27e: ./vmod_cache/_vmod_var.DILAEPESJTTNHFSZENLGFJXNZZCJCQJX(vmod_set_string+0x2e) [0x7fbf837bc27e]
> 0x7fbf884913e8: vcl_git-6b53c70-Tom-Anheyer-2018-07-21-080805-0200.1532153312.713054419/vgc.so(VGC_function_vcl_recv+0x3e8) [0x7fbf884913e8]
> 0x4489eb: /usr/sbin/varnishd() [0x4489eb]
> 0x44b60a: /usr/sbin/varnishd(VCL_recv_method+0x5a) [0x44b60a]
> 0x43d006: /usr/sbin/varnishd(CNT_Request+0x876) [0x43d006]
> 0x45f0b7: /usr/sbin/varnishd() [0x45f0b7]
> 0x4553bf: /usr/sbin/varnishd() [0x4553bf]
> thread = (cache-worker)
> thr.req = 0x7fbf80017020 {
> vxid = 262146, transport = HTTP/1 {
> state = HTTP1::Proc
> }
> step = R_STP_RECV,
> req_body = R_BODY_NONE,
> restarts = 0, esi_level = 0,
> sp = 0x7fbf8000e220 {
> fd = 47, vxid = 262145,
> t_open = 1532158138.334194,
> t_idle = 1532158138.334194,
> ws = 0x7fbf8000e260 {
> id = \"ses\",
> {s, f, r, e} = {0x7fbf8000e298, +96, (nil), +352},
> },
> transport = HTTP/1 {
> state = HTTP1::Proc
> }
> client = 212.45.XXX.XXX 55442 :8080,
> },
> worker = 0x7fbf8bc41de0 {
> ws = 0x7fbf8bc41e88 {
> id = \"wrk\",
> {s, f, r, e} = {0x7fbf8bc41190, +0, (nil), +2040},
> },
> VCL::method = inside RECV,
> VCL::return = 0x0,
> VCL::methods = {RECV},
> },
> ws = 0x7fbf80017168 {
> OVERFLOWED id = \"Req\",
> {s, f, r, e} = {0x7fbf80019098, +57176, (nil), +57184},
> },
> http_conn = 0x7fbf80019038 {
> fd = 47 (@0x7fbf8000e244),
> doclose = NULL,
> ws = 0x7fbf80017168 {
> [Already dumped, see above]
> },
> {rxbuf_b, rxbuf_e} = {0x7fbf80019098, 0x7fbf8001b034},
> {pipeline_b, pipeline_e} = {(nil), (nil)},
> content_length = -1,
> body_status = none,
> first_byte_timeout = 0.000000,
> between_bytes_timeout = 0.000000,
> },
> http[req] = 0x7fbf80017208 {
> ws = 0x7fbf80017168 {
> [Already dumped, see above]
> },
> hdrs {
> \"GET\",
> \"/…\",
> \"HTTP/1.1\",
> \"Accept-Encoding: gzip\",
> \"Accept: text/html,application/xhtml+xml,application/xml&q=0.9,*/*&q=0.8\",
> \"User-Agent: Mozilla/5.0 (compatible& Googlebot/2.1& +http://www.google.com/bot.html)\",
> \"Connection: keep-alive\",
> \"X-Remote-IP: 82.208.XXX.XXX\",
> \"X-SSL: no\",
> \"X-Forwarded-For: 212.45.XXX.XXX\",
> \"host: www.berlin.de\ <http://www.berlin.de%5C>",
> \"x-portal: www.berlin.de\ <http://www.berlin.de%5C>",
> \"X-Forwarded-Host: www.berlin.de\ <http://www.berlin.de%5C>",
> \"x-url: …\",
> \"X-Mobile: desk\",
> \"X-Forwarded-Port: 80\",
> \"X-Forwarded-Proto: http\",
> \"Cookie: DIY_SB=c3530564fad93659f2f381b0be9ba124; PHPSESSID=4f6ki8op43osu4b9i3gsri8g44; 69d3d602ff4d8aeb8f60fc3b111b8dcb=qp65g3okau0jna3h3ipcb5ss27; sid_1_1=a2aea5b171f159bd141fea5e2a9876d7; 8a07c13c411d47270329ee26b294320b=d1a6b8a1c34cd241d0df2762aaee1c17; ApplicationSessionId=fomikuvly3m45i34ycccxxw1; XTCsid=5aeb6d0fb32ccbaa221e2d71eef4dfab; zenid=deleted; session_id=517dc3b73d2a0232f7e7abe3975afb9e; TS01e85bed=01f0e93131a920f276c4ca6385e1aa503fb79a7b35d2098d70e1540b901273ef765d2411e24388b3b8fe030ea928c6ce8810eb726b; partnercode=0WEB; cookie_sec_light=\"\"; JSESSIONID=b230c635a84a1b47fbae19315f24d6a6b365; wishlist=\"\"; ARRAffinity=16a848b5f90db731fac8fe06b5f590dc1b20d0a1465ab9ae168f20b50b1b57bf; language=de-DE; fe_typo_user=66762b4fbff79343198fdfd631c08604; CMSSESSID2c33ccce182f=bccdeaf299cb6bb1ad2c1470e89b0f5f; 2a212043be0c0d476ce384c4dc2b3919=ksvetn2n6m54fnkgqj6vqa3k25; wpml_referer_url=https%3A%2F%2Fwww.triology.de%2Fde%2Freferenzen%2F; 9a4441501cf60b2de9ba5cec4695c188=3a56125bb771baf555826aaa44a67ec7; 6b134e99f4d4cef48239b38f5758fe7d=7c4d05901996da83adff9ee69b6ed2df; 4b960974e614a0d3a9f20e59c2075c23=1eb99e3a97589e7ba72d9f5ec024bccb; com.osiris4.core.Session.id=n82oqxbn3j4wajw9neb3; AL_SESS=AWlGhb3avIwrjuW_fJ_rh11opqwITRB0fdherNdq!oBRyxNx5LFqq_hpPq5fqFAKWH3A; is_mobile=0; sesam=jpcs9aq36qnul8sbns7vaj9ki6; frontend=77eoj47mufttd9cib7bguqjup3; .ASPXANONYMOUS=Pqm8q0tX1AEkAAAAZTdmMjdjNjYtYmMzYS00OWNjLWEwMjUtYzU1MGZjYzE3YTgw0; 4f585ad2d5bdfe8ff86e8dc498e26b8e=353e98d12ce4e7205311501b44dc784a; b9bf211d110c68ea40923af089e21e82=7b8b35d8a6f48b91960354c46ba94280; c035397e6f167b4df4c75737b46c145a=8lhshhho0b87f5u7mc26f89ff3; 8e7c036c46e1fe56d7b28223dfa9a8ca=2hl7vhlbgrss9vghegej5o2735; redirect_count=deleted; pll_language=de; laravel_session=qEeiUR3JWC9KLSEX7Z6oluEoe57aTUOsuLY1LHaG; ea83195f696e334c6155a605755c74be=f9fb404719cd27d44a918c307a4e4d35; c9d4ec90c55ce9b84c3fe44ca36925ab=7ea3a8a036c33119a5686ae58fe82f7e; 6d90de649030d0c32121458eafb460e6=89d2b89bce738e282d5bcdb61ea6629b; CONCRETE5=hn3abpfuupffmmm8p2405ln1b0; SimpleSAMLSessionID=128f7200ab3f8a638e3a8ec17d2a31e8; OJSSID=i40auksitjk9kcf1cj04tmg6a5; H_ITServ=mkv-gmbh.de#_aq2iurcv01k7jp7l4bc46135fs7; bf234a8af86033b1d02b6020cf5bb1b4=6981173e39e8a8d5d42780e273f6effa; SERVERID=wsap01; qtrans_front_language=de; mc_session_ids[multi][4]=dc0c2edd45c690dd65bb1c6a877ef52ad21978c2; mc_session_ids[multi][3]=9fa713410685d2f830dcac2befcb84105672724f; mc_session_ids[multi][2]=a9cf913eeca6711f5be36073348b484a39a76896; mc_session_ids[multi][1]=50af451ebc7dbefe5a26bd83cfdb4b7202cd56d2; mc_session_ids[multi][0]=135a4d446a0d7afa9c4015d90c1caa29a3b48dd1; mc_session_ids[default]=fc5c1339a787744f34b0b7d177b687c75c3f0b17; 8a36a9c9b1ae1ace69f9cbdcaec78f33=1hm5oshvd1rr3bqlt7hk8sa8b0; 67d7a8d8a508ace72eb96b11c1782ffd=63572a9cde154998ddd065a9ea4873be; f928b95a74589147afe5be4aeac0cf49=52432013dd5bf7a5521f84673b5419a9; f410342c31674a2a8a3fbe74704a36fe=aus9gcaldp347dgrv66ts1nag2; twp_session=6cca4650dfdc006078dbc236f253d4c6%7C%7C1532156662%7C%7C1532156302; fa6e138f925b8043a248e80087041649=2b45dc651f753abd3c81006111963875; a382e8ca43069b5cf2b1b71f8eac89b4=g81sa2b55lpng4r10mvkcacukq; wfvt_735686928=5b52d4372aeb9; lep7313sessionid=eb8cd8c85d981ba50491aa0925097860; 1639f822b2be4182f813e5edf85d7073=26726be64951f9926bf3ebde486e4c9e; ASP.NET_SessionId=yyj5rxmfi1zzfwdgy31e1dwn; EDEKA_LB=!/dvYru6LRnuYw8TBsfFthSBJVmbY57eqp+gDw2y8HCjwZd2xCHQ2taQUTmg/JrYMwWyL0cZ2ZXgGvqI=; session-1=13db08707f29b6ebb464ab9ce5714b208fe3a1f55eb398ecae8ef47e8f5b27df; b2d803b5335cdd46894231755923376c=e65941b22836ba608d2fd448ecf10888; I18N_LANGUAGE=\"de\"; a8d276248bbf1f591982252b40a661e1=7pb42flqokqn9ujeeidol59lk5; a5cfece4c5a67dda207ed8d080f8650c=9615f50ab2eae2aeab6215a711499646; 97aca91d7e78e476bf5438d76096b56b=ri80n755erjib0sr61b5it9o52; GaClientId=59b9e349-be7d-4d0d-a9fa-f83506a15c6b; flow_shop=3ec5e6a4005c826081e7f3b80c9cf586; cf7msm_check=1; userFrontendLangId=deleted; dccf082880fecab12971ba47a1c05c29=3b9674f8e102dba87543604fe5ce83e4; CMSPreferredCulture=en-029; 69ae9c5ca3430a65137c01159d69ad70=680762ad8dabdafc2beaf7aee775d61c; session=e9ddf1fc75de1c2651998fdff2441d93; eb6e65597a6a546bdd691711688022fb=1fsdnaf9u5ovu8doen59ca4d63; CMSCsrfCookie=gOoQSS+fd/++qQBQwOldZQjYeFLgOcrR8rVRydgg; 4069b6a736f2df9d9ed9ab3724f75428=ec1f0a9b81c2a31bc7d545d78b05f233; 712239bbb2669c7f510dce1e4353635b=da480fb4746d485e8f5f42eb4ba49909; blotenberg=afef15818d408ed9b51172de84d6fd98; AWSALB=4XFZ05jCCqAxq9FLrKvXMqUFsZ1dxp3kKnOTpZsRIhmOp2L7Yvj/ScBHpgDim2QfohYIFnVNa3SSDwlMW1lv5R3GwO+IsN1FDklxDLvqkclNc0U6HUteTQYxcnpO; 23c53be91f1cac691db4f6dc7ed2ae3c=c087ae481aa6bec69cc06d5bad569033; ci_session=a%3A4%3A%7Bs%3A10%3A%22session_id%22%3Bs%3A32%3A%22033a040176e2b4b29e530e1707528d1f%22%3Bs%3A10%3A%22ip_address%22%3Bs%3A14%3A%2282.208.160.181%22%3Bs%3A10%3A%22user_agent%22%3Bs%3A50%3A%22Mozilla%2F5.0+%28compatible%26+Googlebot%2F2.1%26+%2Bhttp%3A%2F%2Fww%22%3Bs%3A13%3A%22last_activity%22%3Bs%3A10%3A%221532156304%22%3B%7D1a6e2fd3071a7ba00271cdeb3e951bc2; 4e14f0f9e4d726f6edf4c9ebf796016d=355c1d780ebf1862124c980437c7da5a; ASPSESSIONIDQSQCDTBR=PIKPJCGBIFPCCHLGOPLBCNPH; 6989fede777391f26c0e595280bad2a0=7rpmn87ud7cbfcqd9v4l5efns7; NSC_L-0-65_80=ffffffff09e2cc5045525d5f4f58455e445a4a423660; 7ff64242f5ae6d774854212cf8666f77=6tttkst36lki1ea31s6vnk8da5; 133649766b2e2b53c635efea21953378=adc8333e6f6dd987b401263336b52700; TraminoCartSession=DBNp7TBrDJUrwyxNDPq; wordpress_lp_guest=ca37be337e00ee36d9f4b4f4f1711432; wp_learn_press_session_6e9bc03fc841319b6726c68a9aced716=2564da945b1690545422d9cb57b983f3%7C%7C1532329503%7C%7C7505717ac290302bde58847fd8f407ed; cabcfe0d73fd9eb3351ac3221af94e8c=edg34f9o2sjcpd2glqgv0ekal3; fe67ac19ab79a006ccb7fb25019bb38e=8479c8943f644bd0b306a4338f249547; JTLSHOP=ncp3jqnnk5s4ivkj9o2unctug4; 67f80beba5ad09e24ce8ad8db3927fbe=fc453e89b37fdec1c855df54927e2b79; beb453be7f14188ad12f432189419602=06be9ade8f0394e624013c7422b8f9c0; ASPSESSIONIDSWBCTCTR=BFDIEKGBCKMMDCKEFGCPAJBD; 8fe13cc2eb5590453da1b688ac870ed7=vq1qini7q6lfu5dlc67a122e0t; 073080493419c5c0e89964ee2bce49f2=3fcf949a4c6d72572a9006244c29029f; 5c0483c4110ea1ef92bfeea4b966e026=ececdad10ac6e1595db12fcf274b0ab6; CAKEPHP=8mc3gf56a5peibrun1374ef6f7; d2b6f6c6b5b08d0cac6fe65467ad418a=0a51d57499122dd58e12bc7aaeaf408b; BIGipServer~ASP~asp-common_80=rd3010o00000000000000000000ffff0a0a112ao80; f5b48d5f7dafd69a88287a9fc5a4dc39=pf9gb7rtog9mdu21fb9gnbddu2; 202775b2c81c14b657a48eda0763a87c=adbecdc27bed71916a6da1b8b39425aa; cookiesession1=6683AFC0OMAAWSQDLO13M0RBBOMZE704; ASPSESSIONIDSQTQASRA=HCIEKAEBJOFKAOJEJIFIIJAO; ASPSESSIONIDSUTQASRA=ICIEKAEBCMHLDAEBNEBHECNK; AWSELB=CB7D399B1E0EF9A7E9C544E32A45733DA532498A3754D3527BCB7BFDBEE825A0B702413A33C40FDC528E7B73F41410AFD657F852033EEB8A6A62BE346EC9A6C6BD74C28A35; HASSESSIONSCOPE=0; SESSIONSCOPETESTED=0; REDIRECTOR=dr2; pal=de; e68e769bd79f2af0caa6501613059c0f=faf5d566fe5a2d4991c74f8341b0f359; 4d22477e6616204b89f427bcfcbf6d57=311gbi01rnl6qq414sc4am9926; index_is_shown=1; c5bd7f6431fe230edaf4b9a93751a686=n753jcprn2vfhvb5ajcgk0fvj5; b770ad4bc12ababbdecc5e98a4095983=f480990fe9ae33a2b28c1f0d48ebcd11; e96d6a117eb3531698183d02aed1fefb=e7e94b47e67ab79804f0848f04878dbc; django_language=de\",
> },
> },
> vcl = {
> name = \"git-6b53c70-Tom-Anheyer-2018-07-21-080805-0200\",
> busy = 23,
> discard = 0,
> state = auto,
> temp = warm,
> conf = {
> srcname = {
> \"/etc/varnish/vcl.conf\",
> \"Builtin\",
> …
> },
> },
> },
> vmods = {
> std = {Varnish 6.0.0 a068361dff0d25a0d85cf82a6e5fdaf315e06a7d, 0.0},
> cookie = {Varnish 6.0.0 a068361dff0d25a0d85cf82a6e5fdaf315e06a7d, 7.0},
> directors = {Varnish 6.0.0 a068361dff0d25a0d85cf82a6e5fdaf315e06a7d, 0.0},
> vsthrottle = {Varnish 6.0.0 a068361dff0d25a0d85cf82a6e5fdaf315e06a7d, 7.0},
> var = {Varnish 6.0.0 a068361dff0d25a0d85cf82a6e5fdaf315e06a7d, 7.0},
> },
> flags = {
> },
> privs = 0x7fbf800171f0 {
> priv {p 0x7fbf80027040 l 0 f 0x7fbf837bc0e0} vcl 0x7fbf930d7480 id 7fbf80017020 vmod 7fbf886dac88
> priv {p 0x7fbf80027060 l 0 f 0x7fbf85dfc400} vcl 0x7fbf930d7480 id 7fbf80017020 vmod 7fbf886daf08
> },
> },
> thr.busyobj = (nil) {
> },
>
>
> Thanks in advance
>
> tom anheyer
> --
>
> Tom Anheyer
> Entwicklung & Technik
>
> BerlinOnline Stadtportal GmbH & Co. KG
> Alte Jakobstraße 105
> 10969 Berlin
> Germany
>
> Tel.: +49 30 2327-5210
> Fax: +49 30 2327-5596
> E-Mail: tom.anheyer at berlinonline.de
> berlin.de <https://www.berlin.de> | berlinonline.net <https://www.berlinonline.net>
>
> Amtsgericht Berlin-Charlottenburg, HRA 31951
> Sitz der Gesellschaft: Berlin, Deutschland
> Geschäftsführer: Olf Dziadek
> USt-IdNr.: DE219483549
>
> Persönlich haftender Gesellschafter:
> BerlinOnline Stadtportalbeteiligungsgesellschaft mbH
> Amtsgericht Berlin-Charlottenburg, HRB 79077
> Sitz der Gesellschaft: Berlin, Deutschland
> Geschäftsführer: Olf Dziadek
>
> Eine Beteiligung von DuMont Berliner Verlag
>
>
> _______________________________________________
> varnish-misc mailing list
> varnish-misc at varnish-cache.org
> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20180723/95418fdf/attachment-0001.html>
More information about the varnish-misc
mailing list